Git Product home page Git Product logo

Comments (6)

BishoyDemian avatar BishoyDemian commented on June 5, 2024 6

We have been experiencing similar performance degradation with a complex workflow that has other sub-workflows where the delay between a sub-workflow & task completion and the next task execution keeps growing exponentially when multiple workflow executions are happening in parallel.

We also noticed the st2workflowengine CPU consumption skyrocketing to 100% and its only utilising 1 CPU core.

Since we have an enterprise license for EWC (the commercial version of stackstorm), I submitted a support ticket through that channel to Extreme Networks. However, I'm leaving the comment here to let the community know about this issue.

from orquesta.

killsudo avatar killsudo commented on June 5, 2024

Using the following as an example execution,

5c9ec7ccda6c0b4fdb2f1a3e | succeeded (242s elapsed) | fetch_server_hardware_ssd | easydcim.show_device_parts | Sat, 30 Mar 2019 01:35:07 UTC

/var/log/st2/st2workflowengine.log:2019-03-29 20:35:09,910 140546567828976 AUDIT action [-] Action execution requested. LiveAction.id=5c9ec7ccda6c0b4fdb2f1a3d, ActionExecution.id=5c9ec7ccda6c0b4fdb2f1a3e
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:09,911 140546567828976 INFO workflows [-] [5c9ec790da6c0b4fcafcce20] Action execution "5c9ec7ccda6c0b4fdb2f1a3e" requested for task "fetch_server_hardware_ssd", route "5".
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:11,622 140546566645072 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Processing request for workflow execution.
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:12,841 140546566646672 INFO workflows [-] [5c9ec790da6c0b4fcafcce20] Action execution "5c9ec7ccda6c0b4fdb2f1a3e" for task "fetch_server_hardware_ssd" is updated and in "scheduled" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:13,356 140546572133712 INFO workflows [-] [5c9ec790da6c0b4fcafcce20] Action execution "5c9ec7ccda6c0b4fdb2f1a3e" for task "fetch_server_hardware_ssd" is updated and in "running" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:13,412 140546566645072 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Requesting conductor to start running workflow execution.
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:13,413 140546566645072 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Identifying next set (0) of tasks for workflow execution in status "running".
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:13,421 140546566645072 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Identified the following set of tasks to execute next: fetch_item_list (route 0)
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:13,422 140546566645072 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Mark task "fetch_item_list", route "0", in conductor as running.
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:13,425 140546566645072 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Updating workflow execution from status "requested" to "running".
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:16,942 140546566645072 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Requesting execution for task "fetch_item_list", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:16,943 140546566645072 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Processing task execution request for task "fetch_item_list", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:17,191 140546566645072 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Task execution "5c9ec7d5da6c0b4fdb2f1a46" created for task "fetch_item_list", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:28,045 140546566647312 INFO workflows [-] [5c9ec790da6c0b4fcafcce20] Action execution "5c9ec7ccda6c0b4fdb2f1a3e" for task "fetch_server_hardware_ssd" is updated and in "running" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:28,235 140546566645072 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec7d7da6c0b4fdb2f1a4e" requested for task "fetch_item_list", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:28,366 140546566645072 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Identifying next set (1) of tasks for workflow execution in status "running".
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:28,368 140546566645072 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] No tasks identified to execute next.
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:28,460 140546566645072 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec7d7da6c0b4fdb2f1a4e" for task "fetch_item_list" is updated and in "scheduled" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:30,077 140546558973264 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec7d7da6c0b4fdb2f1a4e" for task "fetch_item_list" is updated and in "running" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:30,726 140546567831376 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec7d7da6c0b4fdb2f1a4e" for task "fetch_item_list" is updated and in "succeeded" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:31,333 140546567831376 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Handling completion of action execution "5c9ec7d7da6c0b4fdb2f1a4e" in status "succeeded" for task "fetch_item_list", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:36,798 140546567831376 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Publish task "fetch_item_list", route "0", with status "succeeded" to conductor.
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:38,101 140546567831376 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Identifying next set (0) of tasks after completion of task "fetch_item_list", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:38,124 140546567831376 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Identified the following set of tasks to execute next: fetch_hw_item (route 0), notify (route 1)
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:38,125 140546567831376 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Mark task "fetch_hw_item", route "0", in conductor as running.
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:38,125 140546567831376 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Mark task "fetch_hw_item", route "0", item "0" in conductor as running.
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:38,126 140546567831376 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Mark task "fetch_hw_item", route "0", item "1" in conductor as running.
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:38,127 140546567831376 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Mark task "notify", route "1", in conductor as running.
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:44,810 140546567831376 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Requesting execution for task "fetch_hw_item", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:44,811 140546567831376 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Processing task execution request for task "fetch_hw_item", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:45,448 140546567831376 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Task execution "5c9ec7f1da6c0b4fdb2f1a5e" created for task "fetch_hw_item", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:53,022 140546553945616 INFO workflows [-] [5c9ec790da6c0b4fcafcce20] Action execution "5c9ec7ccda6c0b4fdb2f1a3e" for task "fetch_server_hardware_ssd" is updated and in "running" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:53,959 140546567831376 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec7f5da6c0b4fdb2f1a66" requested for task "fetch_hw_item", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:54,513 140546551317200 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec7f5da6c0b4fdb2f1a66" for task "fetch_hw_item" is updated and in "scheduled" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:54,779 140546553945616 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec7f5da6c0b4fdb2f1a66" for task "fetch_hw_item" is updated and in "running" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:35:57,001 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec7f5da6c0b4fdb2f1a66" for task "fetch_hw_item" is updated and in "succeeded" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:13,414 140546566221008 INFO workflows [-] [5c9ec790da6c0b4fcafcce20] Action execution "5c9ec7ccda6c0b4fdb2f1a3e" for task "fetch_server_hardware_ssd" is updated and in "running" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:15,493 140546567831376 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec803da6c0b4fdb2f1a70" requested for task "fetch_hw_item", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:17,106 140546567831376 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Requesting execution for task "notify", route "1".
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:17,107 140546567831376 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Processing task execution request for task "notify", route "1".
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:17,611 140546555015248 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec803da6c0b4fdb2f1a70" for task "fetch_hw_item" is updated and in "running" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:17,745 140546567831376 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Task execution "5c9ec811da6c0b4fdb2f1a74" created for task "notify", route "1".
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:17,835 140546567828496 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec803da6c0b4fdb2f1a70" for task "fetch_hw_item" is updated and in "scheduled" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:18,048 140546572134992 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec803da6c0b4fdb2f1a70" for task "fetch_hw_item" is updated and in "succeeded" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:25,830 140546566221168 INFO workflows [-] [5c9ec790da6c0b4fcafcce20] Action execution "5c9ec7ccda6c0b4fdb2f1a3e" for task "fetch_server_hardware_ssd" is updated and in "running" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:27,180 140546567831376 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec815da6c0b4fdb2f1a7b" requested for task "notify", route "1".
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:27,532 140546558972144 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec815da6c0b4fdb2f1a7b" for task "notify" is updated and in "scheduled" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:27,609 140546567831376 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Identifying next set (1) of tasks for workflow execution in status "running".
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:27,630 140546567831376 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] No tasks identified to execute next.
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:27,671 140546567429648 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec815da6c0b4fdb2f1a7b" for task "notify" is updated and in "running" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:27,897 140546558974704 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec815da6c0b4fdb2f1a7b" for task "notify" is updated and in "succeeded" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:28,473 140546572134992 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Handling completion of action execution "5c9ec803da6c0b4fdb2f1a70" in status "succeeded" for task "fetch_hw_item", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:33,216 140546572134992 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Publish task "fetch_hw_item", route "0", with status "running" to conductor.
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:34,714 140546572134992 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Identifying next set (0) of tasks after completion of task "fetch_hw_item", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:34,738 140546572134992 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] No tasks identified to execute next.
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:39,789 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Handling completion of action execution "5c9ec7f5da6c0b4fdb2f1a66" in status "succeeded" for task "fetch_hw_item", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:41,337 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Publish task "fetch_hw_item", route "0", with status "succeeded" to conductor.
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:42,878 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Identifying next set (0) of tasks after completion of task "fetch_hw_item", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:42,923 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Identified the following set of tasks to execute next: close_request (route 0), notify (route 2), print_hw_item_id (route 0)
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:42,923 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Mark task "close_request", route "0", in conductor as running.
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:42,925 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Mark task "notify", route "2", in conductor as running.
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:42,926 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Mark task "print_hw_item_id", route "0", in conductor as running.
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:48,878 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Requesting execution for task "close_request", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:48,879 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Processing task execution request for task "close_request", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:36:49,055 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Task execution "5c9ec830da6c0b4fdb2f1a8f" created for task "close_request", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:04,654 140546555017488 INFO workflows [-] [5c9ec790da6c0b4fcafcce20] Action execution "5c9ec7ccda6c0b4fdb2f1a3e" for task "fetch_server_hardware_ssd" is updated and in "running" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:05,555 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec836da6c0b4fdb2f1a94" requested for task "close_request", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:06,155 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Requesting execution for task "notify", route "2".
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:06,156 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Processing task execution request for task "notify", route "2".
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:06,904 140546566645872 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec836da6c0b4fdb2f1a94" for task "close_request" is updated and in "scheduled" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:06,958 140546561632848 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec836da6c0b4fdb2f1a94" for task "close_request" is updated and in "running" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:07,045 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Task execution "5c9ec842da6c0b4fdb2f1a98" created for task "notify", route "2".
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:08,007 140546561634128 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec836da6c0b4fdb2f1a94" for task "close_request" is updated and in "succeeded" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:26,502 140546566220688 INFO workflows [-] [5c9ec790da6c0b4fcafcce20] Action execution "5c9ec7ccda6c0b4fdb2f1a3e" for task "fetch_server_hardware_ssd" is updated and in "running" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:26,988 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec84cda6c0b4fdb2f1a9c" requested for task "notify", route "2".
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:27,691 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Requesting execution for task "print_hw_item_id", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:27,692 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Processing task execution request for task "print_hw_item_id", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:28,636 140546567981968 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec84cda6c0b4fdb2f1a9c" for task "notify" is updated and in "scheduled" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:29,122 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Task execution "5c9ec858da6c0b4fdb2f1a9f" created for task "print_hw_item_id", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:29,899 140546569895440 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec84cda6c0b4fdb2f1a9c" for task "notify" is updated and in "running" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:30,521 140546561632528 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec84cda6c0b4fdb2f1a9c" for task "notify" is updated and in "succeeded" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:47,028 140546558973424 INFO workflows [-] [5c9ec790da6c0b4fcafcce20] Action execution "5c9ec7ccda6c0b4fdb2f1a3e" for task "fetch_server_hardware_ssd" is updated and in "running" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:47,889 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec85eda6c0b4fdb2f1aa5" requested for task "print_hw_item_id", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:49,370 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Identifying next set (1) of tasks for workflow execution in status "running".
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:49,379 140546558973584 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] No tasks identified to execute next.
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:49,685 140546569895440 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec85eda6c0b4fdb2f1aa5" for task "print_hw_item_id" is updated and in "scheduled" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:49,783 140546561632368 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec85eda6c0b4fdb2f1aa5" for task "print_hw_item_id" is updated and in "running" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:50,001 140546567979088 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec85eda6c0b4fdb2f1aa5" for task "print_hw_item_id" is updated and in "succeeded" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:50,534 140546561634128 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Handling completion of action execution "5c9ec836da6c0b4fdb2f1a94" in status "succeeded" for task "close_request", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:53,475 140546561634128 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Publish task "close_request", route "0", with status "succeeded" to conductor.
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:55,624 140546561634128 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Identifying next set (0) of tasks after completion of task "close_request", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:55,645 140546561634128 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Identified the following set of tasks to execute next: notify (route 3)
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:55,646 140546561634128 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Mark task "notify", route "3", in conductor as running.
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:58,215 140546561634128 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Requesting execution for task "notify", route "3".
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:58,217 140546561634128 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Processing task execution request for task "notify", route "3".
/var/log/st2/st2workflowengine.log:2019-03-29 20:37:58,794 140546561634128 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Task execution "5c9ec876da6c0b4fdb2f1aad" created for task "notify", route "3".
/var/log/st2/st2workflowengine.log:2019-03-29 20:38:19,492 140546572132432 INFO workflows [-] [5c9ec790da6c0b4fcafcce20] Action execution "5c9ec7ccda6c0b4fdb2f1a3e" for task "fetch_server_hardware_ssd" is updated and in "running" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:38:21,151 140546561634128 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec87fda6c0b4fdb2f1ab1" requested for task "notify", route "3".
/var/log/st2/st2workflowengine.log:2019-03-29 20:38:21,559 140546567429008 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec87fda6c0b4fdb2f1ab1" for task "notify" is updated and in "scheduled" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:38:21,703 140546561634128 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Identifying next set (1) of tasks for workflow execution in status "running".
/var/log/st2/st2workflowengine.log:2019-03-29 20:38:21,712 140546561634128 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] No tasks identified to execute next.
/var/log/st2/st2workflowengine.log:2019-03-29 20:38:21,774 140546566644752 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec87fda6c0b4fdb2f1ab1" for task "notify" is updated and in "running" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:38:22,386 140546567828976 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Action execution "5c9ec87fda6c0b4fdb2f1ab1" for task "notify" is updated and in "succeeded" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:38:22,768 140546567979088 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Handling completion of action execution "5c9ec85eda6c0b4fdb2f1aa5" in status "succeeded" for task "print_hw_item_id", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:38:25,921 140546567979088 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Publish task "print_hw_item_id", route "0", with status "succeeded" to conductor.
/var/log/st2/st2workflowengine.log:2019-03-29 20:38:27,889 140546567979088 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Identifying next set (0) of tasks after completion of task "print_hw_item_id", route "0".
/var/log/st2/st2workflowengine.log:2019-03-29 20:38:27,898 140546567979088 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] No tasks identified to execute next.
/var/log/st2/st2workflowengine.log:2019-03-29 20:38:30,768 140546558974704 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Handling completion of action execution "5c9ec815da6c0b4fdb2f1a7b" in status "succeeded" for task "notify", route "1".
/var/log/st2/st2workflowengine.log:2019-03-29 20:38:33,967 140546558974704 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Publish task "notify", route "1", with status "succeeded" to conductor.
/var/log/st2/st2workflowengine.log:2019-03-29 20:38:37,136 140546558974704 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Identifying next set (0) of tasks after completion of task "notify", route "1".
/var/log/st2/st2workflowengine.log:2019-03-29 20:38:37,145 140546558974704 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] No tasks identified to execute next.
/var/log/st2/st2workflowengine.log:2019-03-29 20:38:41,955 140546561632528 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Handling completion of action execution "5c9ec84cda6c0b4fdb2f1a9c" in status "succeeded" for task "notify", route "2".
/var/log/st2/st2workflowengine.log:2019-03-29 20:38:43,394 140546561632528 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Publish task "notify", route "2", with status "succeeded" to conductor.
/var/log/st2/st2workflowengine.log:2019-03-29 20:38:44,715 140546561632528 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Identifying next set (0) of tasks after completion of task "notify", route "2".
/var/log/st2/st2workflowengine.log:2019-03-29 20:38:44,725 140546561632528 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] No tasks identified to execute next.
/var/log/st2/st2workflowengine.log:2019-03-29 20:38:56,203 140546567828976 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Handling completion of action execution "5c9ec87fda6c0b4fdb2f1ab1" in status "succeeded" for task "notify", route "3".
/var/log/st2/st2workflowengine.log:2019-03-29 20:39:00,657 140546567828976 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Publish task "notify", route "3", with status "succeeded" to conductor.
/var/log/st2/st2workflowengine.log:2019-03-29 20:39:00,704 140546567828976 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Updating workflow execution from status "running" to "succeeded".
/var/log/st2/st2workflowengine.log:2019-03-29 20:39:03,301 140546567828976 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Workflow action execution is completed and invoking post run.
/var/log/st2/st2workflowengine.log:2019-03-29 20:39:04,462 140546567136432 INFO workflows [-] [5c9ec790da6c0b4fcafcce20] Action execution "5c9ec7ccda6c0b4fdb2f1a3e" for task "fetch_server_hardware_ssd" is updated and in "succeeded" state.
/var/log/st2/st2workflowengine.log:2019-03-29 20:39:04,908 140546567828976 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Identifying next set (0) of tasks after completion of task "notify", route "3".
/var/log/st2/st2workflowengine.log:2019-03-29 20:39:04,919 140546567828976 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] No tasks identified to execute next.
/var/log/st2/st2workflowengine.log:2019-03-29 20:39:08,928 140546567828976 INFO workflows [-] [5c9ec7ccda6c0b4fdb2f1a3e] Workflow execution is in completed status "succeeded".
/var/log/st2/st2workflowengine.log:2019-03-29 20:39:14,924 140546567136432 INFO workflows [-] [5c9ec790da6c0b4fcafcce20] Handling completion of action execution "5c9ec7ccda6c0b4fdb2f1a3e" in status "succeeded" for task "fetch_server_hardware_ssd", route "5".

