Mistral : mistral_http task timeout not working on retry

asked 2018-04-03 06:32:35 -0500

rco gravatar image

updated 2018-04-04 07:41:01 -0500

Hello,

I have a workflow with a single mistral http task with a task timeout. When my task doesn't complete before the timeout the first time, the task is re-executed but the task timeout is not used in the retry.

Here is my workflow definiton :

---
version: "2.0"

workflow_test:
  type: direct
  tasks:
    put_product_category:
      action: std.mistral_http
      timeout : 10
      input:
        url: http://myserver:81/products/categories/ids"
        method: PUT
        headers:
          Content-Type: application/json
        body: "716"
      retry:
        delay: 4
        count: 2

And the execution logs from mistral-engine.log :

2018-04-03 09:12:17.745 233440 INFO workflow_trace [req-6bb8e518-350f-4e4e-87cd-d8c032add3db - - - - -] Workflow 'workflow_test' [IDLE -> RUNNING, msg=None] (execution_id=ec2c3a95-2516-4f63-a30e-cd08d8e960d7)
2018-04-03 09:12:17.753 233440 INFO workflow_trace [req-6bb8e518-350f-4e4e-87cd-d8c032add3db - - - - -] Timeout check scheduled [task=412b1f83-4f15-486e-9c1b-4d0848a44759, timeout(s)=10]. (execution_id=ec2c3a95-2516-4f63-a30e-cd08d8e960d7 task_id=412b1f83-4f15-486e-9c1b-4d0848a44759)
2018-04-03 09:12:54.529 233440 INFO workflow_trace [req-6bb8e518-350f-4e4e-87cd-d8c032add3db - - - - -] Task 'put_product_category' (412b1f83-4f15-486e-9c1b-4d0848a44759) [RUNNING -> ERROR, msg=Task timed out [timeout(s)=10].] (execution_id=ec2c3a95-2516-4f63-a30e-cd08d8e960d7)
2018-04-03 09:12:54.535 233440 INFO workflow_trace [req-6bb8e518-350f-4e4e-87cd-d8c032add3db - - - - -] Task 'put_product_category' [ERROR -> DELAYED, delay = 4 sec] (execution_id=ec2c3a95-2516-4f63-a30e-cd08d8e960d7 task_id=412b1f83-4f15-486e-9c1b-4d0848a44759)
2018-04-03 09:13:25.068 233440 INFO workflow_trace [req-6bb8e518-350f-4e4e-87cd-d8c032add3db - - - - -] Task 'put_product_category' (412b1f83-4f15-486e-9c1b-4d0848a44759) [DELAYED -> RUNNING, msg=None] (execution_id=ec2c3a95-2516-4f63-a30e-cd08d8e960d7)

I was expecting that the second execution use the same task timeout than the first try. Can you help me with this issue ?

I use mistral 3.2.0 without OpenStack.


update:

I created a new test with timeout and this time with a task containing a "join:all" :

---
version: '2.0'

wf_timeout:
  type: direct

  tasks:
    task1:
      timeout: 2
      action: std.echo output="task1"
      on-success:
        - task3

    task2:
      timeout: 2
      action: std.echo output="task2"
      on-success:
        - task3

    task3:
      join: all
      timeout: 2
      action: std.echo output="task3"

and in mistral-engine.log I have :

2018-04-04 12:33:46.618 233440 INFO mistral.engine.engine_server [req-6bb8e518-350f-4e4e-87cd-d8c032add3db - - - - -] Received RPC request 'start_workflow'[workflow_identifier=wf_timeout, workflow_input={}, description=, params={}]
2018-04-04 12:33:46.649 233440 INFO workflow_trace [req-6bb8e518-350f-4e4e-87cd-d8c032add3db - - - - -] Starting workflow [name=wf_timeout, input={}]
2018-04-04 12:33:46.654 233440 INFO workflow_trace [req-6bb8e518-350f-4e4e-87cd-d8c032add3db - - - - -] Workflow 'wf_timeout' [IDLE -> RUNNING, msg=None] (execution_id=503876c8-9927-43a9-b7bd-4b74493cb389)
2018-04-04 12:33:46.663 233440 INFO workflow_trace [req-6bb8e518-350f-4e4e-87cd-d8c032add3db - - - - -] Timeout check scheduled [task=e8a537c4-8aed-484c-8564-5f1932e12fa0, timeout(s)=2]. (execution_id=503876c8-9927-43a9-b7bd-4b74493cb389 task_id=e8a537c4-8aed-484c-8564-5f1932e12fa0)
2018-04-04 12:33:46.679 233440 INFO workflow_trace [req-6bb8e518-350f-4e4e-87cd-d8c032add3db - - - - -] Timeout check scheduled [task=9a22baa8-c3ae-4529-b6a7-334e2bc8dcf4, timeout(s)=2]. (execution_id=503876c8-9927-43a9-b7bd-4b74493cb389 task_id=9a22baa8-c3ae-4529-b6a7-334e2bc8dcf4)
2018-04-04 12:33:46.961 233440 INFO mistral.engine.engine_server [req-6bb8e518-350f-4e4e-87cd-d8c032add3db - - - - -] Received RPC request 'on_action_complete'[action_ex_id=645fd659-83bb-4b22-bd72-ea9e4d9b81df, result=Result [data=task2, error=None, cancel=False]]
2018-04-04 12:33:46.966 233440 INFO workflow_trace [req-6bb8e518-350f-4e4e-87cd-d8c032add3db - - - - -] Action 'std.echo' (645fd659-83bb-4b22-bd72-ea9e4d9b81df)(task=task2) [RUNNING -> SUCCESS, result = task2]
2018-04-04 12:33:46.977 233440 INFO workflow_trace [req-6bb8e518-350f-4e4e-87cd-d8c032add3db - - - - -] Task 'task2' (e8a537c4-8aed-484c-8564-5f1932e12fa0) [RUNNING -> SUCCESS, msg=None] (execution_id=503876c8-9927-43a9-b7bd-4b74493cb389)
2018-04-04 12:33:47.075 233440 INFO mistral.engine.engine_server [req-6bb8e518-350f-4e4e-87cd-d8c032add3db - - - - -] Received RPC request 'on_action_complete'[action_ex_id=ad151ce4-369b-4864-a329-3a8050c20323, result=Result [data=task1, error=None, cancel=False]]
2018-04-04 12:33:47.080 233440 INFO workflow_trace [req-6bb8e518-350f-4e4e-87cd-d8c032add3db - - - - -] Action 'std.echo' (ad151ce4-369b-4864-a329-3a8050c20323)(task=task1) [RUNNING -> SUCCESS, result = task1]
2018-04-04 12:33:47.091 233440 INFO workflow_trace [req-6bb8e518-350f-4e4e-87cd-d8c032add3db - - - - -] Task 'task1' (9a22baa8-c3ae-4529-b6a7-334e2bc8dcf4) [RUNNING -> SUCCESS, msg=None] (execution_id=503876c8-9927-43a9-b7bd-4b74493cb389)
2018-04-04 12:34:22.933 ...
(more)
edit retag flag offensive close merge delete