feat: allow custom request data (#14)

- allow custom request data to be tracked on log entries
- allow removing the default tracked data if needed

Author: carbonrobot

README.md

@@ -114,6 +114,48 @@ across the entire platform.
 
 Amazon XRAY also has a unique tracing ID that is propagated across the requests and can be tracked as well.
 
+## Customize request tracing
+
+You can customize the data that is tracked for each request by adding a per-request mixin. 
+The request mixin takes the Lambda `event` and `context` and returns an object.
+
+This differs from the built in [pino mixin](https://github.com/pinojs/pino/blob/master/docs/api.md#mixin-function) as it only executes
+once per request where the built in pino mixin runs once per log entry.
+
+```ts
+import pino from 'pino-lambda';
+const logger = pino({
+  requestMixin: (event, context) => {
+    return {
+      // add request header host name
+      host: event.headers?.host,
+
+      // you can also set any request property to undefined
+      // which will remove it from the output
+      'x-correlation-id': undefined,
+
+      // add any type of static data
+      brand: 'famicom'
+    };
+  }
+});
+```
+
+Output
+
+```
+2018-12-20T17:05:25.330Z    6fccb00e-0479-11e9-af91-d7ab5c8fe19e    INFO  A log message
+{
+   "awsRequestId": "6fccb00e-0479-11e9-af91-d7ab5c8fe19e",
+   "x-correlation-trace-id": "Root=1-5c1bcbd2-9cce3b07143efd5bea1224f2;Parent=07adc05e4e92bf13;Sampled=1",
+   "level": 30,
+   "host": "www.host.com",
+   "brand": "famicom",
+   "message": "Some A log message",
+   "data": "Some data"
+}
+```
+
 ## Downstream Request Debugging
 
 When upstream services invoke a Lambda using `pino-lambda` they can send the `x-correlation-debug` header with a value of `true`. This will enable `debug` logging for that specific request. This is useful for tracing issues across the platform.

src/index.ts

@@ -2,6 +2,10 @@ import pino, { DestinationStream, LevelMapping, LoggerOptions, Logger } from 'pi
 import { GlobalContextStorageProvider, ContextStorageProvider, ContextMap } from './context';
 
 export interface ExtendedPinoOptions extends LoggerOptions {
+  requestMixin?: (
+    event: LamdbaEvent,
+    context: LambdaContext,
+  ) => { [key: string]: string | undefined };
   storageProvider?: ContextStorageProvider;
   streamWriter?: (str: string | Uint8Array) => boolean;
 }
@@ -148,6 +152,16 @@ export default (extendedPinoOptions?: ExtendedPinoOptions): PinoLambdaLogger =>
       logger.level = configuredLevel;
     }
 
+    // handle custom request level mixins
+    if (pinoOptions.requestMixin) {
+      const result = pinoOptions.requestMixin(event, context);
+      for (const key in result) {
+        // Cast this to string for typescript
+        // when the JSON serializer runs, by default it omits undefined properties
+        ctx[key] = result[key] as string;
+      }
+    }
+
     storageProvider.setContext(ctx);
   };
   return logger;

src/tests/index.spec.ts

@@ -72,9 +72,9 @@ tap.test('should add tags with a child logger', (t) => {
 tap.test('should preserve mixins', (t) => {
   let n = 0;
   const [log, output] = createLogger({
-    mixin () {
-      return { line: ++n }
-    }
+    mixin() {
+      return { line: ++n };
+    },
   });
 
   log.withRequest({}, { awsRequestId: '431234' });
@@ -86,7 +86,7 @@ tap.test('should preserve mixins', (t) => {
 
 tap.test('should capture xray trace IDs', (t) => {
   process.env._X_AMZN_TRACE_ID = 'x-1-2e2323r1234r4';
-  
+
   const [log, output] = createLogger();
 
   log.withRequest({}, { awsRequestId: '431234' });
@@ -97,6 +97,33 @@ tap.test('should capture xray trace IDs', (t) => {
   t.end();
 });
 
+tap.test('should capture custom request data', (t) => {
+  const [log, output] = createLogger({
+    requestMixin: (event, context) => ({
+      host: event.headers?.host,
+      functionName: context.functionName,
+    }),
+  });
+
+  log.withRequest({ headers: { host: 'www.host.com' } }, { awsRequestId: '431234' });
+  log.info('Message with trace ID');
+  t.matchSnapshot(output.buffer);
+  t.end();
+});
+
+tap.test('should allow removing default request data', (t) => {
+  const [log, output] = createLogger({
+    requestMixin: () => ({
+      'x-correlation-id': undefined,
+    }),
+  });
+
+  log.withRequest({}, { awsRequestId: '431234' });
+  log.info('Message with trace ID');
+  t.matchSnapshot(output.buffer);
+  t.end();
+});
+
 /**
  * Creates a test logger and output buffer for assertions
  * Returns the logger and the buffer

tap-snapshots/src-tests-index.spec.ts-TAP.test.js

@@ -9,6 +9,14 @@ exports[`src/tests/index.spec.ts TAP should add tags with a child logger > must
 2016-12-01T06:00:00.000Z	9048989	INFO	Message with userId	{"level":30,"time":1480572000000,"userId":12,"awsRequestId":"9048989","x-correlation-id":"9048989","msg":"Message with userId"}
 `
 
+exports[`src/tests/index.spec.ts TAP should allow removing default request data > must match snapshot 1`] = `
+2016-12-01T06:00:00.000Z	431234	INFO	Message with trace ID	{"level":30,"time":1480572000000,"awsRequestId":"431234","x-correlation-trace-id":"undefined","msg":"Message with trace ID"}
+`
+
+exports[`src/tests/index.spec.ts TAP should capture custom request data > must match snapshot 1`] = `
+2016-12-01T06:00:00.000Z	431234	INFO	Message with trace ID	{"level":30,"time":1480572000000,"awsRequestId":"431234","x-correlation-trace-id":"undefined","x-correlation-id":"431234","host":"www.host.com","msg":"Message with trace ID"}
+`
+
 exports[`src/tests/index.spec.ts TAP should capture xray trace IDs > must match snapshot 1`] = `
 2016-12-01T06:00:00.000Z	431234	INFO	Message with trace ID	{"level":30,"time":1480572000000,"awsRequestId":"431234","x-correlation-trace-id":"x-1-2e2323r1234r4","x-correlation-id":"431234","msg":"Message with trace ID"}
 `