from orquesta.

killsudo avatar killsudo commented on June 5, 2024

Sub-Workflow being called

# cat show_device_parts.yaml 
version: 1.0

description: Return list of hardware parts for dcim device

input:
  - id_num
  - type_id

vars:
  - hw_item_list: {}

tasks:

  fetch_item_list:
    action: easydcim.list_items
    input:
      type_id: <% ctx().type_id %>
    next:
      - when: <% succeeded() %>
        publish:
          - status_message: "Successfully fetched items from EasyDCIM"
          - item_list: <% result().result.api_payload.result.where($.parent_id = ctx('id_num')).select($.id) %>
          - stdout: <% result().stdout %>
          - stderr: <% result().stderr %>
        do:
          - notify
          - fetch_hw_item

  fetch_hw_item:
    with: <% ctx(item_list) %>
    action: easydcim.show_item
    input:
      id_num: <% item() %>
    next:
      - when: <% succeeded() %>
        publish:
          - status_message: "Successfully fetched EasyDCIM Item details"
          - hw_item_list: <% result().result.api_payload.result %>
          - hw_item_id: <% result().result.api_payload.result.id %>
          - stdout: <% result().stdout %>
          - stderr: <% result().stderr %>
        do:
          - notify
          - print_hw_item_id
          - close_request

  close_request:
    action: core.noop
    next:
      - when: <% succeeded() %>
        publish:
          - status_message: "EasyDCIM Item list successfully returned."
        do:
          - notify

  print_hw_item_id:
    action: core.echo message="Collected the following items by id <% ctx(hw_item_id) %>"

  notify:
    action: core.echo message="<% ctx(status_message) %> "

