Skip to content

fix: Enforce max queue length in transport #593

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
untitaker merged 3 commits into from
Jan 21, 2020
Merged

fix: Enforce max queue length in transport #593

Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
51dccfc
fix: Enforce max queue length in transport
untitaker Jan 17, 2020
97d25bf
fix: Revert change to kill()
untitaker Jan 20, 2020
80e69fa
fix: Catch down queue.Full
untitaker Jan 21, 2020
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
17 changes: 14 additions & 3 deletions sentry_sdk/worker.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,7 @@ class BackgroundWorker(object):
def __init__(self):
# type: () -> None
check_thread_support()
self._queue = queue.Queue(-1) # type: Queue[Any]
self._queue = queue.Queue(30) # type: Queue[Any]
Copy link
Contributor

@rhcarvalho rhcarvalho Jan 21, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👍

self._lock = Lock()
self._thread = None # type: Optional[Thread]
self._thread_for_pid = None # type: Optional[int]
Expand Down Expand Up @@ -86,10 +86,18 @@ def start(self):

def kill(self):
# type: () -> None
"""
Kill worker thread. Returns immediately. Not useful for
waiting on shutdown for events, use `flush` for that.
"""
Copy link
Contributor

@rhcarvalho rhcarvalho Jan 21, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In theory now kill may raise queue.Full.

I'll consider people should never call this directly, but instead use Hub.current.client.close(), which does:

           self.flush(timeout=timeout, callback=callback)
           self.transport.kill()

The first flush should empty the queue (may not empty if the timeout is reached), then transport.kill() should be able to put the _TERMINATOR.

Since there are some "shoulds", how about we handle queue.Full explicitly? In that case we can log a debug message. I don't see a clear way out without changing the current termination mechanism.

Thoughts?

Copy link
Member Author

@untitaker untitaker Jan 21, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah I did the same thing as with the other put_nowait now

logger.debug("background worker got kill request")
with self._lock:
if self._thread:
self._queue.put_nowait(_TERMINATOR)
try:
self._queue.put_nowait(_TERMINATOR)
except queue.Full:
logger.debug("background worker queue full, kill failed")

self._thread = None
self._thread_for_pid = None

Expand All @@ -114,7 +122,10 @@ def _wait_flush(self, timeout, callback):
def submit(self, callback):
# type: (Callable[[], None]) -> None
self._ensure_thread()
self._queue.put_nowait(callback)
try:
self._queue.put_nowait(callback)
except queue.Full:
logger.debug("background worker queue full, dropping event")
Copy link
Contributor

@rhcarvalho rhcarvalho Jan 21, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Tested by sending loads of events in a row. This seems to be working as intended.

In a given run, out of 106 events created in a loop, the client dropped 76 and the server received 30.

import os

from sentry_sdk import init, capture_message, flush


init(debug=True)

for i in range(int(os.environ["TEST_N"])):
    capture_message("hello")

flush()
Details 
Running tool: /usr/bin/go test -benchmem -run=^$ github.com/getsentry/sentry-go/internal/testing/external -bench ^(Benchmark)$

goos: linux
goarch: amd64
pkg: github.com/getsentry/sentry-go/internal/testing/external
Benchmark-8   	--- FAIL: Benchmark-8
    /home/rodolfo/sentry/sentry-go/internal/testing/external/external_test.go:56: counter = 30, want 106
        out:
         [sentry] DEBUG: Setting up integrations (with default = True)
         [sentry] DEBUG: Setting up previously not enabled integration logging
         [sentry] DEBUG: Setting up previously not enabled integration stdlib
         [sentry] DEBUG: Setting up previously not enabled integration excepthook
         [sentry] DEBUG: Setting up previously not enabled integration dedupe
         [sentry] DEBUG: Setting up previously not enabled integration atexit
         [sentry] DEBUG: Setting up previously not enabled integration modules
         [sentry] DEBUG: Setting up previously not enabled integration argv
         [sentry] DEBUG: Setting up previously not enabled integration threading
         [sentry] DEBUG: Enabling integration logging
         [sentry] DEBUG: Enabling integration stdlib
         [sentry] DEBUG: Enabling integration excepthook
         [sentry] DEBUG: Enabling integration dedupe
         [sentry] DEBUG: Enabling integration atexit
         [sentry] DEBUG: Enabling integration modules
         [sentry] DEBUG: Enabling integration argv
         [sentry] DEBUG: Enabling integration threading
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: background worker queue full, dropping event
         [sentry] DEBUG: Flushing HTTP transport
         [sentry] DEBUG: background worker got flush request
         [sentry] DEBUG: Sending event, type:null level:info event_id:09e8335bce0649c09da7656ad68075d2 project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:b174e0d0d20c4a9db8333dfbe0c3d1a4 project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:cfefb573eec044b1ae70e85c48aa52e3 project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:80692ebf568d401e8ea5268f58640632 project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:f5c39ade2323471bac4cb74786e97d3a project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:d08bdc0cc4ef4424b27ab3ca14de7ca4 project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:61399f8daf914a27bee67dab24fcd05d project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:e00909b9d7f1462f933dc125eb004d9c project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:0c4375b1274349e3b3775b2a3ba17b63 project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:de9fb90825664d9ab49c674c5e3087ac project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:de899ab160a74dd79e0bb1abfb6441e3 project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:d4554cca8a6143119f206ad17f53995e project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:9b95b26ddf55476a8efb6a09bd27e256 project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:6eda2eba4b754545b25e97b55ad1be27 project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:3339ec53ee764051b877f1b35513a187 project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:43ac680fa32348f3a8f78a47f63c256e project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:81208ad7342848c898c57fab54b7d10e project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:149acb3e77f84698b2912c061517b5b9 project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:80c52b4d76064afa811b5dfad7e94868 project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:e80986ed68b34e78ba0ecb04fce564d0 project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:6888ec59e9404940b1839f2dcbcba2de project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:9bdbe6516be04a1c9d983d42f6368a3a project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:56b7bb41e0df4f0abf4d77251750f7ef project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:3fab2769c26a44f4a2cfe5ffb3665e5c project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:e0af922a3f4747be9e3384ce7dabf717 project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:2d587d0bb3404b6f89e41d75755f9094 project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:49521350105445fc8934eec238ec5b18 project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:a58be743dc3c40109d4e5534c986fc18 project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:a7263a814084424c8d08ec315a6aa895 project:42 host:127.0.0.1
         [sentry] DEBUG: Sending event, type:null level:info event_id:0c56442964054efdb746562aedb2d7ee project:42 host:127.0.0.1
         [sentry] DEBUG: background worker flushed
         [sentry] DEBUG: atexit: got shutdown signal
         [sentry] DEBUG: atexit: shutting down client
         [sentry] DEBUG: Flushing HTTP transport
         [sentry] DEBUG: background worker got flush request
         [sentry] DEBUG: background worker flushed
         [sentry] DEBUG: Killing HTTP transport
         [sentry] DEBUG: background worker got kill request


def _target(self):
# type: () -> None
Expand Down