I am running a GPS listener program. It receives data from GPS devices, decodes, prepares a final data object and then stores the data in Database. I am trying to insert documents to mongodb from nodejs with the following code - (using node mongodb native driver)
var mong = require('mongodb');
var MongoClient = mongo.MongoClient
, format = require('util').format;
MongoClient.connect('mongodb://user:pass@a.b.c.d:27017/dbname', function(err, db) {
if(err) {console.log("mongo connect error " + err); throw err};
gpsdb = db;
console.log("Database Ready");
listener.listen(port);
console.log("Listener Started on: " + port);
});
// code to generate the object to insert - d_obj
var collection = gpsdb.collection(d_obj);
d_obj._id = new mong.ObjectID;
collection.insert(d_obj, {safe:true}, function(err, docs) {
if (err) { console.log("mongo insert query error " + err); return; }
console.log("Inserted 1 rec " + d_obj.imei);
console.dir(docs);
});
The inserts happen for 2-3 minutes after starting the program. After that insertion stops. However, the console logs keep coming.
Sample Log -
Inserted 1 rec 358811020044291
[ { dt_server: '2014-12-12 05:56:14',
dt_tracker: '2014-12-12 05:56:09',
lat: 19.123456,
lng: 73.123456,
angle: 81,
speed: '47',
signal_gsm: 3,
signal_gps: 4,
alarm: 'pcut',
odo: 'y',
offset: 0,
time_stamp: 1418363774454,
ltime: '2014-12-12 05:56:09',
proto: 12,
imei: '123456789123456',
save_mysql: 'no',
altitude: 0,
_id: 548a837e4c73ebaef72d0073 } ]
The console.dir(doc) should execute only if the query was executed properly. I am not getting any errors or warnings. I am getiing this console log for every data object processed. But Inserts are not happening after the first few minutes.
When I test the program with 1 device sending data, it works flawlessly for hours. All data is inserted properly. But when I run it with about 2000 devices connected, the silent fail happens.
I have tried by removing the properties from the data object (d_obj) which has null value. That did not help.
I have not defined any schema or data types anywhere.
Possible Reason
It seems to be a locking issue for async inserts. My program on nodejs sends many parallel inserts. When I run the program normally (in async manner), following is the mongostat output -
connected to: 127.0.0.1
insert query update delete getmore command flushes mapped vsize res faults locked db idx miss % qr|qw ar|aw netIn netOut conn set repl time
138 *0 1 *0 43 28|0 0 496g 992g 10.8g 1 ilogistek:144.8% 0 4|0 0|1 93k 101k 40 rs0 PRI 00:15:12
143 *0 1 *0 70 73|0 0 496g 992g 10.8g 1 ilogistek:176.2% 0 6|0 0|1 106k 108k 40 rs0 PRI 00:15:13
125 *0 1 *0 60 60|0 0 496g 992g 10.9g 2 ilogistek:124.2% 0 5|0 0|1 94k 95k 40 rs0 PRI 00:15:14
181 *0 1 *0 77 96|0 0 496g 992g 11g 0 ilogistek:149.8% 0 6|0 0|1 135k 137k 40 rs0 PRI 00:15:15
91 *0 1 *0 47 45|0 0 496g 992g 11.1g 0 ilogistek:127.0% 0 6|0 0|1 68k 70k 40 rs0 PRI 00:15:16
211 *0 3 *0 74 94|0 0 496g 992g 11.2g 2 ilogistek:138.6% 0 6|0 0|1 152k 156k 40 rs0 PRI 00:15:18
250 *0 2 *0 71 86|0 0 496g 992g 11.2g 5 ilogistek:203.9% 0 10|0 0|1 174k 176k 40 rs0 PRI 00:15:19
270 *0 3 *0 76 111|0 0 496g 992g 10.9g 3 ilogistek:99.2% 0 5|0 0|1 197k 200k 40 rs0 PRI 00:15:20
137 *0 3 *0 54 48|0 0 496g 992g 10.9g 8 ilogistek:137.7% 0 5|0 0|1 97k 100k 40 rs0 PRI 00:15:21
203 *0 1 *0 83 114|0 0 496g 992g 11g 9 ilogistek:154.8% 0 4|0 0|1 153k 152k 40 rs0 PRI 00:15:22
On The other hand, when I force the writes in a synchronous manner (next write goes at the callback of the previous write), the locking does not happen and writes per second increases many times.
insert query update delete getmore command flushes mapped vsize res faults locked db idx miss % qr|qw ar|aw netIn netOut conn set repl time
1670 *0 1 *0 321 515|0 0 496g 992g 11.4g 0 ilogistek:15.7% 0 0|0 0|0 1m 1m 19 rs0 PRI 00:24:47
1830 *0 1 *0 344 621|0 0 496g 992g 11.4g 0 ilogistek:10.3% 0 0|0 0|0 1m 1m 19 rs0 PRI 00:24:48
1767 *0 1 *0 330 571|0 0 496g 992g 11.4g 1 ilogistek:14.5% 0 0|0 0|0 1m 1m 19 rs0 PRI 00:24:49
1726 *0 1 *0 337 599|0 0 496g 992g 11.4g 0 ilogistek:11.9% 0 0|0 0|0 1m 1m 19 rs0 PRI 00:24:50
1743 *0 1 *0 343 590|0 0 496g 992g 11.4g 0 ilogistek:10.9% 0 0|0 0|0 1m 1m 19 rs0 PRI 00:24:51
1758 *0 1 *0 336 605|0 0 496g 992g 11.4g 0 ilogistek:12.2% 0 0|0 0|0 1m 1m 19 rs0 PRI 00:24:52
1657 *0 1 *0 344 625|0 0 496g 992g 11.4g 0 ilogistek:9.9% 0 0|0 0|1 1m 1m 19 rs0 PRI 00:24:53
1688 *0 1 *0 342 567|0 0 496g 992g 11.4g 0 ilogistek:10.6% 0 0|0 0|0 1m 1m 19 rs0 PRI 00:24:54
1689 *0 1 *0 344 610|0 0 496g 992g 11.4g 0 ilogistek:10.1% 0 0|0 0|0 1m 1m 19 rs0 PRI 00:24:55
1780 *0 1 *0 340 596|0 0 496g 992g 11.4g 0 ilogistek:10.8% 0 0|0 0|0 1m 1m 19 rs0 PRI 00:24:56
I cannot run my program in a synchronous manner as that will beat the very purpose of this technology stack.
Is there something obvious I am missing.
Gurus, please help!