Does fluent-plugin-rewrite do memory leak? #=> fixed

gistfile1.md

sender side

<source>
  type tail
  path /var/log/dummy.log
  pos_file /var/tmp/_var_log_dummy.pos
  format ltsv
  tag dummy
</source>
<match dummy>
  type forward
  flush_interval 0
  buffer_chunk_limit 1m
  buffer_queue_limit 64 
  num_threads 32
  <server>
    host xxx.xxx.xxx.xxx
    port 20000
  </server>
</match>

receiver side

<source>
  type forward
  port 20000
</source>
<match dummy>
  type          rewrite
  add_prefix    filtered
  <rule>
    key     path
    pattern ^[A-Z]+
    replace
  </rule>
  <rule>
    key     path
    pattern \s[^\s]+$
    replace
  </rule>
  <rule>
    key     path
    pattern (\/[^\?]+)\?[^\s]*
    replace \1
    last    true
  </rule>
</match>
<match filtered.**>
  type null
</match>

dummy_log_generator.conf

configure 'sample' do
  output "/var/log/dummy.log"
  message "time:2013-11-25 00:23:52 +0900\tlevel:ERROR\tpath:/foo/bar/hoge/moge\tmethod:POST\turi:/api/v1/people\treqtime:3.1983877060667103"
end

$ bin/dummy_log_generator -c ~/dummy_log_generator.conf -r 10000

Results of vmstat 1. The sixth colum stands for free memory. This tells free memory is decreasing.

20131216 14:34:59	 0  0      0 22178800 232508 1552504    0    0     0     0  440  217  0  0 100  0  0	
snipp...
20131216 14:47:12	 1  0      0 20976952 232508 1552712    0    0     0     0 2981 5518  2  0 98  0  0
snipp...
20131216 14:50:27	 0  0      0 20258788 232508 1552784    0    0     0    44 3801 3417  1  1 98  0  0

Add gc_stat plugin configuration as belows. It shows that the heap_live_num is increasing.

<source>
 type gc_stat
 tag debug.gc
</source>
<match debug.gc>
 type stdout
</match>

cf. http://stackoverflow.com/questions/12634370/what-do-the-fields-of-rubys-gc-stat-mean

2013-12-16 15:11:20 +0900 debug.gc: {"count":66,"heap_used":11071,"heap_length":18772,"heap_increment":7701,"heap_live_num":3621800,"heap_free_num":901880,"heap_final_num":0}
2013-12-16 15:12:20 +0900 debug.gc: {"count":75,"heap_used":20573,"heap_length":36378,"heap_increment":15805,"heap_live_num":7089818,"heap_free_num":1316878,"heap_final_num":0}
2013-12-16 15:13:20 +0900 debug.gc: {"count":82,"heap_used":29525,"heap_length":53143,"heap_increment":23618,"heap_live_num":10773811,"heap_free_num":1292016,"heap_final_num":0}

Without rewrite

20131216 14:54:01    1  0      0 22115896 232508 1552844    0    0     0     0  713  501  0  0 100  0  0    
snipp...
20131216 14:57:30    0  0      0 22119160 232508 1552904    0    0     0     0  797  467  0  0 100  0  0

gc_stat heap_live_num does not increase.

2013-12-16 15:17:49 +0900 debug.gc: {"count":227,"heap_used":138,"heap_length":138,"heap_increment":0,"heap_live_num":39634,"heap_free_num":16646,"heap_final_num":7}
2013-12-16 15:18:49 +0900 debug.gc: {"count":400,"heap_used":138,"heap_length":138,"heap_increment":0,"heap_live_num":39640,"heap_free_num":16634,"heap_final_num":133}
2013-12-16 15:19:49 +0900 debug.gc: {"count":570,"heap_used":138,"heap_length":138,"heap_increment":0,"heap_live_num":39638,"heap_free_num":16644,"heap_final_num":113}

I could fix with this change.

sonots/fluent-plugin-rewrite@eccb5b4

So, If we store conf.elements into instance variables, will fluentd do memory leak???

With this change, heap_live_num did not increase

2013-12-16 16:12:11 +0900 debug.gc: {"count":190,"heap_used":138,"heap_length":138,"heap_increment":0,"heap_live_num":39833,"heap_free_num":16585,"heap_final_num":0}
2013-12-16 16:12:21 +0900 debug.gc: {"count":301,"heap_used":138,"heap_length":138,"heap_increment":0,"heap_live_num":39847,"heap_free_num":16571,"heap_final_num":0}
2013-12-16 16:12:31 +0900 debug.gc: {"count":414,"heap_used":138,"heap_length":138,"heap_increment":0,"heap_live_num":39843,"heap_free_num":16575,"heap_final_num":0}
2013-12-16 16:12:41 +0900 debug.gc: {"count":526,"heap_used":138,"heap_length":138,"heap_increment":0,"heap_live_num":39835,"heap_free_num":16583,"heap_final_num":0}
2013-12-16 16:12:51 +0900 debug.gc: {"count":636,"heap_used":138,"heap_length":138,"heap_increment":0,"heap_live_num":39837,"heap_free_num":16581,"heap_final_num":0}
2013-12-16 16:13:01 +0900 debug.gc: {"count":747,"heap_used":138,"heap_length":138,"heap_increment":0,"heap_live_num":39830,"heap_free_num":16588,"heap_final_num":0}

In Conclusion,

conf.elements adds a key to @used array when a key is referenced. It was causing the memory leak. https://github.com/fluent/fluentd/blob/f2cce3a650b6e1bb92c7bea6e9b0e83a05bf7aed/lib/fluent/config.rb#L57

thanks to @tagomoris

I sent pull requests for both fluentd and fluent-plugin-rewrite. Fixing either of them resolves this problem, but fixing both is the best.

1. (fluentd) fluent/fluentd#230
2. (fluent-plugin-rewrite) kentaro/fluent-plugin-rewrite#3