Duplicate Executions with No Active Execution Found error

[nikozila]

Bug Description

I’ve encountered a potential issue where some executions are being executed more than once with the error of “No Active Execution Found”.
Check out the logs:

debug | Resuming execution 6692658 {"scope":"executions","executionId":"6692658","file":"wait-tracker.js","function":"startExecution"}
debug | Found 3 executions. Setting timer for IDs: x, 6692658, y {"scope":"executions","file":"wait-tracker.js"...
debug | Resuming execution 6692658 {"scope":"executions","executionId":"6692658","file":"wait-tracker.js","function":"startExecution"}
debug | Execution added {"executionId":"6692658","file":"active-executions.js","function":"add"}
debug | Execution for workflow [name] id 6692658
debug | Execution added {"executionId":"6692658","file":"active-executions.js","function":"add"}
debug | Execution ID 6692658 had Execution data. Running with payload. {"executionId":"6692658","file":"workflow-runner.js","function":"runMainProcess",
debug | ActiveExecutions attachWorkflowExecution() called | Execution id 6692658
debug | ActiveExections getExecution() called | Execution ID: 6692658, Execution: [object Object]
debug | ActiveExections getExecution() called | Execution ID: 6692658
debug | Execution for workflow [name] was assigned id 6692658
debug | Execution ID 6692658 had Execution data. Running with payload.
debug | ActiveExecutions attachWorkflowExecution() called | Execution id 6692658
debug | ActiveExections getExecution() called | Execution ID: 6692658, Execution: [object Object]
debug | ActiveExections getExecution() called | Execution ID: 6692658, Execution: [object Object]
debug | Setting execution status for 6692658 to "waiting" {"file":"workflow-execute-additional-data.js","function":"setExecutionStatus"}
debug | ActiveExecutions setStatus() called | Execution id 6692658
debug | ActiveExections getExecution() called | Execution ID: 6692658, Execution: [object Object]
debug | Save execution data to database for execution ID 6692658
debug | ActiveExecutions getStatus() called | Execution id 6692658
debug | ActiveExections getExecution() called | Execution ID: 6692658, Execution: [object Object]
debug| ActiveExections getExecution() called | Execution ID: 6692658, Execution: [object Object]
debug | Execution finalized {"executionId":"6692658","file":"active-executions.js","function":"finalizeExecution"}
debug | Execution removed {"executionId":"6692658","file":"active-executions.js"}

As you can see we have two “Resuming execution 6692658” logs.
That’s why some of the execution functions get called more than once. Eventually one of the executions got finalized and removed from the ActiveExecutions list. But here is fun part:

debug | Setting execution status for 6692658 to "waiting" {"file":"workflow-execute-additional-data.js","function":"setExecutionStatus"}
debug | ActiveExecutions setStatus() called | Execution id 6692658
debug | ActiveExections getExecution() called | Execution ID: 6692658, Execution: undefined
debug | Start external error workflow {"executionId":"6692658",...

Since the first execution is removed from the activeExections list, when n8n tries to call getExecution for the second execution, it throws error

debug | ActiveExections getExecution() called | Execution ID: 6692658, Execution: undefined
The execution is undefined. (rather than [object object])

What I realized is that there might be a race condition between getWaitingExecutions, startExecution and workflowrRunner.run methods.

n8n doesn’t check if the execution is running now in waitTracker startExecution function nor in the workflowRunner.run and runMainProcess functions. I think there should be a checking in those functions too to guarantee that an execution is being run only once.

To Reproduce

It happens to a few of my workflows. Honestly I don't know how to reproduce this problem.
But here is my case:

1. Normally we have one execution in 2 seconds. Sometimes we have multiple executions running at the same time.
2. We have some large workflows (with at least 50 nodes)
3. These large workflows consist on many wait nodes.
4. When n8n resumes these wait nodes in those large workflows, this problem occurs.

Expected behavior

You'll see a failed execution with "No Active Execution Found" error and when you open the execution you won's see any data.

Operating System

docker

n8n Version

1.63.4

Node.js Version

20.18.0

Database

PostgreSQL

Execution mode

main (default)

[Joffcom]

Hey @nikozila,

We have created an internal ticket to look into this which we will be tracking as "GHC-486"

[nikozila]

Hi,
I found a new thing!

I put two logs in wait-tracker.ts:

1. One log before the if statement
2. One log after the if statement
   

And I saw this (check the execution id #7027024):

2024-11-27T20:12:15.068Z | debug | wait-tracker - getWaitingExecutions - executionId: 7027024
2024-11-27T20:12:15.068Z | debug | wait-tracker - getWaitingExecutions - no #7027024 in waitingExecutions
2024-11-27T20:13:17.071Z | debug | Resuming execution 7027024
2024-11-27T20:13:17.080Z | debug | Found 4 executions. Setting timer for IDs: 2834745, 7027024, 7042123, 6993420
2024-11-27T20:13:17.081Z | debug | wait-tracker - getWaitingExecutions - executionId: 7027024
2024-11-27T20:13:17.081Z | debug | wait-tracker - getWaitingExecutions - no #7027024 in waitingExecutions
2024-11-27T20:13:17.082Z | debug | Resuming execution 7027024

It ended up with the error: No Active Execution Found because of two running executions at the same time.