subsegments fail in global code with error: Subsegment discarded due to Lambda worker still initializing

[diablodale]

Summary

Creating subsegments in Python global context (aka startup code) fails with errors:

It is an AWS best practice to "Initialize SDK clients and database connections outside of the function handler" https://docs.aws.amazon.com/lambda/latest/dg/best-practices.html

However, since XRay will not create a subsegment in the global startup code, we have no view into this code with XRay. Without a subsegment, we also can not put_annotation() with XRay.

Setup

• AWS Lambda
• Python 3.7
• XRay SDK for Python 2.4.2

Repo

1. In Python code outside lambda_handler() write:

with xray_recorder.in_subsegment('mysubseg') as subsegment:
    subsegment.put_annotation('myanno1', '1')
    print('my old school print')

2. Continue with any simple AWS Lambda Python function
3. Execute the function

Result

Errors in the AWS Lambda console (if you used that) and/or errors in the Cloudwatch logs.

[WARNING] 2019-11-24T15:41:32.241Z Subsegment mysubseg discarded due to Lambda worker still initializing
my old school print
[WARNING] 2019-11-24T15:41:32.245Z No subsegment to end.

In XRay console, there is no subsegment for mysubseg. There is no annotation myanno1.
Only seen is the Initialization black box.

Expected

Within Initialization is the subsegment mysubseg (and another other subsegments I might make) and on the mysubseg is the annotation myanno1=1.

Workarounds

• Use print()
• Use the "discarded" error messages as an implied trace.
• Don't use global code or the AWS best practice approach. If you need similar functionality, consider putting it in a python class, have class initializer that sets class attributes, and on every call to the lambda handler, check if the class has yet been initialized.

Notes

I think there is a related yet separate bug: XRay fails to show traces for boto calls in global code. I patch(botocore) yet calls to services like boto3.session.Session().client('ssm')... are invisible and not reported in any xray data or cloudwatch log.

[bhautikpip]

Hi @diablodale,

I tried to reproduce this issue using repro steps you have provided. I was able to see 2 warnings (Subsegment mysubseg discarded due to Lambda worker still initializing, No subsegment to end) from my end when lambda initialized for the first time but after that I did not see any warnings on cloudwatch logs. I believe that is because when lambda function is executed for the first time it's initialization time is little longer than usual. Moreover, lambda function was executed successfully without throwing any errors or exception.

[diablodale]

Great. You reproduced the issue perfectly.

Naturally, you won't see global code run twice on AWS Lambda. When AWS launched a fresh labmbda instance, the global code is only run once. After that, only the lambda handler is run.

Are you AWS employee and writing the above as a repo? Or are you suggesting something else?

[bhautikpip]

Hi @diablodale,

I see your point. As per my understanding current integration with lambda does not provide capturing the subsegments outside of the function handler. I think what you can do is you can initialize a function called startup and call that function inside your lambda handler to create subsegments as work around.

[diablodale]

Yes, I used my 3rd workaround approach.

Don't use global code or the AWS best practice approach. If you need similar functionality, consider putting it in a python class, have class initializer that sets class attributes, and on every call to the lambda handler, check if the class has yet been initialized.

For now, it is not possible to use XRay at the same time as AWS best practices.

[bhautikpip]

Hi @diablodale,

I have a follow up question.

why do you want to trace global initialization ? would you mind sharing your use case ?

As per my understanding with the help of x-ray you can see and debug micro-service architecture that your application is using. You would gain more visibility in that using x-ray. Basically in global initialization you would initialize the clients and use them to make downstream or upstream calls inside your lambda function which you will be able to see on the x-ray console as segments or subsegments. I hope this clears out the use case of x-ray with lambda.

[diablodale]

Sure. I need to configure both Boto3 and socket and load some parameters from SSM before any lambda handler thread starts. I originally chose the global code approach as it is both a best practice and simple to write. This is to run once before any handler threads. One BotoConfig. One call to SSM for parameters.

Pseudo global code...

socket.setdefaulttimeout(2.5)
boto_config = BotoConfig(
    connect_timeout=2.5,
    read_timeout=6,
    max_pool_connections=6,
    proxies={
        'https': myproxyval()
    },
    retries={'max_attempts': 4}
)
ssm_result = boto3.session.Session().client('ssm', config=boto_config).get_parameters(
    Names=[
        "/deploy/db/dbName",
        "/deploy/db/host",
        "/deploy/db/user",
        "/deploy/db/userPassword",
    ],
    WithDecryption=True
)

Currently, AWS Lambda infrastructure promises to not execute the lambda handler on multiple threads at the same time on the same lambda instance. However, this is a AWS-specific feature/limitation/benefit. Yes, there are also topics of CPython, GIL, etc.

My current workaround is to create an instance of a "MyOneTime" class at the start of every lambda_handler(). That class checks its own attributes to see if it has already been created/initialized once before. And if not, it does all the BotoConfig and SSM work.

This incurs overhead of memory and cpu time to repeatedly create a MyOneTime class instance and do a lock/test to see if the one-time has previously successfully run/initialized and saved its results on the class itself (not the instance).

With the example of the 4 database values from SSM, the lambda_handler() can then do all the work it needs to do to satisfy incoming request.

So why do I want xray on the original global code? Because the calls to SSM are occasionally failing. Using the workaround of the class, tweaking BotoConfig, and lambda function timeout values, I have isolated the failures to be AWS lambda infrastructure instance networking failures (AWS problems outside my control). Though I had to use the class workaround to get to that point.

[bhautikpip]

Hi @diablodale,

Thanks for sharing this. I think that's a fair use case. I will add this item on our Backlog and see if we can accommodate this change with Lambda.

[kendhia]

Hi @bhautikpip
was this bug fixed in later versions?

[msanatan]

Any progress on this? I'm using AWS Chalice, I get these warnings for secret manager which is used in the global scope at startup. These warnings are clogging up our logs and artificially triggering our alert system with their volume. I'm about to rework how we initialize for now, but an outright fix would be better.

[willarmiros]

Hi folks, at this point we do not have plans to allow subsegments to be created in the initialization phase of Lambda functions. It is a known technical limitation but we will update here if there are any improvements to this space.

[MayankBitcot]

Hi @willarmiros,

I'm still encountering the subsegments creation in the initialization phase of the lambda function error. I believe there might be a misconfiguration on my end.

If this issue has been resolved, could you please share any relevant documentation or resources?

Thanks for your help!

@dominikschubert