Workflow incorrectly marked as completed while nodes are still executing, triggered by GeneratorExit in streaming response

[305758409]

Self Checks

• I have read the Contributing Guide and Language Policy.
• This is only for bug report, if you would like to ask a question, please head to Discussions.
• I have searched for existing issues search for existing issues, including closed ones.
• I confirm that I am using English to submit this report, otherwise it will be closed.
• 【中文用户 & Non English User】请使用英语提交，否则会被关闭 ：）
• Please do not modify this template :) and fill in all the required fields.

Dify version

1.10.1

Cloud or Self Hosted

Self Hosted (Docker)

Steps to reproduce

Set up a workflow with multiple dependent nodes (e.g., an LLM node followed by several processing nodes).

Configure one of the earlier nodes to call an external API or service that returns a streamed response (Content‑Type: text/event-stream).

Start the workflow execution.

Observe that the workflow is marked as “completed” even though some nodes have just begun execution and subsequent nodes have not run.

Key logs (user will attach separately):

Lines showing GeneratorExit() exceptions during receive_response_body for dispatch/model/schema calls.

Timestamps indicating that the worker pool is stopped while nodes are still processing.

Please use the right markdown syntax for code blocks when pasting logs.

✔️ Expected Behavior

The workflow should only be marked as completed after all nodes have finished executing successfully or after a clear error/timeout has been raised. Stream responses should be fully consumed, and nodes should not be interrupted prematurely.

❌ Actual Behavior

The workflow is incorrectly flagged as completed while a node is still processing. The logs show:

GeneratorExit exceptions – occurring in GraphWorker-0 and GraphWorker-3 when receiving streamed responses (text/event-stream) for dispatch/model/schema. The receive_response_body fails immediately after starting, before the response body is fully read.

Timeline shows early termination – after the GeneratorExit, the worker pool is stopped (Stopping worker pool) even though downstream nodes are scheduled or still running.

Execution ends prematurely – the workflow reports completion in ~5.88 seconds, but some nodes appear to have been cut off, and subsequent dependent nodes may not execute as expected.

Root cause suspicion:
The GeneratorExit typically indicates that a generator/stream was closed before finishing. This may happen if the workflow’s state is erroneously set to “completed” early, causing the stream handler to be terminated, or if there is a bug in the node‑state tracking that prematurely marks nodes as done.

key logs：

