Task with join runs more than once

[Limor Stotland]

Steps for reproduce:
1. create workflow :
p_d:
  tasks:
    list_servers:
      action: std.echo output='1'
      on-success: [start_heal_servers_workflow]
    list_stack_servers:
      action: std.echo output='2'
      on-success: [start_heal_servers_workflow]
    start_heal_servers_workflow:
      action: std.echo output='3'
      join: all
  type: direct
version: '2.0'
2. rum wf from 1
3. rum task-list

result:
+--------------------------------------+-----------------------------+---------------+--------------------------------------+---------+------------+
| ID | Name | Workflow name | Execution ID | State | State info |
+--------------------------------------+-----------------------------+---------------+--------------------------------------+---------+------------+
| a7980263-15e9-4298-b8b5-6044eb2c10ae | list_stack_servers | p_d | 9616f763-21b0-4b81-88cb-a8f3c779f7ba | SUCCESS | None |
| c917e57e-a2bb-4cde-a9ac-6e323ab7c92b | list_servers | p_d | 9616f763-21b0-4b81-88cb-a8f3c779f7ba | SUCCESS | None |
| 3f775a58-7bb4-465f-bea5-23f368301bc7 | start_heal_servers_workflow | p_d | 9616f763-21b0-4b81-88cb-a8f3c779f7ba | SUCCESS | None |
| e1cb2afe-845d-49e3-ab93-6368b6a620cc | start_heal_servers_workflow | p_d | 9616f763-21b0-4b81-88cb-a8f3c779f7ba | SUCCESS | None |
+--------------------------------------+-----------------------------+---------------+--------------------------------------+---------+------------+

expected result:
task start_heal_servers_workflow scheduler run only once (because of the join)

[Lingxian Kong (kong)]

Limor,

I have tested your workflow, it worked as expected in my deployment, are you testing it in HA mode?

[Moshe Elisha (melisha)]

Lingxian,

Yes - we are running in HA (three of everything).

I verified what you said that by default on DevStack it is not reproduced but I was able to reproduce after I started another engine and executor on my DevStack with the following command:

/usr/bin/python /usr/local/bin/mistral-server --server engine,executor --config-file /etc/mistral/mistral.conf

[Dawid Deja (dawid-deja-0)]

I have just hit it on my Devstack without HA - just one engine and executor

[Guy Paz (guy-paz)]

Thanks Dawid Deja.

Is it happened all the time for you ?
are you using the same WF I attached ?

[Dawid Deja (dawid-deja-0)]

Guy Paz,

It is happening all the time when using attached WF. I think it may be related to this bug: https://bugs.launchpad.net/mistral/+bug/1535722

I have done some debbuging and when we have to tasks that ends at the same time, we have two parallel threads running code from default_engine.py. In the first thread, calling this[1] line result in two cmds (len(cmds) equals 2), when calling it in second thread, cmds is empty list.

[1] https://github.com/openstack/mistral/blob/master/mistral/engine/default_engine.py#L182

[Dawid Deja (dawid-deja-0)]

Unfortunately, I can't work on this bug, but I found the root cause, so someone else can fix it.

Scenario:
Let's assume that we have two tasks, A and B, both run task C on success. Task C has 'join' property set to 'all'

How it was intended to work:
Task A ends. While in 'on_action_complete' function, it check in workflow which tasks are ended[1]. It only finds task A, so it looks which tasks are intended to run after A. It finds C, but since join is not satisfied, it sets C to 'Paused' state. Then task B ends, transition is going same, the only difference is that task C is already in DB, so it only change it state to 'RUNNING'. Task C is run once

How it works in case of race conditions (same as in bug https://bugs.launchpad.net/mistral/+bug/1535722):
Task A and B ends in nearly same time. Since setting task state to 'SUCCESS' is one transaction and checking which tasks should be run then is in another transaction, here's what happens:
1. Task A checks it state to SUCCESS
2. Task B checks it state to SUCCESS
3. Task A looks in workflow which tasks have ended[1]. It finds both A and B. In a for loop[2], it checks which tasks are to be run after tasks A and B, so it finds C to times. Since join is satisfied, it fires up C two times.

Proposed solution:
1) Join two transactions into one (not easy) or
2) After getting list of tasks that are in 'SUCCESS' state, check if some of them want to fire up same task and if so, prevent it somehow

