Skip to content

fix(batcher): Serialize flushed items outside the batcher lock #7776

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

Draft
NicoHinderling wants to merge 1 commit into
base: master
Choose a base branch
from
Draft

fix(batcher): Serialize flushed items outside the batcher lock #7776

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
21 changes: 11 additions & 10 deletions sentry_sdk/_batcher.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -149,36 +149,37 @@ def flush(self) -> None:
finally:
self._active.flag = was_active

def _add_to_envelope(self, envelope: "Envelope") -> None:
def _add_to_envelope(self, envelope: "Envelope", items: "list[T]") -> None:
envelope.add_item(
Item(
type=self.TYPE,
content_type=self.CONTENT_TYPE,
headers={
"item_count": len(self._buffer),
"item_count": len(items),
},
payload=PayloadRef(
json={
"version": 2,
"items": [
self._to_transport_format(item) for item in self._buffer
],
"items": [self._to_transport_format(item) for item in items],
}
),
)
)

def _flush(self) -> "Optional[Envelope]":
envelope = Envelope(
headers={"sent_at": format_timestamp(datetime.now(timezone.utc))}
)
empty_buffer: "list[T]" = []
with self._lock:
if len(self._buffer) == 0:
return None

self._add_to_envelope(envelope)
self._buffer.clear()
items, self._buffer = self._buffer, empty_buffer

# Serialize outside the lock: GC here can run a finalizer that logs, which needs the
# logging handler lock held by another thread already blocked on us in add().
envelope = Envelope(
headers={"sent_at": format_timestamp(datetime.now(timezone.utc))}
)
self._add_to_envelope(envelope, items)
self._capture_func(envelope)
return envelope

Expand Down
27 changes: 25 additions & 2 deletions tests/test_logs.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -889,12 +889,12 @@ def test_reentrant_add_does_not_deadlock(sentry_init, capture_envelopes):
reentrant_add_called = False
original_add_to_envelope = batcher._add_to_envelope

def add_to_envelope_with_reentrant_add(envelope):
def add_to_envelope_with_reentrant_add(envelope, items):
nonlocal reentrant_add_called
# Simulate a GC warning routing back into add() during flush
batcher.add({"fake": "log"})
reentrant_add_called = True
original_add_to_envelope(envelope)
original_add_to_envelope(envelope, items)

batcher._add_to_envelope = add_to_envelope_with_reentrant_add

Expand All @@ -906,6 +906,29 @@ def add_to_envelope_with_reentrant_add(envelope):
# eventually be timed out by pytest-timeout


def test_flush_serializes_outside_the_lock(sentry_init, capture_envelopes):
"""Regression for https://github.com/getsentry/sentry-python/issues/7775."""
sentry_init()
capture_envelopes()

client = sentry_sdk.get_client()
batcher = client.log_batcher

lock_held_while_serializing = []
original_to_transport_format = batcher._to_transport_format

def record_lock_state(item):
lock_held_while_serializing.append(batcher._lock.locked())
return original_to_transport_format(item)

batcher._to_transport_format = record_lock_state

sentry_sdk.logger.warning("test log")
client.flush()

assert lock_held_while_serializing == [False]


@pytest.mark.skipif(
sys.platform == "win32"
or not hasattr(os, "fork")
Expand Down
Loading