Timeout warnings from AWS Lambda integration don't include additional context data

[jrojasendava]

Environment

How do you use Sentry? Sentry SaaS (sentry.io)

Which SDK and version?

sentry-sdk-1.3.1, Python 3.8.

Sentry client configuration details

I instrumented a Python 3.8 lambda function in AWS Lambda to use the sentry-sdk, along with the aws lambda integration, with code like the following:

import json
import sentry_sdk
from sentry_sdk.integrations.aws_lambda import AwsLambdaIntegration

sentry_sdk.init(
    dsn="https://[email protected]/zzzzzzzz",
    integrations=[AwsLambdaIntegration(timeout_warning=True)]
)

And I also added an additional context, to send to sentry additional data (the event data that triggered the lambda function I'm instrumenting):

def lambda_handler(event, context):
    sentry_sdk.set_context("lambda_event", dict(event=json.dumps(event)))
    ...

Steps to Reproduce

1. Run the lambda, and have it time out (run for longer than its configured timeout in the AWS console)
2. Receive the ServerlessTimeoutWarning awslambda:///lambdaFunctionName warning in the sentry console

Expected Result

I expected the context data I sent right at the start of the function (sentry_sdk.set_context("lambda_event", dict(event=json.dumps(event)))) to be available in the sentry console for this serverless timeout warning message.

Actual Result

The data from the context I added is missing.

Goal I was seeking when I found this issue

My goal is just to receive the event data of the event that triggered the execution of the lambda function. If there's a better way of getting that piece of information (the AWS event which in python lambdas is passed as an argument to the lambda handler function), into the sentry console, for any message sent to sentry, I'm more than happy to change how I collect that info.

[AbhiPrasad]

Hey, thanks for writing in. When you refer to Sentry console, do you mean the actual issue/event that shows up in Sentry? Or the logs that come from setting the debug option to true?

Are tags and breadcrumbs being set on the event?

[jrojasendava]

yes, by "Sentry Console" I mean the actual issue/event that shows up in Sentry.

Tags are being set on the event; I see no breadcrumbs, but that's possibly because this is a very small function that I created only for exercising Sentry.

[AbhiPrasad]

Could you provide a link to the Sentry issue? If that's not possible, the event json would be very helpful as well.

[jrojasendava]

{"event_id":"6714cd56c4034005b1f5938ec0ce219a","project":5948058,"release":null,"dist":null,"platform":"python","message":"","datetime":"2021-09-06T21:16:36.993798Z","tags":[["aws_region","us-east-2"],["environment","production"],["handled","no"],["level","error"],["mechanism","threading"],["runtime","CPython 3.8.11"],["runtime.name","CPython"],["server_name","169.254.26.213"],["url","awslambda:///alertDummy"]],"_metrics":{"bytes.ingested.event":1916,"bytes.stored.event":2995},"contexts":{"runtime":{"name":"CPython","version":"3.8.11","build":"3.8.11 (default, Jul 14 2021, 13:00:42) \n[GCC 7.3.1 20180712 (Red Hat 7.3.1-13)]","type":"runtime"}},"culprit":"awslambda:///alertDummy","environment":"production","exception":{"values":[{"type":"ServerlessTimeoutWarning","value":"WARNING : Function is expected to get timed out. Configured timeout duration = 10 seconds.","module":"sentry_sdk.utils","mechanism":{"type":"threading","handled":false}}]},"extra":{"cloudwatch logs":{"log_group":"/aws/lambda/alertDummy","log_stream":"2021/09/06/[$LATEST]608db6dc67524fa283cda044fd2c2905","url":"https://console.aws.amazon.com/cloudwatch/home?region=us-east-2#logEventViewer:group=/aws/lambda/alertDummy;stream=2021/09/06/[$LATEST]608db6dc67524fa283cda044fd2c2905;start=2021-09-06T21:16:27Z;end=2021-09-06T21:16:39Z"},"lambda":{"aws_request_id":"3c0147ae-b382-4b33-80b1-f6aae489bb1f","execution_duration_in_millis":9416,"function_name":"alertDummy","function_version":"$LATEST","invoked_function_arn":"arn:aws:lambda:us-east-2:945204924800:function:alertDummy","remaining_time_in_millis":583},"sys.argv":["/var/runtime/bootstrap.py"]},"fingerprint":["{{ default }}"],"grouping_config":{"enhancements":"eJybzDRxY3J-bm5-npWRgaGlroGxrpHxBABcYgcZ","id":"newstyle:2019-10-29"},"hashes":["8d4c309bc17894e149c32fcc952b9a32"],"ingest_path":[{"public_key":"XE7QiyuNlja9PZ7I9qJlwQotzecWrUIN91BAO7Q5R38","version":"21.8.0"}],"key_id":"1789792","level":"error","logger":"","metadata":{"type":"ServerlessTimeoutWarning","value":"WARNING : Function is expected to get timed out. Configured timeout duration = 10 seconds."},"modules":{"boto3":"1.17.100","botocore":"1.20.100","certifi":"2021.5.30","jmespath":"0.10.0","pip":"21.1.1","python-dateutil":"2.8.2","rapid-client":"0.0.0","s3transfer":"0.4.2","sentry-sdk":"1.3.1","setuptools":"56.0.0","six":"1.16.0","urllib3":"1.26.6"},"nodestore_insert":1630962999.625468,"received":1630962998.226267,"request":{"url":"awslambda:///alertDummy"},"sdk":{"name":"sentry.python","version":"1.3.1","integrations":["argv","atexit","aws_lambda","boto3","dedupe","excepthook","logging","modules","stdlib","threading"],"packages":[{"name":"pypi:sentry-sdk","version":"1.3.1"}]},"timestamp":1630962996.993798,"title":"ServerlessTimeoutWarning: WARNING : Function is expected to get timed out. Configured timeout duration = 10 seconds.","type":"error","version":"7","location":null}

[AbhiPrasad]

The SDK has some trimming logic to prevent event payloads from being too large to send to Sentry. Serializing the entire event may be too large. See: https://github.com/getsentry/sentry-python/issues/377

Could you try sentry_sdk.set_context with something smaller to see if that goes through?

[jrojasendava]

I thought about that too, but that wasn't the source of the issue; I tested the exact same payload, but sending a logger.error instead of triggering a timeout; when I did that, I received the context data and was able to see it in Sentry; see event json below:

{"event_id":"51b40640d5b142c5bfa84bbdb07b8021","project":5948058,"release":null,"dist":null,"platform":"python","message":"this is an error","datetime":"2021-09-06T21:25:28.123276Z","tags":[["aws_region","us-east-2"],["environment","production"],["level","error"],["logger","lambda_function"],["runtime","CPython 3.8.11"],["runtime.name","CPython"],["server_name","169.254.43.229"],["transaction","alertDummy"],["url","awslambda:///alertDummy"]],"_metrics":{"bytes.ingested.event":2116,"bytes.stored.event":2937},"contexts":{"lambda_event":{"event":"{\"command\": \"logerror\"}","type":"lambda_event"},"runtime":{"name":"CPython","version":"3.8.11","build":"3.8.11 (default, Jul 14 2021, 13:00:42) \n[GCC 7.3.1 20180712 (Red Hat 7.3.1-13)]","type":"runtime"},"trace":{"trace_id":"6011412ecf014c36848e186b0582a51d","span_id":"9c5112a72ff33d02","op":"serverless.function","status":"unknown","type":"trace"}},"culprit":"alertDummy","environment":"production","extra":{"asctime":"2021-09-06T21:25:28","aws_request_id":"dc502604-fa79-4563-8bd6-7d0c932c8d4c","cloudwatch logs":{"log_group":"/aws/lambda/alertDummy","log_stream":"2021/09/06/[$LATEST]d9c898eee9fe4cd1ba1e1e86d4ae6ca7","url":"https://console.aws.amazon.com/cloudwatch/home?region=us-east-2#logEventViewer:group=/aws/lambda/alertDummy;stream=2021/09/06/[$LATEST]d9c898eee9fe4cd1ba1e1e86d4ae6ca7;start=2021-09-06T21:25:27Z;end=2021-09-06T21:25:31Z"},"extra_data":1,"lambda":{"aws_request_id":"dc502604-fa79-4563-8bd6-7d0c932c8d4c","execution_duration_in_millis":976,"function_name":"alertDummy","function_version":"$LATEST","invoked_function_arn":"arn:aws:lambda:us-east-2:945204924800:function:alertDummy","remaining_time_in_millis":9024},"more_extra":"whoopsie","sys.argv":["/var/runtime/bootstrap.py"]},"fingerprint":["{{ default }}"],"grouping_config":{"enhancements":"eJybzDRxY3J-bm5-npWRgaGlroGxrpHxBABcYgcZ","id":"newstyle:2019-10-29"},"hashes":["5694556d74004ba7fea452bf03214673"],"ingest_path":[{"public_key":"XE7QiyuNlja9PZ7I9qJlwQotzecWrUIN91BAO7Q5R38","version":"21.8.0"}],"key_id":"1789792","level":"error","logentry":{"formatted":"this is an error","params":[]},"logger":"lambda_function","metadata":{"title":"this is an error"},"modules":{"boto3":"1.17.100","botocore":"1.20.100","certifi":"2021.5.30","jmespath":"0.10.0","pip":"21.1.1","python-dateutil":"2.8.2","rapid-client":"0.0.0","s3transfer":"0.4.2","sentry-sdk":"1.3.1","setuptools":"56.0.0","six":"1.16.0","urllib3":"1.26.6"},"nodestore_insert":1630963531.101735,"received":1630963529.38068,"request":{"url":"awslambda:///alertDummy"},"sdk":{"name":"sentry.python","version":"1.3.1","integrations":["argv","atexit","aws_lambda","boto3","dedupe","excepthook","logging","modules","stdlib","threading"],"packages":[{"name":"pypi:sentry-sdk","version":"1.3.1"}]},"timestamp":1630963528.123276,"title":"this is an error","transaction":"alertDummy","type":"default","version":"7","location":null}

[jrojasendava]

@AbhiPrasad pardon: as of now, do you still need information from me regarding this issue? or should the "needs-information" tag be removed?

[github-actions[bot]]

This issue has gone three weeks without activity. In another week, I will close it.

But! If you comment or otherwise update it, I will reset the clock, and if you label it Status: Backlog or Status: In Progress, I will leave it alone ... forever!

---

"A weed is but an unloved flower." ― Ella Wheeler Wilcox 🥀

[antonpirker]

Hey @jrojasendava Could you post the code of your Lambda function here so we can try to reproduce this? If the context is not sent at all it sure is a bug, and we should fix it.

[antonpirker]

It could also be that you need to set the context outside the handler? Can this be? (I have to admin I am not very deep into our Lambda integration yet.) But we are working on a Lambda Extension so maybe this will work with the Extension (but it will take a couple of week until the extension is ready for prime time)

[waseem-uddin]

@antonpirker Any update on when can we expect a solution to this issue i.e. adding the missing data from the context in case of AWS Lambda timeout. I tried the same with tags sentry_sdk.set_tag(key, value) instead of context but the tag doesn't appear in case of AWS Lambda timeouts, but appears otherwise.

Can you suggest a workaround to extract information from lambda's event/context and display in Sentry Event somehow?

[antonpirker]

Hey! I had another look at this, and I guess it is due to the fact that we start a new thread in the AWS Lambda integration to send the timeout warning [1].

This new thread gets a new Sentry environment and knows nothing about the context you set in the main thread.

SOLUTION: You could try to set the propagate_hub parameter to True in the ThreadingIntegration when calling sentry_sdk.init(). See [2]. This would clone the sentry environment (called the "Hub") to the new thread, and you then should have the context you set in the timeout warning.

Hope this helps!

1: https://github.com/getsentry/sentry-python/blob/master/sentry_sdk/integrations/aws_lambda.py#L120-L136 2: https://docs.sentry.io/platforms/python/configuration/integrations/default-integrations/#threading

[waseem-uddin]

@antonpirker

I tried setting the propagate_hub=True in the ThreadingIntegration when calling sentry_sdk.init(), but it didn't propagate the context for the use case mentioned i.e. when lambda times out and the context is set in the lambda handler.

Interestingly, the context is propagated irrespective of the values of propagate_hub when the context is set right after calling sentry_sdk.init(), as shown below in the settings.py file for my django project (the context propagates even with propagate_hub=False):

settings.py

def set_sentry_context(key: str, value: t.Dict[str, t.Any]):
    sentry_sdk.set_context(key, value)

sentry_sdk.init(
    dsn="https://[email protected]/zzzzzzzz",
    integrations=[
        DjangoIntegration(),
        AwsLambdaIntegration(timeout_warning=True),
        ThreadingIntegration(propagate_hub=False),
    ],
)

set_sentry_context("person", {
    "name": "abc",
    "age": 20
})

The problem is that when the context is set in lambda_handler instead of right after the sentry_sdk.init(), it doesn't get propagated in case of lambda timeout even when I set propagate_hub=True

app.py

from apig_wsgi import make_lambda_handler

from project.settings import set_sentry_context
from project.wsgi import application

apig_wsgi_handler = make_lambda_handler(application)


def django_http_handler(event, context):
    request_context = event["requestContext"]
    api_url = f'{request_context["domainName"]}{request_context["http"]["path"]}'
    
   set_sentry_context("userinfo", {
        "name": "xyz",
        "url": api_url
    })

    response = apig_wsgi_handler(event, context)
    return response

[antonpirker]

Hey @waseem-uddin !

We had another look and this case is hard to support with the way we handle the timeout warning right now. I know that this is not the answer you where hoping for, but for now we can not support this use case.

I will close this issue now.