Fix incorrect timeout warnings in AWS Lambda and GCP integrations #854

shantanu73 · 2020-10-12T06:30:34Z

Added code to stop thread in aws_lambda.py & gcp.py.
Modified logic of run() function of class TimeoutThread to stop the thread and raise ServerlessTimeoutWarning exception, conditionally.

Fixes #846.

1) Added code to stop thread in aws_lambda.py & gcp.py. 2) Modified logic of run() function of class TimeoutThread to stop the thread and raise ServerlessTimeoutWarning exception, conditionally.

shantanu73 · 2020-10-12T06:36:41Z

sentry_sdk/integrations/aws_lambda.py

@@ -116,6 +116,13 @@ def sentry_handler(event, context, *args, **kwargs):
                    )
                    hub.capture_event(event, hint=hint)
                    reraise(*exc_info)
+                finally:


@untitaker In this "finally" block, the code to stop the thread basically works in case of :-

A successful run of lambda function.

When an exception is there in the code.
But, it doesn't stop the thread in case of timeout, which is an expected behavior.

By "stop the thread" I mean explicitly stopping a thread by sending a stop signal.

1) Improved the logic of run() function of class TimeoutThread to remove the dependency on time.sleep() method.

rhcarvalho

Maybe using a Timer would make things cleaner.

Every handler execution starts a new timer (unless we don't have enough "buffer"/threshold).
Whenever the original handler finishes running (the new finally block in this PR) and a timer has been started, call timer.cancel() -- no additional condition.
The Timer runs a function that raises the timeout exception, no conditions.

The above is my suggestion.

Side note
Because the runtime can abort/pause the handler at any time, I imagine there'd be room for the timer firing incorrectly into a future handler execution, but not sure if there's anything we could do about it. (I thought of an Event to mark the end of the handler and the timer could check it, but that doesn't change anything if the finally block of one execution runs into the next execution -- depends how the timeout is implemented by the runtime.)

sentry_sdk/integrations/aws_lambda.py

sentry_sdk/utils.py

rhcarvalho · 2020-10-13T11:22:52Z

Alternative to a Timer, Thread + Event to communicate the stop like in this example https://stackoverflow.com/a/325528/963287
Event.wait(timeout) can be used instead of the loop that sleeps second by second.

rhcarvalho · 2020-10-13T11:30:02Z

sentry_sdk/integrations/aws_lambda.py

+                    if (
+                        integration.timeout_warning
+                        and configured_time > TIMEOUT_WARNING_BUFFER
+                    ):


I see that timeout_thread is only conditionally defined. That's why you need to repeat this condition here.

It would be clearer to always define timeout_thread, initially setting it to None.
That way, here it would become:

if timeout_thread is not None: timeout_thread.stop()

.stop() sets a "stop event" to true, unblocking and terminating the thread if still running, and doing nothing otherwise.

Made this change in latest commit.

1) Removed CPU consuming while loop from logic of run method of TimeoutThread class. 2) Used Event class from threading module to send a stop signal for the thread. 3) Changed cancel() to stop() for stopping thread for AWS and GCP integration files.

rhcarvalho · 2020-10-13T15:08:18Z

sentry_sdk/utils.py

+
+    def stopped(self):
+        # type: () -> Any
+        return self._stop_event.is_set()

    def run(self):
        # type: () -> None

        time.sleep(self.waiting_time)


The thread doesn't need to sleep for the full waiting_time. When the handler returns and we call timeout_thread.stop(), the thread should wake up and terminate.

That's why I suggested using self._stop_event.wait(self.waiting_time).

https://docs.python.org/2.7/library/threading.html#threading.Event.wait

You can either use the return value or wait or .is_set() to decide whether to raise ServerlessTimeoutWarning.

Yes I figured that while I did testing and found it was still waiting for complete waiting time.
I've made final changes accordingly now.

1) Replaced time.sleep() method with wait() method so that the thread terminates before completing the full waiting time.

shantanu73 · 2020-10-14T01:24:22Z

sentry_sdk/utils.py


