feat(logger): add thread safe logging keys

[SimonBFrank]

Issue number: #991

Summary

Changes

• New logger methods:
  • append_thread_local_keys : add key to thread-local ContextVar
  • get_current_thread_keys: get all keys from thread-local ContextVar
  • remove_thread_local_keys: remove list of keys from thread-local ContextVar
  • clear_thread_local_keys: remove all keys from thread-local ContextVar
• Add new logic to_extract_log_keys method to handle error when an additional logging key's value is not a string and the name conflicts with a reserved keys
• clear_state in inject_lambda_context also clears thread-local keys

User experience

Before:

import concurrent.futures

from aws_lambda_powertools import Logger

logger = Logger(service="payment")


def process_payments(payment_id):
    logger.info("Start processing payment", extra={"payment_id": payment_id})
    ...
    logger.info("End processing payment", extra={"payment_id": payment_id})


with concurrent.futures.ThreadPoolExecutor(max_workers=5) as executor:
    futures = [executor.submit(process_payments, payment_id) for payment_id in range(10)]
    for future in concurrent.futures.as_completed(futures):
        future.result()

After:

import concurrent.futures

from aws_lambda_powertools import Logger

logger = Logger(service="payment")


def process_payments(payment_id):
    logger.clear_thread_local_keys()
    logger.append_thread_local_keys(payment_id=payment_id)
    logger.info("Start processing payment")
    ...
    logger.info("End processing payment")


with concurrent.futures.ThreadPoolExecutor(max_workers=5) as executor:
    futures = [executor.submit(process_payments, payment_id) for payment_id in range(10)]
    for future in concurrent.futures.as_completed(futures):
        future.result()

Checklist

If your change doesn't seem to apply, please leave them unchecked.

• Meet tenets criteria
• I have performed a self-review of this change
• Changes have been tested
• Changes are documented
• PR title follows conventional commit semantics

Is this a breaking change?: No, existing functionality isn't broken.

RFC issue number:

Checklist:

• Migration process documented
• Implement warnings (if it can live side by side)

Acknowledgment

By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.

Disclaimer: We value your time and bandwidth. As such, any pull requests created on non-triaged issues might not be successful.

[boring-cyborg]

Thanks a lot for your first contribution! Please check out our contributing guidelines and don't hesitate to ask whatever you need.
In the meantime, check out the #python channel on our Powertools for AWS Lambda Discord: Invite link

[leandrodamascena]

Assigned to @sthulb.

[SimonBFrank]

@sthulb I have made some changes to my PR since the last batch of tests failed due to type checking and | not being supported in Python versions < 3.9. Can you please allow the additional test cases to run?

[sthulb]

@SimonBFrank We have paused all development and merging in to develop/v3 branches until v3 has gone GA, which is currently scheduled for the 23rd now.

We will review and merge after that. Thank you for this contribution.

[sthulb]

This is fine, just got to rebase it into v3

[SimonBFrank]

@leandrodamascena Hey, thanks for the feedback. My responses may be delayed for the next month as my personal life is getting busy.

I think making the logger thread safe by default would not be what I would want as a feature. Let me explain through an example.

I have a Lambda that processes an order that has multiple items. Each item within an order is processed in a separate thread. When I start my function I used append_keys to add the order_id. Then, at the beginning of each thread I use append_thread_local_keys to add the item_id. Example code below:

Code:

import threading
from typing import List

from aws_lambda_powertools import Logger
from aws_lambda_powertools.utilities.typing import LambdaContext

logger = Logger()


def threaded_func(item_id: str):
    logger.append_thread_local_keys(item_id=item_id)
    logger.info("Collecting payment")


def lambda_handler(event: dict, context: LambdaContext) -> str:
    order_id: str = event["order_id"]
    item_ids: List[str] = event["item_ids"]

    logger.append_keys(order_id=order_id)

    for item in item_ids:
        threading.Thread(target=threaded_func, args=(item,)).start()

    return "Success"

Input:

lambda_handler({"order_id": "abc123", "item_ids": ["A1", "A2"]}, {})

Output:

{"level":"INFO","location":"threaded_func:12","message":"Collecting payment","timestamp":"2024-10-02 22:46:16,678-0400","service":"service_undefined","order_id":"abc123","item_id":"A1"}
{"level":"INFO","location":"threaded_func:12","message":"Collecting payment","timestamp":"2024-10-02 22:46:16,678-0400","service":"service_undefined","order_id":"abc123","item_id":"A2"}

---

This is great because I only need to add the order_id once in the beginning of the Lambda call and will be used everywhere. I can use append_keys as "global" logging keys. But, thread specific information (item_id) can be added to each thread. If we were to make append_keys be thread specific, then we would have to add it in every thread. While this is possible, I find this a lot less user friendly. Additionally, I would imagine making append_keys thread safe would break existing behavior which opens a whole new can of worms. Let me know your thoughts.

[leandrodamascena]

Hi @SimonBFrank! Thanks for the feedback! Last week was very busy and I'll check it out this week to merge the PR.

[SimonBFrank]

Hey @leandrodamascena, any updates on getting this reviewed and merged?

[leandrodamascena]

Hey @leandrodamascena, any updates on getting this reviewed and merged?

Hey @SimonBFrank! I've had to deal with some unexpected internal reprioritizations this past week. I dropped the ball a bit here, but tomorrow I'll push some small changes and tests for us to merge, ok?

Thanks

[leandrodamascena]

Update 21/10/2024:

• New logger methods:
  • thread_safe_append_keys : add key to thread-local ContextVar
  • thread_safe_get_current_keys: get all keys from thread-local ContextVar
  • thread_safe_remove_keys: remove list of keys from thread-local ContextVar
  • thread_safe_clear_keys: remove all keys from thread-local ContextVar
• Add new logic to_extract_log_keys method to handle error when an additional logging key's value is not a string and the name conflicts with a reserved keys
• clear_state in inject_lambda_context also clears thread-local keys

[leandrodamascena]

Hi @SimonBFrank! Thanks for your patience and hard work on this PR. I sent a commit with some small changes, but basically I renamed the methods and refactored the documentation to make it more specific.

Please let me know if you have any observation before I ask the @sthulb and merge it.

[sonarqubecloud]

Quality Gate passed

Issues
1 New issue
0 Accepted issues

Measures
0 Security Hotspots
0.0% Coverage on New Code
0.0% Duplication on New Code

See analysis details on SonarCloud

[boring-cyborg]

Awesome work, congrats on your first merged pull request and thank you for helping improve everyone's experience!

[SimonBFrank]

Hi @SimonBFrank! Thanks for your patience and hard work on this PR. I sent a commit with some small changes, but basically I renamed the methods and refactored the documentation to make it more specific.

Please let me know if you have any observation before I ask the @sthulb and merge it.

Looks amazing to me. I will let me team know that this is ready to use. Thanks for the help!