powertools-lambda-typescript icon indicating copy to clipboard operation
powertools-lambda-typescript copied to clipboard

Feature request: Change powertools lambda context capture log key order

Open WtfJoke opened this issue 1 year ago • 3 comments

Use case

We were in the process of enabling the capturing of the lambda context in our logger.

Although we like the additional context, we didnt enable it because the actual logged message is only visible anymore when expanding the log message which makes it almost impossible to skim through log-message and spot the one which looks interesting because they all look the same in the x-ray-tracing-view and I would be forced to scroll sideways.

See this screenshot for reference: image

Solution/User Experience

Is it possible for you to change the order of the logging keys exposed from capturing the lambda context and put it to the end by default (or after the message)?

Alternative solutions

Since v2.8.0 its also possible to define log key order on their own, see here: https://docs.powertools.aws.dev/lambda/typescript/latest/core/logger/#reordering-log-keys-position

Acknowledgment

Future readers

Please react with 👍 and your use case to help us understand customer demand.

WtfJoke avatar Sep 19 '24 16:09 WtfJoke

Hi @WtfJoke, thanks for opening the issue.

As you pointed out in the "Alternative Solutions" section of the issue, in the last release we added the ability to specify the order of the keys when initializing the Logger.

I think however that we could have done a better job in the documentation for the feature. After re-reading it, if I understand correctly your feature request, I think it's not accurate.

The docs say this:

You can change the order of standard Logger keys or any keys that will be appended later at runtime via the logRecordOrder parameter

Technically speaking, the context keys are included in the or any keys that will be appended later at runtime, but I can see how this could be confusing and make you think they are not.

In practice, you can specify any key that Powertools manages - which includes the standard keys and the context keys - but also any other key that your code adds.

For example, if you want message, timestamp, and level to be first you could do it like this:

import { Logger } from '@aws-lambda-powertools/logger';
import type { Handler } from 'aws-lambda';

const logger = new Logger({
  logRecordOrder: ['message', 'timestamp', 'level'],
});

export const handler: Handler = async (_, context) => {
  logger.addContext(context);
  logger.info('Hello, World!');
  logger.info('Hello, World!');
  logger.info('Hello, World!');
  logger.info('Hello, World!');

  return {
    statusCode: 200,
    body: JSON.stringify('Hello, World!'),
  };
};

Which would result in these logs on CloudWatch:

image

The types should also help you with choosing the keys in the IDE:

image

If instead you want full control of how the log is structured and ordered, you can also bring your own custom log formatter and pass it to the Logger when initializing it, below an example of this that I have used in another application:

import type { Handler } from 'aws-lambda';
import { Logger, LogFormatter, LogItem } from '@aws-lambda-powertools/logger';
import type {
  LogAttributes,
  UnformattedAttributes,
} from '@aws-lambda-powertools/logger/types';

/**
 * Custom log formatter to reorganize the log attributes.
 */
class CustomLogFormatter extends LogFormatter {
  public formatAttributes(
    attributes: UnformattedAttributes,
    additionalLogAttributes: LogAttributes
  ): LogItem {
    const {
      feature,
      area,
      appVersion,
      eventId,
      eventType,
      installationId,
      ...otherAttributes
    } = additionalLogAttributes;

    return new LogItem({
      attributes: {
        message: attributes.message,
        timestamp: this.formatTimestamp(attributes.timestamp),
        level: attributes.logLevel,
        logMetadata: {
          feature,
          area,
        },
        service: {
          environment: attributes.environment,
          name: attributes.serviceName,
          version: appVersion,
        },
        correlationIds: {
          awsRequestId: attributes.lambdaContext?.awsRequestId,
          xrayTraceId: attributes.xRayTraceId,
          eventId,
          eventType,
          installationId,
        },
        functionMetadata: {
          memorySize: attributes.lambdaContext?.memoryLimitInMB,
          name: attributes.lambdaContext?.functionName,
          version: attributes.lambdaContext?.functionVersion,
          arn: attributes.lambdaContext?.invokedFunctionArn,
        },
      },
    }).addAttributes(otherAttributes);
  }
}

const logger = new Logger({
  logFormatter: new CustomLogFormatter(),
});

Please let me know if this helps, and also if I understood your feature request correctly.

