Feature request: Change ordering of default log formatter

bilalq commented 1 year ago

Use case

I know that users can provide their own LogFormatter instance, but the I believe the default should still be reasonably well-suited for most people.

The problem today is that the output frontloads a bunch of noise that isn't useful and makes the CloudWatch console log stream view useless without expanding and hard to read/skim even when you do.

At a glance, all you see is whether or not an invocation was a cold start and the ARN. Actually interesting information like log level and message are buried.

Solution/User Experience

Technically, V8 and every other JS engine I'm aware of don't guarantee ordering of JS object literals when serializing/deserializing. In practice, when the object key counts are not high, the order as written does get preserved.

If we look here:

https://github.com/aws-powertools/powertools-lambda-typescript/blob/main/packages/logger/src/formatter/PowertoolLogFormatter.ts#L19-L33

Changing:

    return {
      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 something like this:

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

Would likely be a lot more usable. This brings the log level, message, and execution ids to the forefront.

With regards to backwards compatibility: No promised API or contractual behavior changes. Technically, if a user had regex based parsing of log lines, that may break. However, I'd argue that given the JS engine already doesn't guarantee order preservation, such a dependency never had guarantees to begin with and should not be considered breakage of backwards compatibility.

Alternative solutions

No response

Acknowledgment

[X] This feature request meets Powertools for AWS Lambda (TypeScript) Tenets
[X] Should this be considered in other Powertools for AWS Lambda languages? i.e. Python, Java, and .NET

Future readers

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

bilalq commented 1 year ago

I'm happy to submit a PR for this if the team would be okay to merge it. Also open to hearing feedback on the ordering. My rationale for putting log level first is that it makes it easy to visually scan and see which log entries are for errors vs info vs debug. After that, the message is the most important attribute, IMO. The request and trace ids are then the most useful bits for pulling additional context around a given log line.

dreamorosi commented 1 year ago

Hi @bilalq thank you for taking the time to open an issue.

As you mentioned, we can't guarantee the order of the keys so if my memory serves me correctly, we simply ordered the keys alphabetically when creating the formatter.

I'm okay with changing the ordering as you suggested in your second code example and have level, message, and function_request_id at the front, so if the offer of opening a PR is still valid I'd be happy to review it and help merge it.

As a side note, the Python version of Powertools has level, location, message, and timestamp at the front but also allows customers to override the key position without having to write their own formatter via the log_record_order constructor parameter. I think in the future we should consider having a similar property as well, but this is out of the scope of this issue.

bilalq commented 1 year ago

One correction from the issue description: JSON.stringify serialization does have a well-defined order post ES5.

mmeylan commented 10 months ago

Hi @bilalq thank you for taking the time to open an issue.

As you mentioned, we can't guarantee the order of the keys so if my memory serves me correctly, we simply ordered the keys alphabetically when creating the formatter.

I'm okay with changing the ordering as you suggested in your second code example and have level, message, and function_request_id at the front, so if the offer of opening a PR is still valid I'd be happy to review it and help merge it.

As a side note, the Python version of Powertools has level, location, message, and timestamp at the front but also allows customers to override the key position without having to write their own formatter via the log_record_order constructor parameter. I think in the future we should consider having a similar property as well, but this is out of the scope of this issue.

Having the same functionality in typescript would be awesome ! I'd be willing to contribute with some guidance.

dreamorosi commented 10 months ago

Hi @mmeylan thank you for offering to contribute to the project.

As a first stop, and if you haven't already done so, I would recommend to take a look at the contributing document for the repo. In this doc you should be able to find the main info about how to contribute & setup your dev environment. Since you have already identified an opportunity for contributing and an issue, you're already more than halfway there.

After that, in case you want to get more details about the repo structure or other conventions, I would recommend reading also the pages under the "Contributing" section in our documentation: https://docs.powertools.aws.dev/lambda/typescript/latest/contributing/setup/

Once you feel ready to contribute, you can fork the repo and create your working branch starting from the feat/v2 branch. This feature will be included as part of the next major release, so you won't be merging back to main but to feat/v2.

In terms of implementing the feature, the main reference and North Star in terms of developer experience we are looking for is the one found in the Python version of Powertools.

To that extent, I imagine that we will have to add a new property to the ConstructorOptions type that is used to define the options that customers can use to instantiate a new Logger item. In doing so, we should try to type this in a way that allows customers to get auto complete at least for the keys of the UnformattedAttributes type.

Then, we'll likely have to handle this new option in the constructor method of the Logger and perhaps pass it down to the Logger.setLogFormatter() method called in the Logger.setOptions() method, which will in turn pass it down to the PowertoolsLogFormatter class.

Once that's done, we should modify the implementation of the PowertoolsLogFormatter.formatAttributes() method so that it arranges the keys of the LogItem based on the customer selection.

In doing so, we should keep in mind a couple of things:

we should aim at implementing this in a way that causes the least amount of runtime impact in terms of performance (ideally we should avoid iterating over the keys since the PowertoolsLogFormatter.formatAttributes() function is called every time a log is emitted)
we should allow the customer to pass a partial selection (i.e. only specify that the fields should be message and timestamp) and leave the order of the other fields unchanged.
we should make sure that whenever a field ordering is specified, it's passed to children of the logger instance (see Logger.createChild()) - this should already be the case but it might be worth it to make sure this is the case.

If any of the above is not clear or you'd like to discuss any of it further please don't hesitate to ask. Before staring the implementation it'd be great if you could lay out a rough plan of how you plan on implementing the feature so that we can try catching potential issues with it early on.

Feel free to continue the discussion under this issue, we'll make sure to reply as soon as we can. For a closer collaboration, or if you prefer to have a more real-time conversation (time zone allowing it), you can also join our Discord server, you'll find me & the other maintainers of this repo, as well as other members of the community in the #typescript channel.

willpeixoto commented 4 months ago

I will be glad to help with this issue if still need some help :)

dreamorosi commented 4 months ago

Hi @willpeixoto, yes, help is always welcome!

Thank you for offering, I'll assign the issue to you.

If you have any questions now or during development, please let me know.

We're happy to help either here or on Discord if less async communication is needed.

leandrodamascena commented 4 months ago

I will be glad to help with this issue if still need some help :)

Sensacional hein monstrão @willpeixoto! :D

We are so happy to have your contribution to the Powertools. If you have any questions, let us know and we'll help!

dreamorosi commented 3 months ago

Hi @willpeixoto - just wanted to check in to see if you were still working on this or if you needed any help.

dreamorosi commented 2 months ago

Putting back the issue on the backlog, if anyone is interested in picking this up please leave a comment.

arnabrahman commented 2 months ago

@dreamorosi I have made a draft WIP PR with some questions. Please have a look whenever you are available.

aws-powertools / powertools-lambda-typescript