open-telemetry / open-telemetry/opentelemetry-python-contrib
LoggingInstrumentor and AWS Lambda Python RIC are duplicating logs
Nobody has claimed this yet.
- Dominant language
- Python
- Stars
- 1.1k
- Forks
- 1.1k
- Avg merge
- 4d 15h
- Merged PRs (30d)
- 16
Description
I'm not sure if this fits under Bug or Feature Request.
Describe your environment
AWS Lambda function with Otel Python lambda layer, Python 3.8 in x86_64.
Steps to reproduce
I have an AWS Lambda function equipped with the OpenTelemetry Python lambda layer 0.5.0 and have set the env var OTEL_PYTHON_LOG_CORRELATION: true. The function calls logger.getLogger(__name__) and logger.warning(<msg>), without adding any handlers. Invocation results in duplicate logs, for example:
2024-04-12 23:44:40,808 WARNING [root] [lambda_function.py:32] [trace_id=XXXX span_id=XXXX resource.service.name=lambda_function trace_sampled=XX] - My log inside lambda
[WARNING] 2024-04-12T23:44:40.808Z XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX My log inside lambda
The first log is what I expect for OTEL_PYTHON_LOG_CORRELATION (I've just X'd out the context IDs). The second log has a different format where the long ID is the AWS function invocation request ID. This comes from the aws-lambda-python-runtime-interface-client: this formatting by _setup_logging and always with a Lambda-specific handler. The AWS logging does not seem to be configurable.
What is the expected behavior?
Ideally: it would be great if there was a single set of logs that had the best of both kinds, something like:
2024-04-12 23:44:40,808 WARNING [root] [lambda_function.py:32] [request_id=XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX] [trace_id=XXXX span_id=XXXX resource.service.name=lambda_function trace_sampled=XX] - My log inside lambda
What is the actual behavior?
Duplicate logs for the same messages, in 2 different formats.
Additional context
This might relate to how LoggingInstrumentor does a single logging.basicConfig call as others have already pointed out:
- https://github.com/open-telemetry/opentelemetry-python/issues/3473
- https://github.com/open-telemetry/opentelemetry-python-contrib/issues/2346
Maybe the explicit setting of handler formats in this PR could add span context fields to the lambda runtime-set logging handler, by adaptor or filter: https://github.com/open-telemetry/opentelemetry-python-contrib/pull/1939
Contributor guide
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Research direction
Reproduce the duplicate output with the AWS Lambda Python layer and OTEL_PYTHON_LOG_CORRELATION enabled. Read LoggingInstrumentor's logging.basicConfig behavior alongside awslambdaric/bootstrap.py lines 444-455 and 480, and review PR 1939. Done means one log entry retains both the Lambda request ID and OpenTelemetry context without duplicate messages.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- aws, python
- Domain
- cloud, observability
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 35/100