If yes, please leave the issue open so we can clarify the docs.

dreamorosi avatar Sep 19 '24 17:09 dreamorosi

I think my description was not clear enough 😅 Thanks for the detailed explanation of the functionality, though :)

The feature request was targeted into the direction, if it would make sense to change the default logRecordOrder of Powertools Logger, so that the same result is achieved without specifying a custom logRecordOrder (which fixes my problem as well).

E.g that we go from this: image to this: image

When you add the lambda context to the logger without specifying this custom logRecordOrder the context log keys take so much space in the log message, that you cannot see the interesting bits (such as the log message itself) anymore. image

Which brings me to the point, at least for me, that it looks like it makes no sense to add the lambda context to the logger without specifying a custom logRecordOrder. Instead it would be cool if the default configuration (without specififying any order) when logging the lambda context would already add value (by not inserting them to the beginning and instead at the end for example).

I hope the description was a bit clearer this time, I had a bit a hard time to describe it 🙈 . If something is unclear, please feel free to ask and I try my best to make it more detailed :)

WtfJoke avatar Sep 21 '24 12:09 WtfJoke

This issue has not received a response in 2 weeks. If you still think there is a problem, please leave a comment to avoid the issue from automatically closing.

github-actions[bot] avatar Oct 12 '24 00:10 github-actions[bot]

Hi @WtfJoke - thank you for explaining the request, and sorry for the long delay :/

If I recall correctly, we chose the current order only because the keys are in alphabetic order, however I think it makes sense to place the message at the top and the context keys towards the end, similar to what Powertools for AWS Lambda (Python) does (example).

The change is quite easy and mostly involves updating the docs and perhaps some tests, but I am not sure if we should consider this as a breaking change.

Basically we would change these lines here from this:

cold_start: attributes.lambdaContext?.coldStart,
function_arn: attributes.lambdaContext?.invokedFunctionArn,
function_memory_size: attributes.lambdaContext?.memoryLimitInMB,
function_name: attributes.lambdaContext?.functionName,
function_request_id: attributes.lambdaContext?.awsRequestId,
level: attributes.logLevel,
message: attributes.message,
sampling_rate: attributes.sampleRateValue,
service: attributes.serviceName,
timestamp: this.formatTimestamp(attributes.timestamp),
xray_trace_id: attributes.xRayTraceId,

to this:

level: attributes.logLevel,
message: attributes.message,
timestamp: this.formatTimestamp(attributes.timestamp),
service: attributes.serviceName,
cold_start: attributes.lambdaContext?.coldStart,
function_arn: attributes.lambdaContext?.invokedFunctionArn,
function_memory_size: attributes.lambdaContext?.memoryLimitInMB,
function_name: attributes.lambdaContext?.functionName,
function_request_id: attributes.lambdaContext?.awsRequestId,
sampling_rate: attributes.sampleRateValue,
xray_trace_id: attributes.xRayTraceId,

Aka the order has changed but the keys are the same.

I think if customers are treating these as structured logs and parsing them, then the order doesn't change, but if they're treating them as plain text and analyzing them with regexes then there might be issues.

@leandrodamascena what do you think?

dreamorosi avatar Feb 03 '25 17:02 dreamorosi

Hey! IMO changing the order of fields in a JSON object generally should not cause problems when parsing logs with systems like CloudWatch, OpenSearch, Graylog, or other log management tools. These systems typically parse JSON by field names, not by their order because JSON, by definition, is an unordered collection of name/value pairs.

I think this will make the log record clearer to read. To be honest, this will be a big surprise to me if someone has an issue. And if someone complains, we can quickly revert, release a new version and apologize.

leandrodamascena avatar Feb 03 '25 19:02 leandrodamascena

⚠️ COMMENT VISIBILITY WARNING ⚠️

This issue is now closed. Please be mindful that future comments are hard for our team to see.

If you need more assistance, please either tag a team member or open a new issue that references this one.

If you wish to keep having a conversation with other community members under this issue feel free to do so.

github-actions[bot] avatar Feb 05 '25 18:02 github-actions[bot]

This is now released under v2.14.0 version!

github-actions[bot] avatar Feb 11 '25 12:02 github-actions[bot]