What are you really trying to do?
We have an interceptor that uploads activity output to GCS (our implementation of the claim check pattern from before Temporal supported it, that we still use and will continue to use even after we adopt the Temporal-native solution).
Describe the bug
This interceptor sometimes takes a long time to run (when there are many blobs to upload). Occasionally it will run past the start to close timeout of an activity, Temporal will attempt to cancel the activity, and this error will be generated:
Traceback (most recent call last):
File "/opt/homebrew/Cellar/python@3.11/3.11.14_2/Frameworks/Python.framework/Versions/3.11/lib/python3.11/concurrent/futures/thread.py", line 81, in _worker
work_item = work_queue.get(block=True)
^^^^^^^^^^^^^^^^^^^^^^^^^^
temporalio.exceptions.CancelledError: Cancelled
This kills the thread, preventing it from being used by the worker again. Slowly over time the worker can lose all of its threads and not be doing anything. Metrics reflect that all of the worker slots are used, even though no work is being performed.
Minimal Reproduction
Clone https://github.com/millerick/temporal-worker-leak-reproduction and follow the instructions in the README.
It will output:
[t+ 0.04s] pool status before run: max_workers=1 threads_tracked=0 alive=0
[t+ 0.05s] upload activity fn running on pool thread 6173782016 and returning immediately
[t+ 0.05s] after-interceptor: uploading result to GCS (fn already returned)...
[t+ 3.06s] upload workflow result: 'activity timed out (start-to-close)'
[t+ 3.06s] probing with a separate fast Temporal activity while the worker runs...
[t+ 3.07s] probe0: 'probe0 ran on pool thread 6173782016' (worker still alive)
[t+ 4.08s] probe1: 'probe1 ran on pool thread 6173782016' (worker still alive)
[t+ 5.10s] probe2: 'probe2 ran on pool thread 6173782016' (worker still alive)
[t+ 6.12s] probe3: 'probe3 ran on pool thread 6173782016' (worker still alive)
[t+ 7.15s] probe4: 'probe4 ran on pool thread 6173782016' (worker still alive)
CRITICAL:concurrent.futures:Exception in worker
Traceback (most recent call last):
File "/opt/homebrew/Cellar/python@3.11/3.11.14_2/Frameworks/Python.framework/Versions/3.11/lib/python3.11/concurrent/futures/thread.py", line 81, in _worker
work_item = work_queue.get(block=True)
^^^^^^^^^^^^^^^^^^^^^^^^^^
temporalio.exceptions.CancelledError: Cancelled
[t+14.15s] probe5: probe activity never completed -- executor has no live worker to run it
[t+14.15s] final pool status: max_workers=1 threads_tracked=1 alive=0
[t+14.15s] LEAK CONFIRMED: the pool worker died from the injected CancelledError and was never replaced -> a new threaded activity can no longer run
INFO:temporalio.worker._worker:Beginning worker shutdown, will wait 0:00:00 before cancelling activities
[t+15.05s] after-interceptor: GCS upload complete
The activity that runs long with a simulated upload hits its start to close timeout after the activity code has completed, but while the interceptor code is running
Meanwhile other activities are able to execute on the thread, but they eventually get blocked by the fact that there are no longer any threads in the threadpool executor once the activity cancellation is attempted and the thread is forcibly killed.
Environment/Versions
- OS and processor: Observed on Mac and Linux
- Temporal Version: 1.23.0 +
Additional context
See above
What are you really trying to do?
We have an interceptor that uploads activity output to GCS (our implementation of the claim check pattern from before Temporal supported it, that we still use and will continue to use even after we adopt the Temporal-native solution).
Describe the bug
This interceptor sometimes takes a long time to run (when there are many blobs to upload). Occasionally it will run past the start to close timeout of an activity, Temporal will attempt to cancel the activity, and this error will be generated:
This kills the thread, preventing it from being used by the worker again. Slowly over time the worker can lose all of its threads and not be doing anything. Metrics reflect that all of the worker slots are used, even though no work is being performed.
Minimal Reproduction
Clone https://github.com/millerick/temporal-worker-leak-reproduction and follow the instructions in the README.
It will output:
The activity that runs long with a simulated upload hits its start to close timeout after the activity code has completed, but while the interceptor code is running
Meanwhile other activities are able to execute on the thread, but they eventually get blocked by the fact that there are no longer any threads in the threadpool executor once the activity cancellation is attempted and the thread is forcibly killed.
Environment/Versions
Additional context
See above