Feature request: output text of the message in addition to log keys and values in the log

[lulzneko]

Description of the feature request

The current log output shows the context and additional keys and values.
The message text passed to the logger is stored in the message of the keys and values and is logged as part of the object.

This message should be logged as text, not just as part of the object output in the log.

Problem statement

The message that should be read first in the log is hidden behind the object and cannot be read immediately.
The current log is displayed in CloudWatch Logs as follows

2022-03-17T17:26:49.158+09:00	START RequestId: af117200-3a02-45ee-8d1c-66e7b40bc97e Version: $LATEST
2022-03-17T17:26:49.185+09:00	2022-03-17T08:26:49.185Z 377dbbbe-2a7d-4d30-b4c9-b8dff7ed5601 INFO {"cold_start":true,"function_arn":"arn:aws:lambda:ap-northeast-1:xxx:function:xxx",...
2022-03-17T17:26:49.185+09:00	2022-03-17T08:26:49.185Z 377dbbbe-2a7d-4d30-b4c9-b8dff7ed5601 INFO {"cold_start":true,"function_arn":"arn:aws:lambda:ap-northeast-1:xxx:function:xxx",...
2022-03-17T17:26:49.197+09:00	2022-03-17T08:26:49.178Z af117200-3a02-45ee-8d1c-66e7b40bc97e INFO {"cold_start":true,"function_arn":"arn:aws:lambda:ap-northeast-1:xxx:function:xxx",...
2022-03-17T17:26:49.217+09:00	2022-03-17T08:26:49.197Z af117200-3a02-45ee-8d1c-66e7b40bc97e INFO {"cold_start":true,"function_arn":"arn:aws:lambda:ap-northeast-1:xxx:function:xxx",...
2022-03-17T17:26:49.225+09:00	2022-03-17T08:26:49.225Z 377dbbbe-2a7d-4d30-b4c9-b8dff7ed5601 INFO {"cold_start":true,"function_arn":"arn:aws:lambda:ap-northeast-1:xxx:function:xxx",...
2022-03-17T17:26:49.245+09:00	END RequestId: 377dbbbe-2a7d-4d30-b4c9-b8dff7ed5601
2022-03-17T17:26:49.245+09:00	REPORT RequestId: 377dbbbe-2a7d-4d30-b4c9-b8dff7ed5601 Duration: 93.16 ms Billed Duration: 94 ms Memory Size: 128 MB Max Memory Used: 57 MB Init Duration: 193.84 ms

Summary of the feature

The message passed in the log output function is added to the log object and displayed as text.

Code examples

No change in developer.

logger.info('This is an INFO log');
logger.info('This is a log with an extra variable', { data: myImportantVariable });

The above log output code will be output to CloudWatch Logs as follows

2022-03-17T17:26:49.185+09:00	2022-03-17T08:26:49.185Z 377dbbbe-2a7d-4d30-b4c9-b8dff7ed5601 INFO "This is an INFO log" {"cold_start":true,"function_arn":"arn:aws:lambda:ap-northeast-1:xxx:function:xxx",...
2022-03-17T17:26:49.185+09:00	2022-03-17T08:26:49.185Z 377dbbbe-2a7d-4d30-b4c9-b8dff7ed5601 INFO "This is a log with an extra variable" {"cold_start":true,"function_arn":"arn:aws:lambda:ap-northeast-1:xxx:function:xxx",...

The message passed to the logger will be output after the log level in CloudWatch Logs.
Of course, the message of subsequent objects will be output as before.
The only difference is that the message text is added after the log level.

Benefits for you and the wider AWS community

Improves readability of logs in CloudWatch Logs.
This will facilitate operations and debugging.

Describe alternatives you've considered

Additional context

Related issues, RFCs

[orozcoadrian]

(I'm not a maintainer of this repo. Just giving my 2-cents)
Possible workaround: Use the cloudwatch insights console with a query that shows the message field separately. For example:

fields @timestamp, message, @message
| sort @timestamp asc

[lulzneko]

This can be accomplished by passing a message as the first argument and the object currently being logged as the second argument when calling a console.log type function.

In the v0.7.1 implementation, this part should be as follows
https://github.com/awslabs/aws-lambda-powertools-typescript/blob/v0.7.1/packages/logger/src/Logger.ts#L451

console[consoleMethod](`"${log.getAttributes()['message']}"`, JSON.stringify(log.getAttributes(), this.removeCircularDependencies()));

If it is okay with this change, I would like to submit a pull request.

[dreamorosi]

Hello @lulzneko, thanks for the interest in the project and for taking the time to open an issue & offering to open a PR for your proposal.

We consider JSON-structured logging as one of the key features of Logger and while we appreciate your offer of contributing, we won't be going in that direction for the time being.

While having human-readable output adds value during the initial development phases, unstructured logs can be difficult to interpret and analyze programmatically. Values may appear in these logs arbitrarily, and the format may change over time. On the other hand, applications that implement structured logging, lead to an easier path towards monitoring in production systems. This is in line with the best practices discussed in the AWS Lambda documentation.

Apart from the general benefits of structured logs in JSON, many customers send their CloudWatch logs in a company-wide centralised monitoring tool like Logz.io and Datadog; for this reason it's important the logs produced by Powertools are valid JSON logs that can be correctly parsed by 3rd party vendors, not only CW.

With that said, I see where you're coming from and I can relate on the fact that during development, logging structured as JSON might be a bit too verbose. For those cases you I would suggest (and I personally use) the CloudWatch Insights as mentioned by @orozcoadrian with a query similar to this one (the image below shows how it would look):

fields @timestamp, @message, level, message
| filter level = "INFO" or level = "ERROR"
| sort @timestamp asc

I'm going to close the issue, but if you're still interested to contribute to the project I would encourage you to engage with one of the other items labeled as good-first-issue.

[github-actions]

⚠️ COMMENT VISIBILITY WARNING ⚠️

Comments on closed issues 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.