diff --git a/package-lock.json b/package-lock.json index 7fe1591..5301e9f 100644 --- a/package-lock.json +++ b/package-lock.json @@ -1,12 +1,12 @@ { "name": "mikrolog", - "version": "2.1.10", + "version": "2.1.11", "lockfileVersion": 2, "requires": true, "packages": { "": { "name": "mikrolog", - "version": "2.1.10", + "version": "2.1.11", "license": "MIT", "dependencies": { "aws-metadata-utils": "1" diff --git a/package.json b/package.json index b8f4ec2..88b8fa9 100644 --- a/package.json +++ b/package.json @@ -1,7 +1,7 @@ { "name": "mikrolog", "description": "The JSON logger you always wanted for Lambda.", - "version": "2.1.10", + "version": "2.1.11", "author": "Mikael Vesavuori", "license": "MIT", "main": "./lib/index.js", diff --git a/src/entities/MikroLog.ts b/src/entities/MikroLog.ts index 3e5bf6e..2a7979d 100644 --- a/src/entities/MikroLog.ts +++ b/src/entities/MikroLog.ts @@ -41,7 +41,7 @@ export class MikroLog { private static correlationId: string; private static debugSamplingLevel: number; private static isDebugLogSampled: boolean; - private coldStart = true; + private static isColdStart = true; private constructor() { MikroLog.metadataConfig = {}; @@ -60,6 +60,8 @@ export class MikroLog { * If the `start` method receives any input, that input will * overwrite any existing metadata, event, and context. * + * It will also, consequently, wipe the Lambda cold start state. + * * If you want to "add" to these, you should instead call * `enrich()` and pass in your additional data there. */ @@ -68,10 +70,23 @@ export class MikroLog { MikroLog.metadataConfig = input?.metadataConfig || {}; MikroLog.event = input?.event || {}; MikroLog.context = input?.context || {}; + MikroLog.context.isColdStart = MikroLog.getColdStart(); MikroLog.correlationId = input?.correlationId || ''; return MikroLog.instance; } + /** + * @description Is this a Lambda cold start? + */ + private static getColdStart(): boolean { + if (MikroLog.isColdStart) { + MikroLog.isColdStart = false; + return true; + } + + return false; + } + /** * @description An emergency mechanism if you absolutely need to * reset the instance to its empty default state. @@ -89,18 +104,6 @@ export class MikroLog { MikroLog.context = Object.assign(MikroLog.context, input.context || {}); } - /** - * @description Is this a Lambda cold start? - */ - public isColdStart(): boolean { - if (this.coldStart) { - this.coldStart = false; - return true; - } - - return false; - } - /** * @description Set correlation ID manually, for example for use in cross-boundary calls. * @@ -234,6 +237,7 @@ export class MikroLog { */ private getDynamicMetadata() { const metadata = getMetadata(MikroLog.event, MikroLog.context); + return { ...metadata, correlationId: MikroLog.correlationId || metadata.correlationId @@ -248,7 +252,7 @@ export class MikroLog { Object.entries(metadata).forEach((entry: any) => { const [key, value] = entry; - if (value) filteredMetadata[key] = value; + if (value || value === false || value === 0) filteredMetadata[key] = value; }); return filteredMetadata; @@ -297,7 +301,7 @@ export class MikroLog { error: log.level === 'ERROR', level: log.level, httpStatusCode: log.httpStatusCode, - isColdStart: this.isColdStart() + isColdStart: MikroLog.context.isColdStart }; const filteredOutput = this.filterOutput(logOutput, redactedKeys, maskedValues); diff --git a/src/interfaces/Metadata.ts b/src/interfaces/Metadata.ts index 1e50b3b..29edd3b 100644 --- a/src/interfaces/Metadata.ts +++ b/src/interfaces/Metadata.ts @@ -111,6 +111,10 @@ export interface DynamicMetadataOutput { * @description The AWS account ID that the system is running in. */ accountId: string; + /** + * @description Is this a Lambda cold start? + */ + isColdStart: boolean; } /** diff --git a/testdata/fullLog.json b/testdata/fullLog.json new file mode 100644 index 0000000..29ad6df --- /dev/null +++ b/testdata/fullLog.json @@ -0,0 +1,20 @@ +{ + "version": 1, + "owner": "MyCompany", + "hostPlatform": "aws", + "domain": "CustomerAcquisition", + "system": "ShowroomActivities", + "service": "UserSignUp", + "team": "MyDemoTeam", + "tags": [""], + "dataSensitivity": "public", + "message": "Hello World", + "error": false, + "httpStatusCode": 200, + "isColdStart": true, + "level": "INFO", + "id": "1256767f-c875-4d82-813d-bc260bd0ba07", + "timestamp": "2022-07-25T08:52:21.121Z", + "timestampEpoch": "1656438566041", + "jurisdiction": "EU" +} diff --git a/tests/MikroLog.test.ts b/tests/MikroLog.test.ts index d5c9c86..7b77dc2 100644 --- a/tests/MikroLog.test.ts +++ b/tests/MikroLog.test.ts @@ -3,36 +3,25 @@ import test from 'ava'; import { MikroLog } from '../src/entities/MikroLog'; import { metadataConfig } from '../testdata/config'; +import fullLog from '../testdata/fullLog.json'; -const fullLog = { - version: 1, - owner: 'MyCompany', - hostPlatform: 'aws', - domain: 'CustomerAcquisition', - system: 'ShowroomActivities', - service: 'UserSignUp', - team: 'MyDemoTeam', - tags: [''], - dataSensitivity: 'public', - message: 'Hello World', - error: false, - httpStatusCode: 200, - isColdStart: true, - level: 'INFO', - id: '1256767f-c875-4d82-813d-bc260bd0ba07', - timestamp: '2022-07-25T08:52:21.121Z', - timestampEpoch: '1656438566041', - jurisdiction: 'EU' -}; +function cleanObject(object: Record) { + delete object['id']; + delete object['timestamp']; + delete object['timestampEpoch']; + delete object['isColdStart']; + + return object; +} /** * POSITIVE TESTS */ test.serial('Starting MikroLog will set the instance to a new one', (t) => { + const expected = true; const logger = MikroLog.start(); const isInstance = logger instanceof MikroLog; - const expected = true; t.is(isInstance, expected); }); @@ -64,16 +53,13 @@ test.serial( t.true(response['id'] !== null); t.true(response['timestamp'] !== null); t.true(response['timestampEpoch'] !== null); + t.true(response['isColdStart'] !== null); // Drop dynamic fields for test validation - delete response['id']; - delete response['timestamp']; - delete response['timestampEpoch']; - delete expected['id']; - delete expected['timestamp']; - delete expected['timestampEpoch']; - - t.deepEqual(response, expected); + const cleanedResponse = cleanObject(response); + const cleanedExpected = cleanObject(expected); + + t.deepEqual(cleanedResponse, cleanedExpected); } ); @@ -93,16 +79,13 @@ test.serial('It should return (print out) a structured log when given a string m t.true(response['id'] !== null); t.true(response['timestamp'] !== null); t.true(response['timestampEpoch'] !== null); + t.true(response['isColdStart'] !== null); // Drop dynamic fields for test validation - delete response['id']; - delete response['timestamp']; - delete response['timestampEpoch']; - delete expected['id']; - delete expected['timestamp']; - delete expected['timestampEpoch']; - - t.deepEqual(response, expected); + const cleanedResponse = cleanObject(response); + const cleanedExpected = cleanObject(expected); + + t.deepEqual(cleanedResponse, cleanedExpected); }); test.serial( @@ -123,16 +106,13 @@ test.serial( t.true(response['id'] !== null); t.true(response['timestamp'] !== null); t.true(response['timestampEpoch'] !== null); + t.true(response['isColdStart'] !== null); // Drop dynamic fields for test validation - delete response['id']; - delete response['timestamp']; - delete response['timestampEpoch']; - delete expected['id']; - delete expected['timestamp']; - delete expected['timestampEpoch']; - - t.deepEqual(response, expected); + const cleanedResponse = cleanObject(response); + const cleanedExpected = cleanObject(expected); + + t.deepEqual(cleanedResponse, cleanedExpected); } ); @@ -155,16 +135,13 @@ test.serial( t.true(response['id'] !== null); t.true(response['timestamp'] !== null); t.true(response['timestampEpoch'] !== null); + t.true(response['isColdStart'] !== null); // Drop dynamic fields for test validation - delete response['id']; - delete response['timestamp']; - delete response['timestampEpoch']; - delete expected['id']; - delete expected['timestamp']; - delete expected['timestampEpoch']; - - t.deepEqual(response, expected); + const cleanedResponse = cleanObject(response); + const cleanedExpected = cleanObject(expected); + + t.deepEqual(cleanedResponse, cleanedExpected); } ); @@ -187,16 +164,13 @@ test.serial( t.true(response['id'] !== null); t.true(response['timestamp'] !== null); t.true(response['timestampEpoch'] !== null); + t.true(response['isColdStart'] !== null); // Drop dynamic fields for test validation - delete response['id']; - delete response['timestamp']; - delete response['timestampEpoch']; - delete expected['id']; - delete expected['timestamp']; - delete expected['timestampEpoch']; - - t.deepEqual(response, expected); + const cleanedResponse = cleanObject(response); + const cleanedExpected = cleanObject(expected); + + t.deepEqual(cleanedResponse, cleanedExpected); } ); @@ -221,16 +195,13 @@ test.serial( t.true(response['id'] !== null); t.true(response['timestamp'] !== null); t.true(response['timestampEpoch'] !== null); + t.true(response['isColdStart'] !== null); // Drop dynamic fields for test validation - delete response['id']; - delete response['timestamp']; - delete response['timestampEpoch']; - delete expected['id']; - delete expected['timestamp']; - delete expected['timestampEpoch']; - - t.deepEqual(response, expected); + const cleanedResponse = cleanObject(response); + const cleanedExpected = cleanObject(expected); + + t.deepEqual(cleanedResponse, cleanedExpected); } ); @@ -402,16 +373,13 @@ test.serial('It should redact keys when given a "redactedKeys" list', (t) => { t.true(response['id'] !== null); t.true(response['timestamp'] !== null); t.true(response['timestampEpoch'] !== null); + t.true(response['isColdStart'] !== null); // Drop dynamic fields for test validation - delete response['id']; - delete response['timestamp']; - delete response['timestampEpoch']; - delete expected['id']; - delete expected['timestamp']; - delete expected['timestampEpoch']; - - t.deepEqual(response, expected); + const cleanedResponse = cleanObject(response); + const cleanedExpected = cleanObject(expected); + + t.deepEqual(cleanedResponse, cleanedExpected); }); test.serial('It should mask values when given a "maskedValues" list', (t) => { @@ -449,16 +417,13 @@ test.serial('It should mask values when given a "maskedValues" list', (t) => { t.true(response['id'] !== null); t.true(response['timestamp'] !== null); t.true(response['timestampEpoch'] !== null); + t.true(response['isColdStart'] !== null); // Drop dynamic fields for test validation - delete response['id']; - delete response['timestamp']; - delete response['timestampEpoch']; - delete expected['id']; - delete expected['timestamp']; - delete expected['timestampEpoch']; - - t.deepEqual(response, expected); + const cleanedResponse = cleanObject(response); + const cleanedExpected = cleanObject(expected); + + t.deepEqual(cleanedResponse, cleanedExpected); }); test.serial('It should accept a custom metadata configuration', (t) => { @@ -494,16 +459,13 @@ test.serial('It should accept a custom metadata configuration', (t) => { t.true(response['id'] !== null); t.true(response['timestamp'] !== null); t.true(response['timestampEpoch'] !== null); + t.true(response['isColdStart'] !== null); // Drop dynamic fields for test validation - delete response['id']; - delete response['timestamp']; - delete response['timestampEpoch']; - delete expected['id']; - delete expected['timestamp']; - delete expected['timestampEpoch']; - - t.deepEqual(response, expected); + const cleanedResponse = cleanObject(response); + const cleanedExpected = cleanObject(expected); + + t.deepEqual(cleanedResponse, cleanedExpected); }); test.serial('It should retain falsy but defined values in logs', (t) => { @@ -535,16 +497,13 @@ test.serial('It should retain falsy but defined values in logs', (t) => { t.true(response['id'] !== null); t.true(response['timestamp'] !== null); t.true(response['timestampEpoch'] !== null); + t.true(response['isColdStart'] !== null); // Drop dynamic fields for test validation - delete response['id']; - delete response['timestamp']; - delete response['timestampEpoch']; - delete expected['id']; - delete expected['timestamp']; - delete expected['timestampEpoch']; - - t.deepEqual(response, expected); + const cleanedResponse = cleanObject(response); + const cleanedExpected = cleanObject(expected); + + t.deepEqual(cleanedResponse, cleanedExpected); }); test.serial('It should be able to merge enrichment even if input is essentially empty', (t) => { @@ -570,11 +529,11 @@ test.serial('It should be able to merge enrichment even if input is essentially t.true(response['id'] !== null); t.true(response['timestamp'] !== null); t.true(response['timestampEpoch'] !== null); + t.true(response['isColdStart'] !== null); // Drop dynamic fields for test validation - delete response['id']; - delete response['timestamp']; - delete response['timestampEpoch']; + const cleanedResponse = cleanObject(response); + const cleanedExpected = cleanObject(expected); - t.deepEqual(response, expected); + t.deepEqual(cleanedResponse, cleanedExpected); }); diff --git a/tests/isColdStart.test.ts b/tests/isColdStart.test.ts new file mode 100644 index 0000000..45ae03a --- /dev/null +++ b/tests/isColdStart.test.ts @@ -0,0 +1,31 @@ +import test from 'ava'; + +import { MikroLog } from '../src/entities/MikroLog'; + +/** + * @note These tests should be separated as the cold start state + * is (as intended) only set to `true` on the first call. + */ + +test.serial('It should get a "true" cold start status on the first run', (t) => { + const expected = true; + const logger = MikroLog.start(); + + const response: any = logger.log('').isColdStart; + + t.is(response, expected); +}); + +test.serial('It should get a "false" cold start status if run more than once', (t) => { + MikroLog.reset(); + const expected = false; + MikroLog.start(); + MikroLog.start(); + MikroLog.start(); + MikroLog.start(); + const logger = MikroLog.start(); + + const response: any = logger.log('').isColdStart; + + t.is(response, expected); +});