feat(audit): Add the ability to specify a custom audit log serializer…

… (for err, req and res) (#1746)
restify · Feb 1, 2019 · 6231acd · 6231acd
1 parent 1dc34b4
commit 6231acd
Show file tree

Hide file tree

Showing 2 changed files with 102 additions and 51 deletions.
diff --git a/lib/plugins/audit.js b/lib/plugins/audit.js
@@ -50,6 +50,8 @@ function getResponseHeaders(res) {
  * the audit log object programmatically
  * @param {boolean} [opts.printLog=true] - Whether to print the log
  * via the logger.
+ * @param {Object} [opts.serializers] - Override the default logger serializers
+ * for err, req and res
  * @returns {Function} Handler
  * @fires audit when an audit log has been generated
  * @example
@@ -175,6 +177,7 @@ function auditLogger(opts) {
     assert.optionalFunc(opts.context, 'opts.context');
     assert.optionalObject(opts.server, 'opts.server');
     assert.optionalBool(opts.printLog, 'opts.printLog');
+    assert.optionalObject(opts.serializers, 'opts.serializers');
 
     if (
         opts.event !== 'after' &&
@@ -198,67 +201,69 @@ function auditLogger(opts) {
     }
     var errSerializer = bunyan.stdSerializers.err;
 
+    // don't break legacy use, where there was no top level opts.serializer
     if (opts.log.serializers && opts.log.serializers.err) {
         errSerializer = opts.log.serializers.err;
     }
 
-    var log = opts.log.child({
-        audit: true,
-        component: opts.event,
-        serializers: {
-            err: errSerializer,
-            req: function auditRequestSerializer(req) {
-                if (!req) {
-                    return false;
-                }
+    var DEFAULT_SERIALIZERS = {
+        err: errSerializer,
+        req: function auditRequestSerializer(req) {
+            if (!req) {
+                return false;
+            }
 
-                var timers = {};
-                (req.timers || []).forEach(function forEach(time) {
-                    var t = time.time;
-                    var _t = Math.floor(1000000 * t[0] + t[1] / 1000);
-                    timers[time.name] = (timers[time.name] || 0) + _t;
-                });
-                return {
-                    // account for native and queryParser plugin usage
-                    query:
-                        typeof req.query === 'function'
-                            ? req.query()
-                            : req.query,
-                    method: req.method,
-                    url: req.url,
-                    headers: req.headers,
-                    httpVersion: req.httpVersion,
-                    trailers: req.trailers,
-                    version: req.version(),
-                    body: opts.body === true ? req.body : undefined,
-                    timers: timers,
-                    connectionState:
-                        req.connectionState && req.connectionState()
-                };
-            },
-            res: function auditResponseSerializer(res) {
-                if (!res) {
-                    return false;
-                }
+            var timers = {};
+            (req.timers || []).forEach(function forEach(time) {
+                var t = time.time;
+                var _t = Math.floor(1000000 * t[0] + t[1] / 1000);
+                timers[time.name] = (timers[time.name] || 0) + _t;
+            });
+            return {
+                // account for native and queryParser plugin usage
+                query:
+                    typeof req.query === 'function' ? req.query() : req.query,
+                method: req.method,
+                url: req.url,
+                headers: req.headers,
+                httpVersion: req.httpVersion,
+                trailers: req.trailers,
+                version: req.version(),
+                body: opts.body === true ? req.body : undefined,
+                timers: timers,
+                connectionState: req.connectionState && req.connectionState()
+            };
+        },
+        res: function auditResponseSerializer(res) {
+            if (!res) {
+                return false;
+            }
 
-                var body;
+            var body;
 
-                if (opts.body === true) {
-                    if (res._body instanceof HttpError) {
-                        body = res._body.body;
-                    } else {
-                        body = res._body;
-                    }
+            if (opts.body === true) {
+                if (res._body instanceof HttpError) {
+                    body = res._body.body;
+                } else {
+                    body = res._body;
                 }
-
-                return {
-                    statusCode: res.statusCode,
-                    headers: getResponseHeaders(res),
-                    trailer: res._trailer || false,
-                    body: body
-                };
             }
+
+            return {
+                statusCode: res.statusCode,
+                headers: getResponseHeaders(res),
+                trailer: res._trailer || false,
+                body: body
+            };
         }
+    };
+
+    var serializers = Object.assign({}, DEFAULT_SERIALIZERS, opts.serializers);
+
+    var log = opts.log.child({
+        audit: true,
+        component: opts.event,
+        serializers: serializers
     });
 
     function audit(req, res, route, err) {

diff --git a/test/plugins/audit.test.js b/test/plugins/audit.test.js
@@ -165,6 +165,52 @@ describe('audit logger', function() {
         });
     });
 
+    it('test custom serializers', function(done) {
+        // Dirty hack to capture the log record using a ring buffer.
+        var ringbuffer = new bunyan.RingBuffer({ limit: 1 });
+
+        SERVER.once(
+            'after',
+            restify.plugins.auditLogger({
+                log: bunyan.createLogger({
+                    name: 'audit',
+                    streams: [
+                        {
+                            level: 'info',
+                            type: 'raw',
+                            stream: ringbuffer
+                        }
+                    ]
+                }),
+                event: 'after',
+                serializers: {
+                    req: function(req) {
+                        return { fooReq: 'barReq' };
+                    },
+                    res: function(res) {
+                        return { fooRes: 'barRes' };
+                    }
+                }
+            })
+        );
+
+        SERVER.get('/audit', function aTestHandler(req, res, next) {
+            res.send('');
+            return next();
+        });
+
+        SERVER.on('after', function() {
+            var record = ringbuffer.records && ringbuffer.records[0];
+            assert.equal(record.req.fooReq, 'barReq');
+            assert.equal(record.res.fooRes, 'barRes');
+            done();
+        });
+
+        CLIENT.get('/audit', function(err, req, res) {
+            assert.ifError(err);
+        });
+    });
+
     it('should log handler timers', function(done) {
         // Dirty hack to capture the log record using a ring buffer.
         var ringbuffer = new bunyan.RingBuffer({ limit: 1 });