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

[NicoHinderling]

Batcher._flush held _lock while serializing the buffered items. Serializing can trigger GC, and if a collected object's finalizer logs, the flush thread needs the logging handler lock, which another thread already holds while it waits for _lock in add(). That lock-order inversion freezes every later log call in the process; it's what was hard-killing Seer's Celery tasks (#7775).

• _flush now swaps the buffer out under the lock (the replacement list is allocated before taking it) and builds the envelope after releasing it. Applies to LogBatcher and MetricsBatcher.
• New regression test asserts the lock isn't held while items are serialized; the repro in Deadlock between log batcher lock and logging handler lock when GC runs a finalizer that logs #7775 goes from deadlocking in ~5s to none in 5 runs of 30–40s.
• Behavior change: a batch whose serialization raises is now dropped instead of being retried on every flush.
• Not covered here: SpanBatcher._flush serializes under its own lock the same way, and add() calls _record_lost under the lock once the buffer is full. Happy to follow up on both.

Fixes #7775

[NicoHinderling]

(this was auto generated on behalf of that ticket i reported.. feel free to close this, if you would prefer to address it in a different way, I just opened it in case it's helpful)

[github-actions]

Codecov Results 📊

✅ 129739 passed | ❌ 2 failed | ⏭️ 7169 skipped | Total: 136910 | Pass Rate: 94.76% | Execution Time: 434m 16s

📊 Comparison with Base Branch

Metric	Change
Total Tests	📈 +439
Passed Tests	📈 +438
Failed Tests	📈 +1
Skipped Tests	—

➕ New Tests (2)

View new tests

• test_flush_serializes_outside_the_lock
  • File: tests.test_logs
  • Status: ❌ Failing
• test_flush_serializes_outside_the_lock
  • File: tests.test_logs
  • Status: ❌ Failing

➖ Removed Tests (1)

View removed tests

• test_cache_spans_decorator[True]
  • File: tests.integrations.django.test_cache_module

❌ Failed Tests

test_flush_serializes_outside_the_lock

File: tests.test_logs
Suite: py3.6-common
Error: AttributeError: module 'time' has no attribute 'time_ns'

Stack Trace

tests/test_logs.py:926: in test_flush_serializes_outside_the_lock
    sentry_sdk.logger.warning("test log")
sentry_sdk/logger.py:60: in _capture_log
    "time_unix_nano": time.time_ns(),
E   AttributeError: module 'time' has no attribute 'time_ns'

test_flush_serializes_outside_the_lock

File: tests.test_logs
Suite: py3.6-gevent
Error: AttributeError: module 'time' has no attribute 'time_ns'

Stack Trace

tests/test_logs.py:926: in test_flush_serializes_outside_the_lock
    sentry_sdk.logger.warning("test log")
sentry_sdk/logger.py:60: in _capture_log
    "time_unix_nano": time.time_ns(),
E   AttributeError: module 'time' has no attribute 'time_ns'

✅ Patch coverage is 100.00%. Project has 2553 uncovered lines.
❌ Project coverage is 90.25%. Comparing base (2a499ec) to head (1f3b6f0).

Coverage diff

@@            Coverage Diff             @@
##        master       #PR       +/-##
==========================================
- Coverage    90.27%    90.25%    -0.02%
==========================================
  Files          195       195         —
  Lines        26197     26198        +1
  Branches      9758      9758         —
==========================================
+ Hits         23650     23645        -5
- Misses        2547      2553        +6
- Partials      1484      1483        -1

---

Generated by Codecov Action

[alexander-alderman-webb]

Thanks @NicoHinderling.
I don't think this is the right way to approach this because the lock should guard self._buffer and items is a shallow copy of self._buffer.

[alexander-alderman-webb]

Right this could actually work since self._buffer is cleared at the same time, so it could be safe to mutate items outside of the lock