n8n icon indicating copy to clipboard operation
n8n copied to clipboard

Waiting Executions

Open arthurrferroni opened this issue 1 year ago • 59 comments

Describe the bug if a workflow has a Wait node, and the status is WAITING(> 65 seconds), n8n does not execute and has errors in the log

To Reproduce 1 - create a basic workflow with a node Wait, set it to 5 minutes. 2 - this will not execute and print a log error

Expected behavior Expected to executed on the seted time

Environment (please complete the following information):

  • OS: Ubuntu 20.04
  • n8n Version: Tested on: 1.22.1, 1.22.0, 1.21.1, 1.21.0 ,1.18.4 and others
  • Node.js Version: v20.5.1
  • Database system: Postgres
  • Operation mode: main

Additional context n8n logs 3 n8n logs 2 n8n logs waiting

arthurrferroni avatar Dec 21 '23 22:12 arthurrferroni

Timezone configs: GENERIC_TIMEZONE="America/Sao_Paulo" TZ="America/Sao_Paulo"

Worfkflow is on default

arthurrferroni avatar Dec 21 '23 22:12 arthurrferroni

Hey @arthurrferroni thank you for reporting - we saw this issue before but could never reproduce it.

Do you have database access? Can you check the execution_entity's row for this execuion ID 594672 and check the value of the waitTill column? I'm guessing n8n seems to be saving an invalid date to this field, but we could never reproduce it.

krynble avatar Dec 22 '23 10:12 krynble

Yes I do, but I think is saving correctly, if I restart n8n's pm2, the executions that have already passed the scheduled time and are in waiting status are executed when starting pm2.

i've excluded the ID 594672, but i created a new one id 596515, and is teh row of the database

596515 false "manual" "2023-12-22 12:10:38.888+00" "2023-12-22 12:10:38.896+00" "2023-12-22 08:59:38.896+00" "waiting" "TB3PVn7m7Tdf6IVU"

arthurrferroni avatar Dec 22 '23 12:12 arthurrferroni

#6624

arthurrferroni avatar Dec 22 '23 16:12 arthurrferroni

Hey @arthurrferroni,

Out of interest do you get the same issue if you use the Docker image or Node 18 which is our current recommended version?

Can you share the configuration for Postgres as well? Are you self hosting that as well and does it have any timezone configurations or was it just an apt install postgres.

Joffcom avatar Jan 02 '24 12:01 Joffcom

Hello @janober @Joffcom, I hope 2024 is another year of health, achievements and success in your life and your family.

I've Same problem here. I was able to test up to version 1.14 and the same problem.

I am using Docker Swarm, N8N in Queue Mode. If the Wait is less than 60 seconds it works perfectly, if you set it to 65 seconds or more it waits 60 seconds and considers the workflow completed, but the nodes following the Wait are not executed.

I did the same test using RabbitMQ (I use it in all my workflows), if there is a Wait within a SubWorkflow it considers it completed as well.

No errors are displayed or logs are generated.

Last week I did tests with my friend @cbalbinos and we came to the conclusion that if the wait takes more than 65 seconds, N8N considers it to have been executed successfully and does not execute the rest of the nodes. He opened #8167 .

I belive it is related to #7699

luizeof avatar Jan 03 '24 14:01 luizeof

eu tenho o mesmo problema, segue o post https://community.n8n.io/t/wait-does-not-work-after-65-seconds/34776/4

RuanMD avatar Jan 03 '24 14:01 RuanMD

Hey @luizeof,

If a wait is over a certain time it goes into the database in a waiting state but the workflow isn't really considered "finished", From the testing I did this morning and from the images in #8167 we can see that the waiting executions are working.

In your test can you share any error output you are getting in the logs as the issue with RabbitMQ is not the same as the issue reported here and I don't want this issue to be mixed up with different issues being reported.

Joffcom avatar Jan 03 '24 15:01 Joffcom

