Skip to content

fix(logger): fix handling of additional log keys #614

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 4 commits into from Mar 8, 2022
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
40 changes: 36 additions & 4 deletions docs/core/logger.md
Original file line number Diff line number Diff line change
Expand Up @@ -276,10 +276,12 @@ You can append additional persistent keys and values in the logs generated durin
### Appending additional log keys and values to a single log item

You can append additional keys and values in a single log item passing them as parameters.
Pass a string for logging it with default key name `extra`. Alternatively, pass one or multiple objects with custom keys.
If you already have an object containing a `message` key and an additional property, you can pass this object directly.

=== "handler.ts"

```typescript hl_lines="14 18-19"
```typescript hl_lines="14 18-19 23 31"
import { Logger } from '@aws-lambda-powertools/logger';

const logger = new Logger();
Expand All @@ -300,6 +302,17 @@ You can append additional keys and values in a single log item passing them as p
{ data: myImportantVariable },
{ correlationIds: { myCustomCorrelationId: 'foo-bar-baz' } }
);

// Simply pass a string for logging additional data
logger.info('This is a log with additional string value', 'string value');

// Directly passing an object containing both the message and the additional info
const logObject = {
message: 'This is a log message',
additionalValue: 42
};

logger.info(logObject);

return {
foo: 'bar'
Expand All @@ -309,7 +322,7 @@ You can append additional keys and values in a single log item passing them as p
```
=== "Example CloudWatch Logs excerpt"

```json hl_lines="7 15-16"
```json hl_lines="7 15-16 24 32"
{
"level": "INFO",
"message": "This is a log with an extra variable",
Expand All @@ -327,6 +340,22 @@ You can append additional keys and values in a single log item passing them as p
"data": { "foo": "bar" },
"correlationIds": { "myCustomCorrelationId": "foo-bar-baz" }
}
{
"level": "INFO",
"message": "This is a log with additional string value",
"service": "serverlessAirline",
"timestamp": "2021-12-12T22:06:17.463Z",
"xray_trace_id": "abcdef123456abcdef123456abcdef123456",
"extra": "string value"
}
{
"level": "INFO",
"message": "This is a log message",
"service": "serverlessAirline",
"timestamp": "2021-12-12T22:06:17.463Z",
"xray_trace_id": "abcdef123456abcdef123456abcdef123456",
"additionalValue": 42
}
```

### Logging errors
Expand All @@ -347,14 +376,14 @@ The error will be logged with default key name `error`, but you can also pass yo
throw new Error('Unexpected error #1');
} catch (error) {
// Log information about the error using the default "error" key
logger.error('This is the first error', error);
logger.error('This is the first error', error as Error);
}

