n8n: execute-node-never-end

BrutalBirdie

@jodumont Does anyone use n8n ? No but I did the packaging to get it stable.
I am taking a look at it and also reply to the post on n8ns side.

BrutalBirdie

@brutalbirdie Ran into an issue posting in their forum, all my posts got blacklisted as spam seems the cloudron domain is marked as spam I am already in contact with the staff about this issue.

JOduMonT

@brutalbirdie said in n8n: execute-node-never-end:

I am already in contact with the staff about this issue.

thank you for your promptitude

JOduMonT

I'm wondering if it is not due to NGINX or IPTables rules
https://git.cloudron.io/cloudron/box/-/blob/master/setup/start/cloudron-firewall.sh
which throttle the connection ??

BrutalBirdie

@jodumont best part is when you press stop this happens.

This is the debug log of the execution:

Jul 28 23:41:31 172.18.0.1 - - [28/Jul/2021:21:41:31 +0000] "POST /rest/workflows/run HTTP/1.1" 200 28 "https://test.cloudron.dev/workflow/1" "Mozilla/5.0 (X11; Linux x86_64; rv:91.0) Gecko/20100101 Firefox/91.0"
Jul 28 23:41:31
Jul 28 23:41:31 Loading configuration overwrites from:
Jul 28 23:41:31 - /app/data/.n8n/app-config.json
Jul 28 23:41:31
Jul 28 23:41:31 2021-07-28T21:41:31.691Z | debug | Received child process message of type start for execution ID 3. {"executionId":"3","file":"WorkflowRunner.js"}
Jul 28 23:41:31 2021-07-28T21:41:31.696Z | verbose | Initializing n8n sub-process {"pid":62,"workflowId":"1","file":"WorkflowRunnerProcess.js","function":"runWorkflow"}
Jul 28 23:41:31 2021-07-28T21:41:31.703Z | verbose | Workflow execution started {"workflowId":"1","file":"WorkflowExecute.js","function":"processRunExecutionData"}
Jul 28 23:41:31 2021-07-28T21:41:31.704Z | debug | Received child process message of type processHook for execution ID 3. {"executionId":"3","file":"WorkflowRunner.js"}
Jul 28 23:41:31 2021-07-28T21:41:31.704Z | debug | Start processing node "Cron" {"node":"Cron","workflowId":"1","file":"WorkflowExecute.js"}
Jul 28 23:41:31 2021-07-28T21:41:31.704Z | debug | Executing hook (hookFunctionsPush) {"executionId":"3","sessionId":"woupbridiqe","workflowId":"1","file":"WorkflowExecuteAdditionalData.js","function":"workflowExecuteBefore"}
Jul 28 23:41:31 2021-07-28T21:41:31.705Z | debug | Send data of type "executionStarted" to editor-UI {"dataType":"executionStarted","sessionId":"woupbridiqe","file":"Push.js","function":"send"}
Jul 28 23:41:31 2021-07-28T21:41:31.705Z | debug | Running node "Cron" started {"node":"Cron","workflowId":"1","file":"WorkflowExecute.js"}
Jul 28 23:41:31 2021-07-28T21:41:31.705Z | debug | Received child process message of type processHook for execution ID 3. {"executionId":"3","file":"WorkflowRunner.js"}
Jul 28 23:41:31 2021-07-28T21:41:31.705Z | debug | Executing hook on node "Cron" (hookFunctionsPush) {"executionId":"3","sessionId":"woupbridiqe","workflowId":"1","file":"WorkflowExecuteAdditionalData.js","function":"nodeExecuteBefore"}
Jul 28 23:41:31 2021-07-28T21:41:31.705Z | debug | Send data of type "nodeExecuteBefore" to editor-UI {"dataType":"nodeExecuteBefore","sessionId":"woupbridiqe","file":"Push.js","function":"send"}
Jul 28 23:41:31 2021-07-28T21:41:31.711Z | debug | Running node "Cron" finished successfully {"node":"Cron","workflowId":"1","file":"WorkflowExecute.js"}
Jul 28 23:41:31 2021-07-28T21:41:31.711Z | debug | Received child process message of type processHook for execution ID 3. {"executionId":"3","file":"WorkflowRunner.js"}
Jul 28 23:41:31 2021-07-28T21:41:31.711Z | debug | Executing hook on node "Cron" (hookFunctionsPush) {"executionId":"3","sessionId":"woupbridiqe","workflowId":"1","file":"WorkflowExecuteAdditionalData.js","function":"nodeExecuteAfter"}
Jul 28 23:41:31 2021-07-28T21:41:31.711Z | debug | Start processing node "CoinGecko" {"node":"CoinGecko","workflowId":"1","file":"WorkflowExecute.js"}
Jul 28 23:41:31 2021-07-28T21:41:31.711Z | debug | Send data of type "nodeExecuteAfter" to editor-UI {"dataType":"nodeExecuteAfter","sessionId":"woupbridiqe","file":"Push.js","function":"send"}
Jul 28 23:41:31 2021-07-28T21:41:31.712Z | debug | Received child process message of type processHook for execution ID 3. {"executionId":"3","file":"WorkflowRunner.js"}
Jul 28 23:41:31 2021-07-28T21:41:31.712Z | debug | Running node "CoinGecko" started {"node":"CoinGecko","workflowId":"1","file":"WorkflowExecute.js"}
Jul 28 23:41:31 2021-07-28T21:41:31.712Z | debug | Executing hook on node "CoinGecko" (hookFunctionsPush) {"executionId":"3","sessionId":"woupbridiqe","workflowId":"1","file":"WorkflowExecuteAdditionalData.js","function":"nodeExecuteBefore"}
Jul 28 23:41:31 2021-07-28T21:41:31.712Z | debug | Send data of type "nodeExecuteBefore" to editor-UI {"dataType":"nodeExecuteBefore","sessionId":"woupbridiqe","file":"Push.js","function":"send"}
Jul 28 23:41:31 2021-07-28T21:41:31.802Z | debug | Running node "CoinGecko" finished successfully {"node":"CoinGecko","workflowId":"1","file":"WorkflowExecute.js"}
Jul 28 23:41:31 2021-07-28T21:41:31.803Z | verbose | Workflow execution finished successfully {"workflowId":"1","file":"WorkflowExecute.js","function":"processSuccessExecution"}
Jul 28 23:41:31 2021-07-28T21:41:31.803Z | debug | Received child process message of type processHook for execution ID 3. {"executionId":"3","file":"WorkflowRunner.js"}
Jul 28 23:41:31 2021-07-28T21:41:31.803Z | debug | Executing hook on node "CoinGecko" (hookFunctionsPush) {"executionId":"3","sessionId":"woupbridiqe","workflowId":"1","file":"WorkflowExecuteAdditionalData.js","function":"nodeExecuteAfter"}
Jul 28 23:41:31 2021-07-28T21:41:31.803Z | debug | Send data of type "nodeExecuteAfter" to editor-UI {"dataType":"nodeExecuteAfter","sessionId":"woupbridiqe","file":"Push.js","function":"send"}
Jul 28 23:41:31 2021-07-28T21:41:31.806Z | debug | Received child process message of type processHook for execution ID 3. {"executionId":"3","file":"WorkflowRunner.js"}
Jul 28 23:41:31 2021-07-28T21:41:31.806Z | debug | Executing hook (hookFunctionsSave) {"executionId":"3","workflowId":"1","file":"WorkflowExecuteAdditionalData.js","function":"workflowExecuteAfter"}
Jul 28 23:41:31 2021-07-28T21:41:31.806Z | debug | Save execution data to database for execution ID 3 {"executionId":"3","workflowId":"1","finished":true,"stoppedAt":"2021-07-28T21:41:31.803Z","file":"WorkflowExecuteAdditionalData.js","function":"workflowExecuteAfter"}
Jul 28 23:41:31 2021-07-28T21:41:31.809Z | debug | Received child process message of type end for execution ID 3. {"executionId":"3","file":"WorkflowRunner.js"}
Jul 28 23:41:31 2021-07-28T21:41:31.815Z | debug | Executing hook (hookFunctionsPush) {"executionId":"3","sessionId":"woupbridiqe","workflowId":"1","file":"WorkflowExecuteAdditionalData.js","function":"workflowExecuteAfter"}
Jul 28 23:41:31 2021-07-28T21:41:31.815Z | debug | Save execution progress to database for execution ID 3 {"executionId":"3","workflowId":"1","file":"WorkflowExecuteAdditionalData.js","function":"workflowExecuteAfter"}
Jul 28 23:41:31 2021-07-28T21:41:31.815Z | debug | Send data of type "executionFinished" to editor-UI {"dataType":"executionFinished","sessionId":"woupbridiqe","file":"Push.js","function":"send"}

