[Bug] Deadlock interruption can leak a logging.Handler lock on Python ≤ 3.12 and freeze the worker

Ouverte
#2,095 1 commentaire 0 réactions 0 personnes assignées Voir sur GitHub

Les mainteneurs répondent en général sous 1 jour

Personne n'a encore pris cette issue.

Évaluation

Difficulté
4/5
Temps estimé
3-5 jours
Accessibilité débutants
47/100
Type d'issue
Bug
Clarté
Clairement spécifiée
Activité
Active
Stack technique
python
Domaine
backend

Piste de recherche

Start with temporalio/worker/_workflow.py, where _WorkflowWorker._handle_activation handles _InterruptDeadlockError, and trace how attempt_deadlock_interruption uses Runtime._raise_in_thread. Reproduce the issue on Python 3.12 using the provided logging handler example, then inspect the interruption and lock handling paths. Done means the worker can continue logging after a deadlock interruption without leaking a handler lock; the issue also suggests documenting the risk or considering a detect-only mode.

Rédigé par le modèle d'indexation à partir du texte de l'issue.

Description

What are you really trying to do?

Run a Python worker with sandboxed workflows on Kubernetes. At peak, CPU contention pushes some activations past the 2 s deadlock timeout (TMPRL1101).

Describe the bug

After a TMPRL1101 the worker process sometimes freezes for good. It writes no logs and executes no workflow tasks. Core keeps polling and holding slots, so every task routed to it times out until the pod is killed.

A py-spy dump of a frozen worker:

  • The event-loop thread is blocked in logging.Handler.acquire, called from the logger.exception(...) in _WorkflowWorker._handle_activation.
  • Every other thread is idle in ThreadPoolExecutor._worker, so no live thread holds that lock.

Cause:

  1. attempt_deadlock_interruption calls Runtime._raise_in_thread (PyThreadState_SetAsyncExc) on the workflow thread.
  2. If that thread is waiting in Handler.acquire() while another thread emits a record, the async exception is raised as soon as RLock.acquire() returns. On Python ≤ 3.12 that point is before Handler.handle's try/finally.
  3. The lock stays owned by the workflow thread, which goes back to the pool idle, and the event loop's next log call blocks forever.

Python 3.13's Handler.handle uses with self.lock: (python/cpython#109461, the fix for bpo-43939), and the same sequence releases the lock. Any acquire(); try: pattern in code running on a workflow thread has the same exposure on ≤ 3.12.

Minimal Reproduction
import io, logging, os, threading, time
from temporalio.bridge.runtime import Runtime
from temporalio.worker._workflow import _InterruptDeadlockError

handler = logging.StreamHandler(io.StringIO())
logger = logging.getLogger("repro")
logger.addHandler(handler); logger.propagate = False; logger.setLevel(logging.INFO)

def activation():
    try:
        logger.info("workflow log line")
    except _InterruptDeadlockError:
        pass

handler.acquire()                      # another thread is emitting a record
t = threading.Thread(target=activation); t.start(); time.sleep(0.2)
Runtime._raise_in_thread(t.ident, _InterruptDeadlockError)   # what attempt_deadlock_interruption does
handler.release(); t.join()
print(handler.lock)                                          # state after the interrupted thread finished
print("can log again:", handler.lock.acquire(timeout=2))     # what the event loop's next log call needs
os._exit(0)                            # logging.shutdown() would block on the leaked lock

Output:

  • Python 3.12: <locked _thread.RLock ... count=1> and can log again: False
  • Python 3.13: <unlocked _thread.RLock ... count=0> and can log again: True

Same result with temporalio 1.24.0 and 1.35.0.

Environment/Versions
  • Linux x86_64, Kubernetes, python:3.12-slim
  • temporalio 1.24.0 in production. The repro also fails on 1.35.0, where attempt_deadlock_interruption and _raise_in_thread are unchanged.
Additional context
  • The same interrupt with other symptoms: #2067, #1933.
  • This community thread reports the same freeze after TMPRL1101 at 100% CPU, with no root cause found; this is likely it.
  • Our workaround is Python 3.13 plus a liveness probe on event-loop progress.
  • #1050 keeps the 2 s limit by design, so could the interrupt itself be made safer, for example a detect-only mode that fails the task without injecting into the thread? At minimum, the docs could mention this hazard for Python ≤ 3.12.

  • Found and minimised with AI assistance (Claude Code, Claude Opus 5.5). I reviewed the analysis; the reproduction was run on both Python versions and both temporalio versions above (macOS arm64).
  • I searched existing issues for "deadlock", "_InterruptDeadlockError", "SetAsyncExc", "hang", "stuck" and "logging lock". None reports this.
Langage dominant
Python
Étoiles
1.2k
Forks
285
Merge moyen
1 j 23 h
PR mergées (30 j)
80

Préparer son environnement

Par où commencer

  1. Lisez l'issue en entier, puis le guide de contribution du projet.
  2. Signalez en commentaire que vous la prenez — cela évite que deux personnes fassent le même travail.
  3. Forkez le dépôt et travaillez sur une branche.
  4. Ouvrez une pull request qui référence le numéro de l'issue.

Autres issues de temporalio/sdk-python

Toutes les issues de temporalio/sdk-python

Issues similaires

Plus d'issues Python

Recevez les nouvelles issues par e-mail

Un résumé court des issues GitHub adaptées aux débutants.