api-1 | 2025-12-09 00:00:45.617 DEBUG [GraphWorker-2] [_trace.py:47] - receive_response_body.complete
api-1 | 2025-12-09 00:00:45.617 DEBUG [GraphWorker-2] [_trace.py:47] - response_closed.started
api-1 | 2025-12-09 00:00:45.617 DEBUG [GraphWorker-2] [_trace.py:47] - response_closed.complete
api-1 | 2025-12-09 00:00:45.617 DEBUG [GraphWorker-2] [_trace.py:47] - close.started
api-1 | 2025-12-09 00:00:45.617 DEBUG [GraphWorker-2] [_trace.py:47] - close.complete
api-1 | 2025-12-09 00:00:45.625 DEBUG [GraphWorker-0] [_config.py:82] - load_ssl_context verify=True cert=None trust_env=True http2=False
api-1 | 2025-12-09 00:00:45.626 DEBUG [GraphWorker-0] [_config.py:148] - load_verify_locations cafile='/app/api/.venv/lib/python3.12/site-packages/certifi/cacert.pem'
api-1 | 2025-12-09 00:00:45.650 DEBUG [GraphWorker-0] [_trace.py:47] - connect_tcp.started host='plugin_daemon' port=5002 local_address=None timeout=300.0 socket_options=None
api-1 | 2025-12-09 00:00:45.654 DEBUG [GraphWorker-0] [_trace.py:47] - connect_tcp.complete return_value=<httpcore._backends.sync.SyncStream object at 0x7eff8b27f530>
api-1 | 2025-12-09 00:00:45.654 DEBUG [GraphWorker-0] [_trace.py:47] - send_request_headers.started request=<Request [b'GET']>
api-1 | 2025-12-09 00:00:45.654 DEBUG [GraphWorker-0] [_trace.py:47] - send_request_headers.complete
api-1 | 2025-12-09 00:00:45.655 DEBUG [GraphWorker-0] [_trace.py:47] - send_request_body.started request=<Request [b'GET']>
api-1 | 2025-12-09 00:00:45.655 DEBUG [GraphWorker-0] [_trace.py:47] - send_request_body.complete
api-1 | 2025-12-09 00:00:45.655 DEBUG [GraphWorker-0] [_trace.py:47] - receive_response_headers.started request=<Request [b'GET']>
api-1 | 2025-12-09 00:00:45.672 DEBUG [GraphDispatcher] [execution_limits.py:92] - Step 7 started: 1761798163598
api-1 | 2025-12-09 00:00:45.682 DEBUG [GraphWorker-4] [_trace.py:47] - send_request_headers.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:45.682 DEBUG [GraphWorker-4] [_trace.py:47] - send_request_headers.complete
api-1 | 2025-12-09 00:00:45.682 DEBUG [GraphWorker-4] [_trace.py:47] - send_request_body.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:45.683 DEBUG [GraphWorker-4] [_trace.py:47] - send_request_body.complete
api-1 | 2025-12-09 00:00:45.683 DEBUG [GraphWorker-4] [_trace.py:47] - receive_response_headers.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:45.703 DEBUG [GraphWorker-0] [_trace.py:47] - receive_response_headers.complete return_value=(b'HTTP/1.1', 200, b'OK', [(b'Content-Type', b'application/json; charset=utf-8'), (b'Date', b'Mon, 08 Dec 2025 16:00:45 GMT'), (b'Transfer-Encoding', b'chunked')])
plugin_daemon-1 | [GIN] 2025/12/08 - 16:00:45 | 200 | 48.673406ms | 192.168.16.8 | GET "/plugin/xxx/management/models?page=1&page_size=256"
api-1 | 2025-12-09 00:00:45.703 INFO [GraphWorker-0] [_client.py:1038] - HTTP Request: GET http://plugin_daemon:5002/plugin/xxx/management/models?page=1&page_size=256 "HTTP/1.1 200 OK"
api-1 | 2025-12-09 00:00:45.704 DEBUG [GraphWorker-0] [_trace.py:47] - receive_response_body.started request=<Request [b'GET']>
api-1 | 2025-12-09 00:00:45.706 DEBUG [GraphWorker-0] [_trace.py:47] - receive_response_body.complete
api-1 | 2025-12-09 00:00:45.706 DEBUG [GraphWorker-0] [_trace.py:47] - response_closed.started
api-1 | 2025-12-09 00:00:45.706 DEBUG [GraphWorker-0] [_trace.py:47] - response_closed.complete
api-1 | 2025-12-09 00:00:45.707 DEBUG [GraphDispatcher] [execution_limits.py:92] - Step 8 started: 1764519962802
api-1 | 2025-12-09 00:00:45.709 DEBUG [GraphWorker-0] [_trace.py:47] - close.started
api-1 | 2025-12-09 00:00:45.710 DEBUG [GraphWorker-0] [_trace.py:47] - close.complete
sandbox-1 | [GIN] 2025/12/08 - 16:00:45 | 200 | 42.926592ms | 192.168.0.5 | POST "/v1/sandbox/run"
api-1 | 2025-12-09 00:00:45.775 DEBUG [GraphWorker-4] [_trace.py:47] - receive_response_headers.complete return_value=(b'HTTP/1.1', 200, b'OK', [(b'Content-Type', b'application/json; charset=utf-8'), (b'Date', b'Mon, 08 Dec 2025 16:00:45 GMT'), (b'Content-Length', b'416')])
api-1 | 2025-12-09 00:00:45.775 INFO [GraphWorker-4] [_client.py:1038] - HTTP Request: POST http://sandbox:8194/v1/sandbox/run "HTTP/1.1 200 OK"
api-1 | 2025-12-09 00:00:45.776 DEBUG [GraphWorker-4] [_trace.py:47] - receive_response_body.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:45.776 DEBUG [GraphWorker-4] [_trace.py:47] - receive_response_body.complete
api-1 | 2025-12-09 00:00:45.776 DEBUG [GraphWorker-4] [_trace.py:47] - response_closed.started
api-1 | 2025-12-09 00:00:45.776 DEBUG [GraphWorker-4] [_trace.py:47] - response_closed.complete
api-1 | 2025-12-09 00:00:45.780 DEBUG [GraphDispatcher] [execution_limits.py:92] - Step 9 started: 1764523251213
api-1 | 2025-12-09 00:00:45.800 DEBUG [GraphDispatcher] [execution_limits.py:92] - Step 10 started: 1764523290094
api-1 | 2025-12-09 00:00:45.824 DEBUG [GraphWorker-3] [_config.py:82] - load_ssl_context verify=True cert=None trust_env=True http2=False
api-1 | 2025-12-09 00:00:45.825 DEBUG [GraphWorker-3] [_config.py:148] - load_verify_locations cafile='/app/api/.venv/lib/python3.12/site-packages/certifi/cacert.pem'
api-1 | 2025-12-09 00:00:45.860 DEBUG [GraphWorker-3] [_trace.py:47] - connect_tcp.started host='plugin_daemon' port=5002 local_address=None timeout=300.0 socket_options=None
api-1 | 2025-12-09 00:00:45.864 DEBUG [GraphWorker-3] [_trace.py:47] - connect_tcp.complete return_value=<httpcore._backends.sync.SyncStream object at 0x7eff893c8110>
api-1 | 2025-12-09 00:00:45.864 DEBUG [GraphWorker-3] [_trace.py:47] - send_request_headers.started request=<Request [b'GET']>
api-1 | 2025-12-09 00:00:45.864 DEBUG [GraphWorker-3] [_trace.py:47] - send_request_headers.complete
api-1 | 2025-12-09 00:00:45.865 DEBUG [GraphWorker-3] [_trace.py:47] - send_request_body.started request=<Request [b'GET']>
api-1 | 2025-12-09 00:00:45.865 DEBUG [GraphWorker-3] [_trace.py:47] - send_request_body.complete
api-1 | 2025-12-09 00:00:45.865 DEBUG [GraphWorker-3] [_trace.py:47] - receive_response_headers.started request=<Request [b'GET']>
api-1 | 2025-12-09 00:00:45.869 DEBUG [GraphDispatcher] [execution_limits.py:92] - Step 11 started: 1764523319618
api-1 | 2025-12-09 00:00:45.894 DEBUG [GraphWorker-3] [_trace.py:47] - receive_response_headers.complete return_value=(b'HTTP/1.1', 200, b'OK', [(b'Content-Type', b'application/json; charset=utf-8'), (b'Date', b'Mon, 08 Dec 2025 16:00:45 GMT'), (b'Transfer-Encoding', b'chunked')])
api-1 | 2025-12-09 00:00:45.895 INFO [GraphWorker-3] [_client.py:1038] - HTTP Request: GET http://plugin_daemon:5002/plugin/xxx/management/models?page=1&page_size=256 "HTTP/1.1 200 OK"
api-1 | 2025-12-09 00:00:45.895 DEBUG [GraphWorker-3] [_trace.py:47] - receive_response_body.started request=<Request [b'GET']>
plugin_daemon-1 | [GIN] 2025/12/08 - 16:00:45 | 200 | 32.542095ms | 192.168.16.8 | GET "/plugin/xxx/management/models?page=1&page_size=256"
api-1 | 2025-12-09 00:00:45.899 DEBUG [GraphWorker-3] [_trace.py:47] - receive_response_body.complete
api-1 | 2025-12-09 00:00:45.899 DEBUG [GraphWorker-3] [_trace.py:47] - response_closed.started
api-1 | 2025-12-09 00:00:45.899 DEBUG [GraphWorker-3] [_trace.py:47] - response_closed.complete
api-1 | 2025-12-09 00:00:45.901 DEBUG [GraphWorker-3] [_trace.py:47] - close.started
api-1 | 2025-12-09 00:00:45.901 DEBUG [GraphWorker-3] [_trace.py:47] - close.complete
api-1 | 2025-12-09 00:00:46.251 DEBUG [GraphWorker-0] [_config.py:82] - load_ssl_context verify=True cert=None trust_env=True http2=False
api-1 | 2025-12-09 00:00:46.252 DEBUG [GraphWorker-0] [_config.py:148] - load_verify_locations cafile='/app/api/.venv/lib/python3.12/site-packages/certifi/cacert.pem'
api-1 | 2025-12-09 00:00:46.277 DEBUG [GraphWorker-0] [_trace.py:47] - connect_tcp.started host='plugin_daemon' port=5002 local_address=None timeout=300.0 socket_options=None
api-1 | 2025-12-09 00:00:46.279 DEBUG [GraphWorker-0] [_trace.py:47] - connect_tcp.complete return_value=<httpcore._backends.sync.SyncStream object at 0x7eff8ab01370>
api-1 | 2025-12-09 00:00:46.279 DEBUG [GraphWorker-0] [_trace.py:47] - send_request_headers.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:46.280 DEBUG [GraphWorker-0] [_trace.py:47] - send_request_headers.complete
api-1 | 2025-12-09 00:00:46.280 DEBUG [GraphWorker-0] [_trace.py:47] - send_request_body.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:46.280 DEBUG [GraphWorker-0] [_trace.py:47] - send_request_body.complete
api-1 | 2025-12-09 00:00:46.280 DEBUG [GraphWorker-0] [_trace.py:47] - receive_response_headers.started request=<Request [b'POST']>
plugin_daemon-1 | [GIN] 2025/12/08 - 16:00:46 | 200 | 3.536798ms | 192.168.16.8 | POST "/plugin/xxx/dispatch/model/schema"
api-1 | 2025-12-09 00:00:46.283 DEBUG [GraphWorker-0] [_trace.py:47] - receive_response_headers.complete return_value=(b'HTTP/1.1', 200, b'OK', [(b'Content-Type', b'text/event-stream'), (b'Date', b'Mon, 08 Dec 2025 16:00:46 GMT'), (b'Transfer-Encoding', b'chunked')])
api-1 | 2025-12-09 00:00:46.284 INFO [GraphWorker-0] [_client.py:1038] - HTTP Request: POST http://plugin_daemon:5002/plugin/xxx/dispatch/model/schema "HTTP/1.1 200 OK"
api-1 | 2025-12-09 00:00:46.284 DEBUG [GraphWorker-0] [_trace.py:47] - receive_response_body.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:46.285 DEBUG [GraphWorker-0] [_trace.py:47] - receive_response_body.failed exception=GeneratorExit()
api-1 | 2025-12-09 00:00:46.285 DEBUG [GraphWorker-0] [_trace.py:47] - response_closed.started
api-1 | 2025-12-09 00:00:46.286 DEBUG [GraphWorker-0] [_trace.py:47] - response_closed.complete
api-1 | 2025-12-09 00:00:46.333 DEBUG [GraphWorker-3] [_config.py:82] - load_ssl_context verify=True cert=None trust_env=True http2=False
api-1 | 2025-12-09 00:00:46.334 DEBUG [GraphWorker-3] [_config.py:148] - load_verify_locations cafile='/app/api/.venv/lib/python3.12/site-packages/certifi/cacert.pem'
api-1 | 2025-12-09 00:00:46.359 DEBUG [GraphWorker-3] [_trace.py:47] - connect_tcp.started host='plugin_daemon' port=5002 local_address=None timeout=300.0 socket_options=None
api-1 | 2025-12-09 00:00:46.360 DEBUG [GraphWorker-3] [_trace.py:47] - connect_tcp.complete return_value=<httpcore._backends.sync.SyncStream object at 0x7eff8ab70620>
api-1 | 2025-12-09 00:00:46.361 DEBUG [GraphWorker-3] [_trace.py:47] - send_request_headers.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:46.361 DEBUG [GraphWorker-3] [_trace.py:47] - send_request_headers.complete
api-1 | 2025-12-09 00:00:46.361 DEBUG [GraphWorker-3] [_trace.py:47] - send_request_body.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:46.361 DEBUG [GraphWorker-3] [_trace.py:47] - send_request_body.complete
api-1 | 2025-12-09 00:00:46.362 DEBUG [GraphWorker-3] [_trace.py:47] - receive_response_headers.started request=<Request [b'POST']>
plugin_daemon-1 | [GIN] 2025/12/08 - 16:00:46 | 200 | 3.277684ms | 192.168.16.8 | POST "/plugin/xxx/dispatch/model/schema"
api-1 | 2025-12-09 00:00:46.364 DEBUG [GraphWorker-3] [_trace.py:47] - receive_response_headers.complete return_value=(b'HTTP/1.1', 200, b'OK', [(b'Content-Type', b'text/event-stream'), (b'Date', b'Mon, 08 Dec 2025 16:00:46 GMT'), (b'Transfer-Encoding', b'chunked')])
api-1 | 2025-12-09 00:00:46.365 INFO [GraphWorker-3] [_client.py:1038] - HTTP Request: POST http://plugin_daemon:5002/plugin/xxx/dispatch/model/schema "HTTP/1.1 200 OK"
api-1 | 2025-12-09 00:00:46.365 DEBUG [GraphWorker-3] [_trace.py:47] - receive_response_body.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:46.367 DEBUG [GraphWorker-3] [_trace.py:47] - receive_response_body.failed exception=GeneratorExit()
api-1 | 2025-12-09 00:00:46.367 DEBUG [GraphWorker-3] [_trace.py:47] - response_closed.started
api-1 | 2025-12-09 00:00:46.367 DEBUG [GraphWorker-3] [_trace.py:47] - response_closed.complete
api-1 | 2025-12-09 00:00:46.384 DEBUG [GraphWorker-0] [_config.py:82] - load_ssl_context verify=True cert=None trust_env=True http2=False
api-1 | 2025-12-09 00:00:46.385 DEBUG [GraphWorker-0] [_config.py:148] - load_verify_locations cafile='/app/api/.venv/lib/python3.12/site-packages/certifi/cacert.pem'
api-1 | 2025-12-09 00:00:46.410 DEBUG [GraphWorker-0] [_trace.py:47] - connect_tcp.started host='plugin_daemon' port=5002 local_address=None timeout=300.0 socket_options=None
api-1 | 2025-12-09 00:00:46.412 DEBUG [GraphWorker-0] [_trace.py:47] - connect_tcp.complete return_value=<httpcore._backends.sync.SyncStream object at 0x7eff89ee1730>
api-1 | 2025-12-09 00:00:46.413 DEBUG [GraphWorker-0] [_trace.py:47] - send_request_headers.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:46.413 DEBUG [GraphWorker-0] [_trace.py:47] - send_request_headers.complete
api-1 | 2025-12-09 00:00:46.413 DEBUG [GraphWorker-0] [_trace.py:47] - send_request_body.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:46.414 DEBUG [GraphWorker-0] [_trace.py:47] - send_request_body.complete
api-1 | 2025-12-09 00:00:46.414 DEBUG [GraphWorker-0] [_trace.py:47] - receive_response_headers.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:46.453 DEBUG [GraphWorker-3] [_config.py:82] - load_ssl_context verify=True cert=None trust_env=True http2=False
api-1 | 2025-12-09 00:00:46.454 DEBUG [GraphWorker-3] [_config.py:148] - load_verify_locations cafile='/app/api/.venv/lib/python3.12/site-packages/certifi/cacert.pem'
api-1 | 2025-12-09 00:00:46.494 DEBUG [GraphWorker-3] [_trace.py:47] - connect_tcp.started host='plugin_daemon' port=5002 local_address=None timeout=300.0 socket_options=None
api-1 | 2025-12-09 00:00:46.495 DEBUG [GraphWorker-3] [_trace.py:47] - connect_tcp.complete return_value=<httpcore._backends.sync.SyncStream object at 0x7eff89951970>
api-1 | 2025-12-09 00:00:46.496 DEBUG [GraphWorker-3] [_trace.py:47] - send_request_headers.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:46.496 DEBUG [GraphWorker-3] [_trace.py:47] - send_request_headers.complete
api-1 | 2025-12-09 00:00:46.496 DEBUG [GraphWorker-3] [_trace.py:47] - send_request_body.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:46.497 DEBUG [GraphWorker-3] [_trace.py:47] - send_request_body.complete
api-1 | 2025-12-09 00:00:46.497 DEBUG [GraphWorker-3] [_trace.py:47] - receive_response_headers.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:47.486 DEBUG [GraphWorker-3] [_trace.py:47] - receive_response_headers.complete return_value=(b'HTTP/1.1', 200, b'OK', [(b'Content-Type', b'text/event-stream'), (b'Date', b'Mon, 08 Dec 2025 16:00:47 GMT'), (b'Transfer-Encoding', b'chunked')])
api-1 | 2025-12-09 00:00:47.487 INFO [GraphWorker-3] [_client.py:1038] - HTTP Request: POST http://plugin_daemon:5002/plugin/xxx/dispatch/llm/invoke "HTTP/1.1 200 OK"
api-1 | 2025-12-09 00:00:47.487 DEBUG [GraphWorker-3] [_trace.py:47] - receive_response_body.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:47.634 DEBUG [GraphWorker-0] [_trace.py:47] - receive_response_headers.complete return_value=(b'HTTP/1.1', 200, b'OK', [(b'Content-Type', b'text/event-stream'), (b'Date', b'Mon, 08 Dec 2025 16:00:47 GMT'), (b'Transfer-Encoding', b'chunked')])
api-1 | 2025-12-09 00:00:47.635 INFO [GraphWorker-0] [_client.py:1038] - HTTP Request: POST http://plugin_daemon:5002/plugin/xxx/dispatch/llm/invoke "HTTP/1.1 200 OK"
api-1 | 2025-12-09 00:00:47.635 DEBUG [GraphWorker-0] [_trace.py:47] - receive_response_body.started request=<Request [b'POST']>
plugin_daemon-1 | [GIN] 2025/12/08 - 16:00:47 | 200 | 1.447240721s | 192.168.16.8 | POST "/plugin/xxx/dispatch/llm/invoke"
api-1 | 2025-12-09 00:00:47.944 DEBUG [GraphWorker-3] [_trace.py:47] - receive_response_body.complete
api-1 | 2025-12-09 00:00:47.944 DEBUG [GraphWorker-3] [_trace.py:47] - response_closed.started
api-1 | 2025-12-09 00:00:47.944 DEBUG [GraphWorker-3] [_trace.py:47] - response_closed.complete
api-1 | 2025-12-09 00:00:47.946 DEBUG [GraphWorker-3] [_trace.py:47] - close.started
api-1 | 2025-12-09 00:00:47.946 DEBUG [GraphWorker-3] [_trace.py:47] - close.complete
api-1 | 2025-12-09 00:00:47.966 DEBUG [GraphDispatcher] [execution_limits.py:92] - Step 12 started: 1764523368041
api-1 | 2025-12-09 00:00:47.971 DEBUG [Dummy-66] [workflow_draft_variable_service.py:905] - Skip saving variable as it has been excluded by its node_type, name=finish_reason, node_type=llm
plugin_daemon-1 | [GIN] 2025/12/08 - 16:00:48 | 200 | 2.166283173s | 192.168.16.8 | POST "/plugin/xxx/dispatch/llm/invoke"
api-1 | 2025-12-09 00:00:48.580 DEBUG [GraphWorker-0] [_trace.py:47] - receive_response_body.complete
api-1 | 2025-12-09 00:00:48.580 DEBUG [GraphWorker-0] [_trace.py:47] - response_closed.started
api-1 | 2025-12-09 00:00:48.580 DEBUG [GraphWorker-0] [_trace.py:47] - response_closed.complete
api-1 | 2025-12-09 00:00:48.581 DEBUG [GraphWorker-0] [_trace.py:47] - close.started
api-1 | 2025-12-09 00:00:48.581 DEBUG [GraphWorker-0] [_trace.py:47] - close.complete
api-1 | 2025-12-09 00:00:48.601 DEBUG [Dummy-66] [workflow_draft_variable_service.py:905] - Skip saving variable as it has been excluded by its node_type, name=finish_reason, node_type=llm
api-1 | 2025-12-09 00:00:48.604 DEBUG [GraphDispatcher] [execution_limits.py:92] - Step 13 started: 1764520090239
api-1 | 2025-12-09 00:00:48.625 DEBUG [GraphDispatcher] [execution_limits.py:92] - Step 14 started: 1764520319824
api-1 | 2025-12-09 00:00:48.649 DEBUG [GraphDispatcher] [execution_limits.py:92] - Step 15 started: 1764520384460
api-1 | 2025-12-09 00:00:48.674 DEBUG [GraphDispatcher] [execution_limits.py:92] - Step 16 started: 1764520482312
api-1 | 2025-12-09 00:00:48.700 DEBUG [GraphDispatcher] [execution_limits.py:92] - Step 17 started: 1748154622558
api-1 | 2025-12-09 00:00:48.721 DEBUG [GraphDispatcher] [execution_limits.py:92] - Step 18 started: 1764523518290
api-1 | 2025-12-09 00:00:48.739 DEBUG [GraphDispatcher] [execution_limits.py:92] - Step 19 started: 1751598106835
api-1 | 2025-12-09 00:00:48.758 DEBUG [GraphDispatcher] [execution_limits.py:92] - Step 20 started: 1765201532428
api-1 | 2025-12-09 00:00:48.777 DEBUG [Thread-67 (_generate_worker)] [execution_limits.py:77] - Execution limits monitoring started
api-1 | 2025-12-09 00:00:48.788 DEBUG [Thread-65 (_generate_worker)] [worker_pool.py:125] - Stopping worker pool: 6 workers
api-1 | 2025-12-09 00:00:48.797 DEBUG [Thread-67 (_generate_worker)] [worker_pool.py:106] - Starting worker pool: 5 workers (nodes=22, min=4, max=30)
api-1 | 2025-12-09 00:00:48.802 DEBUG [GraphDispatcher] [execution_limits.py:92] - Step 1 started: 1765199424173
nginx-1 | 114.244.192.216 - - [08/Dec/2025:16:00:48 +0000] "POST /console/api/apps/bc95bd6d-a2f9-4ffb-a614-dda7c22ca145/advanced-chat/workflows/draft/run HTTP/1.1" 200 59601 "http://43.173.127.226/app/bc95bd6d-a2f9-4ffb-a614-dda7c22ca145/workflow" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36" "-"
api-1 | 2025-12-09 00:00:48.821 DEBUG [GraphDispatcher] [execution_limits.py:92] - Step 2 started: 1765205093099
api-1 | 2025-12-09 00:00:48.835 DEBUG [GraphDispatcher] [execution_limits.py:92] - Step 3 started: 17652051555640
api-1 | 2025-12-09 00:00:48.854 DEBUG [GraphDispatcher] [execution_limits.py:92] - Step 4 started: 1765205518936
api-1 | 2025-12-09 00:00:48.888 DEBUG [GraphWorker-3] [_config.py:82] - load_ssl_context verify=True cert=None trust_env=True http2=False
api-1 | 2025-12-09 00:00:48.889 DEBUG [GraphWorker-3] [_config.py:148] - load_verify_locations cafile='/app/api/.venv/lib/python3.12/site-packages/certifi/cacert.pem'
api-1 | 2025-12-09 00:00:48.913 DEBUG [GraphWorker-3] [_trace.py:47] - connect_tcp.started host='plugin_daemon' port=5002 local_address=None timeout=300.0 socket_options=None
api-1 | 2025-12-09 00:00:48.915 DEBUG [GraphWorker-3] [_trace.py:47] - connect_tcp.complete return_value=<httpcore._backends.sync.SyncStream object at 0x7eff8ac64da0>
api-1 | 2025-12-09 00:00:48.915 DEBUG [GraphWorker-3] [_trace.py:47] - send_request_headers.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:48.915 DEBUG [GraphWorker-3] [_trace.py:47] - send_request_headers.complete
api-1 | 2025-12-09 00:00:48.916 DEBUG [GraphWorker-3] [_trace.py:47] - send_request_body.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:48.916 DEBUG [GraphWorker-3] [_trace.py:47] - send_request_body.complete
api-1 | 2025-12-09 00:00:48.916 DEBUG [GraphWorker-3] [_trace.py:47] - receive_response_headers.started request=<Request [b'POST']>
plugin_daemon-1 | [GIN] 2025/12/08 - 16:00:48 | 200 | 3.97087ms | 192.168.16.8 | POST "/plugin/xxx/dispatch/model/schema"
api-1 | 2025-12-09 00:00:48.919 DEBUG [GraphWorker-3] [_trace.py:47] - receive_response_headers.complete return_value=(b'HTTP/1.1', 200, b'OK', [(b'Content-Type', b'text/event-stream'), (b'Date', b'Mon, 08 Dec 2025 16:00:48 GMT'), (b'Transfer-Encoding', b'chunked')])
api-1 | 2025-12-09 00:00:48.920 INFO [GraphWorker-3] [_client.py:1038] - HTTP Request: POST http://plugin_daemon:5002/plugin/xxx/dispatch/model/schema "HTTP/1.1 200 OK"
api-1 | 2025-12-09 00:00:48.920 DEBUG [GraphWorker-3] [_trace.py:47] - receive_response_body.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:48.922 DEBUG [GraphWorker-3] [_trace.py:47] - receive_response_body.failed exception=GeneratorExit()
api-1 | 2025-12-09 00:00:48.922 DEBUG [GraphWorker-3] [_trace.py:47] - response_closed.started
api-1 | 2025-12-09 00:00:48.922 DEBUG [GraphWorker-3] [_trace.py:47] - response_closed.complete
api-1 | 2025-12-09 00:00:48.923 DEBUG [GraphWorker-3] [opendal_storage.py:52] - file upload_files/xxx/ec5b59a4-d1b0-4191-b255-049b0a1bb09f.m4a loaded
api-1 | 2025-12-09 00:00:48.965 DEBUG [GraphWorker-3] [_config.py:82] - load_ssl_context verify=True cert=None trust_env=True http2=False
api-1 | 2025-12-09 00:00:48.965 DEBUG [GraphWorker-3] [_config.py:148] - load_verify_locations cafile='/app/api/.venv/lib/python3.12/site-packages/certifi/cacert.pem'
api-1 | 2025-12-09 00:00:48.990 DEBUG [GraphWorker-3] [_trace.py:47] - connect_tcp.started host='plugin_daemon' port=5002 local_address=None timeout=300.0 socket_options=None
api-1 | 2025-12-09 00:00:48.992 DEBUG [GraphWorker-3] [_trace.py:47] - connect_tcp.complete return_value=<httpcore._backends.sync.SyncStream object at 0x7eff8ac64a40>
api-1 | 2025-12-09 00:00:48.992 DEBUG [GraphWorker-3] [_trace.py:47] - send_request_headers.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:48.992 DEBUG [GraphWorker-3] [_trace.py:47] - send_request_headers.complete
api-1 | 2025-12-09 00:00:48.992 DEBUG [GraphWorker-3] [_trace.py:47] - send_request_body.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:48.993 DEBUG [GraphWorker-3] [_trace.py:47] - send_request_body.complete
api-1 | 2025-12-09 00:00:48.993 DEBUG [GraphWorker-3] [_trace.py:47] - receive_response_headers.started request=<Request [b'POST']>
api-1 | 2025-12-09 00:00:50.104 DEBUG [GraphWorker-3] [_trace.py:47] - receive_response_headers.complete return_value=(b'HTTP/1.1', 200, b'OK', [(b'Content-Type', b'text/event-stream'), (b'Date', b'Mon, 08 Dec 2025 16:00:50 GMT'), (b'Transfer-Encoding', b'chunked')])
api-1 | 2025-12-09 00:00:50.104 INFO [GraphWorker-3] [_client.py:1038] - HTTP Request: POST http://plugin_daemon:5002/plugin/xxx/dispatch/llm/invoke "HTTP/1.1 200 OK"
api-1 | 2025-12-09 00:00:50.104 DEBUG [GraphWorker-3] [_trace.py:47] - receive_response_body.started request=<Request [b'POST']>
plugin_daemon-1 | [GIN] 2025/12/08 - 16:00:50 | 200 | 1.112585104s | 192.168.16.8 | POST "/plugin/xxx/dispatch/llm/invoke"
api-1 | 2025-12-09 00:00:50.105 DEBUG [GraphWorker-3] [_trace.py:47] - receive_response_body.complete
api-1 | 2025-12-09 00:00:50.105 DEBUG [GraphWorker-3] [_trace.py:47] - response_closed.started
api-1 | 2025-12-09 00:00:50.105 DEBUG [GraphWorker-3] [_trace.py:47] - response_closed.complete
api-1 | 2025-12-09 00:00:50.106 DEBUG [GraphWorker-3] [_trace.py:47] - close.started
api-1 | 2025-12-09 00:00:50.106 DEBUG [GraphWorker-3] [_trace.py:47] - close.complete
api-1 | 2025-12-09 00:00:50.122 DEBUG [GraphDispatcher] [execution_limits.py:92] - Step 5 started: 1765205741860
api-1 | 2025-12-09 00:00:50.138 DEBUG [Thread-67 (_generate_worker)] [worker_pool.py:125] - Stopping worker pool: 5 workers
api-1 |
api-1 | [on_tool_execution]
api-1 | Tool: imageAnlys
api-1 | Outputs: {"type":"text","message":{"text":"{"result": "xxx"}"},"meta":null}
api-1 |
api-1 |
api-1 | [on_tool_execution]
api-1 | Tool: imageAnlys
api-1 | Outputs: {"type":"json","message":{"json_object":{"result":"xxx"},"suppress_output":true},"meta":null}
api-1 |
api-1 | 2025-12-09 00:00:50.141 DEBUG [Thread-65 (_generate_worker)] [execution_limits.py:110] - Execution completed: 20 steps in 5.88 seconds
api-1 | 2025-12-09 00:00:50.236 DEBUG [Thread-67 (_generate_worker)] [execution_limits.py:110] - Execution completed: 5 steps in 1.46 seconds
nginx-1 | 114.244.192.216 - - [08/Dec/2025:16:00:50 +0000] "GET /console/api/apps/xxx/workflows/draft/variables?page=2&limit=100 HTTP/1.1" 200 959 "http://xxx/app/xxx/workflow" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/142.0.0.0 Safari/537.36" "-"

