Skip to content
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

Jump to bottom

Deadlock when used with ddtrace with profiling enabled #3753

Open
samertm opened this issue Nov 8, 2024 · 2 comments
Open

Deadlock when used with ddtrace with profiling enabled #3753

samertm opened this issue Nov 8, 2024 · 2 comments
Labels
Component: SDK Core Dealing with the core of the SDK Integration: Logging

Comments

@samertm
Copy link

samertm commented Nov 8, 2024

How do you use Sentry?

Sentry Saas (sentry.io)

Version

2.5.1

Steps to Reproduce

This doesn't happen that often, and we only caught the stack trace once.

We use gunicorn to serve a flask app. We have sentry and ddtrace enabled, and ddtrace has profiling enabled. These are our datadog env vars:

        - name: DD_DBM_PROPAGATION_MODE
          value: full
        - name: DD_LOGS_INJECTION
          value: 'true'
        - name: DD_OPENAI_LOG_PROMPT_COMPLETION_SAMPLE_RATE
          value: '0'
        - name: DD_OPENAI_SPAN_PROMPT_COMPLETION_SAMPLE_RATE
          value: '0'
        - name: DD_PROFILING_CAPTURE_PCT
          value: '5'
        - name: DD_PROFILING_ENABLED
          value: 'true'
        - name: DD_PROFILING_TIMELINE_ENABLED
          value: 'true'
        - name: DD_PROFILING_UPLOAD_INTERVAL
          value: '30'
        - name: DD_RUNTIME_METRICS_ENABLED
          value: 'true'

ddtrace is on version v2.14.2.

Expected Result

No deadlocks.

Actual Result

We had a pod that didn't shutdown within our 10 minute graceful termination timeout, and when we printed out the stack, one the thread stacks looks like sentry_sdk and ddtrace's monkeypatching caused a deadlock:

