StackStorm / StackStorm/st2

Workflow executions running out of order when delayed.

Open
#5,587 9 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

Dominant language
Python
Stars
6.5k
Forks
787
PR merge metrics
No merged PRs in 30d

Description

I have a workflow with a concurrency policy that only allows 1 instance of the Action to run at a time. But i could see that the sequence followed here is LIFO(Last in first out) sometimes.
The logs states that the trigger happened in the sequence of 6220edd5a3eb83216afd4cd5 first and then 6220ee28a3eb83216afd4ce3 , also the delay sequence is same ,but the execution sequence is 6220ee28a3eb83216afd4ce3 first and 6220edd5a3eb83216afd4cd5 later.

Logs from scheduler:
For ID 6220edd5cefb8a6ece90577e

6144 2022-03-03 16:33:25,869 139825213000440 INFO handler [-] [6220edd5a3eb83216afd4cd5] Retrieved item "6220edd5cefb8a6ece90577e" from scheduling queue. 6145 2022-03-03 16:33:25,871 139825213000896 INFO handler [-] [6220edd5a3eb83216afd4cd5] Scheduling Liveaction "6220edd5a3eb83216afd4cd4". (queue_item_id='6220edd5cefb8a6ece90577e') 6146 2022-03-03 16:33:25,874 139825213000896 INFO handler [-] [6220edd5a3eb83216afd4cd5] Liveaction "6220edd5a3eb83216afd4cd4" has status "requested" before applying policies. (queue_item_id='6220edd5c efb8a6ece90577e') 6147 2022-03-03 16:33:25,876 139825213000896 INFO policies [-] Applying policy "zsmanjot.process.concurrency" (action.concurrency) for liveaction "6220edd5a3eb83216afd4cd4".

For ID 6220ee28a3eb83216afd4ce3
6351 2022-03-03 16:34:49,086 139825213000440 INFO handler [-] [6220ee28a3eb83216afd4ce3] Retrieved item "6220ee28cefb8a6ece905780" from scheduling queue. 6352 2022-03-03 16:34:49,088 139825213000896 INFO handler [-] [6220ee28a3eb83216afd4ce3] Scheduling Liveaction "6220ee28a3eb83216afd4ce2". (queue_item_id='6220ee28cefb8a6ece905780') 6353 2022-03-03 16:34:49,092 139825213000896 INFO handler [-] [6220ee28a3eb83216afd4ce3] Liveaction "6220ee28a3eb83216afd4ce2" has status "requested" before applying policies. (queue_item_id='6220ee28c efb8a6ece905780') 6354 2022-03-03 16:34:49,094 139825213000896 INFO policies [-] Applying policy "zsmanjot.process.concurrency" (action.concurrency) for liveaction "6220ee28a3eb83216afd4ce2".

  • Actual Execution followed should have been first 6220edd5cefb8a6ece90577e and then 6220ee28a3eb83216afd4ce3 because the former was delayed first (or was put in the queue first). But the workflow execution happened for the Later first.

2022-03-03 16:34:57,024 139653797263968 INFO workflows [-] [6220ee28a3eb83216afd4ce3] Processing request for workflow execution. 2022-03-03 16:34:57,045 139653797263968 INFO workflows [-] [6220ee28a3eb83216afd4ce3] Requesting conductor to start running workflow execution. 2022-03-03 16:34:57,050 139653797263968 INFO workflows [-] [6220ee28a3eb83216afd4ce3] Identifying next set (iter 0) of tasks for workflow execution in status "running". 2022-03-03 16:34:57,057 139653797263968 INFO workflows [-] [6220ee28a3eb83216afd4ce3] Identified the following set of tasks to execute next: check_for_inprogress_hosts (route 0) 2022-03-03 16:34:57,061 139653797263968 INFO workflows [-] [6220ee28a3eb83216afd4ce3] Mark task "check_for_inprogress_hosts", route "0", in conductor as running. 2022-03-03 16:34:57,061 139653797263968 INFO workflows [-] [6220ee28a3eb83216afd4ce3] Updating workflow execution from **status "requested" to "running"**.

2022-03-03 16:36:22,267 139653800653632 INFO workflows [-] [6220edd5a3eb83216afd4cd5] Processing request for workflow execution. 2022-03-03 16:36:22,290 139653800653632 INFO workflows [-] [6220edd5a3eb83216afd4cd5] Requesting conductor to start running workflow execution. 2022-03-03 16:36:22,294 139653800653632 INFO workflows [-] [6220edd5a3eb83216afd4cd5] Identifying next set (iter 0) of tasks for workflow execution in status "running". 2022-03-03 16:36:22,300 139653800653632 INFO workflows [-] [6220edd5a3eb83216afd4cd5] Identified the following set of tasks to execute next: check_for_inprogress_hosts (route 0) 2022-03-03 16:36:22,303 139653800653632 INFO workflows [-] [6220edd5a3eb83216afd4cd5] Mark task "check_for_inprogress_hosts", route "0", in conductor as running. 2022-03-03 16:36:22,304 139653800653632 INFO workflows [-] [6220edd5a3eb83216afd4cd5] Updating workflow execution from **status "requested" to "running"**.

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start by tracing the scheduler's queue retrieval and the action.concurrency policy using the supplied scheduler and workflow logs. Compare enqueue, policy, and workflow execution timestamps for the two IDs, then reproduce the delayed single-concurrency case; done means executions preserve queue order rather than LIFO.

Written by the indexing model from the issue text.

Assessment

Tech stack
python
Domain
backend, devops
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
25/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.