log updates payload when logging

Author: NickOvt

lib/api/updates.js

@@ -22,6 +22,22 @@ const hasUpdatesStreamLogging = !!(config.log && config.log.updateStream);
 
 const formatLogValue = value => String(value);
 
+const getJournalPayload = entry => {
+    const data = {};
+    Object.keys(entry).forEach(key => {
+        if (!['_id', 'ignore', 'user', 'modseq', 'unseenChange', 'created'].includes(key)) {
+            if (entry.command !== 'COUNTERS' && key === 'unseen') {
+                return;
+            }
+            data[key] = entry[key];
+        }
+    });
+
+    return data;
+};
+
+const stringifyJournalPayload = (entry, space) => JSON.stringify(getJournalPayload(entry), null, space);
+
 const logUpdatesStream = (level, session, message, ...args) => {
     if (!hasUpdatesStreamLogging) {
         return;
@@ -35,32 +51,36 @@ const logUpdatesEvent = (session, source, entry) => {
         return;
     }
 
+    const payload = stringifyJournalPayload(entry);
+
     if (entry.command === 'COUNTERS') {
         return log.verbose(
             'API',
-            '[%s] action=updates-event source=%s user=%s event=%s eventId=%s mailbox=%s total=%s unseen=%s',
+            '[%s] action=updates-event source=%s user=%s event=%s eventId=%s mailbox=%s total=%s unseen=%s payload=%s',
             session.id,
             source,
             formatLogValue(session.user.id),
             entry.command,
             formatLogValue(entry._id),
             formatLogValue(entry.mailbox),
             formatLogValue(entry.total),
-            formatLogValue(entry.unseen)
+            formatLogValue(entry.unseen),
+            payload
         );
     }
 
     log.verbose(
         'API',
-        '[%s] action=updates-event source=%s user=%s event=%s eventId=%s mailbox=%s message=%s modseq=%s',
+        '[%s] action=updates-event source=%s user=%s event=%s eventId=%s mailbox=%s message=%s modseq=%s payload=%s',
         session.id,
         source,
         formatLogValue(session.user.id),
         formatLogValue(entry.command),
         formatLogValue(entry._id),
         formatLogValue(entry.mailbox),
         formatLogValue(entry.message),
-        formatLogValue(entry.modseq)
+        formatLogValue(entry.modseq),
+        payload
     );
 };
 
@@ -201,9 +221,11 @@ module.exports = (db, server, notifier) => {
                     } catch (err) {
                         log.error(
                             'API',
-                            '[%s] action=updates-event-write-fail source=live user=%s error=%s',
+                            '[%s] action=updates-event-write-fail source=live user=%s event=%s payload=%s error=%s',
                             session.id,
                             session.user.id.toString(),
+                            formatLogValue(message.command),
+                            stringifyJournalPayload(message),
                             err.stack || err
                         );
                     }
@@ -387,18 +409,8 @@ module.exports = (db, server, notifier) => {
 };
 
 function formatJournalData(e) {
-    let data = {};
-    Object.keys(e).forEach(key => {
-        if (!['_id', 'ignore', 'user', 'modseq', 'unseenChange', 'created'].includes(key)) {
-            if (e.command !== 'COUNTERS' && key === 'unseen') {
-                return;
-            }
-            data[key] = e[key];
-        }
-    });
-
     let response = [];
-    response.push('data: ' + JSON.stringify(data, false, 2).split('\n').join('\ndata: '));
+    response.push('data: ' + stringifyJournalPayload(e, 2).split('\n').join('\ndata: '));
     if (e._id) {
         response.push('id: ' + e._id.toString());
     }
@@ -496,7 +508,14 @@ function loadJournalStream(db, res, user, lastEventId, done, onEntry) {
                 res.write(data);
                 onEntry('replay', e);
             } catch (err) {
-                log.error('API', 'action=updates-event-write-fail user=%s event=%s error=%s', user.toString(), e.command, err.stack || err);
+                log.error(
+                    'API',
+                    'action=updates-event-write-fail user=%s event=%s payload=%s error=%s',
+                    user.toString(),
+                    formatLogValue(e.command),
+                    stringifyJournalPayload(e),
+                    err.stack || err
+                );
             }
 
             processed++;