Details logged on message received

azure-contrib · Mar 16, 2013 · d36356e · d36356e
1 parent 577fe1c
commit d36356e
Show file tree

Hide file tree

Showing 2 changed files with 30 additions and 3 deletions.
diff --git a/lib/servicebusconnector.js b/lib/servicebusconnector.js
@@ -55,7 +55,6 @@ ServiceBusConnector.prototype.start = function () {
       if (!err) {
         var msg = self.unpackMessage(receivedMessage);
         if (msg.args !== null) {
-          self.log && self.log.info('Service Bus received message', 'from:' + msg.nodeId, 'message:' + msg.name);
           self.emit('message', msg.nodeId, msg.name, msg.args, msg.seq);
         } else {
           self.emit('badmessage', msg.nodeId, msg.name, msg.seq);
@@ -117,13 +116,20 @@ ServiceBusConnector.prototype.unpackMessage = function(message) {
 
   try {
     result.args = JSON.parse(message.body);
+    this.log && this.log.info('Service Bus received message', 'from:' + result.nodeId, 'message:' + result.name);
+    this.log && this.log.debug('Service Bus received message', 'size:' + message.brokerProperties.Size,
+      'enqueuedTime:' + message.brokerProperties.EnqueuedTimeUtc,
+      'messageId:' + message.brokerProperties.MessageId);
     return result;
   } catch (ex) {
     // Issue unpacking the message, assume it's bad and toss it
     this.log && this.log.warn('Service Bus bad message received',
       'CorrelationId:' + message.brokerProperties.CorrelationId,
       'Label:' + message.brokerProperties.Label,
-      'SequenceNumber:' + message.brokerProperties.SequenceNumber);
+      'SequenceNumber:' + message.brokerProperties.SequenceNumber,
+      'size:' + message.brokerProperties.Size,
+      'enqueuedTime:' + message.brokerProperties.EnqueuedTimeUtc,
+      'messageId:' + message.brokerProperties.MessageId);
     return result;
   }
 }

diff --git a/test/logging-tests.js b/test/logging-tests.js
@@ -115,7 +115,28 @@ describe('logging', function () {
     logger.info.calledWith('Service Bus received message',
       'from:sourceNode', 'message:aMessage').should.be.true;
   });
-
+
+  it('should log details when good message is received', function () {
+    var message = {
+      brokerProperties: {
+        CorrelationId: 'sourceNode',
+        Label: 'aMessage',
+        SequenceNumber: 2,
+        EnqueuedTimeUtc: new Date().toString(),
+        MessageId: 1234
+      },
+      body: JSON.stringify([1, 2, 3])
+    };
+    message.brokerProperties.Size = message.body.length;
+
+    recv(message);
+
+    logger.debug.calledWith('Service Bus received message',
+      'size:' + message.brokerProperties.Size,
+      'enqueuedTime:' + message.brokerProperties.EnqueuedTimeUtc,
+      'messageId:' + message.brokerProperties.MessageId).should.be.true;
+  });
+
   // Helpers for sending messages
   function recvNothing() {
     var recvFunc = recvFuncs.shift();