output:
  - {"result": <% ctx(hw_item_list) %>}

from orquesta.

killsudo avatar killsudo commented on June 5, 2024

Main workflow

# cat process_easydcim_order.yaml 
version: 1.0

description: Process EasyDCIM Order to return hardware list

input:
  - easydcim_order_id

vars:
  - hw_item_list: {}

tasks:

  lookup_order:
    action: easydcim.show_order
    input:
      id_num: <% ctx(easydcim_order_id) %>
    next:
      - when: <% succeeded() %>
        publish:
          - status_message: "Successfully fetched EasyDCIM Order id: <% ctx(easydcim_order_id) %>"
          - chatop_message: "Stackstorm is processing EasyDCIM Order id: <% ctx(easydcim_order_id) %>"
          # Register the entire response for processing
          - order_payload: <% result().result.api_payload.result %>
          # Is the order pending or accepted?
          - order_status: <% result().result.api_payload.result.status %>
          - stdout: <% result().stdout %>
          - stderr: <% result().stderr %>
        do: 
          - notify
          - chatop_notify
          - register_order
      - when: <% failed() %>
        publish:
          - status_message: "Could not connect to EasyDCIM. Check Pack configuration."
          - chatop_message: "Stackstorm could not process EasyDCIM Order id: <% ctx(easydcim_order_id) %> , \n
                             Make sure EasyDCIM pack is configured properly."
        do:
          - notify
          - chatop_notify
  
  register_order:
    next:
      - when: <% ctx(order_status) = 'accepted' %>
        publish:
          - status_message: "Successfully Registered EasyDCIM Order details"
          # Server or Colocation Type?
          - order_type: <% ctx(order_payload).type %>
          # Is the service on the order pending or activated?
          - order_service_status: <% ctx(order_payload).service_status %>
          # User id integer
          - order_user_id: <% ctx(order_payload).user_id %>
          # User email - Should be able to look client up in whmcs
          - order_user_email: <% ctx(order_payload).user.email %>
          # Device id integer
          - order_device_id: <% ctx(order_payload).service.related_id %>
        do:
          - notify
          - process_order
      - when: <% ctx(order_status) = 'pending' %>
        publish:
          - status_message: "EasyDCIM order still pending. Assign hardware and accept order to continue."
          - chatop_message: "EasyDCIM Order id: <% ctx(easydcim_order_id) %>, is still pending. \n
                             Make sure that a server has been assigned to the EasyDCIM order."
        do:
          - notify
          - chatop_notify
          
  process_order:
    next:
      - when: <% ctx(order_type) = 'Colocation' %>
        publish:
          - status_message: "EasyDCIM Order type Colocation identified."
        do:
          - notify
          - fetch_order_device
      - when: <% ctx(order_type) = 'Server' %>
        publish:
          - status_message: "EasyDCIM Order type Server identified. Begin Server Provisioning"
          - chatop_message: "EasyDCIM Order id: <% ctx(easydcim_order_id) %>, Found Server Type."
        do:
          - notify
          - chatop_notify
          - fetch_order_device
          
  fetch_order_device:
    action: easydcim.show_device
    input:
      id_num: <% ctx('order_device_id') %>
    next:
      - when: <% succeeded() %>
        publish:
          - status_message: "Successfully fetched EasyDCIM Device: <% result().result.api_payload.result.model %> - <% result().result.api_payload.result.label %>"
          - device_payload: <% result().result.api_payload.result %>
          - device_model: <% result().result.api_payload.result.model %>
          - device_label: <% result().result.api_payload.result.label %>
          - device_hpevcm_profile: <% result().result.api_payload.result.metadata.get('HP-VCM Profile') %>
          - chatop_message: "Located Device <% result().result.api_payload.result.label %> on EasyDCIM Order id: <% ctx(easydcim_order_id) %> "
          - stdout: <% result().stdout %>
          - stderr: <% result().stderr %>
        do:
          - notify
          - chatop_notify
          - map_blade_chassis
          - fetch_server_hardware_cpu
          - fetch_server_hardware_ram
          - fetch_server_hardware_hdd
          - fetch_server_hardware_ssd
          - fetch_server_hardware_san
          
  map_blade_chassis:
    action: easydcim.list_device_bays
    next:
      - when: <% succeeded() %>
        publish:
          - status_message: "Successfully fetched EasyDCIM device bay list for processing."
          - chassis_id: <% result().result.api_payload.result.where($.child_id = ctx().order_device_id).select($.parent_id).single() %>
          - chatop_message: "Matching blade <% ctx('device_label') %> to chassis. "
        do:
          - notify
          - chatop_notify
          - fetch_blade_chassis
          
  fetch_blade_chassis:
    action: easydcim.show_device
    input:
      id_num: <% ctx(chassis_id) %>
    next:
      - when: <% succeeded() %>
        publish:
          - status_message: "Locating HP Virtual Connect Hostname for <% ctx('device_label') %>"
          - chassis_payload: <% result().result.api_payload.result %>
          - hp_vcm_hostname: <% result().result.api_payload.result.metadata.get('HP-VCM Hostname') %>
          - hp_chassis_label: <% result().result.api_payload.result.label %>
          - chatop_message: "Found blade chassis <% result().result.api_payload.result.metadata.Hostname %>"
        do:
          - notify
          - chatop_notify
          - publish_hardware_list
          
  fetch_server_hardware_cpu:
    action: easydcim.show_device_parts
    input:
      id_num: <% ctx('order_device_id') %>
      type_id: 11
    next:
      - when: <% succeeded() %>
        publish:
          - status_message: "Successfully fetched EasyDCIM device hardware for <% ctx('device_label') %> - CPUs"
          - chatop_message: "<% ctx('device_label') %> - Assigned CPUs - Located"
          - hw_item_cpu_list: <% result().output.result %>
        do:
          - notify
          - publish_hardware_list
          - chatop_notify
          
  fetch_server_hardware_ram:
    action: easydcim.show_device_parts
    input:
      id_num: <% ctx('order_device_id') %>
      type_id: 10
    next:
      - when: <% succeeded() %>
        publish:
          - status_message: "Successfully fetched EasyDCIM device hardware for <% ctx('device_label') %> - RAM modules"
          - chatop_message: "<% ctx('device_label') %> - Assigned RAM - Located"
          - hw_item_ram_list: <% result().output.result %>
        do:
          - notify
          - publish_hardware_list
          - chatop_notify
          
  fetch_server_hardware_hdd:
    action: easydcim.show_device_parts
    input:
      id_num: <% ctx('order_device_id') %>
      type_id: 8
    next:
      - when: <% succeeded() %>
        publish:
          - status_message: "Successfully fetched EasyDCIM device hardware for <% ctx('device_label') %> - HDD Disks"
          - chatop_message: "<% ctx('device_label') %> - Assigned HDD Disks - Located"
          - hw_item_hdd_list: <% result().output.result %>
        do:
          - notify
          - publish_hardware_list
          - chatop_notify

  fetch_server_hardware_ssd:
    action: easydcim.show_device_parts
    input:
      id_num: <% ctx('order_device_id') %>
      type_id: 9
    next:
      - when: <% succeeded() %>
        publish:
          - status_message: "Successfully fetched EasyDCIM device hardware for <% ctx('device_label') %> - SSD Disks"
          - chatop_message: "<% ctx('device_label') %> - Assigned SSD Disks - Located"
          - hw_item_ssd_list: <% result().output.result %>
        do:
          - notify
          - publish_hardware_list
          - chatop_notify

  fetch_server_hardware_san:
    action: easydcim.show_device_parts
    input:
      id_num: <% ctx('order_device_id') %>
      type_id: 20
    next:
      - when: <% succeeded() %>
        publish:
          - status_message: "Successfully fetched EasyDCIM device hardware for <% ctx('device_label') %> - SAN Disks"
          - chatop_message: "<% ctx('device_label') %> - Assigned SAN Disks - Located"
          - hw_item_san_list: <% result().output.result %>
        do:
          - notify
          - publish_hardware_list
          - chatop_notify

  publish_hardware_list:
    join: all
    action: core.echo message="Compiling list of hardware items for <% ctx('device_label') %>"
    next:
      - when: <% succeeded() %>
        publish:
          - chatop_message: "Successfully compiled hardware list for EasyDCIM Order id: <% ctx(easydcim_order_id) %>"
          - hw_item_list:
              - device: <% ctx(device_payload) %>
              - cpu_hw: <% ctx(hw_item_cpu_list) %>
              - ram_hw: <% ctx(hw_item_ram_list) %>
              - hdd_hw: <% ctx(hw_item_hdd_list) %>
              - ssd_hw: <% ctx(hw_item_ssd_list) %>
              - san_hw: <% ctx(hw_item_san_list) %>
              - chassis: <% ctx(chassis_payload) %>
        do:
          - chatop_notify
          - close_request

  close_request:
    action: core.noop
    next:
      - when: <% succeeded() %>
        publish:
          - status_message: "EasyDCIM order successfully processed."
          - chatop_message: "Launching tasks to provision EasyDCIM Order id: <% ctx(easydcim_order_id) %>"
        do:
          - notify
          - chatop_notify

  chatop_notify:
    action: chatops.post_message
    input:
      channel: "9gw3pkxznjrtjcnjxwm5sxkxoh"
      message: "**Notice:** <% ctx(chatop_message) %> {~}"
    next:
      - when: <% succeeded() %>
        publish:
          - status_message: "Notified Team via chatops."
        do:
          - notify

  notify:
    action: core.echo message="<% ctx(status_message) %> "