try {
throw new Error('Unexpected error #2');
} catch (error) {
// Log information about the error using a custom "myCustomErrorKey" key
logger.error('This is the second error', { myCustomErrorKey: error } );
logger.error('This is the second error', { myCustomErrorKey: error as Error } );
}

};
Expand Down Expand Up @@ -391,6 +420,9 @@ The error will be logged with default key name `error`, but you can also pass yo
}
```

!!! tip "Logging errors and log level"
You can also log errors using the `warn`, `info`, and `debug` methods. Be aware of the log level though, you might miss those errors when analyzing the log later depending on the log level configuration.

## Advanced

### Using multiple Logger instances across your code
Expand Down
3 changes: 3 additions & 0 deletions packages/logger/examples/additional-keys.ts
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,9 @@ const lambdaHandler: Handler = async () => {
// Pass an error that occurred
logger.error('This is an ERROR log', new Error('Something bad happened!'));

// Pass a simple string as additional data
logger.info('This is an INFO log', 'Extra log data');

return {
foo: 'bar'
};
Expand Down
4 changes: 2 additions & 2 deletions packages/logger/examples/errors.ts
Original file line number Diff line number Diff line change
Expand Up @@ -17,13 +17,13 @@ const lambdaHandler: Handler = async () => {
try {
throw new Error('Unexpected error #1');
} catch (error) {
logger.error('This is an ERROR log #1', error);
logger.error('This is an ERROR log #1', error as Error);
}

try {
throw new Error('Unexpected error #2');
} catch (error) {
logger.error('This is an ERROR log #2', { myCustomErrorKey: error } );
logger.error('This is an ERROR log #2', { myCustomErrorKey: error as Error } );
}

return {
Expand Down
18 changes: 11 additions & 7 deletions packages/logger/src/Logger.ts
Original file line number Diff line number Diff line change
Expand Up @@ -200,7 +200,7 @@ class Logger extends Utility implements ClassThatLogs {
* It prints a log item with level DEBUG.
*
* @param {LogItemMessage} input
* @param {Error | LogAttributes | unknown} extraInput
* @param {Error | LogAttributes | string} extraInput
* @returns {void}
*/
public debug(input: LogItemMessage, ...extraInput: LogItemExtraInput): void {
Expand All @@ -211,7 +211,7 @@ class Logger extends Utility implements ClassThatLogs {
* It prints a log item with level ERROR.
*
* @param {LogItemMessage} input
* @param {Error | LogAttributes | unknown} extraInput
* @param {Error | LogAttributes | string} extraInput
* @returns {void}
*/
public error(input: LogItemMessage, ...extraInput: LogItemExtraInput): void {
Expand All @@ -231,7 +231,7 @@ class Logger extends Utility implements ClassThatLogs {
* It prints a log item with level INFO.
*
* @param {LogItemMessage} input
* @param {Error | LogAttributes | unknown} extraInput
* @param {Error | LogAttributes | string} extraInput
* @returns {void}
*/
public info(input: LogItemMessage, ...extraInput: LogItemExtraInput): void {
Expand Down Expand Up @@ -288,7 +288,7 @@ class Logger extends Utility implements ClassThatLogs {
* It prints a log item with level WARN.
*
* @param {LogItemMessage} input
* @param {Error | LogAttributes | unknown} extraInput
* @param {Error | LogAttributes | string} extraInput
* @returns {void}
*/
public warn(input: LogItemMessage, ...extraInput: LogItemExtraInput): void {
Expand Down Expand Up @@ -336,9 +336,13 @@ class Logger extends Utility implements ClassThatLogs {
if (typeof input !== 'string') {
logItem.addAttributes(input);
}
extraInput.forEach((item: Error | LogAttributes | unknown) => {
const attributes = item instanceof Error ? { error: item } : item;
logItem.addAttributes(<LogAttributes>attributes);
extraInput.forEach((item: Error | LogAttributes | string) => {
const attributes: LogAttributes =
item instanceof Error ? { error: item } :
typeof item === 'string' ? { extra: item } :
item;

logItem.addAttributes(attributes);
});

return logItem;
Expand Down
2 changes: 1 addition & 1 deletion packages/logger/src/types/Logger.ts
Original file line number Diff line number Diff line change
Expand Up @@ -50,7 +50,7 @@ type UnformattedAttributes = {
};

type LogItemMessage = string | LogAttributesWithMessage;
type LogItemExtraInput = Array<Error | LogAttributes | unknown>;
type LogItemExtraInput = [Error | string] | LogAttributes[];

type HandlerMethodDecorator = (
target: LambdaInterface,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -30,7 +30,7 @@ const testFunction = async (event: APIGatewayProxyEvent, context: Context): Prom
try {
throw new Error(ERROR_MSG);
} catch (e) {
logger.error(ERROR_MSG, e);
logger.error(ERROR_MSG, e as Error);
}

return {
Expand Down
9 changes: 9 additions & 0 deletions packages/logger/tests/unit/Logger.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -288,6 +288,7 @@ describe('Class: Logger', () => {
logger[methodOfLogger]( { message: 'A log item with an object as first parameters', extra: 'parameter' });
logger[methodOfLogger]('A log item with a string as first parameter, and an error as second parameter', new Error('Something happened!') );
logger[methodOfLogger]('A log item with a string as first parameter, and an error with custom key as second parameter', { myCustomErrorKey: new Error('Something happened!') });
logger[methodOfLogger]('A log item with a string as first parameter, and a string as second parameter', 'parameter');
}

// Assess
Expand Down Expand Up @@ -351,6 +352,14 @@ describe('Class: Logger', () => {
stack: expect.stringMatching(/Logger.test.ts:[0-9]+:[0-9]+/),
},
}));
expect(console[methodOfConsole]).toHaveBeenNthCalledWith(7, JSON.stringify({
level: method.toUpperCase(),
message: 'A log item with a string as first parameter, and a string as second parameter',
service: 'hello-world',
timestamp: '2016-06-20T12:08:10.000Z',
xray_trace_id: 'abcdef123456abcdef123456abcdef123456',
extra: 'parameter',
}));
});
});

Expand Down