With this debug log:

Jul 28 23:42:09 ERROR RESPONSE
Jul 28 23:42:09 Error: The execution id "3" could not be found.
Jul 28 23:42:09 at /usr/local/node-14.17.0/lib/node_modules/n8n/dist/src/Server.js:1270:27
Jul 28 23:42:09 at processTicksAndRejections (internal/process/task_queues.js:95:5)
Jul 28 23:42:09 at async /usr/local/node-14.17.0/lib/node_modules/n8n/dist/src/ResponseHelper.js:86:26
Jul 28 23:42:09 172.18.0.1 - - [28/Jul/2021:21:42:09 +0000] "POST /rest/executions-current/3/stop HTTP/1.1" 500 380 "https://test.cloudron.dev/workflow/1" "Mozilla/5.0 (X11; Linux x86_64; rv:91.0) Gecko/20100101 Firefox/91.0"
Jul 28 23:42:09 172.18.0.1 - - [28/Jul/2021:21:42:09 +0000] "GET /rest/executions/3 HTTP/1.1" 200 4027 "https://test.cloudron.dev/workflow/1" "Mozilla/5.0 (X11; Linux x86_64; rv:91.0) Gecko/20100101 Firefox/91.0"

JOduMonT

@brutalbirdie thank you for your digging, but I just see a bunch of line with code and could only deduce you want to tell me than the issue somewhere in the process/task_queues.js so on their side