output:
  - {"result": <% ctx(hw_item_list) %>}

from orquesta.

userlocalhost avatar userlocalhost commented on June 5, 2024

I confirmed similar symptom was happened with this.
As the number of tasks is increased, the proceeding time of sub-workflow would be longer as below.

Result

I ran same workflow (wf_scalable_check which is mentioned later) that runs another workflow (sub-workflow, wf_intermediate which is also mentioned later) with changing iteration number.
In proportion to the iteration number, processing time of sub-workflow until it is completed would be longer.

These are the average time to complete of the sub-workflow for each cases that changed number of tasks parameter.

3 sec (iteration number is 2)

スクリーンショット 2019-07-30 18 10 50

21 sec (iteration number is 10)

スクリーンショット 2019-07-30 18 13 26

27 sec (iteration number is 20)

スクリーンショット 2019-07-30 18 14 56

How to confirm this

This describes the definitions of workflows which are shown in above.

wf_scalable_check ---+
                     |
                     +--- wf_intermediate ---+
                                             |
                                             +--- core.noop (action)

wf_scalable_check.yaml

---
name: wf_scalable_check
description: A workflow to check performance when large amount of workflow would be run
runner_type: orquesta
entry_point: workflows/wf_scalable_check.yaml
enabled: true
parameters:
  number_of_tasks:
    type: integer
    default: 10

