Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Rewrite_Tag is causing significant memory spike when upstream connectivity is lost #4049

Closed
utkmishr opened this issue Sep 3, 2021 · 11 comments · Fixed by #4128 · May be fixed by #4357
Closed

Rewrite_Tag is causing significant memory spike when upstream connectivity is lost #4049

utkmishr opened this issue Sep 3, 2021 · 11 comments · Fixed by #4128 · May be fixed by #4357

Comments

@utkmishr
Copy link

utkmishr commented Sep 3, 2021

Bug Report

Describe the bug
When using Rewrite_Tag in my configuration I am seeing significant memory spike . Observed this when remote upstream connectivity is lost and Retry_Limit is set as False. I have set Mem_Buf_Limit as 5mb

To Reproduce

Expected behavior
on reaching Mem_Buf_Limit (5mb) the plugin should pause and should not cause the memory spike.

Screenshots
image

Your Environment

  • Version used: Fluent-Bit : 1.7.0 ( and also in 1.8.4 )
  • Configuration: - attached above
  • Environment name and version (e.g. Kubernetes? What version?): 1.15
  • Server type and version:
  • Operating System and version: ubuntu :18.04
  • Filters and plugins: attached configuration above

Additional context
Issue exists in both 1.7.0 and 1.8.4

@utkmishr
Copy link
Author

@edsiper we are really stuck on that ... any help is appreciated ... please let me know if you need more details on it.

@utkmishr
Copy link
Author

Also have captured some details by running Massif with Valgrind
The Mem_Buf_Limit is 15 MB in my configuration

--------------------------------------------------------------------------------
Command:            bin/fluent-bit -c etc/fluent-bit.conf
Massif arguments:   (none)
ms_print arguments: massif.out.30
--------------------------------------------------------------------------------


    MB
295.6^                                                                    #   
     |                                                                    #:::
     |                                                                    #:::
     |                                                                    #:::
     |                                                                    #:::
     |                                                                    #:::
     |                                                                    #:::
     |                                                                    #:::
     |                                                                    #:::
     |                                                             ::::::@#:::
     |                                      :::@:::::@:::::::::::::: ::: @#:::
     |                                      : :@: :: @: : : : :: ::: ::: @#:::
     |                                      : :@: :: @: : : : :: ::: ::: @#:::
     |                                      : :@: :: @: : : : :: ::: ::: @#:::
     |                      @::::::::::::::@: :@: :: @: : : : :: ::: ::: @#:::
     |                      @::: ::: ::: ::@: :@: :: @: : : : :: ::: ::: @#:::
     |               :::::::@::: ::: ::: ::@: :@: :: @: : : : :: ::: ::: @#:::
     |          :    : ::: :@::: ::: ::: ::@: :@: :: @: : : : :: ::: ::: @#:::
     |    :::::::::::: ::: :@::: ::: ::: ::@: :@: :: @: : : : :: ::: ::: @#:::
     |  ::: :: ::: : : ::: :@::: ::: ::: ::@: :@: :: @: : : : :: ::: ::: @#:::
   0 +----------------------------------------------------------------------->Gi
     0                                                                   143.4

Number of snapshots: 57
 Detailed snapshots: [17, 29, 32, 36, 49, 52 (peak)]

--------------------------------------------------------------------------------
  n        time(i)         total(B)   useful-heap(B) extra-heap(B)    stacks(B)
--------------------------------------------------------------------------------
  0              0                0                0             0            0
  1  2,885,371,100       13,632,152       13,503,480       128,672            0
  2  5,638,993,326       20,485,824       20,355,899       129,925            0
  3  7,395,155,951       25,022,208       24,891,012       131,196            0
  4 10,390,687,873       31,915,512       31,783,068       132,444            0
  5 13,152,093,296       41,989,216       41,855,417       133,799            0
  6 16,066,527,308       42,213,016       42,075,636       137,380            0
  7 19,983,808,981       39,183,600       39,046,837       136,763            0
  8 23,249,862,881       48,188,176       48,051,047       137,129            0
  9 25,528,323,197       42,684,728       42,547,621       137,107            0
 10 28,434,738,230       44,465,576       44,328,245       137,331            0
 11 32,190,085,417       61,908,400       61,770,481       137,919            0
 12 33,862,870,611       62,988,024       62,850,081       137,943            0
 13 36,951,613,961       63,904,520       63,766,060       138,460            0
 14 39,291,167,079       63,913,608       63,774,877       138,731            0
 15 42,633,861,230       65,215,256       65,074,082       141,174            0
 16 45,570,071,098       66,184,584       66,043,224       141,360            0
 17 47,173,981,890       99,782,232       99,640,811       141,421            0
