Appending additional keys state kept between Lambda invocations

[mh-love]

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

[heitorlessa]

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!

[mh-love]

@heitorlessa Thank you!

[heitorlessa]

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]

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]

Hey @LironEr - nope, is that because you want a clean slate and you’re not sure what keys were added along the code execution? There is one way today (structure_logs method, no args), but that will also remove Lambda injected context. if you don’t mind, open up a feature request and we can easily do a flag at the inject lambda context to clean up the state before injecting the context, or something else you can think of. https://github.com/awslabs/aws-lambda-powertools-roadmap

…

On Thu, 3 Jun 2021 at 14:10, LironEr ***@***.***> wrote: Hey @heitorlessa <https://github.com/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! — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#407 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAZPQBAZZILDZZHZKDO5OUDTQ5WLPANCNFSM43KZK5UA> .