[1] https://github.com/openstack/mistral/blob/master/mistral/workflow/direct_workflow.py#L77
[2] https://github.com/openstack/mistral/blob/master/mistral/workflow/direct_workflow.py#L82

[Renat Akhmerov (rakhmerov)]

Dawid, I started investigating this bug and read your comment. It seems like you don't take locks into account. "Nearly at the same time" shouldn't matter because we have locking mechanism. I recently fixed another similar bug (https://review.openstack.org/#/c/299751/) which was caused by the fact that we had two transactions instead of one in on_action_complete() in default_engine. So that the whole transactional logic was broken. I guess this bug could be related with that too. I'm now trying to reproduce it in my environment.

Please tell me I'm missing something on locking.

Thanks

[Renat Akhmerov (rakhmerov)]

I wasn't able to reproduce it so far. I tried both HA and non-HA mode.

[Renat Akhmerov (rakhmerov)]

I stopped working on it for now because I wasn't able to reproduce it so far. It may have been fixed as a side effect of fixing https://bugs.launchpad.net/mistral/+bug/1524477.

If we stumble on it again, we can get back to it.

[Dawid Deja (dawid-deja-0)]

Renat,

I wasn't able to reproduce this too.
In your fix, you have merged two transaction into one in 'on_action_complete' and I believe that the fact that transaction was splitted into two parts produced this bug. So my guess is this one can be resolved.

[Renat Akhmerov (rakhmerov)]

Ok, great.

Renat

> 6 апр. 2016 г., в 17:23, Dawid Deja <email address hidden> написал(а):
>
> Renat,
>
> I wasn't able to reproduce this too.
> In your fix, you have merged two transaction into one in 'on_action_complete' and I believe that the fact that transaction was splitted into two parts produced this bug. So my guess is this one can be resolved.
>
> --
> You received this bug notification because you are a bug assignee.
> https://bugs.launchpad.net/bugs/1535295
>
> Title:
> Task with join runs more than once
>
> Status in Mistral:
> Incomplete
>
> Bug description:
> Steps for reproduce:
> 1. create workflow :
> p_d:
> tasks:
> list_servers:
> action: std.echo output='1'
> on-success: [start_heal_servers_workflow]
> list_stack_servers:
> action: std.echo output='2'
> on-success: [start_heal_servers_workflow]
> start_heal_servers_workflow:
> action: std.echo output='3'
> join: all
> type: direct
> version: '2.0'
> 2. rum wf from 1
> 3. rum task-list
>
> result:
> +--------------------------------------+-----------------------------+---------------+--------------------------------------+---------+------------+
> | ID | Name | Workflow name | Execution ID | State | State info |
> +--------------------------------------+-----------------------------+---------------+--------------------------------------+---------+------------+
> | a7980263-15e9-4298-b8b5-6044eb2c10ae | list_stack_servers | p_d | 9616f763-21b0-4b81-88cb-a8f3c779f7ba | SUCCESS | None |
> | c917e57e-a2bb-4cde-a9ac-6e323ab7c92b | list_servers | p_d | 9616f763-21b0-4b81-88cb-a8f3c779f7ba | SUCCESS | None |
> | 3f775a58-7bb4-465f-bea5-23f368301bc7 | start_heal_servers_workflow | p_d | 9616f763-21b0-4b81-88cb-a8f3c779f7ba | SUCCESS | None |
> | e1cb2afe-845d-49e3-ab93-6368b6a620cc | start_heal_servers_workflow | p_d | 9616f763-21b0-4b81-88cb-a8f3c779f7ba | SUCCESS | None |
> +--------------------------------------+-----------------------------+---------------+--------------------------------------+---------+------------+
>
> expected result:
> task start_heal_servers_workflow scheduler run only once (because of the join)
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/mistral/+bug/1535295/+subscriptions

[Dougal Matthews (d0ugal)]

Marking this as invalid to clear out the incomplete bugs. The last two comments around 2 years ago said this couldn't be reproduced. Happy to reopen it if there is more info provided.