workflows/wf_scalable_check.yaml

version: 1.0
description: Check performance when large amount of workflow would be run
input:
  - number_of_tasks

tasks:
  intermediate_task:
    with:
      items: <% range(ctx(number_of_tasks)).toList().select(str($)) %>
    action: default.wf_intermediate

wf_intermediate.yaml

---
name: wf_intermediate
description: Intermediate workflow to check performance
runner_type: orquesta
entry_point: workflows/wf_intermediate.yaml
enabled: true
parameters: {}

workflows/wf_intermediate.yaml

version: 1.0
description: Intermediate workflow to check performance

tasks:
  task:
    action: core.noop

Environment information

(virtualenv) vagrant@ubuntu1:~$ st2 --version
st2 3.2dev, on Python 2.7.15
(virtualenv) vagrant@ubuntu1:~$ pip show orquesta
DEPRECATION: Python 2.7 will reach the end of its life on January 1st, 2020. Please upgrade your Python as Python 2.7 won't be maintained after that date. A future version of pip will drop support for Python 2.7.
Name: orquesta
Version: 1.0.0
Summary: UNKNOWN
Home-page: https://www.stackstorm.com
Author: StackStorm
Author-email: [email protected]
License: Apache License (2.0)
Location: /home/vagrant/st2/virtualenv/lib/python2.7/site-packages
Requires: eventlet, jsonschema, chardet, networkx, stevedore, python-dateutil, Jinja2, yaql, PyYAML, six
Required-by: st2common, stackstorm-runner-orquesta
(virtualenv) vagrant@ubuntu1:~$ 

