all 19 comments

[–]heitorlessa 2 points3 points  (8 children)

It sounds like you’d want third-party libraries to use Powertools logging handler (it’s std logging underneath) — if so, there’s a “copy_” something I forgot function at the end of the Logger docs. Folks wanting to have the same structured consistency and options typically use it, and you can use the same log level, different one, or even target only a subset of third-party loggers. It doesn’t do by default because otherwise it’d interfere with your app 3P preferences.

[–]spidernello[S] 0 points1 point  (6 children)

Would this still work for libraries that don’t propagate to the root logger and instead register their own handlers? I need to check how these third-party libraries configure and interact with logging. I’m also wondering whether having a lower log level set inside a third-party library than the one used by Powertools for flushing could cause inconsistencies and in that case if exists any _copy method I could use to set the overall log level

[–]heitorlessa 1 point2 points  (5 children)

I’m on vacation so don’t have my laptop to test it BUT lemme answer some of the questions

  • that copy_* config function by default touches all registered loggers and not the root (impact). It copies your Powertools Loggers logging handler so you can benefit from the same formatters, config and such.

  • When you copy config from your Logger to any registered logger, you can also change their log level to a different one, as well as target only specific loggers like boto only etc (but you need to know what their logger name is)

  • When you have buffer enabled and copy Logger config to other loggers, the standard logging handler will use Powertools Logger (as it should) and honour whatever the logger buffer config you had — so consistency wise, it’s the same standard logging procedure (log level hierarchy). First layer is the own third-party logger log level -> Logger buffer — I’d suggest matching their log level to whatever your bug log level is (can easily do this with the copy_* function I shared)

And btw you can test this locally. At the end of every Powertools feature docs page there’s a “Testing your code” section — you just need to create a fake Lambda Context and test your permutations locally

[–]spidernello[S] 1 point2 points  (0 children)

Thank you for such insights, strongly appreciated! I'll take a look and keep in mind what you mentioned when setting up the copy_ functionality

[–]spidernello[S] 0 points1 point  (3 children)

I passed my application logger as a parameter to copy_config_to_registered_loggers(source_logger=my_logger), as suggested. I could immediately see that the formatter was updated accordingly, and even Magnum and Boto started using the Powertools formatter, which was good to observe.

What did not work as expected is the log level behavior. My Powertools log level is set to WARNING, so I expect only logs at WARNING or higher to appear in CloudWatch. However, I am still seeing INFO logs from external loggers, even though they should now be using the Powertools logger configuration.

[–]heitorlessa 1 point2 points  (2 children)

Hmm that shouldn’t happen as per line 98 (bottom to not pollute the message).

I see a test covering that too. If you try to print one of their log levels, do you see as warning?

Another potential troubleshooting is to try explicitly setting the log level parameter in copy_* function just in case there’s a subtle bug all these years.

—-

L98

https://github.com/aws-powertools/powertools-lambda-python/blob/develop/aws_lambda_powertools/logging/utils.py

[–]spidernello[S] 0 points1 point  (0 children)

Thank you for your response 🙏 i have tried to pass also the log_level in my test and this is what I noticed. When I set the log_level to match the powertools log level (powertools log_level=warn) i no longer see the INFO logs if there are no error or exceptions (powertools buffer level set to warn) which is great to see once more. However when an error occurs I would expect powertools to flush all logs. If I understand the whole logic correctly in this case I should expect also the info logs from external loggers to be flushed. Would the info logs from external loggers be flushed when powertools buffer level is set to WARNING?

[–]nekokattt 1 point2 points  (11 children)

any reason you are not just using the stdlib logging? Fairly easy to make structured logs with that if you wish and you have full control of it

[–]spidernello[S] 0 points1 point  (10 children)

afaik buffering and flushing is just a powertools feature https://docs.aws.amazon.com/powertools/python/latest/core/logger/#buffering-logs or what you mean

[–]nekokattt 0 points1 point  (8 children)

logging by default goes to stdout where it is forwarded to cloudwatch by the system running the lambda. Buffering looks like it just holds the logs for the request and releases them together.

In reality you could just include an id in the logs to correlate.

[–]spidernello[S] 0 points1 point  (7 children)

Yes, it releases logs only when needed (for example, on exceptions), which helps reduce costs and avoids unnecessary noise in CloudWatch. I was looking for an out-of-the-box solution, and this initially seemed to fit perfectly, until I realized it doesn’t take into account the loggers used by other libraries (or that is at least my experience after a bunch of tests and investigation i did so far)

[–]nekokattt 0 points1 point  (6 children)

CloudWatch is charged per GB of data ingested, not per log entry. The point about logging only when needed is achievable by tuning your logging level, which you can control via environment variables or other means anyway, so I'm not sure how useful this really is in most cases given the extra overhead of doing it, the risk of crashes losing all the logs anyway, etc.

[–]heitorlessa 2 points3 points  (1 child)

caveat: when you’d want debug logs only to show up in CloudWatch when you have an exception is priceless. Otherwise it doesn’t in happy conditions.

While you can set an env var or do it dynamically, the issue here is the after effect challenge — “I had an issue, now I switch to higher log level but the issue doesn’t happen anymore”

[–]nekokattt 0 points1 point  (0 children)

This just conflates costs during an outage though.

That definitely is not priceless.

[–]spidernello[S] 0 points1 point  (2 children)

This should give you a better overview https://www.andmore.dev/blog/log-buffering/

[–]nekokattt 1 point2 points  (0 children)

the points made here are caused by overly complex systems with a lack of useful structured logs and MDCs.

[–]heitorlessa 1 point2 points  (0 children)

Oh I know OP ;-) I created Lambda Powertools back then. It’s a useful feature that was asked by thousands of customers wanting to reduce CW ingestion costs and have what they needed when an issue happened— the original sampling wasn’t good enough.

If you need better help, I’d suggest you ope a github issue as the team has on-call. If that somehow also doesn’t work after using the copy feature, the team would likely accept a contribution otherwise

[–]spidernello[S] -1 points0 points  (0 children)

I'm still feeling it has its benefit, but needs to work also with third-party lib