@RuanMD do you see the same error message in your log?

Joffcom avatar Jan 03 '24 15:01 Joffcom

o you see the same error message in your log?

I don't know where the error is, but I did several tests, when the wait is longer than 65 seconds it just stays waiting and doesn't execute the automation

RuanMD avatar Jan 03 '24 15:01 RuanMD

Hey @RuanMD,

The log will be in the docker output of n8n, I would not be surprised if there are a couple of different issues here.

Joffcom avatar Jan 03 '24 15:01 Joffcom

I haven't tested with node 18, only 20, running on pm2, the execution was saved with waiting status, not finished, but when the time set expires doesn't execute the next nodes, and logs the error on the pm2 logs.

arthurrferroni avatar Jan 04 '24 18:01 arthurrferroni

Hey @arthurrferroni,

Are you able to test with 18 which is the version we officially support?

Do you also have your database configuration handy?

Joffcom avatar Jan 04 '24 19:01 Joffcom

I'll up another vps and taste this, I'm running on postgres SQL, 6cpu and 16gb ram

arthurrferroni avatar Jan 04 '24 19:01 arthurrferroni

I'll up another vps and taste this, I'm running on postgres SQL, 6cpu and 16gb ram

image I'm using version 18, on Docker Swarm with Postgres 14, 4GB machine and 3cpu

RuanMD avatar Jan 04 '24 19:01 RuanMD

@RuanMD if you are using docker it will be node 18 already, in your case what I want to know is if you see the same error in the docker logs although we already have someone internally looking at your report so it may be worth keeping to your post as it could be a different issue and we may end up repeating things.

Joffcom avatar Jan 04 '24 20:01 Joffcom

hello @Joffcom

I was able to reproduce the latest version:

image

image

I set 85 seconds of waiting. The workflow run by the editor works well.

In Production it is not executed.

I'm running in queue mode:

  • In the Worker container, no execution log appears.
  • In the editor container, the log below appears:
Started with job ID: 65119 (Execution ID: 66643)
Started with job ID: 65120 (Execution ID: 66644)
ApplicationError: Only saved workflows can be resumed.
There was a problem starting the waiting execution with id "66644": "Only saved workflows can be resumed."
ApplicationError: Only saved workflows can be resumed.
There was a problem starting the waiting execution with id "66644": "Only saved workflows can be resumed."
Started with job ID: 65121 (Execution ID: 66646)
ApplicationError: Only saved workflows can be resumed.
There was a problem starting the waiting execution with id "66644": "Only saved workflows can be resumed."
Started with job ID: 65122 (Execution ID: 66647)
ApplicationError: Only saved workflows can be resumed.
There was a problem starting the waiting execution with id "66646": "Only saved workflows can be resumed."
ApplicationError: Only saved workflows can be resumed.
There was a problem starting the waiting execution with id "66644": "Only saved workflows can be resumed."
ApplicationError: Only saved workflows can be resumed.
There was a problem starting the waiting execution with id "66646": "Only saved workflows can be resumed."
ApplicationError: Only saved workflows can be resumed.
There was a problem starting the waiting execution with id "66647": "Only saved workflows can be resumed."
Started with job ID: 65123 (Execution ID: 66649)
Started with job ID: 65124 (Execution ID: 66650)
ApplicationError: Only saved workflows can be resumed.
There was a problem starting the waiting execution with id "66644": "Only saved workflows can be resumed."
ApplicationError: Only saved workflows can be resumed.
There was a problem starting the waiting execution with id "66647": "Only saved workflows can be resumed."
ApplicationError: Only saved workflows can be resumed.
There was a problem starting the waiting execution with id "66646": "Only saved workflows can be resumed."

luizeof avatar Jan 04 '24 23:01 luizeof

Hey @luizeof,

If you look at your error message it is not the same as the one earlier in this topic, But looking at that error I have to ask... Was the workflow saved before you ran it?

