Memory usage

[carsotho]

I am noticing a big increase in memory usage between the releases 3.1.3 and 4.0.0 and above.

Our app is running on node 0.12.6 and we create our elasticsearch client with the following properties:

var esClient = new elasticsearch.Client({
  hosts: localhost:9200,
  apiVersion: "1.3",
  minSockets: 10,
  maxSockets: 10
});

When running on 3.1.3 we converge around 350-400MB. When upgrading to 4.0.0 or any later release the memory just seems to grow until hitting the v8-limit (1,4GB).

[spalger]

Weird, I can't find any change that might cause increased memory usage between 3.1.3 and 4.0. I did update forever-agent between 4.0.0 and 4.0.1 though, which might have caused something. I'll try to reproduce and use git bisect to track down the issue.

[RWOverdijk]

Any leads on this?

[spalger]

Nope, memory usage is something we have been trying to tackle over in elastic/kibana but haven't had luck reproducing or fixing. It seems the only real progress was made when Node released updates and ambient memory usage drops just dropped.

I'm not sure how to approach this and without solid evidence of an issue it's hard to dedicate time.

[dylancwood]

I think that I am experiencing the same issue. We are running a relatively thin proxy layer between our mobile clients and elastic search. Each node of that layer is receiving around 300 requests per minute.
When we upgraded to Node 4+, we ran into max-stack depth exceeded errors with elasticsearch-js 3.1.3, so we upgraded to the latest version.

Memory consumption went up about four-fold with just this little change. To confirm that elasticsearch-js is responsible, I forked the repo and fixed the max-stack depth exceeded issue by pulling in a change from later versions of elasticsearch-js (https://github.com/dylancwood/elasticsearch-js/blob/3-1-3-speed/src/lib/log.js#L66).

Below are graphs of memory consumption, throughput and response time for two servers. Both servers are running Node 4.3.0, and were inundated with as many requests as they could handle for about 15 minutes (hence the poor response time). The only difference is that the red one is using elasticsearch-js 4.0.0 and the yellow one is using my patched fork of elasticsearch-js 3.1.3. Note that the response time is actually better on the 4.0.0 version 👍, but 700MB of memory is a high price to pay. Also, I cannot explain why the response time is faster on the 4.0.0 server, but the throughput is lower...

@spalger: I hope you'll consider this to be solid evidence. FTR, we use only three methods of this package: mget, search and indices.analyze.

[dylancwood]

Also, @spalger: would you take a PR that patches 3.1.3 to have the EventEmitter.listenerCount updates? Maybe you can create a 3.1.4 branch and cherry-pick the patch into it, then tag + publish?

[spalger]

Wow, that looks like pretty solid evidence @dylancwood ... I would love to try bisecting to identify where this memory usage spike came from, and I'll release a patch to 3.1 in the mean time. Thank you for the report

[dylancwood]

👍

[RWOverdijk]

@dylancwood Thanks for going the extra mile on this! Nice :)

[andrewstoker]

@spalger Is this leaky behaviour still being investigated in the newer versions beyond 3.1.4? We are on node v4.4.5 and with any elasticsearch.js client above 4.x, the memory usage is far higher, leaking and behaving much differently as observed by @dylancwood. See below two charts.

V3.1.4 client:

V11.0.1 client:

Both are with the following client configuration (hosts commented out) :

elasticsearch: {
        hosts:           [
            'http://xxxxx:9200',
            'http://xxxxx:9200',
            'http://xxxxx:9200'
        ],
        minSockets:             10,
        maxSockets:             100
    }

@spalger

I have yet to organise our application memory stats as neatly as the other posters have done above but I do believe we are experiencing these exact same issues in our pre-production environment.

Node 5.11.1
ES Client 11.01

Currently writing only several entries per second to the ES Index but memory usage keeps accumulating steadily over time until we run out.

Based on the information provided by the other posters I switched the ES client package from v11.01 to v3.1.4 yesterday. Using the same configuration provided below I can confirm that the v3.1.4 ES Client seems to maintain a steady memory usage of around 35-40MB, while the v11.01 ES Client is running around 140MB. This is after running for approx. 19hrs.

<hostname>:~$ pm2 list
┌────────────────────────────────┬────┬─────────┬──────┬────────┬─────────┬────────┬──────────────┬──────────┐
│ App name                       │ id │ mode    │ pid  │ status │ restart │ uptime │ memory       │ watching │
├────────────────────────────────┼────┼─────────┼──────┼────────┼─────────┼────────┼──────────────┼──────────┤
│ nl_es_stat_update_collector │ 0  │ cluster │ 1637 │ online │ 0       │ 19h    │ 148.605 MB   │ disabled │
│ nl_es_stat_update_collector │ 2  │ cluster │ 1618 │ online │ 0       │ 19h    │ 30.105 MB    │ disabled │
└────────────────────────────────┴────┴─────────┴──────┴────────┴─────────┴────────┴──────────────┴──────────┘

Below is the ES configuration we are using (reading from a Redis channel and writing to ES Index). Note the v3.1.4 ES Client does not support API version 2.3, which is the version of our ES Cluster so I commented it out.

var elasticsearch = require('elasticsearch');

// Define ES Client variable
var es_client = new elasticsearch.Client({
    //apiVersion: '2.3',
    host: '<ip address>:9200',
    keepalive: 'true',
    maxKeepAliveTime: '500',
    maxSockets: 15,
    minSockets: 10,
    sniffOnStart: false,
    log: {
      level: 'info'
    }
});

// Dispatch NL Update to Elasticsearch
sub.on('message', function(channel, message) {
    console.log(message);
    es_client.index({
      index: ('nl_stat_update_2016.' + es_index_date),
      type: 'nl_stat_update',
      body: {
        timestamp: new Date(),
        station_update: (JSON.parse(message))
      }
    })
});

As things stand we are not able to use the v11.01 ES Client in production. This means we need to use the old v3.1.4, which means the ES Cluster (2.3) and ES Client will have mismatched API capabilities.
We would very much appreciate your team continuing research into this issue.

Regards,
Reinier

[spalger]

Thanks all for the updated info folks, keep it coming.

[andrewstoker]

More to think of here.
I think the RSS leak we are seeing may be related to the promise libraries being used in v4 elasticsearch client and above. Especially when calling es client repeatedly (i.e in a loop or quick succession in response to say a rabbitmq feed). Each get/search/put request in the es client returns a promise - these are placed into old memory but not being garbage collected natively. Whereas bluebird behaves differently and will garbage collect the old memory.

I know the below scripts are not elastic client specific but its concise enough to show the behaviour of bluebird with promises returned as part of a loop vs native promises.

This script will not leak (bluebird 3.1.1, node 4.4.7)

var Promise = require('bluebird');

function immediate() {
    return new Promise(function(resolve) {
        setImmediate(resolve);
    });
}

(function loop(value) {
    return immediate().then(function() {
        if (value % 10000 === 0) {
            console.log(process.memoryUsage().heapUsed, value);
        }
        return value + 1;
    }).then(loop);
})(0);

This will (using native promise library)

function immediate() {
    return new Promise(function(resolve) {
        setImmediate(resolve);
    });
}

(function loop(value) {
    return immediate().then(function() {
        if (value % 10000 === 0) {
            console.log(process.memoryUsage().heapUsed, value);
        }
        return value + 1;
    }).then(loop);
})(0);

Can someone validate? Maybe something further to discuss in bluebird/node.js community?