[dosubot]

This issue is caused by how Dify tracks node execution and workflow completion when handling streaming responses. If a streaming response (like text/event-stream) is interrupted—triggering a GeneratorExit—the node may be marked as finished too early, causing the workflow to be flagged as complete even though downstream nodes haven't run. This happens because the workflow engine considers execution complete when both the ready queue is empty and there are no executing nodes, which can occur if a node's execution is prematurely removed from the tracking set due to an exception in the stream handler. The worker pool may also stop while nodes are still processing, compounding the problem.

To mitigate this, you can try increasing HTTP timeouts, disabling proxy buffering in NGINX, and adjusting Uvicorn server settings to reduce the chance of premature stream closure. If possible, disable streaming in your plugin/model configuration for affected nodes. For a code-level fix, the node execution state should only be marked as finished after the stream is fully consumed or a proper error is raised, not on any exception. Handling GeneratorExit separately and ensuring the node remains in the "executing" state until the stream is truly done would prevent premature workflow completion. See this relevant code and discussion and streaming error context for more details.

To reply, just mention @dosu.

---

^{How did I do? Good | Irrelevant | Incorrect | Verbose | Hallucination | Report 🐛 | Other}

   

[305758409]

This issue does not only occur with LLM nodes; it can also happen with code execution nodes, and it is not caused by node exceptions. The code execution node completes successfully.