from orquesta.

m4dcoder avatar m4dcoder commented on June 5, 2024

There are known issues documented. The current version of orquesta (st2 v3.2) is sensitive to large JSON writes to the MongoDB. If the workflow input or action output that are published into the workflow context are huge or that there are a lot of items in the list passed to a with items task, this will increase the size of the workflow state that will be written to the database. This will result in longer writes to the database and thus increase the latency in between task transition and impact resources utilization on the system.

To minimize this

  • avoid passing large amount of data directly as input into the workflow
  • avoid passing large amount of data from the action execution output and then publish into another variable in the workflow.

There are workarounds to passing large amount of data in the workflow

  • store the large data in redis and then pass the key into the workflow
  • use task().result to access the large action execution output instead of publishing the data into another variable in the workflow
  • in st2 3.2, we refactored with items list to store less data in the workflow state

If the latency and performance issue is load related and not data related, then we have success case where adding additional st2workflowengine services will distribute the load.

from orquesta.

Related Issues (20)

Recommend Projects

  • React photo React

    A declarative, efficient, and flexible JavaScript library for building user interfaces.

  • Vue.js photo Vue.js

    🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.

  • Typescript photo Typescript

    TypeScript is a superset of JavaScript that compiles to clean JavaScript output.

  • TensorFlow photo TensorFlow

    An Open Source Machine Learning Framework for Everyone

  • Django photo Django

    The Web framework for perfectionists with deadlines.

  • D3 photo D3

    Bring data to life with SVG, Canvas and HTML. 📊📈🎉

Recommend Topics

  • javascript

    JavaScript (JS) is a lightweight interpreted programming language with first-class functions.

  • web

    Some thing interesting about web. New door for the world.

  • server

    A server is a program made to process requests and deliver data to clients.

  • Machine learning

    Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.

  • Game

    Some thing interesting about game, make everyone happy.

Recommend Org

  • Facebook photo Facebook

    We are working to build community through open source technology. NB: members must have two-factor auth.

  • Microsoft photo Microsoft

    Open source projects and samples from Microsoft.

  • Google photo Google

    Google ❤️ Open Source for everyone.

  • D3 photo D3

    Data-Driven Documents codes.