Skip to content

Appending additional keys state kept between Lambda invocations #407

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
mh-love opened this issue Apr 21, 2021 · 5 comments
Closed

Appending additional keys state kept between Lambda invocations #407

mh-love opened this issue Apr 21, 2021 · 5 comments
Labels
bug Something isn't working documentation Improvements or additions to documentation

Comments

@mh-love
Copy link

mh-love commented Apr 21, 2021

From the "Appending additional keys" docs:

You can append additional keys using either mechanism:

Persist new keys across all future log messages via structure_logs method

"Persist new keys across all future log messages via structure_logs method" could be read as either:

  1. "new keys will be added to all future logs across all Lambda invocations "
  2. "new keys will be added to all future logs for the duration of a Lambda invocation".

I chose the latter because of your example, which I think implies that an order_id is appended to all logs for for the duration of a Lambda invocation:

def handler(event, context):
 order_id = event.get("order_id")
 logger.structure_logs(append=True, order_id=order_id)
 logger.info("Collecting payment")

 
 If I change your example to this:
 

 def handler(event, context):
   logger.info('Something before order_id is known')
   order_id = event.get("order_id")
   logger.structure_logs(append=True, order_id=order_id)
   logger.info("Collecting payment")

The result is:

  1. If order_id=1... Lambda is invoked the first time and the correct order_id of "1" is logged with "Collecting payment".
  2. If order_id=2... Lambda is invoked the second time and incorrect order_id is logged as "1" with "Something before order_id is known", and then the correct order_id of "2" is logged with "Collecting payment".
     
    Is this expected behavior? Seems like a state issue? Either way I think it might make sense to make the docs or examples more clear! Thanks!

Environment

  • Powertools version used: 1.14.0
  • Packaging format (Layers, PyPi): PyPi
  • AWS Lambda function runtime: Python 3.8
@mh-love mh-love added bug Something isn't working triage Pending triage from maintainers labels Apr 21, 2021
@heitorlessa
Copy link
Contributor

Hi @mh-love thanks a lot for raising this - It's indeed confusing and we can do better in the docs.

Explanation: Your state assertion is correct. As the Logger instance is created outside the handler, the structured log is kept in memory so the first log statement you had will use the previous value, then update it, then log with the new value.

I'm finishing a refactor of the logger to make this and other parts easier to use, and will make sure the docs are clearer in a subsequent PR: #404

Thank you!

@heitorlessa heitorlessa added area/logger documentation Improvements or additions to documentation and removed triage Pending triage from maintainers labels Apr 21, 2021
@mh-love
Copy link
Author

mh-love commented Apr 21, 2021

@heitorlessa Thank you!

@heitorlessa heitorlessa added the pending-release Fix or implementation already in dev waiting to be released label May 4, 2021
@heitorlessa
Copy link
Contributor

Just released 1.15.0 with LOTS of goodies including a banner in the docs to cautious people on this, and a more explicit way to append and remove keys at runtime: #423

Thanks again for reporting and helping us improve this for everyone :)

@LironEr
Copy link

LironEr commented Jun 3, 2021

Hey @heitorlessa

So currently, is there a way to remove all keys at the start of the lambda?
I couldn't find anything in the docs / code

I dont want keys from old lambda invocations to pass to a new lambda invocation, so I must remove keys everytime at the start of the lambda.

def handler(event, context):
  logger.remove_keys(['key1', 'key2'])

  logger.info('log info')

  logger.append_keys(key1=body['something'])

  # some code...

  logger.append_keys(key2=some_value)

  logger.info('log log log')

Thanks!

@heitorlessa
Copy link
Contributor

heitorlessa commented Jun 3, 2021 via email

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working documentation Improvements or additions to documentation
Projects
Development

No branches or pull requests

3 participants