Log Analysis: Precise Timing of Code Node Stuck

Key Timeline

From another log, we can see:

1. 01:19:05.177 - Step 20 started: 17652140556320 (Code node starts)
2. 01:19:05.169-170 - GraphWorker-2 begins sending a request to the sandbox (POST /v1/sandbox/run)
3. 01:19:05.193 - Stopping worker pool: 6 workers (16 milliseconds later, the workflow stops)
4. 01:19:05.193 - HTTP request returns 200 (Workflow completes)
5. 01:19:10.207 - 5 seconds later, the sandbox returns 200 (Code node completes)

Key Findings

The code node was marked as Step 20 started at 01:19:05.177, but at 01:19:05.193 (16 ms later), the workflow was already determined to be complete. However, the code node was still executing (waiting for the sandbox response) and only completed at 01:19:10.207.

Exact Timing of the Issue

1. T1: 01:19:05.177 - Code node starts

   • EventHandler processes a node completion event
   • Adds the code node (17652140556320) to the ready queue and _executing_nodes (start_execution(code_node))
   • Marks it as Step 20 started

2. T2: 01:19:05.169-170 - Worker begins executing the code node (almost simultaneously)

   • Worker picks up the code node from the ready queue
   • Worker calls node.run()
   • Code node immediately yields NodeRunStartedEvent
   • Event is placed into the event_queue
   • Worker continues execution, calls _run(), starts calling the sandbox (sleeps for 5 seconds, blocking)

