Include X-Ray Trace ID in Logger when detected

[brysontyrrell]

Is your feature request related to a problem? Please describe.
When using CloudWatch ServiceLens, logs are aggregated if the lines contain the trace ID you're looking at. This is handled by the default root logger, but it lost when using the Powertools logger.

The Powertools logger would be more powerful is it worked better together with both X-Ray and ServiceLens. Structured JSON logging is must easier to search and view in ServiceLens results. The whole thing becomes a better out-of-the-box solution.

Describe the solution you'd like
If present, I would like the X-Ray trace ID appended automatically to the log structure.

Describe alternatives you've considered
I've worked around this in one Lambda Function I've been using to try out Powertools.

@lambda_handler_decorator
def lambda_middleware(handler, event, context):
    logger.structure_logs(
        append=True,
        xray_trace_id=os.environ["_X_AMZN_TRACE_ID"].split(";")[0].strip("Root=")
        or None,
    )
    try:
        return handler(event, context)
    except Exception as error:
        logger.exception({"error": str(error)})
        raise

[heitorlessa]

Thanks for raising the issue @brysontyrrell :)

We definitely want to do this. I have one question for you, though: At what point should this key be added?

• A) During Logger initialization since this is available at runtime e.g. logger = Logger()
• B) When using inject_lambda_context decorator

[heitorlessa]

@brysontyrrell could you double check the implementation meets your expectation?

We'll only add the key xray_trace_id if your Lambda function enabled Tracing. You can also change the order of the key in your final log record if you fancy too.

[brysontyrrell]

@heitorlessa Sorry for the delay in replying!

I took a look at the implementation you linked. The trace ID changes for each invocation. Setting in the init of the formatter would mean that the logger would have to be initialized in the handler and not the root, right?

[heitorlessa]

That is absolutely true, and I completely forgot that! @brysontyrrell - This means we'll only guarantee this if customers use the inject_lambda_context decorator since we can update the logger on every invocation.

Does that still work for you?

[brysontyrrell]

@heitorlessa That would still work. I'd like to know more about how the Python Lambda environment configures the root logger to handle this as it sets the trace ID in the logger for each invoke even if you've initialized in the global context.

Example output from some testing I just did:

XRAY TraceId: 1-5f4be783-6e3816ed594eceb206b65359	SegmentId: 40d625d54b0dd18b	Sampled: true

The logger parsed this from the env var (not the segment ID though - unsure where's that set so the logger can discover it):

_X_AMZN_TRACE_ID: Root=1-5f4be783-6e3816ed594eceb206b65359;Parent=9335e1d5c7bb5c5d;Sampled=1

[heitorlessa]

This is likely at the bootstrap.py who imports your code and updates the root logger handler. Lemme see how much of a performance impact it has if I were to update that when formatting the log keys - This would be fetched at every log statement

[heitorlessa]

Perf impact is negligible, this change won't impact customers - Difference in fetching it while formatting log records is ~0.10 nanoseconds.

I'll change this now, and merge the PR after updating tests :) -- It'll be in the next release during this coming week

Thanks again for the heads up @brysontyrrell

[heitorlessa]

I've just tested it and works @brysontyrrell, also worked with the Service Lens team to ensure this will work consistently :)

Merging soon, and will update here once it's released along with other new shiny features in 1.5.0 this week

[heitorlessa]

Closing as this was included in 1.5.0 :)