diff --git a/docs/core/logger.md b/docs/core/logger.md index ab0bd44986..1153edfb3d 100644 --- a/docs/core/logger.md +++ b/docs/core/logger.md @@ -104,6 +104,9 @@ Your Logger will include the following keys to your structured logging (default | **xray_trace_id**: `string` | `1-5759e988-bd862e3fe1be46a994272793` | X-Ray Trace ID. This value is always presented in Lambda environment, whether [tracing is enabled](https://docs.aws.amazon.com/lambda/latest/dg/services-xray.html){target="_blank"} or not. Logger will always log this value. | | **error**: `Object` | `{ name: "Error", location: "/my-project/handler.ts:18", message: "Unexpected error #1", stack: "[stacktrace]"}` | Optional - An object containing information about the Error passed to the logger | +???+ info + When `POWERTOOLS_DEV` environment variable is present and set to `"true"` or `"1"`, Logger will pretty-print log messages for easier readability. We recommend to use this setting only when debugging on local environments. + ### Capturing Lambda context info You can enrich your structured logs with key Lambda context information in multiple ways. diff --git a/docs/index.md b/docs/index.md index 2b40b2a656..8a96d71be8 100644 --- a/docs/index.md +++ b/docs/index.md @@ -293,6 +293,7 @@ Core utilities such as Tracing, Logging, and Metrics will be available across al | **POWERTOOLS_TRACER_CAPTURE_HTTPS_REQUESTS** | Captures HTTP(s) requests as segments. | [Tracer](./core/tracer) | `true` | | **POWERTOOLS_LOGGER_LOG_EVENT** | Logs incoming event | [Logger](./core/logger) | `false` | | **POWERTOOLS_LOGGER_SAMPLE_RATE** | Debug log sampling | [Logger](./core/logger) | `0` | +| **POWERTOOLS_DEV** | Increase JSON indentation to ease debugging when running functions locally or in a non-production environment | [Logger](./core/logger) | `false` | | **LOG_LEVEL** | Sets logging level | [Logger](./core/logger) | `INFO` | ## Tenets diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts index 92f0d9ee07..e2198153ae 100644 --- a/packages/logger/src/Logger.ts +++ b/packages/logger/src/Logger.ts @@ -6,6 +6,7 @@ import { LogItem } from './log'; import cloneDeep from 'lodash.clonedeep'; import merge from 'lodash.merge'; import { ConfigServiceInterface, EnvironmentVariablesService } from './config'; +import { LogJsonIndent } from './types'; import type { ClassThatLogs, Environment, @@ -127,6 +128,8 @@ class Logger extends Utility implements ClassThatLogs { private logFormatter?: LogFormatterInterface; + private logIndentation: number = LogJsonIndent.COMPACT; + private logLevel?: LogLevel; private readonly logLevelThresholds: LogLevelThresholds = { @@ -595,7 +598,7 @@ class Logger extends Utility implements ClassThatLogs { const consoleMethod = logLevel.toLowerCase() as keyof ClassThatLogs; - this.console[consoleMethod](JSON.stringify(log.getAttributes(), this.removeCircularDependencies())); + this.console[consoleMethod](JSON.stringify(log.getAttributes(), this.removeCircularDependencies(), this.logIndentation)); } /** @@ -688,6 +691,19 @@ class Logger extends Utility implements ClassThatLogs { this.logFormatter = logFormatter || new PowertoolLogFormatter(); } + /** + * If the `POWERTOOLS_DEV' env variable is set, + * it adds JSON indentation for pretty printing logs. + * + * @private + * @returns {void} + */ + private setLogIndentation(): void { + if (this.getEnvVarsService().getDevMode()) { + this.logIndentation = LogJsonIndent.PRETTY; + } + } + /** * It sets the Logger's instance log level. * @@ -757,6 +773,7 @@ class Logger extends Utility implements ClassThatLogs { this.setLogFormatter(logFormatter); this.setPowertoolLogData(serviceName, environment); this.setLogEvent(); + this.setLogIndentation(); this.addPersistentLogAttributes(persistentLogAttributes); diff --git a/packages/logger/src/config/ConfigServiceInterface.ts b/packages/logger/src/config/ConfigServiceInterface.ts index 1f1a6ecc32..43f25d3649 100644 --- a/packages/logger/src/config/ConfigServiceInterface.ts +++ b/packages/logger/src/config/ConfigServiceInterface.ts @@ -22,6 +22,13 @@ interface ConfigServiceInterface { */ getCurrentEnvironment(): string + /** + * It returns the value of the POWERTOOLS_DEV environment variable. + * + * @returns {boolean} + */ + getDevMode(): boolean + /** * It returns the value of the POWERTOOLS_LOGGER_LOG_EVENT environment variable. * @@ -50,6 +57,14 @@ interface ConfigServiceInterface { */ getServiceName(): string + /** + * It returns true if the string value represents a boolean true value. + * + * @param {string} value + * @returns boolean + */ + isValueTrue(value: string): boolean + } export { diff --git a/packages/logger/src/config/EnvironmentVariablesService.ts b/packages/logger/src/config/EnvironmentVariablesService.ts index 28b5ee7b4b..fab7ec9fc8 100644 --- a/packages/logger/src/config/EnvironmentVariablesService.ts +++ b/packages/logger/src/config/EnvironmentVariablesService.ts @@ -20,6 +20,7 @@ class EnvironmentVariablesService extends CommonEnvironmentVariablesService impl // Reserved environment variables private awsRegionVariable = 'AWS_REGION'; private currentEnvironmentVariable = 'ENVIRONMENT'; + private devModeVariable = 'POWERTOOLS_DEV'; private functionNameVariable = 'AWS_LAMBDA_FUNCTION_NAME'; private functionVersionVariable = 'AWS_LAMBDA_FUNCTION_VERSION'; private logEventVariable = 'POWERTOOLS_LOGGER_LOG_EVENT'; @@ -45,6 +46,17 @@ class EnvironmentVariablesService extends CommonEnvironmentVariablesService impl return this.get(this.currentEnvironmentVariable); } + /** + * It returns the value of the POWERTOOLS_DEV environment variable. + * + * @returns {boolean} + */ + public getDevMode(): boolean { + const value = this.get(this.devModeVariable); + + return this.isValueTrue(value); + } + /** * It returns the value of the AWS_LAMBDA_FUNCTION_MEMORY_SIZE environment variable. * @@ -81,8 +93,8 @@ class EnvironmentVariablesService extends CommonEnvironmentVariablesService impl */ public getLogEvent(): boolean { const value = this.get(this.logEventVariable); - - return value.toLowerCase() === 'true' || value === '1'; + + return this.isValueTrue(value); } /** @@ -105,6 +117,18 @@ class EnvironmentVariablesService extends CommonEnvironmentVariablesService impl return (value && value.length > 0) ? Number(value) : undefined; } + /** + * It returns true if the string value represents a boolean true value. + * + * @param {string} value + * @returns boolean + */ + public isValueTrue(value: string): boolean { + const truthyValues: string[] = [ '1', 'y', 'yes', 't', 'true', 'on' ]; + + return truthyValues.includes(value.toLowerCase()); + } + } export { diff --git a/packages/logger/src/types/Logger.ts b/packages/logger/src/types/Logger.ts index add56ee28a..2976277c3c 100644 --- a/packages/logger/src/types/Logger.ts +++ b/packages/logger/src/types/Logger.ts @@ -74,3 +74,8 @@ export { ConstructorOptions, HandlerOptions }; + +export const enum LogJsonIndent { + PRETTY = 4, + COMPACT = 0, +} diff --git a/packages/logger/tests/unit/Logger.test.ts b/packages/logger/tests/unit/Logger.test.ts index 17b7969230..6fbf9a527a 100644 --- a/packages/logger/tests/unit/Logger.test.ts +++ b/packages/logger/tests/unit/Logger.test.ts @@ -11,7 +11,7 @@ import * as dummyEvent from '../../../../tests/resources/events/custom/hello-wor import { createLogger, Logger } from '../../src'; import { EnvironmentVariablesService } from '../../src/config'; import { PowertoolLogFormatter } from '../../src/formatter'; -import { ClassThatLogs } from '../../src/types'; +import { ClassThatLogs, LogJsonIndent } from '../../src/types'; import { Context, Handler } from 'aws-lambda'; import { Console } from 'console'; @@ -573,6 +573,7 @@ describe('Class: Logger', () => { customConfigService: undefined, envVarsService: expect.any(EnvironmentVariablesService), logEvent: false, + logIndentation: 0, logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'DEBUG', logLevelThresholds: { @@ -1271,6 +1272,7 @@ describe('Class: Logger', () => { customConfigService: undefined, envVarsService: expect.any(EnvironmentVariablesService), logEvent: false, + logIndentation: 0, logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'DEBUG', logLevelThresholds: { @@ -1295,6 +1297,7 @@ describe('Class: Logger', () => { customConfigService: undefined, envVarsService: expect.any(EnvironmentVariablesService), logEvent: false, + logIndentation: 0, logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'DEBUG', logLevelThresholds: { @@ -1321,6 +1324,7 @@ describe('Class: Logger', () => { customConfigService: undefined, envVarsService: expect.any(EnvironmentVariablesService), logEvent: false, + logIndentation: 0, logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'DEBUG', logLevelThresholds: { @@ -1345,6 +1349,7 @@ describe('Class: Logger', () => { customConfigService: undefined, envVarsService: expect.any(EnvironmentVariablesService), logEvent: false, + logIndentation: 0, logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'ERROR', logLevelThresholds: { @@ -1411,4 +1416,49 @@ describe('Class: Logger', () => { }); }); + describe('Feature: Pretty indentation for a local or non-production environment', () => { + + test('when the `POWERTOOLS_DEV` env var is SET it makes log output has multiple lines', () => { + + // Prepare + process.env.POWERTOOLS_DEV = 'true'; + const INDENTATION = LogJsonIndent.PRETTY; + const logger = new Logger(); + const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); + + // Act + logger.info('Message with pretty identation'); + + // Assess + expect(consoleSpy).toBeCalledTimes(1); + expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ + level: 'INFO', + message: 'Message with pretty identation', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + }, null, INDENTATION)); + }); + + test('when the `POWERTOOLS_DEV` env var is NOT SET it makes log output as one-liner', () => { + + // Prepare + const logger = new Logger(); + const consoleSpy = jest.spyOn(logger['console'], 'info').mockImplementation(); + + // Act + logger.info('Message without pretty identation'); + + // Assess + expect(consoleSpy).toBeCalledTimes(1); + expect(consoleSpy).toHaveBeenNthCalledWith(1, JSON.stringify({ + level: 'INFO', + message: 'Message without pretty identation', + service: 'hello-world', + timestamp: '2016-06-20T12:08:10.000Z', + xray_trace_id: '1-5759e988-bd862e3fe1be46a994272793', + })); + }); + }); + }); \ No newline at end of file diff --git a/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts b/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts index b64c4c228f..ccaf0084bf 100644 --- a/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts +++ b/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts @@ -119,105 +119,149 @@ describe('Class: EnvironmentVariablesService', () => { expect(value).toEqual(true); }); - test('It returns true if the environment variable POWERTOOLS_LOGGER_LOG_EVENT is "TRUE"', () => { + test('It returns false if the environment variable POWERTOOLS_LOGGER_LOG_EVENT is "false"', () => { // Prepare - process.env.POWERTOOLS_LOGGER_LOG_EVENT = 'TRUE'; + process.env.POWERTOOLS_LOGGER_LOG_EVENT = 'false'; const service = new EnvironmentVariablesService(); // Act const value = service.getLogEvent(); // Assess - expect(value).toEqual(true); + expect(value).toEqual(false); }); - test('It returns true if the environment variable POWERTOOLS_LOGGER_LOG_EVENT is "1"', () => { + test('It returns false if the environment variable POWERTOOLS_LOGGER_LOG_EVENT is "somethingsilly"', () => { // Prepare - process.env.POWERTOOLS_LOGGER_LOG_EVENT = '1'; + process.env.POWERTOOLS_LOGGER_LOG_EVENT = 'somethingsilly'; const service = new EnvironmentVariablesService(); // Act const value = service.getLogEvent(); // Assess - expect(value).toEqual(true); + expect(value).toEqual(false); }); - test('It returns false if the environment variable POWERTOOLS_LOGGER_LOG_EVENT is "false"', () => { + }); + + describe('Method: getLogLevel', () => { + + test('It returns the value of the environment variable LOG_LEVEL', () => { // Prepare - process.env.POWERTOOLS_LOGGER_LOG_EVENT = 'false'; + process.env.LOG_LEVEL = 'ERROR'; const service = new EnvironmentVariablesService(); // Act - const value = service.getLogEvent(); + const value = service.getLogLevel(); // Assess - expect(value).toEqual(false); + expect(value).toEqual('ERROR'); }); - test('It returns false if the environment variable POWERTOOLS_LOGGER_LOG_EVENT is "0"', () => { + }); + + describe('Method: getSampleRateValue', () => { + + test('It returns the value of the environment variable POWERTOOLS_LOGGER_SAMPLE_RATE', () => { // Prepare - process.env.POWERTOOLS_LOGGER_LOG_EVENT = '0'; + process.env.POWERTOOLS_LOGGER_SAMPLE_RATE = '0.01'; const service = new EnvironmentVariablesService(); // Act - const value = service.getLogEvent(); + const value = service.getSampleRateValue(); // Assess - expect(value).toEqual(false); + expect(value).toEqual(0.01); }); - test('It returns false if the environment variable POWERTOOLS_LOGGER_LOG_EVENT is "somethingsilly"', () => { + }); + + describe('Method: getDevMode', () => { + + test('It returns true if the environment variable POWERTOOLS_DEV is "true"', () => { // Prepare - process.env.POWERTOOLS_LOGGER_LOG_EVENT = 'somethingsilly'; + process.env.POWERTOOLS_DEV = 'true'; const service = new EnvironmentVariablesService(); // Act - const value = service.getLogEvent(); + const value = service.getDevMode(); // Assess - expect(value).toEqual(false); + expect(value).toEqual(true); }); - }); - - describe('Method: getLogLevel', () => { - - test('It returns the value of the environment variable LOG_LEVEL', () => { + test('It returns false if the environment variable POWERTOOLS_DEV is "false"', () => { // Prepare - process.env.LOG_LEVEL = 'ERROR'; + process.env.POWERTOOLS_DEV = 'false'; const service = new EnvironmentVariablesService(); // Act - const value = service.getLogLevel(); + const value = service.getDevMode(); // Assess - expect(value).toEqual('ERROR'); + expect(value).toEqual(false); }); - }); + test('It returns false if the environment variable POWERTOOLS_DEV is NOT set', () => { - describe('Method: getSampleRateValue', () => { + // Prepare + process.env.POWERTOOLS_DEV = 'somethingsilly'; + const service = new EnvironmentVariablesService(); - test('It returns the value of the environment variable POWERTOOLS_LOGGER_SAMPLE_RATE', () => { + // Act + const value = service.getDevMode(); + + // Assess + expect(value).toEqual(false); + }); + + test('It returns false if the environment variable POWERTOOLS_DEV is "somethingsilly"', () => { // Prepare - process.env.POWERTOOLS_LOGGER_SAMPLE_RATE = '0.01'; + process.env.POWERTOOLS_DEV = 'somethingsilly'; const service = new EnvironmentVariablesService(); // Act - const value = service.getSampleRateValue(); + const value = service.getDevMode(); // Assess - expect(value).toEqual(0.01); + expect(value).toEqual(false); }); }); + describe('Method: isValueTrue', () => { + + const valuesToTest: Array> = [ + [ '1', true ], + [ 'y', true ], + [ 'yes', true ], + [ 't', true ], + [ 'TRUE', true ], + [ 'on', true ], + [ '', false ], + [ 'false', false ], + [ 'fasle', false ], + [ 'somethingsilly', false ], + [ '0', false ] + ]; + + test.each(valuesToTest)('It takes string "%s" and returns %s', (input, output) => { + // Prepare + const service = new EnvironmentVariablesService(); + // Act + const value = service.isValueTrue(input as string); + // Assess + expect(value).toBe(output); + }); + + }); + }); \ No newline at end of file diff --git a/packages/logger/tests/unit/helpers.test.ts b/packages/logger/tests/unit/helpers.test.ts index 9309bea207..ab49edd114 100644 --- a/packages/logger/tests/unit/helpers.test.ts +++ b/packages/logger/tests/unit/helpers.test.ts @@ -77,6 +77,7 @@ describe('Helper: createLogger function', () => { customConfigService: expect.any(EnvironmentVariablesService), envVarsService: expect.any(EnvironmentVariablesService), logEvent: false, + logIndentation: 0, logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'WARN', console: expect.any(Console), @@ -117,6 +118,7 @@ describe('Helper: createLogger function', () => { customConfigService: undefined, envVarsService: expect.any(EnvironmentVariablesService), logEvent: false, + logIndentation: 0, logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'INFO', console: expect.any(Console), @@ -238,6 +240,7 @@ describe('Helper: createLogger function', () => { customConfigService: undefined, envVarsService: expect.any(EnvironmentVariablesService), logEvent: false, + logIndentation: 0, logFormatter: expect.any(PowertoolLogFormatter), logLevel: 'INFO', console: expect.any(Console), @@ -307,7 +310,13 @@ describe('Helper: createLogger function', () => { getServiceName(): string { return 'my-backend-service'; }, - + getDevMode(): boolean { + return false; + }, + isValueTrue(): boolean { + return true; + }, + }; // Prepare const loggerOptions:ConstructorOptions = { diff --git a/packages/logger/tests/unit/middleware/middy.test.ts b/packages/logger/tests/unit/middleware/middy.test.ts index e734e61e61..88e37b9fce 100644 --- a/packages/logger/tests/unit/middleware/middy.test.ts +++ b/packages/logger/tests/unit/middleware/middy.test.ts @@ -336,7 +336,12 @@ describe('Middy middleware', () => { getServiceName(): string { return 'my-backend-service'; }, - + getDevMode(): boolean { + return false; + }, + isValueTrue(): boolean { + return true; + }, }; const logger = new Logger({