3. T3: 01:19:05.193 - Dispatcher checks completion conditions (16 ms later)

   • Dispatcher in _dispatcher_loop checks execution_complete on each loop iteration
   • execution_complete property calls is_execution_complete():

     def is_execution_complete(self) -> bool:
         with self._lock:
             return self._ready_queue.empty() and len(self._executing_nodes) == 0

   • If the ready queue is empty at this moment (code node has been taken out) and _executing_nodes contains the code node, it should return False
   • However, if the workflow was marked as complete, it implies _executing_nodes was empty

4. T4: 01:19:05.193 - Workflow stops

   • Dispatcher determines execution_complete is True
   • Dispatcher exits the loop
   • Calls _stop_execution(), stops the worker pool
   • But the code node is still executing (waiting for the sandbox response)

5. T5: 01:19:10.207 - Code node completes (5 seconds later)

   • Sandbox returns 200
   • Code node finishes execution
   • But the workflow has already stopped

Root Cause Analysis

Key Question: Why was the workflow determined to be complete while the code node was still in _executing_nodes?

Possible Causes:

1. Timing issue with Dispatcher checking completion conditions:

   • Code node is added to _executing_nodes at 01:19:05.177
   • Worker starts executing the code node at 01:19:05.169-170
   • Dispatcher checks completion conditions at 01:19:05.193 (16 ms later)
   • If the Dispatcher checks after the code node is added to _executing_nodes but before the Worker truly begins execution, it might detect the issue
   • Or, if the Dispatcher checks before the code node is added to _executing_nodes, _executing_nodes would be empty