-        integer_configured_timeout = int(self.configured_timeout)
+        if not self._stop_event.is_set():


@rhcarvalho I made final changes, if these look okay then PR can be merged.

rhcarvalho

Thanks @shantanu73 👍

I've made a small change to avoid increasing indentation.
Would be nice to have a test case to cover this bug and prevent regression in a follow up.

Let's get this in first though. Thanks again!

Changes:

d808d64

1) Added code to stop thread in aws_lambda.py & gcp.py. 2) Modified logic of run() function of class TimeoutThread to stop the thread and raise ServerlessTimeoutWarning exception, conditionally.

ajjindal requested review from untitaker and rhcarvalho October 12, 2020 06:36

shantanu73 commented Oct 12, 2020

View reviewed changes

Changes:

33eecb6

1) Improved the logic of run() function of class TimeoutThread to remove the dependency on time.sleep() method.

rhcarvalho reviewed Oct 12, 2020

View reviewed changes

sentry_sdk/integrations/aws_lambda.py Outdated Show resolved Hide resolved

sentry_sdk/utils.py Outdated Show resolved Hide resolved

rhcarvalho reviewed Oct 12, 2020

View reviewed changes

sentry_sdk/utils.py Outdated Show resolved Hide resolved

rhcarvalho reviewed Oct 13, 2020

View reviewed changes

Changes:

1806fef

1) Removed CPU consuming while loop from logic of run method of TimeoutThread class. 2) Used Event class from threading module to send a stop signal for the thread. 3) Changed cancel() to stop() for stopping thread for AWS and GCP integration files.

rhcarvalho reviewed Oct 13, 2020

View reviewed changes

Changes:

7e841a5

1) Replaced time.sleep() method with wait() method so that the thread terminates before completing the full waiting time.

shantanu73 commented Oct 14, 2020

View reviewed changes

rhcarvalho changed the title ~~Fix for Bug #846 : Incorrect timeout warnings when using AWS Lambda integration~~ Fix incorrect timeout warnings in AWS Lambda and GCP integrations Oct 14, 2020

rhcarvalho added 2 commits October 14, 2020 10:07

ref: reduce indentation

80d79aa

fix: remove trailing whitespace

59b32d4

rhcarvalho approved these changes Oct 14, 2020

View reviewed changes

rhcarvalho merged commit e12a350 into getsentry:master Oct 14, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix incorrect timeout warnings in AWS Lambda and GCP integrations #854

Fix incorrect timeout warnings in AWS Lambda and GCP integrations #854

shantanu73 commented Oct 12, 2020 •

edited by rhcarvalho

shantanu73 Oct 12, 2020 •

edited

rhcarvalho left a comment

rhcarvalho commented Oct 13, 2020

rhcarvalho Oct 13, 2020

shantanu73 Oct 13, 2020

rhcarvalho Oct 13, 2020

shantanu73 Oct 14, 2020

shantanu73 Oct 14, 2020

rhcarvalho left a comment


		integer_configured_timeout = int(self.configured_timeout)
		if not self._stop_event.is_set():

Fix incorrect timeout warnings in AWS Lambda and GCP integrations #854

Fix incorrect timeout warnings in AWS Lambda and GCP integrations #854

Conversation

shantanu73 commented Oct 12, 2020 • edited by rhcarvalho

shantanu73 Oct 12, 2020 • edited

Choose a reason for hiding this comment

rhcarvalho left a comment

Choose a reason for hiding this comment

rhcarvalho commented Oct 13, 2020

rhcarvalho Oct 13, 2020

Choose a reason for hiding this comment

shantanu73 Oct 13, 2020

Choose a reason for hiding this comment

rhcarvalho Oct 13, 2020

Choose a reason for hiding this comment

shantanu73 Oct 14, 2020

Choose a reason for hiding this comment

shantanu73 Oct 14, 2020

Choose a reason for hiding this comment

rhcarvalho left a comment

Choose a reason for hiding this comment

shantanu73 commented Oct 12, 2020 •

edited by rhcarvalho

shantanu73 Oct 12, 2020 •

edited