99.86% (99,640,811B) (heap allocation functions) malloc/new/new[], --alloc-fns, etc.
->70.49% (70,336,512B) 0x26937F: msgpack_sbuffer_write (sbuffer.h:81)
| ->70.49% (70,336,512B) 0x2699D2: in_emitter_add_record (emitter.c:114)
|   ->70.49% (70,336,512B) 0x3197B2: process_record (rewrite_tag.c:331)
|     ->70.49% (70,336,512B) 0x319961: cb_rewrite_tag_filter (rewrite_tag.c:382)
|       ->70.49% (70,336,512B) 0x21C5DA: flb_filter_do (flb_filter.c:118)
|         ->70.49% (70,336,512B) 0x24EB92: flb_input_chunk_append_raw (flb_input_chunk.c:832)
|           ->70.49% (70,336,512B) 0x26EC76: process_content (tail_file.c:358)
|             ->70.49% (70,336,512B) 0x270B70: flb_tail_file_chunk (tail_file.c:981)
|               ->70.41% (70,254,592B) 0x26A533: in_tail_collect_static (tail.c:140)
|               | ->70.41% (70,254,592B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|               |   ->70.41% (70,254,592B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|               |     ->70.41% (70,254,592B) 0x210702: flb_lib_worker (flb_lib.c:493)
|               |       ->70.41% (70,254,592B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|               |         ->70.41% (70,254,592B) 0x6E0F71D: clone (clone.S:95)
|               |           
|               ->00.08% (81,920B) in 1+ places, all below ms_print's threshold (01.00%)
|               
->11.82% (11,796,480B) 0x517CE6: cio_memfs_open (cio_memfs.c:42)
| ->11.82% (11,796,480B) 0x5134E4: cio_chunk_open (cio_chunk.c:82)
|   ->11.82% (11,796,480B) 0x24DEA2: flb_input_chunk_create (flb_input_chunk.c:407)
|     ->11.82% (11,796,480B) 0x24E4A3: input_chunk_get (flb_input_chunk.c:568)
|       ->11.82% (11,796,480B) 0x24E9E6: flb_input_chunk_append_raw (flb_input_chunk.c:791)
|         ->10.77% (10,747,904B) 0x269A80: cb_queue_chunks (emitter.c:142)
|         | ->10.77% (10,747,904B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|         |   ->10.77% (10,747,904B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|         |     ->10.77% (10,747,904B) 0x210702: flb_lib_worker (flb_lib.c:493)
|         |       ->10.77% (10,747,904B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|         |         ->10.77% (10,747,904B) 0x6E0F71D: clone (clone.S:95)
|         |           
|         ->01.05% (1,048,576B) in 2 places, all below massif's threshold (1.00%)
|           
->08.31% (8,290,304B) 0x517E74: cio_memfs_write (cio_memfs.c:91)
| ->08.31% (8,290,304B) 0x513698: cio_chunk_write (cio_chunk.c:161)
|   ->08.31% (8,290,304B) 0x24D3F9: flb_input_chunk_write (flb_input_chunk.c:67)
|     ->08.31% (8,290,304B) 0x24EAC1: flb_input_chunk_append_raw (flb_input_chunk.c:815)
|       ->08.31% (8,290,304B) 0x269A80: cb_queue_chunks (emitter.c:142)
|         ->08.31% (8,290,304B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|           ->08.31% (8,290,304B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|             ->08.31% (8,290,304B) 0x210702: flb_lib_worker (flb_lib.c:493)
|               ->08.31% (8,290,304B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|                 ->08.31% (8,290,304B) 0x6E0F71D: clone (clone.S:95)
|                   
->04.47% (4,457,538B) 0x217EF4: flb_malloc (flb_mem.h:62)
| ->04.47% (4,457,538B) 0x218113: sds_alloc (flb_sds.c:40)
|   ->04.46% (4,449,218B) 0x21824F: flb_sds_create_size (flb_sds.c:92)
|   | ->04.44% (4,432,221B) 0x217171: flb_msgpack_raw_to_json_sds (flb_pack.c:699)
|   | | ->04.44% (4,429,066B) 0x217A32: flb_pack_msgpack_to_json_format (flb_pack.c:973)
|   | | | ->04.44% (4,429,066B) 0x2B46AB: cb_http_flush (http.c:319)
|   | | |   ->04.44% (4,429,066B) 0x21D778: output_pre_cb_flush (flb_output.h:463)
|   | | |     ->04.44% (4,429,066B) 0x717105: co_init (amd64.c:117)
|   | | |       
|   | | ->00.00% (3,155B) in 1+ places, all below ms_print's threshold (01.00%)
|   | | 
|   | ->00.02% (16,997B) in 1+ places, all below ms_print's threshold (01.00%)
|   | 
|   ->00.01% (8,320B) in 1+ places, all below ms_print's threshold (01.00%)
|   
->02.83% (2,825,008B) 0x26D7EB: flb_malloc (flb_mem.h:62)
| ->02.50% (2,490,368B) 0x26FB25: flb_tail_file_append (tail_file.c:706)
| | ->02.50% (2,490,368B) 0x2745EC: tail_scan_path (tail_scan_glob.c:255)
| |   ->02.50% (2,490,368B) 0x2748AC: flb_tail_scan (tail_scan.c:42)
| |     ->02.50% (2,490,368B) 0x26AAB6: in_tail_init (tail.c:297)
| |       ->02.50% (2,490,368B) 0x21AB31: flb_input_instance_init (flb_input.c:483)
| |         ->02.50% (2,490,368B) 0x21AC0E: flb_input_init_all (flb_input.c:519)
| |           ->02.50% (2,490,368B) 0x22D2EF: flb_engine_start (flb_engine.c:501)
| |             ->02.50% (2,490,368B) 0x210702: flb_lib_worker (flb_lib.c:493)
| |               ->02.50% (2,490,368B) 0x4E3C6D9: start_thread (pthread_create.c:463)
| |                 ->02.50% (2,490,368B) 0x6E0F71D: clone (clone.S:95)
| |                   
| ->00.34% (334,640B) in 1+ places, all below ms_print's threshold (01.00%)
| 
->01.94% (1,934,969B) in 305 places, all below massif's threshold (1.00%)
  
--------------------------------------------------------------------------------
  n        time(i)         total(B)   useful-heap(B) extra-heap(B)    stacks(B)
--------------------------------------------------------------------------------
 18 49,620,721,768      102,811,656      102,670,207       141,449            0
 19 52,556,920,165      100,419,168      100,277,379       141,789            0
 20 55,003,919,589      103,212,464      103,070,227       142,237            0
 21 58,429,234,624      102,777,376      102,634,808       142,568            0
 22 60,525,905,822      103,149,272      103,006,396       142,876            0
 23 63,375,900,780      103,614,664      103,471,259       143,405            0
 24 66,938,134,556      101,236,992      101,093,442       143,550            0
 25 69,788,595,507       98,157,640       98,014,246       143,394            0
 26 72,638,387,551       98,062,304       97,918,959       143,345            0
 27 75,488,925,820       98,303,360       98,159,873       143,487            0
 28 77,626,949,146       98,547,016       98,403,221       143,795            0
 29 80,540,237,616      107,901,752      107,751,307       150,445            0
99.86% (107,751,307B) (heap allocation functions) malloc/new/new[], --alloc-fns, etc.
->65.27% (70,426,624B) 0x26937F: msgpack_sbuffer_write (sbuffer.h:81)
| ->65.27% (70,426,624B) 0x2699D2: in_emitter_add_record (emitter.c:114)
|   ->65.27% (70,426,624B) 0x3197B2: process_record (rewrite_tag.c:331)
|     ->65.27% (70,426,624B) 0x319961: cb_rewrite_tag_filter (rewrite_tag.c:382)
|       ->65.27% (70,426,624B) 0x21C5DA: flb_filter_do (flb_filter.c:118)
|         ->65.27% (70,426,624B) 0x24EB92: flb_input_chunk_append_raw (flb_input_chunk.c:832)
|           ->65.27% (70,426,624B) 0x26EC76: process_content (tail_file.c:358)
|             ->65.27% (70,426,624B) 0x270B70: flb_tail_file_chunk (tail_file.c:981)
|               ->65.12% (70,262,784B) 0x26A533: in_tail_collect_static (tail.c:140)
|               | ->65.12% (70,262,784B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|               |   ->65.12% (70,262,784B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|               |     ->65.12% (70,262,784B) 0x210702: flb_lib_worker (flb_lib.c:493)
|               |       ->65.12% (70,262,784B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|               |         ->65.12% (70,262,784B) 0x6E0F71D: clone (clone.S:95)
|               |           
|               ->00.15% (163,840B) in 1+ places, all below ms_print's threshold (01.00%)
|               
->13.61% (14,680,064B) 0x517CE6: cio_memfs_open (cio_memfs.c:42)
| ->13.61% (14,680,064B) 0x5134E4: cio_chunk_open (cio_chunk.c:82)
|   ->13.61% (14,680,064B) 0x24DEA2: flb_input_chunk_create (flb_input_chunk.c:407)
|     ->13.61% (14,680,064B) 0x24E4A3: input_chunk_get (flb_input_chunk.c:568)
|       ->13.61% (14,680,064B) 0x24E9E6: flb_input_chunk_append_raw (flb_input_chunk.c:791)
|         ->11.90% (12,845,056B) 0x269A80: cb_queue_chunks (emitter.c:142)
|         | ->11.90% (12,845,056B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|         |   ->11.90% (12,845,056B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|         |     ->11.90% (12,845,056B) 0x210702: flb_lib_worker (flb_lib.c:493)
|         |       ->11.90% (12,845,056B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|         |         ->11.90% (12,845,056B) 0x6E0F71D: clone (clone.S:95)
|         |           
|         ->01.70% (1,835,008B) 0x26112E: in_systemd_collect (systemd.c:284)
|         | ->01.70% (1,835,008B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|         |   ->01.70% (1,835,008B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|         |     ->01.70% (1,835,008B) 0x210702: flb_lib_worker (flb_lib.c:493)
|         |       ->01.70% (1,835,008B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|         |         ->01.70% (1,835,008B) 0x6E0F71D: clone (clone.S:95)
|         |           
|         ->00.00% (0B) in 1+ places, all below ms_print's threshold (01.00%)
|         
->07.68% (8,290,304B) 0x517E74: cio_memfs_write (cio_memfs.c:91)
| ->07.68% (8,290,304B) 0x513698: cio_chunk_write (cio_chunk.c:161)
|   ->07.68% (8,290,304B) 0x24D3F9: flb_input_chunk_write (flb_input_chunk.c:67)
|     ->07.68% (8,290,304B) 0x24EAC1: flb_input_chunk_append_raw (flb_input_chunk.c:815)
|       ->07.68% (8,290,304B) 0x269A80: cb_queue_chunks (emitter.c:142)
|         ->07.68% (8,290,304B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|           ->07.68% (8,290,304B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|             ->07.68% (8,290,304B) 0x210702: flb_lib_worker (flb_lib.c:493)
|               ->07.68% (8,290,304B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|                 ->07.68% (8,290,304B) 0x6E0F71D: clone (clone.S:95)
|                   
->03.84% (4,144,694B) 0x217EF4: flb_malloc (flb_mem.h:62)
| ->03.84% (4,144,694B) 0x218113: sds_alloc (flb_sds.c:40)
|   ->03.83% (4,136,353B) 0x21824F: flb_sds_create_size (flb_sds.c:92)
|   | ->03.82% (4,119,467B) 0x217171: flb_msgpack_raw_to_json_sds (flb_pack.c:699)
|   | | ->03.81% (4,116,312B) 0x217A32: flb_pack_msgpack_to_json_format (flb_pack.c:973)
|   | | | ->03.81% (4,116,312B) 0x2B46AB: cb_http_flush (http.c:319)
|   | | |   ->03.81% (4,116,312B) 0x21D778: output_pre_cb_flush (flb_output.h:463)
|   | | |     ->03.81% (4,116,312B) 0x717105: co_init (amd64.c:117)
|   | | |       
|   | | ->00.00% (3,155B) in 1+ places, all below ms_print's threshold (01.00%)
|   | | 
|   | ->00.02% (16,886B) in 1+ places, all below ms_print's threshold (01.00%)
|   | 
|   ->00.01% (8,341B) in 1+ places, all below ms_print's threshold (01.00%)
|   
->03.29% (3,550,480B) 0x6F6D55: msgpack_zone_malloc_expand (zone.c:83)
| ->03.29% (3,550,480B) 0x6F4651: msgpack_zone_malloc (zone.h:121)
|   ->02.39% (2,574,800B) 0x6F4BDD: template_callback_map (unpack.c:259)
|   | ->01.60% (1,722,000B) 0x6F53D7: template_execute (unpack_template.h:233)
|   | | ->01.60% (1,722,000B) 0x6F6AF7: msgpack_unpack_next (unpack.c:677)
|   | |   ->01.60% (1,722,000B) 0x2171C4: flb_msgpack_raw_to_json_sds (flb_pack.c:706)
|   | |   | ->01.60% (1,722,000B) 0x217A32: flb_pack_msgpack_to_json_format (flb_pack.c:973)
|   | |   |   ->01.60% (1,722,000B) 0x2B46AB: cb_http_flush (http.c:319)
|   | |   |     ->01.60% (1,722,000B) 0x21D778: output_pre_cb_flush (flb_output.h:463)
|   | |   |       ->01.60% (1,722,000B) 0x717105: co_init (amd64.c:117)
|   | |   |         
|   | |   ->00.00% (0B) in 1+ places, all below ms_print's threshold (01.00%)
|   | |   
|   | ->00.79% (852,800B) in 1+ places, all below ms_print's threshold (01.00%)
|   | 
|   ->00.90% (975,680B) in 1+ places, all below ms_print's threshold (01.00%)
|   
->02.65% (2,862,130B) 0x26D7EB: flb_malloc (flb_mem.h:62)
| ->02.34% (2,523,136B) 0x26FB25: flb_tail_file_append (tail_file.c:706)
| | ->02.34% (2,523,136B) 0x2745EC: tail_scan_path (tail_scan_glob.c:255)
| |   ->02.34% (2,523,136B) 0x2748AC: flb_tail_scan (tail_scan.c:42)
| |     ->02.31% (2,490,368B) 0x26AAB6: in_tail_init (tail.c:297)
| |     | ->02.31% (2,490,368B) 0x21AB31: flb_input_instance_init (flb_input.c:483)
| |     |   ->02.31% (2,490,368B) 0x21AC0E: flb_input_init_all (flb_input.c:519)
| |     |     ->02.31% (2,490,368B) 0x22D2EF: flb_engine_start (flb_engine.c:501)
| |     |       ->02.31% (2,490,368B) 0x210702: flb_lib_worker (flb_lib.c:493)
| |     |         ->02.31% (2,490,368B) 0x4E3C6D9: start_thread (pthread_create.c:463)
| |     |           ->02.31% (2,490,368B) 0x6E0F71D: clone (clone.S:95)
| |     |             
| |     ->00.03% (32,768B) in 1+ places, all below ms_print's threshold (01.00%)
| |     
| ->00.31% (338,994B) in 1+ places, all below ms_print's threshold (01.00%)
| 
->01.94% (2,097,152B) 0x2156ED: msgpack_sbuffer_write (sbuffer.h:81)
| ->01.94% (2,097,152B) 0x6F2B81: msgpack_pack_str_body (pack_template.h:784)
| | ->01.94% (2,097,152B) 0x6F2FFA: msgpack_pack_object (objectc.c:68)
| |   ->01.94% (2,097,152B) 0x217815: flb_pack_msgpack_to_json_format (flb_pack.c:896)
| |   | ->01.94% (2,097,152B) 0x2B46AB: cb_http_flush (http.c:319)
| |   |   ->01.94% (2,097,152B) 0x21D778: output_pre_cb_flush (flb_output.h:463)
| |   |     ->01.94% (2,097,152B) 0x717105: co_init (amd64.c:117)
| |   |       
| |   ->00.00% (0B) in 1+ places, all below ms_print's threshold (01.00%)
| |   
| ->00.00% (0B) in 1+ places, all below ms_print's threshold (01.00%)
| 
->01.58% (1,699,859B) in 303 places, all below massif's threshold (1.00%)
  
--------------------------------------------------------------------------------
  n        time(i)         total(B)   useful-heap(B) extra-heap(B)    stacks(B)
--------------------------------------------------------------------------------
 30 83,303,409,267      169,465,552      169,321,721       143,831            0
 31 86,153,998,916      169,446,792      169,302,873       143,919            0
 32 88,291,336,362      169,936,832      169,792,676       144,156            0
99.92% (169,792,676B) (heap allocation functions) malloc/new/new[], --alloc-fns, etc.
->80.93% (137,535,488B) 0x26937F: msgpack_sbuffer_write (sbuffer.h:81)
| ->80.93% (137,535,488B) 0x2699D2: in_emitter_add_record (emitter.c:114)
|   ->80.93% (137,535,488B) 0x3197B2: process_record (rewrite_tag.c:331)
|     ->80.93% (137,535,488B) 0x319961: cb_rewrite_tag_filter (rewrite_tag.c:382)
|       ->80.93% (137,535,488B) 0x21C5DA: flb_filter_do (flb_filter.c:118)
|         ->80.93% (137,535,488B) 0x24EB92: flb_input_chunk_append_raw (flb_input_chunk.c:832)
|           ->80.93% (137,535,488B) 0x26EC76: process_content (tail_file.c:358)
|             ->80.93% (137,535,488B) 0x270B70: flb_tail_file_chunk (tail_file.c:981)
|               ->80.84% (137,371,648B) 0x26A533: in_tail_collect_static (tail.c:140)
|               | ->80.84% (137,371,648B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|               |   ->80.84% (137,371,648B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|               |     ->80.84% (137,371,648B) 0x210702: flb_lib_worker (flb_lib.c:493)
|               |       ->80.84% (137,371,648B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|               |         ->80.84% (137,371,648B) 0x6E0F71D: clone (clone.S:95)
|               |           
|               ->00.10% (163,840B) in 1+ places, all below ms_print's threshold (01.00%)
|               
->08.95% (15,204,352B) 0x517CE6: cio_memfs_open (cio_memfs.c:42)
| ->08.95% (15,204,352B) 0x5134E4: cio_chunk_open (cio_chunk.c:82)
|   ->08.95% (15,204,352B) 0x24DEA2: flb_input_chunk_create (flb_input_chunk.c:407)
|     ->08.95% (15,204,352B) 0x24E4A3: input_chunk_get (flb_input_chunk.c:568)
|       ->08.95% (15,204,352B) 0x24E9E6: flb_input_chunk_append_raw (flb_input_chunk.c:791)
|         ->07.71% (13,107,200B) 0x269A80: cb_queue_chunks (emitter.c:142)
|         | ->07.71% (13,107,200B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|         |   ->07.71% (13,107,200B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|         |     ->07.71% (13,107,200B) 0x210702: flb_lib_worker (flb_lib.c:493)
|         |       ->07.71% (13,107,200B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|         |         ->07.71% (13,107,200B) 0x6E0F71D: clone (clone.S:95)
|         |           
|         ->01.08% (1,835,008B) 0x26112E: in_systemd_collect (systemd.c:284)
|         | ->01.08% (1,835,008B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|         |   ->01.08% (1,835,008B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|         |     ->01.08% (1,835,008B) 0x210702: flb_lib_worker (flb_lib.c:493)
|         |       ->01.08% (1,835,008B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|         |         ->01.08% (1,835,008B) 0x6E0F71D: clone (clone.S:95)
|         |           
|         ->00.15% (262,144B) in 1+ places, all below ms_print's threshold (01.00%)
|         
->04.88% (8,290,304B) 0x517E74: cio_memfs_write (cio_memfs.c:91)
| ->04.88% (8,290,304B) 0x513698: cio_chunk_write (cio_chunk.c:161)
|   ->04.88% (8,290,304B) 0x24D3F9: flb_input_chunk_write (flb_input_chunk.c:67)
|     ->04.88% (8,290,304B) 0x24EAC1: flb_input_chunk_append_raw (flb_input_chunk.c:815)
|       ->04.88% (8,290,304B) 0x269A80: cb_queue_chunks (emitter.c:142)
|         ->04.88% (8,290,304B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|           ->04.88% (8,290,304B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|             ->04.88% (8,290,304B) 0x210702: flb_lib_worker (flb_lib.c:493)
|               ->04.88% (8,290,304B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|                 ->04.88% (8,290,304B) 0x6E0F71D: clone (clone.S:95)
|                   
->02.43% (4,124,724B) 0x217EF4: flb_malloc (flb_mem.h:62)
| ->02.43% (4,124,724B) 0x218113: sds_alloc (flb_sds.c:40)
|   ->02.42% (4,116,383B) 0x21824F: flb_sds_create_size (flb_sds.c:92)
|   | ->02.41% (4,099,497B) 0x217171: flb_msgpack_raw_to_json_sds (flb_pack.c:699)
|   | | ->02.41% (4,096,342B) 0x217A32: flb_pack_msgpack_to_json_format (flb_pack.c:973)
|   | | | ->02.41% (4,096,342B) 0x2B46AB: cb_http_flush (http.c:319)
|   | | |   ->02.41% (4,096,342B) 0x21D778: output_pre_cb_flush (flb_output.h:463)
|   | | |     ->02.41% (4,096,342B) 0x717105: co_init (amd64.c:117)
|   | | |       
|   | | ->00.00% (3,155B) in 1+ places, all below ms_print's threshold (01.00%)
|   | | 
|   | ->00.01% (16,886B) in 1+ places, all below ms_print's threshold (01.00%)
|   | 
|   ->00.00% (8,341B) in 1+ places, all below ms_print's threshold (01.00%)
|   
->01.68% (2,862,130B) 0x26D7EB: flb_malloc (flb_mem.h:62)
| ->01.48% (2,523,136B) 0x26FB25: flb_tail_file_append (tail_file.c:706)
| | ->01.48% (2,523,136B) 0x2745EC: tail_scan_path (tail_scan_glob.c:255)
| |   ->01.48% (2,523,136B) 0x2748AC: flb_tail_scan (tail_scan.c:42)
| |     ->01.47% (2,490,368B) 0x26AAB6: in_tail_init (tail.c:297)
| |     | ->01.47% (2,490,368B) 0x21AB31: flb_input_instance_init (flb_input.c:483)
| |     |   ->01.47% (2,490,368B) 0x21AC0E: flb_input_init_all (flb_input.c:519)
| |     |     ->01.47% (2,490,368B) 0x22D2EF: flb_engine_start (flb_engine.c:501)
| |     |       ->01.47% (2,490,368B) 0x210702: flb_lib_worker (flb_lib.c:493)
| |     |         ->01.47% (2,490,368B) 0x4E3C6D9: start_thread (pthread_create.c:463)
| |     |           ->01.47% (2,490,368B) 0x6E0F71D: clone (clone.S:95)
| |     |             
| |     ->00.02% (32,768B) in 1+ places, all below ms_print's threshold (01.00%)
| |     
| ->00.20% (338,994B) in 1+ places, all below ms_print's threshold (01.00%)
| 
->01.04% (1,775,678B) in 305 places, all below massif's threshold (1.00%)
  
--------------------------------------------------------------------------------
  n        time(i)         total(B)   useful-heap(B) extra-heap(B)    stacks(B)
--------------------------------------------------------------------------------
 33 91,141,719,048      166,366,992      166,222,617       144,375            0
 34 94,891,549,671      169,575,304      169,430,484       144,820            0
 35 97,829,563,617      170,031,320      169,886,028       145,292            0
 36 101,745,107,692      169,976,944      169,831,565       145,379            0
99.91% (169,831,565B) (heap allocation functions) malloc/new/new[], --alloc-fns, etc.
->80.92% (137,543,680B) 0x26937F: msgpack_sbuffer_write (sbuffer.h:81)
| ->80.92% (137,543,680B) 0x2699D2: in_emitter_add_record (emitter.c:114)
|   ->80.92% (137,543,680B) 0x3197B2: process_record (rewrite_tag.c:331)
|     ->80.92% (137,543,680B) 0x319961: cb_rewrite_tag_filter (rewrite_tag.c:382)
|       ->80.92% (137,543,680B) 0x21C5DA: flb_filter_do (flb_filter.c:118)
|         ->80.92% (137,543,680B) 0x24EB92: flb_input_chunk_append_raw (flb_input_chunk.c:832)
|           ->80.92% (137,543,680B) 0x26EC76: process_content (tail_file.c:358)
|             ->80.92% (137,543,680B) 0x270B70: flb_tail_file_chunk (tail_file.c:981)
|               ->80.82% (137,371,648B) 0x26A533: in_tail_collect_static (tail.c:140)
|               | ->80.82% (137,371,648B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|               |   ->80.82% (137,371,648B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|               |     ->80.82% (137,371,648B) 0x210702: flb_lib_worker (flb_lib.c:493)
|               |       ->80.82% (137,371,648B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|               |         ->80.82% (137,371,648B) 0x6E0F71D: clone (clone.S:95)
|               |           
|               ->00.10% (172,032B) in 1+ places, all below ms_print's threshold (01.00%)
|               
->09.41% (15,990,784B) 0x517CE6: cio_memfs_open (cio_memfs.c:42)
| ->09.41% (15,990,784B) 0x5134E4: cio_chunk_open (cio_chunk.c:82)
|   ->09.41% (15,990,784B) 0x24DEA2: flb_input_chunk_create (flb_input_chunk.c:407)
|     ->09.41% (15,990,784B) 0x24E4A3: input_chunk_get (flb_input_chunk.c:568)
|       ->09.41% (15,990,784B) 0x24E9E6: flb_input_chunk_append_raw (flb_input_chunk.c:791)
|         ->08.02% (13,631,488B) 0x269A80: cb_queue_chunks (emitter.c:142)
|         | ->08.02% (13,631,488B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|         |   ->08.02% (13,631,488B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|         |     ->08.02% (13,631,488B) 0x210702: flb_lib_worker (flb_lib.c:493)
|         |       ->08.02% (13,631,488B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|         |         ->08.02% (13,631,488B) 0x6E0F71D: clone (clone.S:95)
|         |           
|         ->01.23% (2,097,152B) 0x26112E: in_systemd_collect (systemd.c:284)
|         | ->01.23% (2,097,152B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|         |   ->01.23% (2,097,152B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|         |     ->01.23% (2,097,152B) 0x210702: flb_lib_worker (flb_lib.c:493)
|         |       ->01.23% (2,097,152B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|         |         ->01.23% (2,097,152B) 0x6E0F71D: clone (clone.S:95)
|         |           
|         ->00.15% (262,144B) in 1+ places, all below ms_print's threshold (01.00%)
|         
->04.88% (8,290,304B) 0x517E74: cio_memfs_write (cio_memfs.c:91)
| ->04.88% (8,290,304B) 0x513698: cio_chunk_write (cio_chunk.c:161)
|   ->04.88% (8,290,304B) 0x24D3F9: flb_input_chunk_write (flb_input_chunk.c:67)
|     ->04.88% (8,290,304B) 0x24EAC1: flb_input_chunk_append_raw (flb_input_chunk.c:815)
|       ->04.88% (8,290,304B) 0x269A80: cb_queue_chunks (emitter.c:142)
|         ->04.88% (8,290,304B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|           ->04.88% (8,290,304B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|             ->04.88% (8,290,304B) 0x210702: flb_lib_worker (flb_lib.c:493)
|               ->04.88% (8,290,304B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|                 ->04.88% (8,290,304B) 0x6E0F71D: clone (clone.S:95)
|                   
->01.88% (3,195,334B) 0x217EF4: flb_malloc (flb_mem.h:62)
| ->01.88% (3,195,334B) 0x218113: sds_alloc (flb_sds.c:40)
|   ->01.87% (3,186,993B) 0x21824F: flb_sds_create_size (flb_sds.c:92)
|   | ->01.87% (3,170,107B) 0x217171: flb_msgpack_raw_to_json_sds (flb_pack.c:699)
|   | | ->01.86% (3,166,952B) 0x217A32: flb_pack_msgpack_to_json_format (flb_pack.c:973)
|   | | | ->01.86% (3,166,952B) 0x2B46AB: cb_http_flush (http.c:319)
|   | | |   ->01.86% (3,166,952B) 0x21D778: output_pre_cb_flush (flb_output.h:463)
|   | | |     ->01.86% (3,166,952B) 0x717105: co_init (amd64.c:117)
|   | | |       
|   | | ->00.00% (3,155B) in 1+ places, all below ms_print's threshold (01.00%)
|   | | 
|   | ->00.01% (16,886B) in 1+ places, all below ms_print's threshold (01.00%)
|   | 
|   ->00.00% (8,341B) in 1+ places, all below ms_print's threshold (01.00%)
|   
->01.68% (2,862,130B) 0x26D7EB: flb_malloc (flb_mem.h:62)
| ->01.48% (2,523,136B) 0x26FB25: flb_tail_file_append (tail_file.c:706)
| | ->01.48% (2,523,136B) 0x2745EC: tail_scan_path (tail_scan_glob.c:255)
| |   ->01.48% (2,523,136B) 0x2748AC: flb_tail_scan (tail_scan.c:42)
| |     ->01.47% (2,490,368B) 0x26AAB6: in_tail_init (tail.c:297)
| |     | ->01.47% (2,490,368B) 0x21AB31: flb_input_instance_init (flb_input.c:483)
| |     |   ->01.47% (2,490,368B) 0x21AC0E: flb_input_init_all (flb_input.c:519)
| |     |     ->01.47% (2,490,368B) 0x22D2EF: flb_engine_start (flb_engine.c:501)
| |     |       ->01.47% (2,490,368B) 0x210702: flb_lib_worker (flb_lib.c:493)
| |     |         ->01.47% (2,490,368B) 0x4E3C6D9: start_thread (pthread_create.c:463)
| |     |           ->01.47% (2,490,368B) 0x6E0F71D: clone (clone.S:95)
| |     |             
| |     ->00.02% (32,768B) in 1+ places, all below ms_print's threshold (01.00%)
| |     
| ->00.20% (338,994B) in 1+ places, all below ms_print's threshold (01.00%)
| 
->01.15% (1,949,333B) in 305 places, all below massif's threshold (1.00%)
  
--------------------------------------------------------------------------------
  n        time(i)         total(B)   useful-heap(B) extra-heap(B)    stacks(B)
--------------------------------------------------------------------------------
 37 104,681,765,511      167,959,888      167,814,204       145,684            0
 38 108,598,899,328      167,858,072      167,712,342       145,730            0
 39 112,514,446,960      167,741,288      167,595,386       145,902            0
 40 116,430,022,916      168,087,368      167,941,271       146,097            0
 41 120,345,582,672      168,436,456      168,290,143       146,313            0
 42 123,282,762,136      168,719,072      168,572,580       146,492            0
 43 126,219,885,747      169,019,000      168,872,181       146,819            0
 44 130,136,558,376      169,063,696      168,916,733       146,963            0
 45 132,154,280,763      173,276,944      173,126,333       150,611            0
 46 135,091,711,384      171,208,512      171,060,970       147,542            0
 47 137,049,498,487      171,225,256      171,077,584       147,672            0
 48 140,018,367,576      173,885,008      173,737,279       147,729            0
 49 143,879,093,975      182,473,152      182,318,089       155,063            0
99.92% (182,318,089B) (heap allocation functions) malloc/new/new[], --alloc-fns, etc.
->75.45% (137,674,752B) 0x26937F: msgpack_sbuffer_write (sbuffer.h:81)
| ->75.45% (137,674,752B) 0x2699D2: in_emitter_add_record (emitter.c:114)
|   ->75.45% (137,674,752B) 0x3197B2: process_record (rewrite_tag.c:331)
|     ->75.45% (137,674,752B) 0x319961: cb_rewrite_tag_filter (rewrite_tag.c:382)
|       ->75.45% (137,674,752B) 0x21C5DA: flb_filter_do (flb_filter.c:118)
|         ->75.45% (137,674,752B) 0x24EB92: flb_input_chunk_append_raw (flb_input_chunk.c:832)
|           ->75.45% (137,674,752B) 0x26EC76: process_content (tail_file.c:358)
|             ->75.45% (137,674,752B) 0x270B70: flb_tail_file_chunk (tail_file.c:981)
|               ->75.28% (137,371,648B) 0x26A533: in_tail_collect_static (tail.c:140)
|               | ->75.28% (137,371,648B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|               |   ->75.28% (137,371,648B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|               |     ->75.28% (137,371,648B) 0x210702: flb_lib_worker (flb_lib.c:493)
|               |       ->75.28% (137,371,648B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|               |         ->75.28% (137,371,648B) 0x6E0F71D: clone (clone.S:95)
|               |           
|               ->00.17% (303,104B) in 1+ places, all below ms_print's threshold (01.00%)
|               
->10.49% (19,136,512B) 0x517CE6: cio_memfs_open (cio_memfs.c:42)
| ->10.49% (19,136,512B) 0x5134E4: cio_chunk_open (cio_chunk.c:82)
|   ->10.49% (19,136,512B) 0x24DEA2: flb_input_chunk_create (flb_input_chunk.c:407)
|     ->10.49% (19,136,512B) 0x24E4A3: input_chunk_get (flb_input_chunk.c:568)
|       ->10.49% (19,136,512B) 0x24E9E6: flb_input_chunk_append_raw (flb_input_chunk.c:791)
|         ->08.62% (15,728,640B) 0x269A80: cb_queue_chunks (emitter.c:142)
|         | ->08.62% (15,728,640B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|         |   ->08.62% (15,728,640B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|         |     ->08.62% (15,728,640B) 0x210702: flb_lib_worker (flb_lib.c:493)
|         |       ->08.62% (15,728,640B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|         |         ->08.62% (15,728,640B) 0x6E0F71D: clone (clone.S:95)
|         |           
|         ->01.87% (3,407,872B) 0x26112E: in_systemd_collect (systemd.c:284)
|         | ->01.87% (3,407,872B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|         |   ->01.87% (3,407,872B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|         |     ->01.87% (3,407,872B) 0x210702: flb_lib_worker (flb_lib.c:493)
|         |       ->01.87% (3,407,872B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|         |         ->01.87% (3,407,872B) 0x6E0F71D: clone (clone.S:95)
|         |           
|         ->00.00% (0B) in 1+ places, all below ms_print's threshold (01.00%)
|         
->04.54% (8,290,304B) 0x517E74: cio_memfs_write (cio_memfs.c:91)
| ->04.54% (8,290,304B) 0x513698: cio_chunk_write (cio_chunk.c:161)
|   ->04.54% (8,290,304B) 0x24D3F9: flb_input_chunk_write (flb_input_chunk.c:67)
|     ->04.54% (8,290,304B) 0x24EAC1: flb_input_chunk_append_raw (flb_input_chunk.c:815)
|       ->04.54% (8,290,304B) 0x269A80: cb_queue_chunks (emitter.c:142)
|         ->04.54% (8,290,304B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|           ->04.54% (8,290,304B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|             ->04.54% (8,290,304B) 0x210702: flb_lib_worker (flb_lib.c:493)
|               ->04.54% (8,290,304B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|                 ->04.54% (8,290,304B) 0x6E0F71D: clone (clone.S:95)
|                   
->03.70% (6,756,494B) 0x217EF4: flb_malloc (flb_mem.h:62)
| ->03.70% (6,756,494B) 0x218113: sds_alloc (flb_sds.c:40)
|   ->03.70% (6,748,153B) 0x21824F: flb_sds_create_size (flb_sds.c:92)
|   | ->03.69% (6,731,267B) 0x217171: flb_msgpack_raw_to_json_sds (flb_pack.c:699)
|   | | ->03.69% (6,728,110B) 0x217A32: flb_pack_msgpack_to_json_format (flb_pack.c:973)
|   | | | ->03.69% (6,728,110B) 0x2B46AB: cb_http_flush (http.c:319)
|   | | |   ->03.69% (6,728,110B) 0x21D778: output_pre_cb_flush (flb_output.h:463)
|   | | |     ->03.69% (6,728,110B) 0x717105: co_init (amd64.c:117)
|   | | |       
|   | | ->00.00% (3,157B) in 1+ places, all below ms_print's threshold (01.00%)
|   | | 
|   | ->00.01% (16,886B) in 1+ places, all below ms_print's threshold (01.00%)
|   | 
|   ->00.00% (8,341B) in 1+ places, all below ms_print's threshold (01.00%)
|   
->01.95% (3,558,680B) 0x6F6D55: msgpack_zone_malloc_expand (zone.c:83)
| ->01.95% (3,558,680B) 0x6F4651: msgpack_zone_malloc (zone.h:121)
|   ->01.41% (2,566,600B) 0x6F4BDD: template_callback_map (unpack.c:259)
|   | ->01.41% (2,566,600B) in 2 places, all below massif's threshold (1.00%)
|   |   
|   ->00.54% (992,080B) in 1+ places, all below ms_print's threshold (01.00%)
|   
->01.57% (2,862,130B) 0x26D7EB: flb_malloc (flb_mem.h:62)
| ->01.38% (2,523,136B) 0x26FB25: flb_tail_file_append (tail_file.c:706)
| | ->01.38% (2,523,136B) 0x2745EC: tail_scan_path (tail_scan_glob.c:255)
| |   ->01.38% (2,523,136B) 0x2748AC: flb_tail_scan (tail_scan.c:42)
| |     ->01.36% (2,490,368B) 0x26AAB6: in_tail_init (tail.c:297)
| |     | ->01.36% (2,490,368B) 0x21AB31: flb_input_instance_init (flb_input.c:483)
| |     |   ->01.36% (2,490,368B) 0x21AC0E: flb_input_init_all (flb_input.c:519)
| |     |     ->01.36% (2,490,368B) 0x22D2EF: flb_engine_start (flb_engine.c:501)
| |     |       ->01.36% (2,490,368B) 0x210702: flb_lib_worker (flb_lib.c:493)
| |     |         ->01.36% (2,490,368B) 0x4E3C6D9: start_thread (pthread_create.c:463)
| |     |           ->01.36% (2,490,368B) 0x6E0F71D: clone (clone.S:95)
| |     |             
| |     ->00.02% (32,768B) in 1+ places, all below ms_print's threshold (01.00%)
| |     
| ->00.19% (338,994B) in 1+ places, all below ms_print's threshold (01.00%)
| 
->01.15% (2,097,152B) 0x2156ED: msgpack_sbuffer_write (sbuffer.h:81)
| ->01.15% (2,097,152B) 0x6F2B81: msgpack_pack_str_body (pack_template.h:784)
| | ->01.15% (2,097,152B) 0x6F2FFA: msgpack_pack_object (objectc.c:68)
| |   ->01.15% (2,097,152B) 0x217815: flb_pack_msgpack_to_json_format (flb_pack.c:896)
| |   | ->01.15% (2,097,152B) 0x2B46AB: cb_http_flush (http.c:319)
| |   |   ->01.15% (2,097,152B) 0x21D778: output_pre_cb_flush (flb_output.h:463)
| |   |     ->01.15% (2,097,152B) 0x717105: co_init (amd64.c:117)
| |   |       
| |   ->00.00% (0B) in 1+ places, all below ms_print's threshold (01.00%)
| |   
| ->00.00% (0B) in 1+ places, all below ms_print's threshold (01.00%)
| 
->01.06% (1,942,065B) in 303 places, all below massif's threshold (1.00%)
  
--------------------------------------------------------------------------------
  n        time(i)         total(B)   useful-heap(B) extra-heap(B)    stacks(B)
--------------------------------------------------------------------------------
 50 145,483,007,261      175,737,720      175,589,523       148,197            0
 51 147,087,779,961      175,728,208      175,579,925       148,283            0
 52 147,524,179,575      309,954,392      309,806,052       148,340            0
99.95% (309,806,052B) (heap allocation functions) malloc/new/new[], --alloc-fns, etc.
->87.72% (271,900,672B) 0x26937F: msgpack_sbuffer_write (sbuffer.h:81)
| ->87.72% (271,900,672B) 0x2699D2: in_emitter_add_record (emitter.c:114)
|   ->87.72% (271,900,672B) 0x3197B2: process_record (rewrite_tag.c:331)
|     ->87.72% (271,900,672B) 0x319961: cb_rewrite_tag_filter (rewrite_tag.c:382)
|       ->87.72% (271,900,672B) 0x21C5DA: flb_filter_do (flb_filter.c:118)
|         ->87.72% (271,900,672B) 0x24EB92: flb_input_chunk_append_raw (flb_input_chunk.c:832)
|           ->87.72% (271,900,672B) 0x26EC76: process_content (tail_file.c:358)
|             ->87.72% (271,900,672B) 0x270B70: flb_tail_file_chunk (tail_file.c:981)
|               ->87.62% (271,589,376B) 0x26A533: in_tail_collect_static (tail.c:140)
|               | ->87.62% (271,589,376B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|               |   ->87.62% (271,589,376B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|               |     ->87.62% (271,589,376B) 0x210702: flb_lib_worker (flb_lib.c:493)
|               |       ->87.62% (271,589,376B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|               |         ->87.62% (271,589,376B) 0x6E0F71D: clone (clone.S:95)
|               |           
|               ->00.10% (311,296B) in 1+ places, all below ms_print's threshold (01.00%)
|               
->06.34% (19,660,800B) 0x517CE6: cio_memfs_open (cio_memfs.c:42)
| ->06.34% (19,660,800B) 0x5134E4: cio_chunk_open (cio_chunk.c:82)
|   ->06.34% (19,660,800B) 0x24DEA2: flb_input_chunk_create (flb_input_chunk.c:407)
|     ->06.34% (19,660,800B) 0x24E4A3: input_chunk_get (flb_input_chunk.c:568)
|       ->06.34% (19,660,800B) 0x24E9E6: flb_input_chunk_append_raw (flb_input_chunk.c:791)
|         ->05.16% (15,990,784B) 0x269A80: cb_queue_chunks (emitter.c:142)
|         | ->05.16% (15,990,784B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|         |   ->05.16% (15,990,784B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|         |     ->05.16% (15,990,784B) 0x210702: flb_lib_worker (flb_lib.c:493)
|         |       ->05.16% (15,990,784B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|         |         ->05.16% (15,990,784B) 0x6E0F71D: clone (clone.S:95)
|         |           
|         ->01.10% (3,407,872B) 0x26112E: in_systemd_collect (systemd.c:284)
|         | ->01.10% (3,407,872B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|         |   ->01.10% (3,407,872B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|         |     ->01.10% (3,407,872B) 0x210702: flb_lib_worker (flb_lib.c:493)
|         |       ->01.10% (3,407,872B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|         |         ->01.10% (3,407,872B) 0x6E0F71D: clone (clone.S:95)
|         |           
|         ->00.08% (262,144B) in 1+ places, all below ms_print's threshold (01.00%)
|         
->02.67% (8,290,304B) 0x517E74: cio_memfs_write (cio_memfs.c:91)
| ->02.67% (8,290,304B) 0x513698: cio_chunk_write (cio_chunk.c:161)
|   ->02.67% (8,290,304B) 0x24D3F9: flb_input_chunk_write (flb_input_chunk.c:67)
|     ->02.67% (8,290,304B) 0x24EAC1: flb_input_chunk_append_raw (flb_input_chunk.c:815)
|       ->02.67% (8,290,304B) 0x269A80: cb_queue_chunks (emitter.c:142)
|         ->02.67% (8,290,304B) 0x21BE05: flb_input_collector_fd (flb_input.c:1004)
|           ->02.67% (8,290,304B) 0x22D7C8: flb_engine_start (flb_engine.c:352)
|             ->02.67% (8,290,304B) 0x210702: flb_lib_worker (flb_lib.c:493)
|               ->02.67% (8,290,304B) 0x4E3C6D9: start_thread (pthread_create.c:463)
|                 ->02.67% (8,290,304B) 0x6E0F71D: clone (clone.S:95)
|                   
->01.70% (5,268,408B) 0x217EF4: flb_malloc (flb_mem.h:62)
| ->01.70% (5,268,408B) 0x218113: sds_alloc (flb_sds.c:40)
|   ->01.70% (5,260,047B) 0x21824F: flb_sds_create_size (flb_sds.c:92)
|   | ->01.69% (5,243,016B) 0x217171: flb_msgpack_raw_to_json_sds (flb_pack.c:699)
|   | | ->01.69% (5,239,859B) 0x217A32: flb_pack_msgpack_to_json_format (flb_pack.c:973)
|   | | | ->01.69% (5,239,859B) 0x2B46AB: cb_http_flush (http.c:319)
|   | | |   ->01.69% (5,239,859B) 0x21D778: output_pre_cb_flush (flb_output.h:463)
|   | | |     ->01.69% (5,239,859B) 0x717105: co_init (amd64.c:117)
|   | | |       
|   | | ->00.00% (3,157B) in 1+ places, all below ms_print's threshold (01.00%)
|   | | 
|   | ->00.01% (17,031B) in 1+ places, all below ms_print's threshold (01.00%)
|   | 
|   ->00.00% (8,361B) in 1+ places, all below ms_print's threshold (01.00%)
|   
->01.51% (4,685,868B) in 306 places, all below massif's threshold (1.00%)
  
--------------------------------------------------------------------------------
  n        time(i)         total(B)   useful-heap(B) extra-heap(B)    stacks(B)
--------------------------------------------------------------------------------
 53 149,128,102,916      309,903,672      309,755,325       148,347            0
 54 150,732,259,730      307,258,840      307,110,506       148,334            0
 55 152,336,178,160      307,293,112      307,144,731       148,381            0
 56 153,940,096,136      307,651,840      307,503,259       148,581            0

So looking at the output the heap mem keeps on growing which is unexpected behaviour as I have set Mem_Buf_Limit 15MB.
so looks like this limit is not being respected -

my input configuration

  fluent-bit.conf: |
    [SERVICE]
        Flush  1
        Daemon Off
        Log_Level info
        Parsers_File parsers.conf
        Parsers_File custom_parsers.conf
        HTTP_Server On
        HTTP_Listen 0.0.0.0
        HTTP_Port 2020
    
    [INPUT]
        Name tail
        Path /var/log/containers/*.log
        Parser docker
        Tag kube.*
        Mem_Buf_Limit 15MB
        Skip_Long_Lines On
        DB /tail-db/tail-containers-state.db
        DB.Sync Normal
    [INPUT]
        Name systemd
        Tag host.*
        Systemd_Filter _SYSTEMD_UNIT=kubelet.service
        Read_From_Tail On
    [INPUT]
        Name tail
        Path /var/log/syslog
        Parser syslog
        Tag syslog.*
        Refresh_Interval 5
        Mem_Buf_Limit 5MB
        Skip_Long_Lines On
        DB /tail-db/tail-syslog-state.db
        DB.Sync          Normal
    [INPUT]
        Name tail
        Path /var/log/auth.log
        Parser syslog
        Tag syslog.*
        Refresh_Interval 5
        Mem_Buf_Limit 5MB
        Skip_Long_Lines On
        DB /tail-db/tail-authlog-state.db
        DB.Sync Normal
    
    [FILTER]
        Name kubernetes
        Match kube.*
        Merge_Log On
        Keep_Log Off
        K8S-Logging.Parser On
        K8S-Logging.Exclude On
        Buffer_Size 64k
        Annotations Off
        Labels Off
    [FILTER]
        Name lua
        Match kube.*
        script /fluent-bit/scripts/dedot
        call dedot
    # https://github.com/fluent/fluent-bit/issues/422#issuecomment-873569854
    [FILTER]
        Name            nest
        Match           kube.*
        Operation       lift
        Nested_under    kubernetes
        Add_prefix      kubernetes.
    [FILTER]
        Name        record_modifier
        Match       kube.*
        Remove_key  kubernetes.container_hash
        Remove_key  kubernetes.docker_id
        Remove_key  kubernetes.pod_id
    [FILTER]
        Name            nest
        Match           kube.*
        Operation       nest
        Wildcard        kubernetes.*
        Nest_under      kubernetes
        Remove_prefix   kubernetes.
    [FILTER]
        Name    modify
        Match   *
        Add     dragoneye.tenant dna-edge
    [FILTER]
        Name parser
        Match kube.var.log.containers.*
        Key_Name log
        Parser glog
        Reserve_Data True
    [FILTER]
        Name parser
        Match kube.var.log.containers.calico-node-*
        Key_Name log
        Parser calico
        Reserve_Data True
    [FILTER]
        Name parser
        Match kube.var.log.containers.tiller-deploy-*
        Key_Name log
        Parser tiller
        Reserve_Data True
    [FILTER]
        Name parser
        Match kube.var.log.containers.kong-*
        Key_Name log
        Parser kong
        Reserve_Data True
    [FILTER]
        Name parser
        Match kube.var.log.containers.nso-*
        Key_Name log
        Parser nso
        Reserve_Data True
    [FILTER]
        Name parser
        Match kube.var.log.containers.*_kafka-broker-*
        Key_Name log
        Parser kafka
        Reserve_Data True
    [FILTER]
        Name parser
        Match kube.var.log.containers.*_rabbitmq-ha-*
        Key_Name log
        Parser rabbitmq
        Reserve_Data True
    [FILTER]
        Name parser
        Match kube.var.log.containers.*_zookeeper-*
        Key_Name log
        Parser zookeeper
        Reserve_Data True
    [FILTER]
        Name parser
        Match kube.var.log.containers.*_elasticsearch-*
        Key_Name log
        Parser elasticsearch
        Reserve_Data True
    [FILTER]
        Name parser
        Match kube.var.log.containers.*_mongodb-replicaset-*
        Key_Name log
        Parser mongodb3
        Parser mongodb4
        Parser mongodb5
        Parser mongodb2
        Reserve_Data True
    [FILTER]
        Name parser
        Match syslog.*
        Key_Name message
        Parser calicosyslog
        Reserve_Data True
    [FILTER]
        Name modify
        Match kube.var.log.containers.gatekeeper-audit-*
        Remove updateConstraints
    [FILTER]
        Name modify
        Match kube.var.log.containers.*
        Condition Key_value_matches level ^[eE]
        Set level error
    [FILTER]
        Name modify
        Match kube.var.log.containers.*
        Condition Key_value_matches level ^[iI]
        Set level info
    [FILTER]
        Name modify
        Match kube.var.log.containers.*
        Condition Key_value_matches level ^[dD]
        Set level debug
    [FILTER]
        Name modify
        Match kube.var.log.containers.*
        Condition Key_value_matches level ^[wW]
        Set level warn
    [FILTER]
        Name modify
        Match kube.var.log.containers.*
        Rename msg message
    [FILTER]
        Name modify
        Match kube.var.log.containers.*
        Add level garbage
    # Group logs by kubernetes namespace_name into multiple tags; with each tag having logs from a single namespace
    [FILTER]
        Name                  rewrite_tag
        Match                 host.*
        Rule                  $message ^(.*)$ node false
        Emitter_Name          host_tag_rewriter
        Emitter_Mem_Buf_Limit 10MB
    [FILTER]
        Name                  rewrite_tag
        Match                 syslog.*
        Rule                  $message ^(.*)$ node false
        Emitter_Name          syslog_tag_rewriter
        Emitter_Mem_Buf_Limit 10MB
    [FILTER]
        Name                  rewrite_tag
        Match                 kube.*
        Rule                  $kubernetes['namespace_name'] ^(.*)$ $1 false
        Emitter_Name          kube_tag_rewriter
        Emitter_Mem_Buf_Limit 10MB
    
    
    [OUTPUT]
        Name  http
        Match *
        Log_Level  debug
        Host  flaskapp.thp.svc.cluster.local
        #Host  logsth.thp.svc.cluster.local
        Port  9090
        URI   /hello
        Retry_Limit   False
        #Format        json_lines
        Format        json
        Compress      gzip
        net.keepalive False
        json_date_key @timestamp
        json_date_format iso8601
        tls           off
        tls.verify    off
        tls.debug     1
        header_tag    X-LOGS-NAMESPACE
        Header        X-LOGS-FORMAT json_lines

have parsers

  custom_parsers.conf: |
    [PARSER]
        Name docker_no_time
        Format json
        Time_Keep Off
        Time_Key time
        Time_Format %Y-%m-%dT%H:%M:%S.%L
    [PARSER]
        Name        glog
        Format      regex
        Regex       ^(?<level>[A-Z])(?<time>\d{4}\s+\d{2}:\d{2}:\d{2}\.\d+)\s+(?<thread>\d+)\s+(?<filename>[\w\.]+):(?<line>\d+)]\s+(?<message>.+)$
        Time_Key    time
        Time_Format %m%d %H:%M:%S.%L
    [PARSER]
        Name        calico
        Format      regex
        Regex       ^(?<time>\d{4}-\d{2}-\d{2}\s+\d{2}:\d{2}:\d{2}.\d+)\s+\[(?<level>\w+)\]\[(?<thread>\d+)\]\s+(?<filename>\S+)\s+(?<line>\d+):\s+(?<message>.+)$
        Time_Key    time
        Time_Format %Y-%m-%d %H:%M:%S.%L
    [PARSER]
        Name        tiller
        Format      regex
        Regex       ^\[(?<component>\w+)\]\s+(?<time>\d{4}\/\d{2}\/\d{2}\s+\d{2}:\d{2}:\d{2})\s+(?<message>.+)$
        Time_Key    time
        Time_Format %Y/%m/%d %H:%M:%S
    [PARSER]
        Name        kong
        Format      regex
        Regex       ^(?<time>\d{4}\/\d{2}\/\d{2}\s+\d{2}:\d{2}:\d{2})\s+\[(?<level>\w+)\]\s+(?<PID>\d+)(\#)(?<TID>\d+)(\:)\s+(\*)(?<CID>\d+)\s+(?<msg>.*)$
        Time_Key    time
        Time_Format %Y/%m/%d %H:%M:%S
    [PARSER]
        Name        nso
        Format      regex
        Regex       ^(?<level><\w+>)\s(?<time>\d{2}-\w{3}-\d{4}::\d{2}:\d{2}:\d{2}.\d*)\s(?<podname>\S+)\s\S+\s(?<message>.+)$
        Time_Key    time
        Time_Format %d-%b-%Y::%H:%M:%S.%SSS
    [PARSER]
        Name        kafka
        Format      regex
        Regex       ^\[(?<time>[^\]]+)]\s+(?<severity>\w+)\s+\[(?<component>[^\]]+)]\s+(?<message>.*?)\s*\((?<class>[^)]*)\)[^(]*$
        Time_Key    time
        Time_Format %Y-%m-%d %H:%M:%S,%L
    [PARSER]
        Name        rabbitmq
        Format      regex
        Regex       ^(?<time>[^\]]+)\s\[(?<severity>\w*)]\s(?<message>.*)$
        Time_Key    time
        Time_Format %Y-%m-%d %H:%M:%S.%L
    [PARSER]
        Name        zookeeper
        Format      regex
        Regex       ^\[(?<time>[^\]]+)]\s+(?<severity>\w+)\s+(?<message>.*?)\s*\((?<class>[^)]*)\)[^(]*$
        Time_Key    time
        Time_Format %Y-%m-%d %H:%M:%S,%L
    [PARSER]
        Name        elasticsearch
        Format      regex
        Regex       ^\[(?<time>[^\]]+)]\[(?<severity>[^\]\s]+)\s*]\s*\[(?<component>[^\]\s]+)\s*]\s*(\[[^\]]+])?(?<message>.*)
        Time_Key    time
        Time_Format %Y-%m-%dT%H:%M:%S,%L
    [PARSER]
        Name        mongodb2
        Format      regex
        Regex       ^(?<time>[^ ]*)\s+(?<severity>\w)\s+(?<component>[^ ]+)\s+\[(?<context>[^\]]+)]\s+(?<message>.*?) *(?<ms>(\d+))?(:?ms)?$
        Time_Key    time
        Time_Format %Y-%m-%dT%H:%M:%S.%L
    [PARSER]
        Name        mongodb3
        Format      regex
        Regex       ^(?<time>[^ ]*)\s+(?<severity>\w)\s+(?<component>[WRITE]+)\s+\[(?<context>[^\]]+)]\s+(?<op>\w+)\s+(?<db>\w+).(?<coll>\w+)\s+(?<query>.*?)\splanSummary: (?<planName>\w+)\s+(?<planSummary>.*?) *(?<ms>(\d+))?(:?ms)?$
        Time_Key    time
        Time_Format %Y-%m-%dT%H:%M:%S.%L
    [PARSER]
        Name        mongodb4
        Format      regex
        Regex       ^(?<time>[^ ]*)\s+(?<severity>\w)\s+(?<component>[COMMAND]+)\s+\[(?<context>[^\]]+)]\s+command\s+(?<db>[a-zA-z0-9]+).[$\w+]+\s+command: (?<op>\w+) \{ \w+: \"(?<coll>[0-9a-zA-Z]+)(?<query>.*?) *(?<ms>(\d+))?(:?ms)?$
        Time_Key    time
        Time_Format %Y-%m-%dT%H:%M:%S.%L
    [PARSER]
        Name        mongodb5
        Format      regex
        Regex       ^(?<time>[^ ]*)\s+(?<severity>\w)\s+(?<component>[NETWORK]+)\s+\[(?<context>[^\]]+)] received client metadata from (?<client_ip>[0-9.]+):(?<message>.*?)?$
        Time_Key    time
        Time_Format %Y-%m-%dT%H:%M:%S.%L
    [PARSER]
        Name        syslog
        Format      regex
        Regex       ^(?<time>\w+\s+\d{1,2}\s+\d{2}:\d{2}:\d{2})\s+(?<host>[\w-]+)\s+(?<ident>[^\[]+)(?:\[(?<pid>[0-9]+)\])?:\s+(?<message>.+)$
        Time_Key    time
        Time_Format %b %d %H:%M:%S
    [PARSER]
        Name        calicosyslog
        Format      regex
        Regex       ^(?:calico-packet:)\s+(?:IN=(?<in>.+))\s+(?:OUT=(?<out>.+))\s+(?:MAC=(?<mac>[0-9a-f:]+))\s+(?:SRC=(?<src>[0-9.]+))\s+(?:DST=(?<dst>[0-9.]+)).*(?:PROTO=(?<proto>\S+))(?:\s+TYPE=(?<type>[0-9]+))?(?:\s+SPT=(?<sport>[0-9]+))?(?:\s+DPT=(?<dport>[0-9]+))?\s+(?<others>.+)$

@nokute78
Copy link
Collaborator

Currently in_emitter has 2 threads.

  1. rewrite_tag -> in_emitter_add_record -> msgpack_sbuffer_write
  2. (timer thread. every 0.5 sec) cb_queue_chunks -> flb_input_chunk_append_raw

I think mem_buf_limit is for flb_input_chunk API, so the thread 1 doesn't have limits.

nokute78 added a commit to nokute78/fluent-bit that referenced this issue Sep 27, 2021
In previous implementation, in_emitter has 2 buffers.
- 1. rewrite_tag -> in_emitter_add_record -> msgpack_sbuffer_write
- 2. (timer thread. every 0.5 sec) cb_queue_chunks -> flb_input_chunk_append_raw

'mem_buf_limit' is for flb_input_chunk API, so the thread 1 doesn't have limits.

The patch is to modify writing sequence.
rewrite_tag -> in_emitter_add_record -> flb_input_chunk_append_raw

Signed-off-by: Takahiro Yamashita <[email protected]>
@utkmishr
Copy link
Author

utkmishr commented Sep 30, 2021

Hi @nokute78 thanks for providing the fix.I have tested fluent-bit with the changes in your PR .
I can see that now the memory spikes are gone and the memory-footprint is constant when both the emitter and tail plugin is paused.

Command:            bin/fluent-bit -c etc/fluent-bit.conf
Massif arguments:   (none)
ms_print arguments: massif.out.372
--------------------------------------------------------------------------------


    MB
158.8^                                              ##                        
     |                                             @#                         
     |                                             @#                         
     |                                            @@#                         
     |                                          @:@@#                         
     |                                        ::@:@@#  ::@:                   
     |                                     @@@: @:@@# :::@:::::::::::::::::@::
     |                                   @:@@ : @:@@# :::@:: :::: :: ::::::@::
     |                                 ::@:@@ : @:@@# :::@:: :::: :: ::::::@::
     |                              @@@: @:@@ : @:@@# :::@:: :::: :: ::::::@::
     |                             @@ @: @:@@ : @:@@# :::@:: :::: :: ::::::@::
     |                            @@@ @: @:@@ : @:@@# :::@:: :::: :: ::::::@::
     |                          ::@@@ @: @:@@ : @:@@# :::@:: :::: :: ::::::@::
     |                        @@: @@@ @: @:@@ : @:@@# :::@:: :::: :: ::::::@::
     |                      ::@@: @@@ @: @:@@ : @:@@# :::@:: :::: :: ::::::@::
     |                     @: @@: @@@ @: @:@@ : @:@@# :::@:: :::: :: ::::::@::
     |              ::@@@::@: @@: @@@ @: @:@@ : @:@@# :::@:: :::: :: ::::::@::
     |          ::::: @@ ::@: @@: @@@ @: @:@@ : @:@@# :::@:: :::: :: ::::::@::
     |      ::::: ::: @@ ::@: @@: @@@ @: @:@@ : @:@@# :::@:: :::: :: ::::::@::
     | :::@:: : : ::: @@ ::@: @@: @@@ @: @:@@ : @:@@# :::@:: :::: :: ::::::@::
   0 +----------------------------------------------------------------------->Gi
     0                                                                   54.15

this fixes our major concern when the pods we getting OOM killed.
However I see a side effect of this fix that if there is a time delay between "emitter" plugin pause and "tail" plugin pause , then the records processed in that time interval are not getting filter-applied.

will try to explain in steps as -

  1. no upstream http connection .

  2. I am processing a text file . having 125 lines with same json format.
    input_data_to_filter.txt

  3. I have a rewrite_tag filter to process each of the input data lines and retag them with a different tag.

[FILTER]
    Name          rewrite_tag
    Match         test_pop
    Rule          $tool ^(fluent)$  from.$TAG.out false
    Emitter_Name  re_emitted
    Emitter_Mem_Buf_Limit  1kb

my configuration ->
input_data_to_filter.txt

  1. I observed that first "emitter" plugin gets paused and then "tail" plugin gets paused.
  2. At this point I start the upstream http server.
  3. As per the Rewrite_Filter rules defined all the records in the input file should get retagged and should get emitted with a new tag, but i see that the record from line 1 to 32 gets tagged with the new filter rules but 33 to 125 gets emitted with the original ( tail plugin) tag. Attaching the logs from my http server .
    webserver_data.txt

Observation - So looks like when the emitter plugin goes for a pause - below condition becomes true -

if ((ret == FLB_TRUE && keep == FLB_TRUE) || ret == FLB_FALSE) {

so till the time tail plugin is not paused , data gets written to the original chunk.
please confirm whether my understanding is correct.

Thanks

@nokute78
Copy link
Collaborator

nokute78 commented Oct 1, 2021

@utkmishr Thank you for testing.
I'll check the side effect.

nokute78 added a commit to nokute78/fluent-bit that referenced this issue Oct 3, 2021
In previous implementation, in_emitter has 2 buffers.
- 1. rewrite_tag -> in_emitter_add_record -> msgpack_sbuffer_write
- 2. (timer thread. every 0.5 sec) cb_queue_chunks -> flb_input_chunk_append_raw

'mem_buf_limit' is for flb_input_chunk API, so the thread 1 doesn't have limits.

The patch is to modify writing sequence.
rewrite_tag -> in_emitter_add_record -> flb_input_chunk_append_raw

Signed-off-by: Takahiro Yamashita <[email protected]>
@nokute78
Copy link
Collaborator

nokute78 commented Oct 3, 2021

@utkmishr I updated #4128.
Below patch is to prevent emitting original record when in_emitter is pausing.

diff --git a/plugins/filter_rewrite_tag/rewrite_tag.c b/plugins/filter_rewrite_tag/rewrite_tag.c
index 28fff0ba..de0703d3 100644
--- a/plugins/filter_rewrite_tag/rewrite_tag.c
+++ b/plugins/filter_rewrite_tag/rewrite_tag.c
@@ -398,7 +398,7 @@ static int cb_rewrite_tag_filter(const void *data, size_t bytes,
          * - record with new tag was emitted and the rule says it must be preserved
          * - record was not emitted
          */
-        if ((ret == FLB_TRUE && keep == FLB_TRUE) || ret == FLB_FALSE) {
+        if (keep == FLB_TRUE) {
             msgpack_sbuffer_write(&mp_sbuf, (char *) data + pre, off - pre);
         }

@utkmishr
Copy link
Author

Hi @nokute78 , I am not sure whether the above commit e2b566e , will work as expected.
If we do not write to mp_sbuf buffer then tail plugin will not be paused ( If I understood this code flow correctly )?

@utkmishr
Copy link
Author

Hi @edsiper @nokute78 Can these fixes be reviewed/merged, We need rewrite_tag filter in our workflows but not able to use due to the issue mentioned.

@nokute78
Copy link
Collaborator

@utkmishr e2b566e is to prevent emitting when in_emitter pauses.
It is to respect KEEP of Rule property even if in_emitter pauses.
https://docs.fluentbit.io/manual/pipeline/filters/rewrite-tag#keep

i see that the record from line 1 to 32 gets tagged with the new filter rules but 33 to 125 gets emitted with the original ( tail plugin) tag.

I think line 33 to125 will not be emitted by above patch.

@utkmishr
Copy link
Author

utkmishr commented Oct 19, 2021

Hi @nokute78 , you are right, the tail plugin also gets paused with this fix , I missed the condition https://github.com/nokute78/fluent-bit/blob/e2b566e9221922ccc0398957649a8ced0cdb3fa4/src/flb_filter.c#L138 .

However, I have done a few tests and looks like some records goes missing due to change e2b566e.

In my test set up , I have mem_buf_limit as 32kb , I am emitting records each 1 kb in length and there is no upstream connection when I started the test.

so after emitting 30 records(30kb) emitter_plugin gets paused and then tail_plugin gets paused.
At this point I start the upstream connection.

In the output I have observed that from 1 to 30 sequence number gets tagged with rewrite filter and then sequence number 60 onwards gets tagged with the original tag, Also looks like seq number 30 to 60 went missing in both the tags.

So as per my observation if we have 60 records in a chunk then first 30 gets tagged by rewrite tag by the function -
https://github.com/nokute78/fluent-bit/blob/e2b566e9221922ccc0398957649a8ced0cdb3fa4/plugins/filter_rewrite_tag/rewrite_tag.c#L389

so at this stage the value of emitter count https://github.com/nokute78/fluent-bit/blob/e2b566e9221922ccc0398957649a8ced0cdb3fa4/plugins/filter_rewrite_tag/rewrite_tag.c#L392 is greater than 0.

and after that no records gets written to the buffer https://github.com/nokute78/fluent-bit/blob/e2b566e9221922ccc0398957649a8ced0cdb3fa4/plugins/filter_rewrite_tag/rewrite_tag.c#L402.

so finally code block https://github.com/nokute78/fluent-bit/blob/e2b566e9221922ccc0398957649a8ced0cdb3fa4/src/flb_filter.c#L140 is executed and we loose that data.

My input file is -
pop1.txt
Conf that I am using -
conf_finput_upstream_rewrite.txt

And the output -
output.txt

Can you please test the commit e2b566e with these inputs and let me know if I missed anything.

edsiper pushed a commit that referenced this issue Oct 20, 2021
In previous implementation, in_emitter has 2 buffers.
- 1. rewrite_tag -> in_emitter_add_record -> msgpack_sbuffer_write
- 2. (timer thread. every 0.5 sec) cb_queue_chunks -> flb_input_chunk_append_raw

'mem_buf_limit' is for flb_input_chunk API, so the thread 1 doesn't have limits.

The patch is to modify writing sequence.
rewrite_tag -> in_emitter_add_record -> flb_input_chunk_append_raw

Signed-off-by: Takahiro Yamashita <[email protected]>
edsiper pushed a commit that referenced this issue Oct 21, 2021
In previous implementation, in_emitter has 2 buffers.
- 1. rewrite_tag -> in_emitter_add_record -> msgpack_sbuffer_write
- 2. (timer thread. every 0.5 sec) cb_queue_chunks -> flb_input_chunk_append_raw

'mem_buf_limit' is for flb_input_chunk API, so the thread 1 doesn't have limits.

The patch is to modify writing sequence.
rewrite_tag -> in_emitter_add_record -> flb_input_chunk_append_raw

Signed-off-by: Takahiro Yamashita <[email protected]>
@nokute78
Copy link
Collaborator

@utkmishr You are right.

Could you test filesystem buffering ? Your issue is backpressure issue.
https://docs.fluentbit.io/manual/administration/buffering-and-storage

Emitter_Storage.type of rewrite_tag and storage.path of service is useful.
https://docs.fluentbit.io/manual/pipeline/filters/rewrite-tag
https://docs.fluentbit.io/manual/administration/buffering-and-storage#service-section-configuration

However filesystem buffering doesn't work. #4221
If you try to test, you need to merge below patch.
#4222

edsiper pushed a commit that referenced this issue Oct 27, 2021
In previous implementation, in_emitter has 2 buffers.
- 1. rewrite_tag -> in_emitter_add_record -> msgpack_sbuffer_write
- 2. (timer thread. every 0.5 sec) cb_queue_chunks -> flb_input_chunk_append_raw

'mem_buf_limit' is for flb_input_chunk API, so the thread 1 doesn't have limits.

The patch is to modify writing sequence.
rewrite_tag -> in_emitter_add_record -> flb_input_chunk_append_raw

Signed-off-by: Takahiro Yamashita <[email protected]>
edsiper pushed a commit that referenced this issue Oct 27, 2021
In previous implementation, in_emitter has 2 buffers.
- 1. rewrite_tag -> in_emitter_add_record -> msgpack_sbuffer_write
- 2. (timer thread. every 0.5 sec) cb_queue_chunks -> flb_input_chunk_append_raw

'mem_buf_limit' is for flb_input_chunk API, so the thread 1 doesn't have limits.

The patch is to modify writing sequence.
rewrite_tag -> in_emitter_add_record -> flb_input_chunk_append_raw

Signed-off-by: Takahiro Yamashita <[email protected]>
0Delta pushed a commit to 0Delta/fluent-bit that referenced this issue Jan 20, 2022
In previous implementation, in_emitter has 2 buffers.
- 1. rewrite_tag -> in_emitter_add_record -> msgpack_sbuffer_write
- 2. (timer thread. every 0.5 sec) cb_queue_chunks -> flb_input_chunk_append_raw

'mem_buf_limit' is for flb_input_chunk API, so the thread 1 doesn't have limits.

The patch is to modify writing sequence.
rewrite_tag -> in_emitter_add_record -> flb_input_chunk_append_raw

Signed-off-by: Takahiro Yamashita <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
2 participants