2. Timing issue with state updates:

   • After the code node is added to _executing_nodes, the Worker starts executing it
   • But during Worker execution (while waiting for the sandbox response), the Dispatcher checks completion conditions
   • If there is a problem with the check logic or a timing issue with state updates, it might incorrectly judge the workflow as complete

[Chenyl-Sai]

Hi, @305758409 I can’t reproduce your issue. After reading the code, I found a potential edge case.
When the last node is executed successfully, the next node is added to both _ready_queue and _executing_nodes:

        for node_id in ready_nodes:
            self._state_manager.enqueue_node(node_id) # 1
            self._state_manager.start_execution(node_id) # 2

If, after step #1, the worker thread consumes the node from _ready_queue, and before step #2 the dispatcher check occurs, both _ready_queue and _executing_nodes could be empty at that moment.
What do you think about reversing these two steps—adding the node to _executing_nodes first, and then enqueuing it into _ready_queue?
This would prevent the worker from consuming the node before it is registered in _executing_nodes.

[305758409]

@Chenyl-Sai

This issue is quite strange. It appears that when the number of nodes or concurrent nodes is small, the problem does not occur. And when it doesn't occur, it almost never happens. However, when the number of agent nodes or parallel branches reaches a certain level, the issue becomes almost guaranteed to occur.

