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

Aberta
  • Algo errado?
#2,095 1 comentário 0 reações 0 responsáveis Ver no GitHub

Mantenedores costumam responder em até 1 dia

Ninguém assumiu esta issue ainda.

Avaliação

Dificuldade
4/5
Tempo estimado
3-5 dias
Facilidade para iniciantes
47/100
Tipo de issue
Bug
Clareza
Claramente especificada
Status de atividade
Ativa
Stack de tecnologia
python
Domínio
backend

Direção de pesquisa

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.

Escrita pelo modelo de indexação a partir do texto da issue.

Descrição

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.
Linguagem predominante
Python
Estrelas
1.2k
Forks
285
Merge médio
1d 23h
PRs com merge (30d)
80

Preparar o ambiente

Primeiros passos

  1. Leia a issue inteira e depois o guia de contribuição do projeto.
  2. Comente na issue dizendo que vai assumir — evita que duas pessoas façam o mesmo trabalho.
  3. Faça um fork do repositório e trabalhe em uma branch.
  4. Abra um pull request que referencie o número da issue.

Mais de temporalio/sdk-python

Todas as issues de temporalio/sdk-python

Issues semelhantes

Mais issues de Python

Receba novas issues na sua caixa de entrada

Um resumo curto de issues do GitHub para quem está começando.