Thread 0x7fc0b89866c0 (most recent call first):
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 118, in _acquire
    return inner_func(*args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 252, in __enter__
    return self._acquire(self.__wrapped__.__enter__, *args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 62, in start
    with self._lock:
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 40, in _ensure_thread
    self.start()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 121, in submit
    self._ensure_thread()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/transport.py", line 553, in capture_envelope
    if not self._worker.submit(send_envelope_wrapper):
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/client.py", line 753, in capture_event
    self.transport.capture_envelope(envelope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/scope.py", line 1115, in capture_event
    event_id = Scope.get_client().capture_event(event=event, hint=hint, scope=scope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/api.py", line 123, in capture_event
    return Scope.get_current_scope().capture_event(
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/logging.py", line 255, in _emit
    sentry_sdk.capture_event(event, hint=hint)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/logging.py", line 179, in emit
    return self._emit(record)
  File "/usr/local/lib/python3.10/logging/__init__.py", line 968, in handle
    self.emit(record)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/logging.py", line 77, in _handle_record
    self._handler.handle(record)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/logging.py", line 108, in sentry_patched_callhandlers
    integration._handle_record(record)
  File "/usr/local/lib/python3.10/logging/__init__.py", line 1634, in handle
    self.callHandlers(record)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/internal/logger.py", line 176, in handle
    super(DDLogger, self).handle(record)
  File "/usr/local/lib/python3.10/logging/__init__.py", line 1624, in _log
    self.handle(record)
  File "/usr/local/lib/python3.10/logging/__init__.py", line 1489, in warning
    self._log(WARNING, msg, args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 243, in _release
    LOG.warning("Error recording lock release event: %s", e)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 247, in release
    return self._release(self.__wrapped__.release, *args, **kwargs)
  File "/usr/local/lib/python3.10/threading.py", line 274, in _release_save
    self._lock.release()           # No state to save
  File "/usr/local/lib/python3.10/threading.py", line 316, in wait
    saved_state = self._release_save()
  File "/usr/local/lib/python3.10/threading.py", line 607, in wait
    signaled = self._cond.wait(timeout)
  File "/usr/local/lib/python3.10/threading.py", line 940, in start
    self._started.wait()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 78, in sentry_start
    return old_start(self, *a, **kw)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/utils.py", line 1711, in runner
    return sentry_patched_function(*args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 69, in start
    self._thread.start()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 40, in _ensure_thread
    self.start()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 121, in submit
    self._ensure_thread()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/transport.py", line 553, in capture_envelope
    if not self._worker.submit(send_envelope_wrapper):
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/client.py", line 753, in capture_event
    self.transport.capture_envelope(envelope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/scope.py", line 1115, in capture_event
    event_id = Scope.get_client().capture_event(event=event, hint=hint, scope=scope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 866, in finish
    return hub.capture_event(event)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 306, in __exit__
    self.finish(scope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 750, in __exit__
    super().__exit__(ty, value, tb)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/wsgi.py", line 98, in __call__
    with sentry_sdk.start_transaction(
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/flask.py", line 84, in sentry_patched_wsgi_app
    return SentryWsgiMiddleware(lambda *a, **kw: old_app(self, *a, **kw))(
  File "/usr/local/lib/python3.10/site-packages/gunicorn/workers/gthread.py", line 334, in handle_request
    respiter = self.wsgi(environ, resp.start_response)
  File "/usr/local/lib/python3.10/site-packages/gunicorn/workers/gthread.py", line 282, in handle
    keepalive = self.handle_request(req, conn)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/contrib/internal/futures/threading.py", line 36, in _wrap_execution
    return fn(*args, **kwargs)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 83, in _worker
    work_item.run()
  File "/usr/local/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 92, in _run_old_run_func
    return old_run_func(self, *a, **kw)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 99, in run
    return _run_old_run_func()
  File "/usr/local/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.10/threading.py", line 973, in _bootstrap
    self._bootstrap_inner()

The issue there is that it tries to enter the worker.py _lock twice.

We saw a small increase in frontend requests hitting the timeout at the same time for requests that should ~never time out. When you look at all the thread stacks, most of them look like they're waiting on that lock:

Signal received, printing stack traces.
Thread 0x7fc08a3fc6c0 (most recent call first):
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 118, in _acquire
    return inner_func(*args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 252, in __enter__
    return self._acquire(self.__wrapped__.__enter__, *args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 62, in start
    with self._lock:
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 40, in _ensure_thread
    self.start()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 121, in submit
    self._ensure_thread()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/transport.py", line 553, in capture_envelope
    if not self._worker.submit(send_envelope_wrapper):
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/client.py", line 753, in capture_event
    self.transport.capture_envelope(envelope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/scope.py", line 1115, in capture_event
    event_id = Scope.get_client().capture_event(event=event, hint=hint, scope=scope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 866, in finish
    return hub.capture_event(event)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 306, in __exit__
    self.finish(scope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 750, in __exit__
    super().__exit__(ty, value, tb)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/wsgi.py", line 98, in __call__
    with sentry_sdk.start_transaction(
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/flask.py", line 84, in sentry_patched_wsgi_app
    return SentryWsgiMiddleware(lambda *a, **kw: old_app(self, *a, **kw))(
  File "/usr/local/lib/python3.10/site-packages/gunicorn/workers/gthread.py", line 334, in handle_request
    respiter = self.wsgi(environ, resp.start_response)
  File "/usr/local/lib/python3.10/site-packages/gunicorn/workers/gthread.py", line 282, in handle
    keepalive = self.handle_request(req, conn)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/contrib/internal/futures/threading.py", line 36, in _wrap_execution
    return fn(*args, **kwargs)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 83, in _worker
    work_item.run()
  File "/usr/local/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 92, in _run_old_run_func
    return old_run_func(self, *a, **kw)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 99, in run
    return _run_old_run_func()
  File "/usr/local/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.10/threading.py", line 973, in _bootstrap
    self._bootstrap_inner()

Thread 0x7fc08abfd6c0 (most recent call first):
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 122, in _acquire
    return inner_func(*args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 252, in __enter__
    return self._acquire(self.__wrapped__.__enter__, *args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 62, in start
    with self._lock:
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 40, in _ensure_thread
    self.start()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 121, in submit
    self._ensure_thread()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/transport.py", line 553, in capture_envelope
    if not self._worker.submit(send_envelope_wrapper):
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/client.py", line 310, in _capture_envelope
    self.transport.capture_envelope(envelope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/sessions.py", line 145, in flush
    self.capture_func(envelope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/sessions.py", line 167, in _thread
    self.flush()
  File "/usr/local/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 92, in _run_old_run_func
    return old_run_func(self, *a, **kw)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 99, in run
    return _run_old_run_func()
  File "/usr/local/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.10/threading.py", line 973, in _bootstrap
    self._bootstrap_inner()

Thread 0x7fc08bfff6c0 (most recent call first):
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 118, in _acquire
    return inner_func(*args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 252, in __enter__
    return self._acquire(self.__wrapped__.__enter__, *args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 62, in start
    with self._lock:
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 40, in _ensure_thread
    self.start()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 121, in submit
    self._ensure_thread()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/transport.py", line 553, in capture_envelope
    if not self._worker.submit(send_envelope_wrapper):
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/client.py", line 753, in capture_event
    self.transport.capture_envelope(envelope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/scope.py", line 1115, in capture_event
    event_id = Scope.get_client().capture_event(event=event, hint=hint, scope=scope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 866, in finish
    return hub.capture_event(event)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 306, in __exit__
    self.finish(scope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 750, in __exit__
    super().__exit__(ty, value, tb)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/wsgi.py", line 98, in __call__
    with sentry_sdk.start_transaction(
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/flask.py", line 84, in sentry_patched_wsgi_app
    return SentryWsgiMiddleware(lambda *a, **kw: old_app(self, *a, **kw))(
  File "/usr/local/lib/python3.10/site-packages/gunicorn/workers/gthread.py", line 334, in handle_request
    respiter = self.wsgi(environ, resp.start_response)
  File "/usr/local/lib/python3.10/site-packages/gunicorn/workers/gthread.py", line 282, in handle
    keepalive = self.handle_request(req, conn)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/contrib/internal/futures/threading.py", line 36, in _wrap_execution
    return fn(*args, **kwargs)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 83, in _worker
    work_item.run()
  File "/usr/local/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 92, in _run_old_run_func
    return old_run_func(self, *a, **kw)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 99, in run
    return _run_old_run_func()
  File "/usr/local/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.10/threading.py", line 973, in _bootstrap
    self._bootstrap_inner()

Thread 0x7fc0a8bf96c0 (most recent call first):
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 118, in _acquire
    return inner_func(*args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 252, in __enter__
    return self._acquire(self.__wrapped__.__enter__, *args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 62, in start
    with self._lock:
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 40, in _ensure_thread
    self.start()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 121, in submit
    self._ensure_thread()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/transport.py", line 553, in capture_envelope
    if not self._worker.submit(send_envelope_wrapper):
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/client.py", line 753, in capture_event
    self.transport.capture_envelope(envelope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/scope.py", line 1115, in capture_event
    event_id = Scope.get_client().capture_event(event=event, hint=hint, scope=scope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 866, in finish
    return hub.capture_event(event)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 306, in __exit__
    self.finish(scope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 750, in __exit__
    super().__exit__(ty, value, tb)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/wsgi.py", line 98, in __call__
    with sentry_sdk.start_transaction(
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/flask.py", line 84, in sentry_patched_wsgi_app
    return SentryWsgiMiddleware(lambda *a, **kw: old_app(self, *a, **kw))(
  File "/usr/local/lib/python3.10/site-packages/gunicorn/workers/gthread.py", line 334, in handle_request
    respiter = self.wsgi(environ, resp.start_response)
  File "/usr/local/lib/python3.10/site-packages/gunicorn/workers/gthread.py", line 282, in handle
    keepalive = self.handle_request(req, conn)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/contrib/internal/futures/threading.py", line 36, in _wrap_execution
    return fn(*args, **kwargs)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 83, in _worker
    work_item.run()
  File "/usr/local/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 92, in _run_old_run_func
    return old_run_func(self, *a, **kw)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 99, in run
    return _run_old_run_func()
  File "/usr/local/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.10/threading.py", line 973, in _bootstrap
    self._bootstrap_inner()

Thread 0x7fc08b7fe6c0 (most recent call first):
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 118, in _acquire
    return inner_func(*args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 252, in __enter__
    return self._acquire(self.__wrapped__.__enter__, *args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 62, in start
    with self._lock:
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 40, in _ensure_thread
    self.start()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 121, in submit
    self._ensure_thread()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/transport.py", line 553, in capture_envelope
    if not self._worker.submit(send_envelope_wrapper):
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/client.py", line 753, in capture_event
    self.transport.capture_envelope(envelope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/scope.py", line 1115, in capture_event
    event_id = Scope.get_client().capture_event(event=event, hint=hint, scope=scope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 866, in finish
    return hub.capture_event(event)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 306, in __exit__
    self.finish(scope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 750, in __exit__
    super().__exit__(ty, value, tb)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/wsgi.py", line 98, in __call__
    with sentry_sdk.start_transaction(
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/flask.py", line 84, in sentry_patched_wsgi_app
    return SentryWsgiMiddleware(lambda *a, **kw: old_app(self, *a, **kw))(
  File "/usr/local/lib/python3.10/site-packages/gunicorn/workers/gthread.py", line 334, in handle_request
    respiter = self.wsgi(environ, resp.start_response)
  File "/usr/local/lib/python3.10/site-packages/gunicorn/workers/gthread.py", line 282, in handle
    keepalive = self.handle_request(req, conn)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/contrib/internal/futures/threading.py", line 36, in _wrap_execution
    return fn(*args, **kwargs)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 83, in _worker
    work_item.run()
  File "/usr/local/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 92, in _run_old_run_func
    return old_run_func(self, *a, **kw)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 99, in run
    return _run_old_run_func()
  File "/usr/local/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.10/threading.py", line 973, in _bootstrap
    self._bootstrap_inner()

Thread 0x7fc0a93fa6c0 (most recent call first):
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 118, in _acquire
    return inner_func(*args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 252, in __enter__
    return self._acquire(self.__wrapped__.__enter__, *args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 62, in start
    with self._lock:
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 40, in _ensure_thread
    self.start()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 121, in submit
    self._ensure_thread()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/transport.py", line 553, in capture_envelope
    if not self._worker.submit(send_envelope_wrapper):
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/client.py", line 753, in capture_event
    self.transport.capture_envelope(envelope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/scope.py", line 1115, in capture_event
    event_id = Scope.get_client().capture_event(event=event, hint=hint, scope=scope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 866, in finish
    return hub.capture_event(event)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 306, in __exit__
    self.finish(scope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 750, in __exit__
    super().__exit__(ty, value, tb)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/wsgi.py", line 98, in __call__
    with sentry_sdk.start_transaction(
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/flask.py", line 84, in sentry_patched_wsgi_app
    return SentryWsgiMiddleware(lambda *a, **kw: old_app(self, *a, **kw))(
  File "/usr/local/lib/python3.10/site-packages/gunicorn/workers/gthread.py", line 334, in handle_request
    respiter = self.wsgi(environ, resp.start_response)
  File "/usr/local/lib/python3.10/site-packages/gunicorn/workers/gthread.py", line 282, in handle
    keepalive = self.handle_request(req, conn)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/contrib/internal/futures/threading.py", line 36, in _wrap_execution
    return fn(*args, **kwargs)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 83, in _worker
    work_item.run()
  File "/usr/local/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 92, in _run_old_run_func
    return old_run_func(self, *a, **kw)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 99, in run
    return _run_old_run_func()
  File "/usr/local/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.10/threading.py", line 973, in _bootstrap
    self._bootstrap_inner()

Thread 0x7fc0a9bfb6c0 (most recent call first):
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 118, in _acquire
    return inner_func(*args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 252, in __enter__
    return self._acquire(self.__wrapped__.__enter__, *args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 62, in start
    with self._lock:
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 40, in _ensure_thread
    self.start()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 121, in submit
    self._ensure_thread()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/transport.py", line 553, in capture_envelope
    if not self._worker.submit(send_envelope_wrapper):
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/client.py", line 753, in capture_event
    self.transport.capture_envelope(envelope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/scope.py", line 1115, in capture_event
    event_id = Scope.get_client().capture_event(event=event, hint=hint, scope=scope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 866, in finish
    return hub.capture_event(event)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 306, in __exit__
    self.finish(scope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 750, in __exit__
    super().__exit__(ty, value, tb)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/wsgi.py", line 98, in __call__
    with sentry_sdk.start_transaction(
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/flask.py", line 84, in sentry_patched_wsgi_app
    return SentryWsgiMiddleware(lambda *a, **kw: old_app(self, *a, **kw))(
  File "/usr/local/lib/python3.10/site-packages/gunicorn/workers/gthread.py", line 334, in handle_request
    respiter = self.wsgi(environ, resp.start_response)
  File "/usr/local/lib/python3.10/site-packages/gunicorn/workers/gthread.py", line 282, in handle
    keepalive = self.handle_request(req, conn)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/contrib/internal/futures/threading.py", line 36, in _wrap_execution
    return fn(*args, **kwargs)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 83, in _worker
    work_item.run()
  File "/usr/local/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 92, in _run_old_run_func
    return old_run_func(self, *a, **kw)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 99, in run
    return _run_old_run_func()
  File "/usr/local/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.10/threading.py", line 973, in _bootstrap
    self._bootstrap_inner()

Thread 0x7fc0aa3fc6c0 (most recent call first):
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 118, in _acquire
    return inner_func(*args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 252, in __enter__
    return self._acquire(self.__wrapped__.__enter__, *args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 62, in start
    with self._lock:
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 40, in _ensure_thread
    self.start()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 121, in submit
    self._ensure_thread()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/transport.py", line 553, in capture_envelope
    if not self._worker.submit(send_envelope_wrapper):
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/client.py", line 753, in capture_event
    self.transport.capture_envelope(envelope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/scope.py", line 1115, in capture_event
    event_id = Scope.get_client().capture_event(event=event, hint=hint, scope=scope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 866, in finish
    return hub.capture_event(event)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 306, in __exit__
    self.finish(scope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 750, in __exit__
    super().__exit__(ty, value, tb)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/wsgi.py", line 98, in __call__
    with sentry_sdk.start_transaction(
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/flask.py", line 84, in sentry_patched_wsgi_app
    return SentryWsgiMiddleware(lambda *a, **kw: old_app(self, *a, **kw))(
  File "/usr/local/lib/python3.10/site-packages/gunicorn/workers/gthread.py", line 334, in handle_request
    respiter = self.wsgi(environ, resp.start_response)
  File "/usr/local/lib/python3.10/site-packages/gunicorn/workers/gthread.py", line 282, in handle
    keepalive = self.handle_request(req, conn)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/contrib/internal/futures/threading.py", line 36, in _wrap_execution
    return fn(*args, **kwargs)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 83, in _worker
    work_item.run()
  File "/usr/local/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 92, in _run_old_run_func
    return old_run_func(self, *a, **kw)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 99, in run
    return _run_old_run_func()
  File "/usr/local/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.10/threading.py", line 973, in _bootstrap
    self._bootstrap_inner()

Thread 0x7fc0aabfd6c0 (most recent call first):
  File "/usr/local/lib/python3.10/threading.py", line 320, in wait
    waiter.acquire()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/_queue.py", line 240, in get
    self.not_empty.wait()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 131, in _target
    callback = self._queue.get()
  File "/usr/local/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 92, in _run_old_run_func
    return old_run_func(self, *a, **kw)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 99, in run
    return _run_old_run_func()
  File "/usr/local/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.10/threading.py", line 973, in _bootstrap
    self._bootstrap_inner()

Thread 0x7fc0ab7fe6c0 (most recent call first):
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/profiler.py", line 892, in run
    thread_sleep(self.interval - elapsed)
  File "/usr/local/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 92, in _run_old_run_func
    return old_run_func(self, *a, **kw)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 99, in run
    return _run_old_run_func()
  File "/usr/local/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.10/threading.py", line 973, in _bootstrap
    self._bootstrap_inner()

Thread 0x7fc0abfff6c0 (most recent call first):
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/monitor.py", line 57, in _thread
    time.sleep(self.interval)
  File "/usr/local/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 92, in _run_old_run_func
    return old_run_func(self, *a, **kw)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 99, in run
    return _run_old_run_func()
  File "/usr/local/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.10/threading.py", line 973, in _bootstrap
    self._bootstrap_inner()

Thread 0x7fc0b89866c0 (most recent call first):
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 118, in _acquire
    return inner_func(*args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 252, in __enter__
    return self._acquire(self.__wrapped__.__enter__, *args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 62, in start
    with self._lock:
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 40, in _ensure_thread
    self.start()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 121, in submit
    self._ensure_thread()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/transport.py", line 553, in capture_envelope
    if not self._worker.submit(send_envelope_wrapper):
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/client.py", line 753, in capture_event
    self.transport.capture_envelope(envelope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/scope.py", line 1115, in capture_event
    event_id = Scope.get_client().capture_event(event=event, hint=hint, scope=scope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/api.py", line 123, in capture_event
    return Scope.get_current_scope().capture_event(
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/logging.py", line 255, in _emit
    sentry_sdk.capture_event(event, hint=hint)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/logging.py", line 179, in emit
    return self._emit(record)
  File "/usr/local/lib/python3.10/logging/__init__.py", line 968, in handle
    self.emit(record)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/logging.py", line 77, in _handle_record
    self._handler.handle(record)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/logging.py", line 108, in sentry_patched_callhandlers
    integration._handle_record(record)
  File "/usr/local/lib/python3.10/logging/__init__.py", line 1634, in handle
    self.callHandlers(record)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/internal/logger.py", line 176, in handle
    super(DDLogger, self).handle(record)
  File "/usr/local/lib/python3.10/logging/__init__.py", line 1624, in _log
    self.handle(record)
  File "/usr/local/lib/python3.10/logging/__init__.py", line 1489, in warning
    self._log(WARNING, msg, args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 243, in _release
    LOG.warning("Error recording lock release event: %s", e)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/profiling/collector/_lock.py", line 247, in release
    return self._release(self.__wrapped__.release, *args, **kwargs)
  File "/usr/local/lib/python3.10/threading.py", line 274, in _release_save
    self._lock.release()           # No state to save
  File "/usr/local/lib/python3.10/threading.py", line 316, in wait
    saved_state = self._release_save()
  File "/usr/local/lib/python3.10/threading.py", line 607, in wait
    signaled = self._cond.wait(timeout)
  File "/usr/local/lib/python3.10/threading.py", line 940, in start
    self._started.wait()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 78, in sentry_start
    return old_start(self, *a, **kw)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/utils.py", line 1711, in runner
    return sentry_patched_function(*args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 69, in start
    self._thread.start()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 40, in _ensure_thread
    self.start()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/worker.py", line 121, in submit
    self._ensure_thread()
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/transport.py", line 553, in capture_envelope
    if not self._worker.submit(send_envelope_wrapper):
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/client.py", line 753, in capture_event
    self.transport.capture_envelope(envelope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/scope.py", line 1115, in capture_event
    event_id = Scope.get_client().capture_event(event=event, hint=hint, scope=scope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 866, in finish
    return hub.capture_event(event)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 306, in __exit__
    self.finish(scope)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/tracing.py", line 750, in __exit__
    super().__exit__(ty, value, tb)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/wsgi.py", line 98, in __call__
    with sentry_sdk.start_transaction(
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/flask.py", line 84, in sentry_patched_wsgi_app
    return SentryWsgiMiddleware(lambda *a, **kw: old_app(self, *a, **kw))(
  File "/usr/local/lib/python3.10/site-packages/gunicorn/workers/gthread.py", line 334, in handle_request
    respiter = self.wsgi(environ, resp.start_response)
  File "/usr/local/lib/python3.10/site-packages/gunicorn/workers/gthread.py", line 282, in handle
    keepalive = self.handle_request(req, conn)
  File "/usr/local/lib/python3.10/site-packages/ddtrace/contrib/internal/futures/threading.py", line 36, in _wrap_execution
    return fn(*args, **kwargs)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 83, in _worker
    work_item.run()
  File "/usr/local/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 92, in _run_old_run_func
    return old_run_func(self, *a, **kw)
  File "/usr/local/lib/python3.10/site-packages/sentry_sdk/integrations/threading.py", line 99, in run
    return _run_old_run_func()
  File "/usr/local/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.10/threading.py", line 973, in _bootstrap
    self._bootstrap_inner()

Thread 0x7fc0bad896c0 (most recent call first):
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 81, in _worker
    work_item = work_queue.get(block=True)
  File "/usr/local/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.10/threading.py", line 973, in _bootstrap
    self._bootstrap_inner()

Thread 0x7fc0bf1ff6c0 (most recent call first):
  File "/usr/local/lib/python3.10/threading.py", line 324, in wait
    gotit = waiter.acquire(True, timeout)
  File "/usr/local/lib/python3.10/queue.py", line 180, in get
    self.not_empty.wait(remaining)
  File "/usr/local/lib/python3.10/site-packages/libhoney/transmission.py", line 146, in _sender
    ev = self.pending.get(timeout=self.send_frequency)
  File "/usr/local/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.10/threading.py", line 973, in _bootstrap
    self._bootstrap_inner()

Current thread 0x7fc1b63d3b80 (most recent call first):
  File "/usr/local/lib/python3.10/threading.py", line 324, in wait
    gotit = waiter.acquire(True, timeout)
  File "/usr/local/lib/python3.10/threading.py", line 607, in wait
    signaled = self._cond.wait(timeout)
  File "/usr/local/lib/python3.10/concurrent/futures/_base.py", line 307, in wait
    waiter.event.wait(timeout)
  File "/usr/local/lib/python3.10/site-packages/gunicorn/workers/gthread.py", line 240, in run
    futures.wait(self.futures, timeout=self.cfg.graceful_timeout)
  File "/usr/local/lib/python3.10/site-packages/gunicorn/workers/base.py", line 142, in init_process
    self.run()
  File "/usr/local/lib/python3.10/site-packages/gunicorn/workers/gthread.py", line 95, in init_process
    super().init_process()
  File "/usr/local/lib/python3.10/site-packages/gunicorn/arbiter.py", line 609, in spawn_worker
    worker.init_process()
  File "/usr/local/lib/python3.10/site-packages/gunicorn/arbiter.py", line 642, in spawn_workers
    self.spawn_worker()
  File "/usr/local/lib/python3.10/site-packages/gunicorn/arbiter.py", line 571, in manage_workers
    self.spawn_workers()
  File "/usr/local/lib/python3.10/site-packages/gunicorn/arbiter.py", line 202, in run
    self.manage_workers()
  File "/usr/local/lib/python3.10/site-packages/gunicorn/app/base.py", line 72, in run
    Arbiter(self).run()
  File "/usr/local/lib/python3.10/site-packages/gunicorn/app/base.py", line 236, in run
    super().run()
  File "/usr/local/lib/python3.10/site-packages/gunicorn/app/wsgiapp.py", line 67, in run
    WSGIApplication("%(prog)s [OPTIONS] [APP_MODULE]", prog=prog).run()
  File "/usr/local/bin/gunicorn", line 8, in <module>
    sys.exit(run())

Though the weird thing is that the pod was still able to handle requests according to its logs.
@getsantry getsantry bot moved this to Waiting for: Product Owner in GitHub Issues with 👀 3 Nov 8, 2024
@samertm
Copy link
Author

samertm commented Nov 9, 2024

We're going to disable the datadog lock, but I think the learning here is that anything that logs before self._thread_for_pid is set can cause a deadlock if you have the sentry logging integration enabled, because that'll trigger the deadlock.

Here's a repro that prints out the bad stack w/o the datadog dependency:

import wrapt
import logging

logging.basicConfig(level=logging.INFO)

class _BadLock(wrapt.ObjectProxy):

    def __init__(self, wrapped):
        wrapt.ObjectProxy.__init__(self, wrapped)

    def release(self, *args, **kwargs):
        logging.info('releasing 11')
        return self.__wrapped__.release(*args, **kwargs)

import threading

OriginalLock = threading.Lock

def create_bad_lock(*args, **kwargs):
    lock = OriginalLock(*args, **kwargs)
    return _BadLock(lock)

threading.Lock = create_bad_lock


import sentry_sdk
import logging
import threading
import time
import traceback

from sentry_sdk.integrations.logging import LoggingIntegration
import sys


def get_stacktrace() -> str:
    """Returns the stacktrace as a string. Don't call this all the time because it's expensive."""
    code = []
    current_thread_id = threading.get_ident()

    frames = list(sys._current_frames().items())
    # Move current thread to the end
    current_thread_id_idx = None
    for i, (thread_id, _stack) in enumerate(frames):
        if thread_id == current_thread_id:
            current_thread_id_idx = i
            break

    if current_thread_id_idx is not None:
        frames.append(frames.pop(current_thread_id_idx))

    for thread_id, stack in frames:
        prefix = 'Current thread' if thread_id == current_thread_id else 'Thread'

        code.append(f'{prefix} {hex(thread_id)} (most recent call first):')
        for filename, lineno, name, line in reversed(traceback.extract_stack(stack)):
            if name == 'print_stacks_signal_handler':
                continue
            code.append('  File "%s", line %d, in %s' % (filename, lineno, name))
            if line:
                code.append(f'    {line.strip()}')

        code[-1] += '\n'

    return '\n'.join(code)


def print_out_threads():
    time.sleep(10)
    print(get_stacktrace())

thread = threading.Thread(target=print_out_threads, daemon=True)
thread.start()


sentry_sdk.init(
    dsn="...",
    environment='local',
    integrations=[
        LoggingIntegration(
            level=logging.INFO,
            event_level=logging.INFO,#WARNING,
        ),
    ],
)


logging.info('test 11')

@sentrivana
Copy link
Contributor

Hey @samertm, thanks for the great bug report and for providing a way to repro easily. We will look into this.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
Component: SDK Core Dealing with the core of the SDK Integration: Logging
Projects
GitHub Issues with 👀 3
Status: No status
Milestone
No milestone
Development

No branches or pull requests
3 participants
@samertm @stephanie-anderson @sentrivana