oh! I see you posted it also on their community
the strange thing, is this is not happening if I use SQLite as DB, but happen with Postgres and MySQL.

JOduMonT

It seems to be the NGINX cache, because on my side

I opened the port 5678 and access it directly with this port instead of behind NGINX
and n8n + mysql or postgres works well if we abstract the proxy (NGINX).

and now it works well, even behind NGINX if I use

proxy_pass http://localhost:5678;
proxy_set_header Connection '';
proxy_http_version 1.1;
chunked_transfer_encoding off;
proxy_buffering off;
proxy_cache off;

@BrutalBirdie please modify the nginx proxy in consequence.

nebulon

@jodumont nice, so I guess that was already part of the nginx within the app container https://git.cloudron.io/cloudron/n8n-app/-/blob/master/docker/app/pkg/nginx.conf#L64

However Cloudron also has another reverse proxy nginx instance on the system, which lacks those tweaks. Have to see how can tell the system about this.

Is there a good way to reproduce the problem in the first place, that way we can see which nginx setting fixes it and maybe it could be set normally in the system config as well then.

BrutalBirdie

@JOduMonT not sure if this is really solved tho since the issue still persists on cloudron site.

nebulon

@brutalbirdie I guess @JOduMonT has also tweaked the system nginx config for the app manually. Of course this won't be persistent for the moment, but good to know. We have to find a solution on the platform for this though.

BrutalBirdie

@nebulon huh I got to test this.
Since @JOduMonT wrote this:

@BrutalBirdie please modify the nginx proxy in consequence.

I got the impression he did this fix for his local docker-compose setup.

https://community.n8n.io/t/execute-node-never-end/6899/17?u=brutalbirdie

Now I am even more confused. @JOduMonT could you please clear up what you exactly did?

BrutalBirdie

@jodumont I did fix the manual execution.
Update coming out soon.

girish

@brutalbirdie Ah great. Does this also fix (or is it even related to) https://forum.cloudron.io/topic/5415/connection-lost-n8n/ ?

BrutalBirdie

@girish not sure about that since this issue is already resolved and in the automated tests and I cant reproduce his error.

bencreynolds

@brutalbirdie I am having this issue as well. Is there going to be a fix implemented? I have no idea how to edit my Nginx settings in cloudron.

girish

@bencreynolds The fix is ready. We will publish a new package asap.

JOduMonT

@nebulon said in n8n: execute-node-never-end:

I guess @JOduMonT has also tweaked the system nginx config for the app manually.

no I didn't, of course I could build another Cloudron at home (as development and test it) but in Prod I touch nothing, you are the master of my ProdMachine

girish

@bencreynolds I have pushed an update, can you please check?

bencreynolds

@girish I haven't had time to come back to this until now. This update did not fix the issue. Replicate the issue by creating an n8n instance and attempting to execute a GET request on google.com. It just spins forever and it's impossible to stop the execution.

Stopping the server while its infinitely executing will return the expected result of the GET request.

girish

@bencreynolds Is this using the HTTP Request node? Seems to work for me. The URL i tried is https://api.cloudron.io/api/v1/apps/io.n8n.cloudronapp (this gives info of the n8n package in JSON format)

Cloudron makes it easy to run web apps like WordPress, Nextcloud, GitLab on your server. Find out more or install now.

Cloudron Forum

n8n: execute-node-never-end

and now it works well, even behind NGINX if I use