Failures during secondary index queries

[aerospike]

Failures during secondary index queries

[denisbetsi]

Looks like memory leak. Although, your script looks to be an infinite loop, under what conditions would that loop end? I am guessing it is creating a queue of call backs faster than it can resolve them. Have you tried inserting some sort of a condition in there where if i is above 100 than exit the loop?

Are you trying to create a timeseries report grouping results by 1 minute increments?

[maxvgi]

The example is only simplified artifitial example of a bug. Of course real code has an exit condition and exits after several iterations. But nevertheless it failes several times a day.

The daemon is automatically restarted after each failure. But the most annoying situation is the hangup of process when it simply stops processing any queries until being be killed manually.

[GayathriKaliyamoorthy]

Hi,

We fixed the leak when using query APIs in Aerospike Client and made an official release version 1.0.41.
Please upgrade the client driver and let us know if you have any feedback.

Thanks

[maxvgi]

The situation did not change in any way.
The memory usage is growing indefinitely.

It seems that GC does not destroy AerospikeQuery objects.
If you want, I could send you a couple of v8 heap dumps.

And the process still fails if I remove setImmediate.

[GayathriKaliyamoorthy]

Hi @maxvgi

We got a confirmation from another user that the memory growth subsided significantly and our longevity also confirmed. In our longevity set up, we ran a query which returned a million records( of size 20 bytes), for 100 times consecutively. The memory did not grow beyond 120MB. (RSS of the process) Are you sure, your application is exiting properly and not keeping the references around. How many records does the query return for your use case, and what is the approximate size of each record?

AerospikeQuery object is referenced throughout the query lifecycle, that is all the results of the query are emitted as data event. However the references to objects returned by stream has to be released for the GC to free up the memory.

[denisbetsi]

@GayathriKaliyamoorthy from the look of the sample code, there's a for loop that runs a query for every 1 minute, I am guessing it's some sort of a manual aggregation that is taking place. So if that query is in fact running in production like select results for 10 hour period, that's 600 queries that execute within a short period of time. So that's just for 10 hours, if that query logic runs with selection of 48 or 72 hours then it probably chews up all of the memory real quick. .

[maxvgi]

@GayathriKaliyamoorthy, I am trying to execute several thousands of queries consecutively. Each query returns 2 records. Each record consist of 8 bins: 6 integers and 2 strings with total length of 110 bytes.

Now I do not use the results of a query in my testing environment, I am just sending queries. Query object is created in function scope with no links outside. I also tried to remove event listeners manually with no effect.

So, there are no external references from my code.

It seems that memory grows slowed down in 1.0.41. Now rss of the process is 300MB after 20k requests, but it continues increasing. The same situation happens when the results of queries are empty (when it returnes no records).

In the previous version of SDK rss of process was more then 1GB after the same number of queries. So the situation became much better. Thank you for your work.

But there are still opened questions (memory growth and segmentation faults) before running in production.

[GayathriKaliyamoorthy]

@maxvgi

Are you still seeing the crash, after upgrading to the latest release. I am looking for ways to reproduce the crash, it is not happening in our Dev/Test environment. If you could provide me with deterministic steps to reproduce the crash, it would be really be helpful to debug the issue.

Regarding the memory growth, RSS of the process grows until 1.7GB (maximum memory allowed for a nodejs process). It is due to the way V8 Garbage Collector works. In our longevity setup, the memory grew upto 1.6GB - 1.7GB and stabilized at it. Could you confirm the memory growth beyond this number?

[maxvgi]

@GayathriKaliyamoorthy

Yes, I can still reproduce the crash. I have installed aerospike to new VM and will give you full scenraio to reproduce the problem soon.

The process after 160k queries:

USER    PID     %CPU    %MEM        VSZ     RSS     TTY     STAT    START   TIME    COMMAND
root    13559   25.4    23.3        2655976 1984572 pts/3   Rl+     19:03   22:35   node test.js

[maxvgi]

@GayathriKaliyamoorthy

I deployed aerospike 3.5.14, node.js v0.12.5 and aerospike node client v1.0.42 on a fresh Debian 7 VM.

The database is absolutely empty. Aerospike namespace configuration:

namespace test {
    replication-factor 2
    memory-size 512M
    default-ttl 30d

    storage-engine device {
        file /home/node/aerospike.dat
        filesize 1G
        data-in-memory false
    }
}

Memory leak could be reproduced with the following code:

var aerospike=require('aerospike');
var client = aerospike.client({hosts: [{ addr: '127.0.0.1', port: 3000 }]});
client.connect(function() {
    console.log('connected');
});







var sendReq=function(time_from,callback) {
    var statement={
        filters:[aerospike.filter.range("time", time_from,time_from+60000)]
    };

    var scan = client.query("test", 'testset', statement);
    var stream = scan.execute();

    function onData(record) {}
    function onError(error) {
        console.error(error);
        process.exit(-1);
    }
    function onEnd(){
        stream.removeListener('data',onData);
        stream.removeListener('error',onError);
        stream.removeListener('end',onEnd);
        stream=null;
        scan=null;
        callback();
    }

    stream.on('data', onData);
    stream.on('error', onError);
    stream.on('end', onEnd);
};




var from=0;
var i=0;
var recursivelySendRequests=function() {
    i++;
    sendReq(from,function(){
        from+=60000;
        recursivelySendRequests();
    });
};






//create index
var options = {
    ns: "test",
    set: 'testset',
    bin: "time",
    index: "idx_recording"
};

client.createIntegerIndex(options, function(err) {
    if(err && err.code!=aerospike.status.AEROSPIKE_OK) {
        console.error('error creating index',err);
    }

    recursivelySendRequests();
});





//logging
setInterval(function(){
    console.log(i);
},1000);

Good news are that I could not reproduce segfault on virtual machine, just memory leak.

After that I updated ASD, node.js and AS client on my production server. I still get segfaults. I continue digging into problem.

[maxvgi]

@GayathriKaliyamoorthy

I figured out, that I get segfaults from aerospike client only if virtual machine it is running on uses 2 or more CPU cores.

But the process works for a long time (untill the system is out of memory) if I set number of cores to 1.

Checked with KVM (VPS hosting) and VirtualBox (hosted on my local PC). Also I always get segfault on my PC (Intel i3, 2 cores). Tested on the following systems

Linux debian7-1 3.2.0-4-amd64 #1 SMP Debian 3.2.68-1+deb7u2 x86_64 GNU/Linux
Linux debian-vm 3.16.0-0.bpo.4-amd64 #1 SMP Debian 3.16.7-ckt11-1~bpo70+1 (2015-06-08) x86_64 GNU/Linux
Linux office-4 3.13.0-57-generic #95-Ubuntu SMP Fri Jun 19 09:28:15 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux

Debian 7.8, Ubuntu 14.04
node.js v0.10.39, v0.12.2, v0.12.5
aerospike community edition 3.2.9, 3.5.14

Is your testing system single-core?
Should I do some more test to clarify the situation?

[codest]

+1

[GayathriKaliyamoorthy]

@maxvgi

We found the reason for the crash. And also fixed a leak in the query code path.
The query was crashing, because I was using non-thread safe uv_async API without any synchronization. Here is the link to latest release.
https://www.npmjs.com/package/aerospike

Please do try and give us your feedback. Thanks for your patience.

[maxvgi]

It seems that you did it, there are no more failures!
Thank you very much for your work!

I saw the memory leak fix in your commit. But the node process still can take over 2 GB. If you want, we can close this bug report and issue a new one.

[GayathriKaliyamoorthy]

I'll close this issue and reopen another issue for better tracking purpose.

Thanks