{"action":"created","issue":{"url":"https://api.github.com/repos/fluent/fluentd/issues/1657","repository_url":"https://api.github.com/repos/fluent/fluentd","labels_url":"https://api.github.com/repos/fluent/fluentd/issues/1657/labels{/name}","comments_url":"https://api.github.com/repos/fluent/fluentd/issues/1657/comments","events_url":"https://api.github.com/repos/fluent/fluentd/issues/1657/events","html_url":"https://github.com/fluent/fluentd/issues/1657","id":248177661,"number":1657,"title":"Fluentd retains excessive amounts of memory after handling traffic peaks","user":{"login":"joell","id":840599,"avatar_url":"https://avatars1.githubusercontent.com/u/840599?v=4","gravatar_id":"","url":"https://api.github.com/users/joell","html_url":"https://github.com/joell","followers_url":"https://api.github.com/users/joell/followers","following_url":"https://api.github.com/users/joell/following{/other_user}","gists_url":"https://api.github.com/users/joell/gists{/gist_id}","starred_url":"https://api.github.com/users/joell/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/joell/subscriptions","organizations_url":"https://api.github.com/users/joell/orgs","repos_url":"https://api.github.com/users/joell/repos","events_url":"https://api.github.com/users/joell/events{/privacy}","received_events_url":"https://api.github.com/users/joell/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":1,"created_at":"2017-08-05T10:31:06Z","updated_at":"2017-08-09T16:16:36Z","closed_at":null,"body":"When setting up a simple, 2-part Fluentd (TCP -> forwarder) -> (forwardee -> disk configuration) and giving it 5 million JSON objects to process all at once, resident-set memory consumption jumps from an inital 30MB to between 200-450MB, and does not come back down after computation is complete.  This is observed using version 2.3.5-1.el7 of the TD Agent RPM package running on CentOS 7.  (The version of Fluentd in that package is 0.12.36.)\r\n\r\nSteps to reproduce:\r\n```sh\r\n# define and start a simple TCP forwarder\r\n$ cat > test-in.conf <<'EOF'\r\n<source>\r\n  @type  tcp\r\n  tag    testing\r\n  format json\r\n  port   10130\r\n</source>\r\n\r\n<match **>\r\n  @type forward\r\n  require_ack_response true\r\n  flush_interval 10s\r\n\r\n  <server>\r\n    host 127.0.0.1\r\n    port 10131\r\n  </server>\r\n</match>\r\nEOF\r\n$ td-agent --no-supervisor -c test-in.conf &\r\n\r\n# define and start a simple forwadee that logs to disk\r\n$ cat > test-out.conf <<'EOF'\r\n<source>\r\n   @type forward\r\n   port  10131\r\n</source>\r\n\r\n<match **>\r\n  @type              file\r\n  format             json\r\n  path               \"/tmp/fluent-test\"\r\n  flush_interval     10s\r\n  buffer_chunk_limit 16m\r\n  compress           gzip\r\n</match>\r\nEOF\r\n$ td-agent --no-supervisor -c test-out.conf &\r\n\r\n# observe initial memory consumption\r\n$ ps -o pid,vsz,rss,cmd | grep '[t]d-'\r\n 4254 431724 30544 /opt/td-agent/embedded/bin/ruby /sbin/td-agent --no-supervisor -c test-out.conf\r\n 4259 498816 30052 /opt/td-agent/embedded/bin/ruby /sbin/td-agent --no-supervisor -c test-in.conf\r\n\r\n# pump a bunch of data through it\r\n$ seq 1 5000000 | sed 's/.*/{\"num\": &, \"filler\": \"this is filler text to make the event larger\"}/' > /dev/tcp/localhost/10130 &\r\n\r\n# wait for all data to flush to disk and CPU to return to idle\r\n$ watch -n1 'ls -lt /tmp/fluent-test.* | head -5'\r\n\r\n# observe final memory consumption\r\n$ ps -o pid,rss,cmd | grep '[t]d-'\r\n 4338 628248 288972 /opt/td-agent/embedded/bin/ruby /sbin/td-agent --no-supervisor -c test-out.conf\r\n 4343 1023868 461616 /opt/td-agent/embedded/bin/ruby /sbin/td-agent --no-supervisor -c test-in.conf\r\n```\r\n\r\nAs you can see from the RSS numbers, each td-agent process started out around 30MB and they ended at ~290MB and ~460MB, respectively.  Neither process will release that memory if you wait a while.  (In the real-world staging system we initially discovered this on, memory consumption of the `test-out.conf`-equivalent configuration reached over 3GB, and the `test-in.conf`-equivalent was a Fluent Bit instance exhibiting a recently-fixed [duplication bug](https://github.com/fluent/fluent-bit/issues/342).)\r\n\r\nReviewing a [Fluentd-related kubernetes issue](https://github.com/kubernetes/kubernetes/issues/32762) during our own diagnostics, we noticed that the behavior we observed seemed similar to the Fluentd behavior described there when built without jemalloc.  This led us to check if the td-agent binary we were using was in fact linked with jemalloc.  According to the [FAQ](https://www.fluentd.org/faqs), jemalloc is used when building the Treasure Data RPMs, and though we found jemalloc libraries installed on the system, we couldn't find any existence of jemalloc in the process running in memory.  Specifically, we tried the following things:\r\n\r\n```sh\r\n# given a td-agent process with PID 4343...\r\n\r\n# no jemalloc shared library mentioned in the memory mapping\r\n$ pmap 4343 | grep jemalloc\r\n# ... so it doesn't look like it's dynamically linked\r\n\r\n# grab the entire memory space and search it for references to jemalloc\r\n$ gcore 4343\r\n$ strings core.4343 | fgrep jemalloc\r\n\r\n# ... but if it were statically linked, you'd expect to find some of these strings\r\n$ strings /opt/td-agent/embedded/lib/libjemalloc.a | fgrep jemalloc\r\n```\r\n\r\nIn short, this leads us to wonder... are the binaries invoked by `td-agent` actually linked with jemalloc?  If they are not, is the old memory fragmentation problem that jemalloc solved what we are observing here?  (And if they aren't, am I raising this issue in the wrong place, and if so where should I raise it?)"},"comment":{"url":"https://api.github.com/repos/fluent/fluentd/issues/comments/321305179","html_url":"https://github.com/fluent/fluentd/issues/1657#issuecomment-321305179","issue_url":"https://api.github.com/repos/fluent/fluentd/issues/1657","id":321305179,"user":{"login":"joell","id":840599,"avatar_url":"https://avatars1.githubusercontent.com/u/840599?v=4","gravatar_id":"","url":"https://api.github.com/users/joell","html_url":"https://github.com/joell","followers_url":"https://api.github.com/users/joell/followers","following_url":"https://api.github.com/users/joell/following{/other_user}","gists_url":"https://api.github.com/users/joell/gists{/gist_id}","starred_url":"https://api.github.com/users/joell/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/joell/subscriptions","organizations_url":"https://api.github.com/users/joell/orgs","repos_url":"https://api.github.com/users/joell/repos","events_url":"https://api.github.com/users/joell/events{/privacy}","received_events_url":"https://api.github.com/users/joell/received_events","type":"User","site_admin":false},"created_at":"2017-08-09T16:16:36Z","updated_at":"2017-08-09T16:16:36Z","body":"Yes, even with constraints on the oldobject factor, the problem persists.  In fact, even with more draconion restrictions on the garbage collector the problem persists, e.g.:\r\n```sh\r\n$ RUBY_GC_HEAP_OLDOBJECT_LIMIT_FACTOR=0.9 \\\r\n  RUBY_GC_HEAP_GROWTH_FACTOR=1.05         \\\r\n  RUBY_GC_MALLOC_LIMIT_MAX=16777216       \\\r\n  RUBY_GC_OLDMALLOC_LIMIT_MAX=16777216    \\\r\n  td-agent --no-supervisor -c test.conf &\r\n```\r\n\r\nCoupling that output `td-agent` process with an input of ...\r\n```sh\r\n$ td-agent-bit -i tcp://127.0.0.1:10130 -t test -o forward://127.0.0.1:10131 &\r\n$ seq 1 3000 | sed 's/.*/{\"num\": &, \"filler\": \"this is filler text to make the event larger\"}/' > /dev/tcp/localhost/10130 &\r\n```\r\n... sees the `td-agent` resident-set memory jump to around ~650MB and hold there, even long after all data has been processed.  (Note: I'm using Fluent Bit 0.11.15 here, which has a [nasty data duplication problem](https://github.com/fluent/fluent-bit/issues/342) which is useful in stressing `td-agent` with input in this test.)\r\n\r\nHonestly, it seems like the real issue here is the Ruby 2.1 garbage collector; as far as I can tell, it never releases memory to the OS that it allocates, thereby damning any process that has an even momentary need for a large quantity of memory to hold on to that memory for the rest of its lifetime.  (Please correct me if I'm wrong here.)\r\n\r\nIf the Ruby gc issue cannot be fixed by some form of additional configuration, then perhaps Fluentd could use some type of backpressure mechanism to avoid ingesting input faster than it can truly process it and avoid accumulating large queues in memory?"}}
{"actor":{"display_login":"joell"}}