feat: support lambda structured logging format (#51)

Author: carbonrobot

README.md

@@ -140,9 +140,46 @@ Output
 }
 ```
 
-## Customize output format
+### Lambda Structured Log Format
 
-By default, the `pinoLambdaDestination` uses the `CloudwatchLogFormatter`. If you want the request tracing features of `pino-lambda`, but don't need the Cloudwatch format, you can use the `PinoLogFormatter` which matches the default object output format of `pino`.
+By default, the `pinoLambdaDestination` uses the `CloudwatchLogFormatter`. 
+
+If you would like to use the new [AWS Lambda Advanced Logging Controls](https://aws.amazon.com/blogs/compute/introducing-advanced-logging-controls-for-aws-lambda-functions/) format for your logs, ensure your Lambda function is properly configured and enable `StructuredLogFormatter` in `pino-lambda`.
+
+```ts
+import pino from 'pino';
+import { lambdaRequestTracker, pinoLambdaDestination, StructuredLogFormatter } from 'pino-lambda';
+
+const destination = pinoLambdaDestination({
+  formatter: new StructuredLogFormatter()
+});
+const logger = pino(destination);
+const withRequest = lambdaRequestTracker();
+
+async function handler(event, context) {
+  withRequest(event, context);
+  logger.info({ data: 'Some data' }, 'A log message');
+}
+```
+
+Output
+
+```json
+{
+  "timestamp": "2016-12-01T06:00:00.000Z",
+  "requestId": "6fccb00e-0479-11e9-af91-d7ab5c8fe19e",
+  "level": "INFO",
+  "message": {
+    "msg": "A log message",
+    "data": "Some data",
+    "x-correlation-trace-id": "Root=1-5c1bcbd2-9cce3b07143efd5bea1224f2;Parent=07adc05e4e92bf13;Sampled=1"
+  }
+}
+```
+
+### Pino Log Format
+
+If you want the request tracing features of `pino-lambda`, but don't need the Cloudwatch format, you can use the `PinoLogFormatter` which matches the default object output format of `pino`.
 
 ```ts
 import pino from 'pino';
@@ -162,16 +199,19 @@ async function handler(event, context) {
 
 Output
 
-```
+```json
 {
-   "awsRequestId": "6fccb00e-0479-11e9-af91-d7ab5c8fe19e",
-   "x-correlation-trace-id": "Root=1-5c1bcbd2-9cce3b07143efd5bea1224f2;Parent=07adc05e4e92bf13;Sampled=1",
-   "level": 30,
-   "message": "A log message",
-   "data": "Some data"
+  "awsRequestId": "6fccb00e-0479-11e9-af91-d7ab5c8fe19e",
+  "x-correlation-trace-id": "Root=1-5c1bcbd2-9cce3b07143efd5bea1224f2;Parent=07adc05e4e92bf13;Sampled=1",
+  "level": 30,
+  "time": 1480572000000,
+  "msg": "A log message",
+  "data": "Some data"
 }
 ```
 
+### Custom Log Format
+
 The formatter function can also be replaced with any custom implementation you need by using the supplied interface.
 
 ```ts
@@ -197,7 +237,7 @@ Output
    "awsRequestId": "6fccb00e-0479-11e9-af91-d7ab5c8fe19e",
    "x-correlation-trace-id": "Root=1-5c1bcbd2-9cce3b07143efd5bea1224f2;Parent=07adc05e4e92bf13;Sampled=1",
    "level": 30,
-   "message": "A log message",
+   "msg": "A log message",
    "data": "Some data"
 }
 ```

src/formatters/format.ts

@@ -0,0 +1,10 @@
+import pino from 'pino';
+
+export const formatLevel = (level: string | number): string => {
+  if (typeof level === 'string') {
+    return level.toLocaleUpperCase();
+  } else if (typeof level === 'number') {
+    return pino.levels.labels[level]?.toLocaleUpperCase();
+  }
+  return level;
+};

src/formatters/index.ts

@@ -1,2 +1,3 @@
 export * from './lambda';
 export * from './pino';
+export * from './structured';

src/formatters/lambda.ts

@@ -1,14 +1,5 @@
-import pino from 'pino';
 import { ILogFormatter, LogData } from '../types';
-
-const formatLevel = (level: string | number): string => {
-  if (typeof level === 'string') {
-    return level.toLocaleUpperCase();
-  } else if (typeof level === 'number') {
-    return pino.levels.labels[level]?.toLocaleUpperCase();
-  }
-  return level;
-};
+import { formatLevel } from './format';
 
 /**
  * Formats the log in native cloudwatch format and

src/formatters/structured.ts

@@ -0,0 +1,18 @@
+import { ILogFormatter, LogData } from '../types';
+import { formatLevel } from './format';
+
+/**
+ * Formats the log in structured JSON format while
+ * including the Lambda context data automatically
+ * @see https://aws.amazon.com/blogs/compute/introducing-advanced-logging-controls-for-aws-lambda-functions
+ */
+export class StructuredLogFormatter implements ILogFormatter {
+  format({ awsRequestId, level, ...data }: LogData): string {
+    return JSON.stringify({
+      timestamp: new Date().toISOString(),
+      level: formatLevel(level),
+      requestId: awsRequestId,
+      message: data,
+    });
+  }
+}

src/tests/index.spec.ts

@@ -11,6 +11,7 @@ import {
   LambdaEvent,
   PinoLogFormatter,
   LogData,
+  StructuredLogFormatter,
 } from '../';
 
 import { GlobalContextStorageProvider } from '../context';
@@ -190,6 +191,17 @@ tap.test('should allow default pino formatter', (t) => {
   t.end();
 });
 
+tap.test('should allow structured logging format for cloudwatch', (t) => {
+  const { log, output, withRequest } = createLogger(undefined, {
+    formatter: new StructuredLogFormatter(),
+  });
+
+  withRequest({}, { awsRequestId: '431234' });
+  log.info('Message with pino formatter');
+  t.matchSnapshot(output.buffer);
+  t.end();
+});
+
 tap.test('should allow custom formatter', (t) => {
   const bananaFormatter = {
     format(data: LogData) {

tap-snapshots/src/tests/index.spec.ts.test.cjs

@@ -25,6 +25,10 @@ exports[`src/tests/index.spec.ts TAP should allow removing default request data
 2016-12-01T06:00:00.000Z	431234	INFO	Message with trace ID	{"awsRequestId":"431234","level":30,"time":1480572000000,"msg":"Message with trace ID"}
 `
 
+exports[`src/tests/index.spec.ts TAP should allow structured logging format for cloudwatch > must match snapshot 1`] = `
+{"timestamp":"2016-12-01T06:00:00.000Z","level":"INFO","requestId":"431234","message":{"x-correlation-id":"431234","time":1480572000000,"msg":"Message with pino formatter"}}
+`
+
 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	{"awsRequestId":"431234","x-correlation-id":"431234","host":"www.host.com","level":30,"time":1480572000000,"msg":"Message with trace ID"}
 `