Simple agents seem never to encounter this problem. I am confident that this issue exists, but it is also reasonable that it is not consistently reproducible. This is because it is a race condition problem.

I've made the following modifications locally, and the bug no longer reappears. It seems to be resolved, though the solution might not be particularly elegant or entirely reasonable. I sincerely hope this helps the community resolve this issue. This is for your reference.

Issue Overview
Symptom: A workflow is marked as "completed" while LLM/tool nodes are still running, and front‑end nodes appear stuck in a running state.
Trigger Scenario: High probability of occurrence with the first LLM/tool node after a branch (especially sub‑workflow/tool nodes). The first request after a restart is usually normal; the issue reproduces in subsequent requests.

Root Cause (Race Condition):
When the Dispatcher checks execution_complete, both the ready_queue and _executing_nodes are empty, but there are still pending events in the event_queue (such as NodeRunStartedEvent / NodeRunSucceededEvent). Subsequent processing of these events will trigger new node starts, causing the parent workflow to be incorrectly judged as completed.

Changes in graph_state_manager.py

• Enhanced is_execution_complete: Added a check on the event_queue to ensure no pending events exist.
• Five consecutive checks with a 300 ms interval between each (total wait 1.2 s). Completion is only confirmed when all the following conditions are met simultaneously:
  • ready_queue is empty
  • _executing_nodes is empty
  • event_queue is empty
