Skip to content

Commit

Permalink
docs(logger): rework working with keys doc sections (#2696)
Browse files Browse the repository at this point in the history
  • Loading branch information
@dreamorosi
dreamorosi authored Jun 27, 2024
1 parent f1cdb15 commit d1284bf
Show file tree
Hide file tree
Showing 16 changed files with 420 additions and 220 deletions.
254 changes: 152 additions & 102 deletions docs/core/logger.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -181,93 +181,199 @@ When debugging in non-production environments, you can instruct Logger to log th

Use `POWERTOOLS_LOGGER_LOG_EVENT` environment variable to enable or disable (`true`/`false`) this feature.

### Appending persistent additional log keys and values
### Appending additional keys

You can append additional persistent keys and values in the logs generated during a Lambda invocation using either mechanism:
You can append additional keys using either machanism:

* Via the Logger's `appendKeys` method, for all log items generated after calling this method
* Passing them in the Logger's constructor
* Add **extra keys** to a single log message by passing them to the log method directly
* Append **temporary keys** to all future log messages via the `appendKeys()` method until `resetKeys()` is called
* Set **Persistent keys** for the logger instance via the `persistentKeys` constructor option or the `appendPersistentKeys()` method

To remove the keys you added, you can use the `removeKeys` method.
#### Extra keys

You can append additional data to a single log item by passing objects as additional parameters.

* Pass a simple string for logging it with default key name `extra`
* Pass one or multiple objects containing arbitrary data to be logged. Each data object should be placed in an enclosing object as a single property value, you can name this property as you need: `{ myData: arbitraryObjectToLog }`
* 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="5-13 17-25 32"
--8<-- "examples/snippets/logger/appendKeys.ts"
```typescript hl_lines="16-18 23-25 37"
--8<-- "examples/snippets/logger/extraData.ts"
```
=== "Example CloudWatch Logs excerpt"

```json hl_lines="7-12 20-25"
```json hl_lines="7 15-21 29 37"
{
"level": "INFO",
"message": "This is an INFO log",
"message": "This is a log with an extra variable",
"service": "serverlessAirline",
"timestamp": "2021-12-12T21:49:58.084Z",
"timestamp": "2021-12-12T22:06:17.463Z",
"xray_trace_id": "abcdef123456abcdef123456abcdef123456",
"aws_account_id": "123456789012",
"aws_region": "eu-west-1",
"logger": {
"name": "@aws-lambda-powertools/logger",
"version": "0.0.1"
"data": { "foo": "bar" }
}
{
"level": "INFO",
"message": "This is a log with 3 extra objects",
"service": "serverlessAirline",
"timestamp": "2021-12-12T22:06:17.466Z",
"xray_trace_id": "abcdef123456abcdef123456abcdef123456",
"data": { "foo": "bar" },
"correlationIds": { "myCustomCorrelationId": "foo-bar-baz" },
"lambdaEvent": {
"exampleEventData": {
"eventValue": 42
}
}
}
{
"level": "INFO",
"message": "This is another INFO log",
"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
}
```

#### Temporary keys

You can append additional keys to all future log messages by using the `appendKeys()` method.

???+ tip "When is this useful?"
This is helpful to contextualize log messages emitted during a specific function.

=== "handler.ts"

```typescript hl_lines="9-11"
--8<-- "examples/snippets/logger/appendAndRemoveKeys.ts"
```

1. You can also remove specific keys by calling the `removeKeys()` method.

=== "Example CloudWatch Logs excerpt"

```json hl_lines="7"
{
"level": "INFO",
"message": "transaction processed",
"service": "serverlessAirline",
"timestamp": "2021-12-12T21:49:58.084Z",
"xray_trace_id": "abcdef123456abcdef123456abcdef123456",
"customerId": "123456789012"
}
{
"level": "INFO",
"message": "other business logic processed",
"service": "serverlessAirline",
"timestamp": "2021-12-12T21:49:58.088Z",
"xray_trace_id": "abcdef123456abcdef123456abcdef123456"
}
```

#### Persistent keys

You can persist keys across Lambda invocations by using the `persistentKeys` constructor option or the `appendPersistentKeys()` method. These keys will persist even if you call the [`resetKeys()` method](#resetting-keys).

A common use case is to set keys about your environment or application version, so that you can easily filter logs in CloudWatch Logs.

=== "As constructor options"

```typescript hl_lines="5-8"
--8<-- "examples/snippets/logger/persistentKeysConstructor.ts"
```

=== "Via dynamic method"

```typescript hl_lines="13"
--8<-- "examples/snippets/logger/persistentKeys.ts"
```

=== "Example CloudWatch Logs excerpt"

```json hl_lines="7-8"
{
"level": "INFO",
"message": "processing transaction",
"service": "serverlessAirline",
"timestamp": "2021-12-12T21:49:58.084Z",
"xray_trace_id": "abcdef123456abcdef123456abcdef123456",
"aws_account_id": "123456789012",
"aws_region": "eu-west-1",
"logger": {
"name": "@aws-lambda-powertools/logger",
"version": "0.0.1"
}
"environment": "prod",
"version": "1.2.0",
}
```

!!! tip "Logger will automatically ignore any key with an `undefined` value"
### Removing additional keys

You can remove additional keys from the logger instance at any time:

* Remove temporary keys added via the `appendKeys()` method by using the `removeKeys()` method
* Remove persistent keys added via the `persistentKeys` constructor option or the `appendPersistentKeys()` method by using the `removePersistentKeys()` method

=== "Remove temporary keys"

```typescript hl_lines="17"
--8<-- "examples/snippets/logger/removeKeys.ts"
```

=== "Remove persistent keys"

#### Clearing all state
```typescript hl_lines="19"
--8<-- "examples/snippets/logger/removePersistentKeys.ts"
```

#### Resetting keys

Logger is commonly initialized in the global scope. Due to [Lambda Execution Context](https://docs.aws.amazon.com/lambda/latest/dg/lambda-runtime-environment.html){target="_blank"} reuse, this means that custom keys can be persisted across invocations.

Resetting the state allows you to clear all the temporary keys you have added.

???+ tip "Tip: When is this useful?"
This is useful when you add multiple custom keys conditionally or when you use canonical or wide logs.

The Logger utility is commonly initialized in the global scope, outside the handler function.
When you attach persistent log attributes through the `persistentLogAttributes` constructor option or via the `appendKeys`, `addPersistentLogAttributes` methods, this data is attached to the Logger instance.
=== "Clearing state manually"

Due to the [Lambda Execution Context reuse](https://docs.aws.amazon.com/lambda/latest/dg/runtimes-context.html), this means those persistent log attributes may be reused across invocations.
If you want to make sure that persistent attributes added **inside the handler function** code are not persisted across invocations, you can set the parameter `clearState` as `true` in the `injectLambdaContext` middleware or decorator.
```typescript hl_lines="25"
--8<-- "examples/snippets/logger/resetKeys.ts"
```

=== "Middy Middleware"

```typescript hl_lines="31"
--8<-- "examples/snippets/logger/clearStateMiddy.ts"
```typescript hl_lines="24"
--8<-- "examples/snippets/logger/resetKeysMiddy.ts"
```

=== "Decorator"

```typescript hl_lines="16"
--8<-- "examples/snippets/logger/clearStateDecorator.ts"
```typescript hl_lines="13"
--8<-- "examples/snippets/logger/resetKeysDecorator.ts"
```

1. Binding your handler method allows your handler to access `this` within the class methods.

In each case, the printed log will look like this:

=== "First invocation"

```json hl_lines="2 4-7"
```json hl_lines="2 4"
{
"biz": "baz",
"environment": "prod",
"cold_start": true,
"details": {
"special_key": "123456",
},
"userId": "123456789012",
"foo": "bar",
"function_arn": "arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function",
"function_memory_size": 128,
"function_name": "foo-bar-function",
"function_request_id": "abcdef123456abcdef123456",
"level": "DEBUG",
"message": "This is a DEBUG log with the user_id",
"level": "INFO",
"message": "WIDE",
"service": "hello-world",
"timestamp": "2021-12-12T22:32:54.670Z",
"xray_trace_id": "1-5759e988-bd862e3fe1be46a994272793"
Expand All @@ -277,77 +383,21 @@ In each case, the printed log will look like this:

```json hl_lines="2 4"
{
"biz": "baz",
"environment": "prod",
"cold_start": false,
"foo": "bar",
"userId": "210987654321",
"function_arn": "arn:aws:lambda:eu-west-1:123456789012:function:foo-bar-function",
"function_memory_size": 128,
"function_name": "foo-bar-function",
"function_request_id": "abcdef123456abcdef123456",
"level": "DEBUG",
"message": "This is a DEBUG log with the user_id",
"level": "INFO",
"message": "WIDE",
"service": "hello-world",
"timestamp": "2021-12-12T22:40:23.120Z",
"xray_trace_id": "1-5759e988-bd862e3fe1be46a994272793"
}
```

### Appending additional data to a single log item

You can append additional data to a single log item by passing objects as additional parameters.

* Pass a simple string for logging it with default key name `extra`
* Pass one or multiple objects containing arbitrary data to be logged. Each data object should be placed in an enclosing object as a single property value, you can name this property as you need: `{ myData: arbitraryObjectToLog }`
* 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="16-18 23-25 37"
--8<-- "examples/snippets/logger/extraData.ts"
```
=== "Example CloudWatch Logs excerpt"

```json hl_lines="7 15-21 29 37"
{
"level": "INFO",
"message": "This is a log with an extra variable",
"service": "serverlessAirline",
"timestamp": "2021-12-12T22:06:17.463Z",
"xray_trace_id": "abcdef123456abcdef123456abcdef123456",
"data": { "foo": "bar" }
}
{
"level": "INFO",
"message": "This is a log with 3 extra objects",
"service": "serverlessAirline",
"timestamp": "2021-12-12T22:06:17.466Z",
"xray_trace_id": "abcdef123456abcdef123456abcdef123456",
"data": { "foo": "bar" },
"correlationIds": { "myCustomCorrelationId": "foo-bar-baz" },
"lambdaEvent": {
"exampleEventData": {
"eventValue": 42
}
}
}
{
"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

You can log errors by using the `error` method and pass the error object as parameter.
Expand Down Expand Up @@ -471,7 +521,7 @@ In the event you have set a log level in Powertools to a level that is lower tha

### Using multiple Logger instances across your code

The `createChild` method allows you to create a child instance of the Logger, which inherits all of the attributes from its parent. You have the option to override any of the settings and attributes from the parent logger, including [its settings](#utility-settings), any [persistent attributes](#appending-persistent-additional-log-keys-and-values), and [the log formatter](#custom-log-formatter-bring-your-own-formatter).
The `createChild` method allows you to create a child instance of the Logger, which inherits all of the attributes from its parent. You have the option to override any of the settings and attributes from the parent logger, including [its settings](#utility-settings), any [extra keys](#appending-additional-keys), and [the log formatter](#custom-log-formatter-bring-your-own-formatter).

Once a child logger is created, the logger and its parent will act as separate instances of the Logger class, and as such any change to one won't be applied to the other.

Expand Down
30 changes: 30 additions & 0 deletions examples/snippets/logger/appendAndRemoveKeys.ts
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,30 @@
import { Logger } from '@aws-lambda-powertools/logger';

const logger = new Logger({
serviceName: 'serverlessAirline',
});

const processTransaction = async (customerId: string): Promise<void> => {
try {
logger.appendKeys({
customerId,
});

// ... your business logic

logger.info('transaction processed');
} finally {
logger.resetKeys(); // (1)!
}
};

export const handler = async (
event: { customerId: string },
_context: unknown
): Promise<void> => {
await processTransaction(event.customerId);

// .. other business logic

logger.info('other business logic processed');
};
31 changes: 0 additions & 31 deletions examples/snippets/logger/appendKeys.ts
View file

This file was deleted.

Loading

0 comments on commit d1284bf

Please sign in to comment.