feat(logging): Log email template header if available (#1466), r=@jbuck

* feat(logging): Log email template header if avalible

* feat(logging): Add flow logging and unit tests

* feat(logging): Remove flowEvent logging

* feat(logging): Add logging of bounce type

* feat(logging): Fix busted test case

Author: vbudhram

lib/bounces.js

@@ -49,6 +49,23 @@ module.exports = function (log, error) {
       }
     }
 
+    function getHeaderValue(headerName, message){
+      var value = ''
+      if (message.mail && message.mail.headers) {
+        message.mail.headers.some(function (header) {
+          if (header.name === headerName) {
+            value = header.value
+            return true
+          }
+
+          return false
+        })
+      }
+
+      return value
+    }
+
+
     function handleBounce(message) {
       var recipients = []
       if (message.bounce && message.bounce.bounceType === 'Permanent') {
@@ -57,17 +74,43 @@ module.exports = function (log, error) {
       else if (message.complaint && message.complaint.complaintFeedbackType === 'abuse') {
         recipients = message.complaint.complainedRecipients
       }
+
+      // SES can now send custom headers if enabled on topic.
+      // Headers are stored as an array of name/value pairs.
+      // Log the `X-Template-Name` header to help track the email template that bounced.
+      // Ref: http://docs.aws.amazon.com/ses/latest/DeveloperGuide/notification-contents.html
+      var templateName = getHeaderValue('X-Template-Name', message)
+
       return P.each(recipients, function (recipient) {
+
         var email = recipient.emailAddress
-        log.info({
+        var logData = {
           op: 'handleBounce',
           action: recipient.action,
           email: email,
           bounce: !!message.bounce,
           diagnosticCode: recipient.diagnosticCode,
           status: recipient.status
-        })
+        }
+
+        // Template name corresponds directly with the email template that was used
+        if(templateName) {
+          logData.template = templateName
+        }
+
+        // Log the type of bounce that occurred
+        // Ref: http://docs.aws.amazon.com/ses/latest/DeveloperGuide/notification-contents.html#bounce-types
+        if (message.bounce && message.bounce.bounceType) {
+          logData.bounceType = message.bounce.bounceType
+
+          if (message.bounce && message.bounce.bounceSubType) {
+            logData.bounceSubType = message.bounce.bounceSubType
+          }
+        }
+
+        log.info(logData)
         log.increment('account.email_bounced')
+
         return findEmailRecord(email)
           .then(
             deleteAccountIfUnverified,

test/local/bounce_tests.js

@@ -65,7 +65,7 @@ test(
       t.equal(mockDB.deleteAccount.callCount, 2)
       t.equal(mockDB.emailRecord.args[0][0], 'test@example.com')
       t.equal(mockDB.emailRecord.args[1][0], 'foobar@example.com')
-      t.equal(mockLog.messages.length, 6)
+      t.equal(mockLog.messages.length, 6, 'messages logged')
       t.equal(mockLog.messages[1].level, 'increment')
       t.equal(mockLog.messages[1].args[0], 'account.email_bounced')
       t.equal(mockLog.messages[5].level, 'info')
@@ -271,3 +271,53 @@ test(
     })
   }
 )
+
+test(
+  'can log email template name and bounceType',
+  function (t) {
+    var mockLog = spyLog()
+    var mockDB = {
+      emailRecord: sinon.spy(function (email) {
+        return P.resolve({
+          uid: '123456',
+          email: email,
+          emailVerified: false
+        })
+      }),
+      deleteAccount: sinon.spy(function () {
+        return P.resolve({ })
+      })
+    }
+    var mockMsg = mockMessage({
+      bounce: {
+        bounceType: 'Permanent',
+        bounceSubType: 'General',
+        bouncedRecipients: [
+          {emailAddress: 'test@example.com'}
+        ]
+      },
+      mail: {
+        headers: [
+          {
+            name: 'X-Template-Name',
+            value: 'verifyLoginEmail'
+          }
+        ]
+      }
+    })
+
+    return mockedBounces(mockLog, mockDB).handleBounce(mockMsg).then(function () {
+      t.equal(mockDB.emailRecord.callCount, 1)
+      t.equal(mockDB.emailRecord.args[0][0], 'test@example.com')
+      t.equal(mockDB.deleteAccount.callCount, 1)
+      t.equal(mockDB.deleteAccount.args[0][0].email, 'test@example.com')
+      t.equal(mockLog.messages.length, 3)
+      t.equal(mockLog.messages[0].args[0].op, 'handleBounce')
+      t.equal(mockLog.messages[0].args[0].email, 'test@example.com')
+      t.equal(mockLog.messages[0].args[0].template, 'verifyLoginEmail')
+      t.equal(mockLog.messages[0].args[0].bounceType, 'Permanent')
+      t.equal(mockLog.messages[0].args[0].bounceSubType, 'General')
+      t.equal(mockLog.messages[1].args[0], 'account.email_bounced')
+    })
+  }
+)