• Enhanced logging ([WORKFLOW_FIX]): Outputs debug information such as queue‑empty status, number of executing nodes, event‑queue size, etc.

Changes in graph_engine.py

• When creating the GraphStateManager, the event_queue is now passed in, allowing the completion check to also inspect the event queue.

Key Code Paths

1. api/core/workflow/graph_engine/graph_state_manager.py

   • Method: is_execution_complete
   • Changes: Added event_queue check; five consecutive 300 ms confirmations; debug logs.

2. api/core/workflow/graph_engine/graph_engine.py

   • Change: GraphStateManager(self._graph, self._ready_queue, self._event_queue)

[Chenyl-Sai]

Hi @305758409, I’m very interested in this issue.

As I mentioned above, my earlier assumption—that the dispatcher check could occur before start_execution—was incorrect, since both operations run in the same thread and that scenario should not happen.

However, I still can’t reproduce this bug. If it’s convenient, could you please share a DSL so I can try to reproduce it on my side?

[suntao2015005848]

+1

[suntao2015005848]

Dify workflow execution was interrupted.

[305758409]

Dify workflow execution was interrupted.

Yes, the screenshot you sent shows exactly the same problem I encountered.

[305758409]

Hi @305758409, I’m very interested in this issue.

As I mentioned above, my earlier assumption—that the dispatcher check could occur before start_execution—was incorrect, since both operations run in the same thread and that scenario should not happen.

However, I still can’t reproduce this bug. If it’s convenient, could you please share a DSL so I can try to reproduce it on my side?

@Chenyl-Sai I apologize, but this agent is for internal company use and cannot be shared directly. Making an anonymized version is a bit challenging, but I will try to replicate a sanitized version of the agent. However, this will require some time.