Skip to content

Commit

Permalink
Working on more error logging for tracking down issues in production
Browse files Browse the repository at this point in the history
  • Loading branch information
christkv committed Oct 3, 2011
1 parent 088a0ee commit be0257a
Show file tree
Hide file tree
Showing 6 changed files with 102 additions and 77 deletions.
17 changes: 15 additions & 2 deletions lib/mongodb/connections/repl_set_servers.js
Original file line number Diff line number Diff line change
Expand Up @@ -269,8 +269,18 @@ ReplSetServers.prototype.connect = function(parent, callback) {
this.send(db_command);

server.connection.on("data", function(message) {
// Parse the data as a reply object
var reply = new MongoReply(parent, message);
var reply = null;

// Catch error and log
try {
// Parse the data as a reply object
reply = new MongoReply(parent, message);
} catch(err) {
var errObj = {err:"unparsable", bin:message, parseState:err};
server.logger.error("mongoreplyParserError", errObj);
return parent.emit("error", errObj);
}

// Emit error if there is one
reply.responseHasError ? parent.emit(reply.responseTo.toString(), reply.documents[0], reply) : parent.emit(reply.responseTo.toString(), null, reply);
// Remove the listener
Expand All @@ -282,6 +292,9 @@ ReplSetServers.prototype.connect = function(parent, callback) {
});

server.connection.on("error", function(err) {
// Log error message
server.logger.error("connectionError", err);

if(parent.isInitializing) {
//we only have one error, if the rest are ok there is no problem
numberOfErrorServers++;
Expand Down
14 changes: 12 additions & 2 deletions lib/mongodb/connections/server.js
Original file line number Diff line number Diff line change
Expand Up @@ -92,8 +92,18 @@ Server.prototype.connect = function(parent, callback) {
});

server.connection.on("data", function(message) {
// Parse the data as a reply object
var reply = new MongoReply(parent, message);
var reply = null;

// Catch error and log
try {
// Parse the data as a reply object
reply = new MongoReply(parent, message);
} catch(err) {
var errObj = {err:"unparsable", bin:message, parseState:err};
server.logger.error("mongoreplyParserError", errObj);
return parent.emit("error", errObj);
}

// Emit message
parent.emit(reply.responseTo.toString(), null, reply);
// Remove the listener
Expand Down
10 changes: 5 additions & 5 deletions lib/mongodb/db.js
Original file line number Diff line number Diff line change
Expand Up @@ -44,11 +44,11 @@ var Db = exports.Db = function(databaseName, serverConfig, options) {
this.notReplied ={};
this.isInitializing = true;
this.auths = [];
this.logger = options.logger != null
&& (typeof options.logger.debug == 'function')
&& (typeof options.logger.error == 'function')
&& (typeof options.logger.debug == 'function')
? options.logger : {error:function(message, object) {}, log:function(message, object) {}, debug:function(message, object) {}};
this.logger = this.options.logger != null
&& (typeof this.options.logger.debug == 'function')
&& (typeof this.options.logger.error == 'function')
&& (typeof this.options.logger.debug == 'function')
? this.options.logger : {error:function(message, object) {}, log:function(message, object) {}, debug:function(message, object) {}};
// Allow slaveOk
this.slaveOk = this.options["slave_ok"] == null ? false : this.options["slave_ok"];

Expand Down
76 changes: 36 additions & 40 deletions lib/mongodb/responses/mongo_reply.js
Original file line number Diff line number Diff line change
Expand Up @@ -6,47 +6,43 @@ var Long = require('../goog/math/long').Long,
Reply message from mongo db
**/
var MongoReply = exports.MongoReply = function(db, binary_reply) {
try {
this.documents = [];
var index = 0;
// Unpack the standard header first
var messageLength = binary_reply[index] | binary_reply[index + 1] << 8 | binary_reply[index + 2] << 16 | binary_reply[index + 3] << 24;
index = index + 4;
// Fetch the request id for this reply
this.requestId = binary_reply[index] | binary_reply[index + 1] << 8 | binary_reply[index + 2] << 16 | binary_reply[index + 3] << 24;
index = index + 4;
// Fetch the id of the request that triggered the response
this.responseTo = binary_reply[index] | binary_reply[index + 1] << 8 | binary_reply[index + 2] << 16 | binary_reply[index + 3] << 24;
// Skip op-code field
index = index + 4 + 4;
// Unpack the reply message
this.responseFlag = binary_reply[index] | binary_reply[index + 1] << 8 | binary_reply[index + 2] << 16 | binary_reply[index + 3] << 24;
index = index + 4;
// Unpack the cursor id (a 64 bit long integer)
var low_bits = binary_reply[index] | binary_reply[index + 1] << 8 | binary_reply[index + 2] << 16 | binary_reply[index + 3] << 24;
index = index + 4;
var high_bits = binary_reply[index] | binary_reply[index + 1] << 8 | binary_reply[index + 2] << 16 | binary_reply[index + 3] << 24;
index = index + 4;
this.cursorId = new db.bson_deserializer.Long(low_bits, high_bits);
// Unpack the starting from
this.startingFrom = binary_reply[index] | binary_reply[index + 1] << 8 | binary_reply[index + 2] << 16 | binary_reply[index + 3] << 24;
index = index + 4;
// Unpack the number of objects returned
this.numberReturned = binary_reply[index] | binary_reply[index + 1] << 8 | binary_reply[index + 2] << 16 | binary_reply[index + 3] << 24;
index = index + 4;
this.documents = [];
var index = 0;
// Unpack the standard header first
var messageLength = binary_reply[index] | binary_reply[index + 1] << 8 | binary_reply[index + 2] << 16 | binary_reply[index + 3] << 24;
index = index + 4;
// Fetch the request id for this reply
this.requestId = binary_reply[index] | binary_reply[index + 1] << 8 | binary_reply[index + 2] << 16 | binary_reply[index + 3] << 24;
index = index + 4;
// Fetch the id of the request that triggered the response
this.responseTo = binary_reply[index] | binary_reply[index + 1] << 8 | binary_reply[index + 2] << 16 | binary_reply[index + 3] << 24;
// Skip op-code field
index = index + 4 + 4;
// Unpack the reply message
this.responseFlag = binary_reply[index] | binary_reply[index + 1] << 8 | binary_reply[index + 2] << 16 | binary_reply[index + 3] << 24;
index = index + 4;
// Unpack the cursor id (a 64 bit long integer)
var low_bits = binary_reply[index] | binary_reply[index + 1] << 8 | binary_reply[index + 2] << 16 | binary_reply[index + 3] << 24;
index = index + 4;
var high_bits = binary_reply[index] | binary_reply[index + 1] << 8 | binary_reply[index + 2] << 16 | binary_reply[index + 3] << 24;
index = index + 4;
this.cursorId = new db.bson_deserializer.Long(low_bits, high_bits);
// Unpack the starting from
this.startingFrom = binary_reply[index] | binary_reply[index + 1] << 8 | binary_reply[index + 2] << 16 | binary_reply[index + 3] << 24;
index = index + 4;
// Unpack the number of objects returned
this.numberReturned = binary_reply[index] | binary_reply[index + 1] << 8 | binary_reply[index + 2] << 16 | binary_reply[index + 3] << 24;
index = index + 4;

// Let's unpack all the bson document, deserialize them and store them
for(var object_index = 0; object_index < this.numberReturned; object_index++) {
// Read the size of the bson object
var bsonObjectSize = binary_reply[index] | binary_reply[index + 1] << 8 | binary_reply[index + 2] << 16 | binary_reply[index + 3] << 24;
// Deserialize the object and add to the documents array
this.documents.push(db.bson_deserializer.BSON.deserialize(binary_reply.slice(index, index + bsonObjectSize)));
// Adjust binary index to point to next block of binary bson data
index = index + bsonObjectSize;
}
} catch(err) {
debug("============================= caught error :: " + inspect(err))
}
// Let's unpack all the bson document, deserialize them and store them
for(var object_index = 0; object_index < this.numberReturned; object_index++) {
// Read the size of the bson object
var bsonObjectSize = binary_reply[index] | binary_reply[index + 1] << 8 | binary_reply[index + 2] << 16 | binary_reply[index + 3] << 24;
// Deserialize the object and add to the documents array
this.documents.push(db.bson_deserializer.BSON.deserialize(binary_reply.slice(index, index + bsonObjectSize)));
// Adjust binary index to point to next block of binary bson data
index = index + bsonObjectSize;
}
};

MongoReply.prototype.is_error = function(){
Expand Down
56 changes: 29 additions & 27 deletions test/bson/bson_test.js
Original file line number Diff line number Diff line change
Expand Up @@ -18,11 +18,11 @@ var testCase = require('../../deps/nodeunit').testCase,
Double = mongodb.Double,
BinaryParser = mongodb.BinaryParser;

var m = require('../../lib/mongodb').pure();
Long = m.Long;
Timestamp = m.Timestamp;
ObjectID = m.ObjectID;
Binary = m.Binary;
// var m = require('../../lib/mongodb').pure();
// Long = m.Long;
// Timestamp = m.Timestamp;
// ObjectID = m.ObjectID;
// Binary = m.Binary;

var BSONSE = mongodb,
BSONDE = mongodb;
Expand Down Expand Up @@ -540,28 +540,28 @@ var tests = testCase({
test.done();
},

'Should Deserialize Larger Integers as Long not Number' : function(test) {
function roundTrip(val) {
var doc = {doc: val};
var serialized_data = BSONSE.BSON.serialize(doc, false, true);

var serialized_data2 = new Buffer(BSONSE.BSON.calculateObjectSize(doc));
BSONSE.BSON.serializeWithBufferAndIndex(doc, false, serialized_data2, 0);
assertBuffersEqual(test, serialized_data, serialized_data2, 0);

var deserialized_data = BSONDE.BSON.deserialize(serialized_data);
test.deepEqual(doc.doc, deserialized_data.doc);
};

var long1 = require('../../lib/mongodb').pure().Long.fromNumber(Math.pow(2,53))
.add(require('../../lib/mongodb').pure().Long.ONE);
var long2 = require('../../lib/mongodb').pure().Long.fromNumber(-Math.pow(2,53))
.subtract(require('../../lib/mongodb').pure().Long.ONE);

roundTrip(long1);
roundTrip(long2);
test.done();
},
// 'Should Deserialize Larger Integers as Long not Number' : function(test) {
// function roundTrip(val) {
// var doc = {doc: val};
// var serialized_data = BSONSE.BSON.serialize(doc, false, true);
//
// var serialized_data2 = new Buffer(BSONSE.BSON.calculateObjectSize(doc));
// BSONSE.BSON.serializeWithBufferAndIndex(doc, false, serialized_data2, 0);
// assertBuffersEqual(test, serialized_data, serialized_data2, 0);
//
// var deserialized_data = BSONDE.BSON.deserialize(serialized_data);
// test.deepEqual(doc.doc, deserialized_data.doc);
// };
//
// var long1 = require('../../lib/mongodb').pure().Long.fromNumber(Math.pow(2,53))
// .add(require('../../lib/mongodb').pure().Long.ONE);
// var long2 = require('../../lib/mongodb').pure().Long.fromNumber(-Math.pow(2,53))
// .subtract(require('../../lib/mongodb').pure().Long.ONE);
//
// roundTrip(long1);
// roundTrip(long2);
// test.done();
// },

'Should Correctly Serialize and Deserialize Long Integer and Timestamp as different types' : function(test) {
var long = Long.fromNumber(9223372036854775807);
Expand Down Expand Up @@ -1075,3 +1075,5 @@ var tests = testCase({

// Assign out tests
module.exports = tests;

// Crazy docs
6 changes: 5 additions & 1 deletion test/socket_error_handling_test.js
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,7 @@ var hexStringToBinary = exports.hexStringToBinary = function(string) {
for(var i = 0; i < numberofValues; i++) {
array += String.fromCharCode(parseInt(string[i*2] + string[i*2 + 1], 16));
}

return array;
}

Expand All @@ -50,7 +51,7 @@ var tests = testCase({
},

tearDown: function(callback) {
callback();
callback();
},

'Should connect to dummy socket delivering garbage messages that should force error to be emitted' : function(test) {
Expand Down Expand Up @@ -91,6 +92,9 @@ var tests = testCase({
test.equal("unparsable", err.err)
test.equal(-1222, err.parseState.sizeOfMessage)

// Close server
server.close();
// Test is done
test.done();
})
});
Expand Down

0 comments on commit be0257a

Please sign in to comment.