Joffcom avatar Jan 05 '24 14:01 Joffcom

Hey @luizeof,

If you look at your error message it is not the same as the one earlier in this topic, But looking at that error I have to ask... Was the workflow saved before you ran it?

the workflow was saved.

luizeof avatar Jan 05 '24 14:01 luizeof

Hey @luizeof,

That is interesting, So I can see your timezone is Sao Paulo and I know another report of this is also using that Timezone. I wonder if that is related as I am not able to reproduce this with Europe/London with either the unsaved or the other error message.

I will do some testing on Monday and see if it is timezone related.

Joffcom avatar Jan 05 '24 15:01 Joffcom

@Joffcom make some tests changing this https://github.com/n8n-io/n8n/blob/3cf6704dbb347cf4d59848cad508db926c54bc4b/packages/nodes-base/nodes/Wait/Wait.node.ts#L433

luizeof avatar Jan 05 '24 16:01 luizeof

@luizeof We already know one of the issues will be coming from where the data is saved to the database to be picked up again later the bit we don't know is why it can't always be reproduced and why there are different errors for example your error is n8n saying the workflow was not saved the original error in this workflow is around something not being a function that should be.

Once we can reproduce the different errors in here we will be able to resolve it.

Joffcom avatar Jan 08 '24 12:01 Joffcom

@Joffcom @RuanMD I updated to the latest version (1.22.4) and so far the problem has stopped.

luizeof avatar Jan 09 '24 12:01 luizeof

Contributor

thank you luiz

RuanMD avatar Jan 09 '24 12:01 RuanMD

The fix in 1.22.4 fixes something that I think was introduced in 1.22.2 or 1.22.3 so if you were seeing this before that this change should make no difference 🤔

Joffcom avatar Jan 09 '24 15:01 Joffcom

@luizeof what version of postgres are you running?

netroy avatar Jan 12 '24 10:01 netroy

@luizeof what version of postgres are you running?

postgres 16

luizeof avatar Jan 12 '24 11:01 luizeof

Thanks. Can you also please share the output of this query 🙏🏽

SELECT status, "waitTill" FROM "execution_entity" WHERE "waitTill" IS NOT NULL;

netroy avatar Jan 12 '24 11:01 netroy

Quick update, the issue originally reported in this post has been seen in 1.22.6 so there is a possibility that there are 2 different issues being reported in this thread.

If your log file does not mention that waitTill.getTime is not a function can you create a new issue and let us know so we can filter out what is relevant to this problem.

Joffcom avatar Jan 14 '24 09:01 Joffcom

I've noticed this error since before version 1.0, I've even opened 5 topics about it and it never resolves

https://community.n8n.io/t/wait-node-does-not-continue-after-65-seconds/32550/2 https://community.n8n.io/t/wait-does-not-continue-after-scheduling/30395/5 https://community.n8n.io/t/does-wait-occupy-position-in-webhook-or-worker/30195/6 https://community.n8n.io/t/flow-does-not-continue-after-wait/28629/19 https://community.n8n.io/t/flow-does-not-continue-after-wait-up/28790/4

I've even asked the question a few times in the @luizeof community and at the time it either didn't happen to anyone or no one had noticed yet, what decided it for me was to replicate the same logic that is done in n8n, I created a table called 'await' to save the data and a flow that, with a schedule every 1 minute, checks if there is a flow to start over and the flow starts again.

the problem is certainly related to the time zone connection, this same bug interferes with the visualization of flows in the editor where in some flows you cannot view executions that recently ended if there is another flow of the same running, see the image below for the time I filtered and the time that is showing, 3 hours difference which is my time zone, I tested it now in version 1.22.6 and the wait continues without working for more than 65 seconds.

Captura de Tela 2024-01-16 às 14 32 12

Today I use n8n in Docker queue mode version 1.22.6

DRIMOL avatar Jan 16 '24 18:01 DRIMOL