[MuranoPL] Reporter not always reports last state

[Dmitry Kubatkin]

With code looking like this:
          - $.instance.agent.call($template, $resources)
          - $._environment.reporter.report($this, 'Deploy IBM MQ complete')
          - If: $.instance.assignFloatingIp
            Then:
              - $address: $.instance.floatingIpAddress
            Else:
              - $address: $.instance.ipAddresses[0]
          - $login: 'administrator'
          - $._environment.reporter.report($this, format('MQ queue named {0} running at RDP {1} with {2}/{3} creds', $.qmgr, $address, $login, $password))
          - $.setAttr(deployed, true)

Sometimes when environment is deployed 'Deploy IBM MQ complete' but not 'MQ queue named...' appears in 'Last operations' field in horizon. Environments has exaclty same configuration.

[Kirill Zaitsev (kzaitsev)]

Looks like a race-condition.

It can be mitigated, for example by obtaining report-date on engine side, and transferring it, with the rest of the data. This would not eliminate race condition, but might help, because creation-dates would be sorted correctly.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/300414

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/mitaka
Review: https://review.openstack.org/300415

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/liberty
Review: https://review.openstack.org/300419

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/300415
Committed: https://git.openstack.org/cgit/openstack/murano/commit/?id=7411ddbd20e3d82f2cc48983b18a472431d965bc
Submitter: Jenkins
Branch: stable/mitaka

commit 7411ddbd20e3d82f2cc48983b18a472431d965bc
Author: Stan Lagun <email address hidden>
Date: Fri Apr 1 13:59:24 2016 +0300

    Track status report timestamp

    Report status messages were ordered by the time
    they were inserted into database. And that is the
    time they were received and processed not the
    time the report message was generated. So if
    deployment generates reports faster than they
    get processed it can be that they accumulate
    in RabbitMQ and then received by the API not
    in original order. Another possibility is that
    several API instances would get those messages
    and because of the race condition insert them
    into database in wrong order.

    With this fix report timestamp becomes part
    of the report itself and is inserted into "created"
    table column. Thus created is now when the
    report was created, not the database record.

    Change-Id: I1d41d644ed399cb9d58192e567f11187fa2cf593
    Closes-Bug: #1462270

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/300419
Committed: https://git.openstack.org/cgit/openstack/murano/commit/?id=c49931810721128161e8928ba6e1be080f1116f2
Submitter: Jenkins
Branch: stable/liberty

commit c49931810721128161e8928ba6e1be080f1116f2
Author: Stan Lagun <email address hidden>
Date: Fri Apr 1 14:06:42 2016 +0300

    Track status report timestamp

    Report status messages were ordered by the time
    they were inserted into database. And that is the
    time they were received and processed not the
    time the report message was generated. So if
    deployment generates reports faster than they
    get processed it can be that they accumulate
    in RabbitMQ and then received by the API not
    in original order. Another possibility is that
    several API instances would get those messages
    and because of the race condition insert them
    into database in wrong order.

    With this fix report timestamp becomes part
    of the report itself and is inserted into "created"
    table column. Thus created is now when the
    report was created, not the database record.

    Change-Id: I5b705ee95c6fa2275937513aba0bcb0053c0901c
    Closes-Bug: #1462270

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/300414
Committed: https://git.openstack.org/cgit/openstack/murano/commit/?id=51de28f7a99c4c43a93f01ff237265193510f398
Submitter: Jenkins
Branch: master

commit 51de28f7a99c4c43a93f01ff237265193510f398
Author: Stan Lagun <email address hidden>
Date: Fri Apr 1 13:59:24 2016 +0300

    Track status report timestamp

    Report status messages were ordered by the time
    they were inserted into database. And that is the
    time they were received and processed not the
    time the report message was generated. So if
    deployment generates reports faster than they
    get processed it can be that they accumulate
    in RabbitMQ and then received by the API not
    in original order. Another possibility is that
    several API instances would get those messages
    and because of the race condition insert them
    into database in wrong order.

    With this fix report timestamp becomes part
    of the report itself and is inserted into "created"
    table column. Thus created is now when the
    report was created, not the database record.

    Change-Id: I1d41d644ed399cb9d58192e567f11187fa2cf593
    Closes-Bug: #1462270

[Alexander Tivelkov (ativelkov)]

Still having this kind of behaviour in latest master

[Alexander Tivelkov (ativelkov)]

Seems like the database has a second-level precision. It looks like the dtaabase schema has to be modified to include datetime(N) column size to include some second fractions.

[OpenStack Infra (hudson-openstack)]

Change abandoned by Stan Lagun (<email address hidden>) on branch: stable/mitaka
Review: https://review.openstack.org/311046
Reason: We don't backport database migrations

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/311045
Committed: https://git.openstack.org/cgit/openstack/murano/commit/?id=89a4c4cb5af9b22ef07ea5f1ddcff6edd4997623
Submitter: Jenkins
Branch: master

commit 89a4c4cb5af9b22ef07ea5f1ddcff6edd4997623
Author: Stan Lagun <email address hidden>
Date: Fri Apr 29 00:33:34 2016 -0700

    Increase status report messages time resolution

    We use DATETIME SQL type for created/updated columns
    everywhere through the database. In SQL standard
    DATETIME defaults to DATETIME(6) which is 6 digit
    fraction second part. However MySQL defaults it
    to DATETIME(0) for backward compatibility. In result
    status messages timestamps get rounded to the
    second boundary and if there are several status
    messages were generated within a second
    after table sort they might be shown in a different
    order.

    This commit adds MySQL migration that increases
    resolution for the status table and adds subseconds
    to the generated status repor timestamps.

    Change-Id: Ice8c2d82c6a320c7f73c27f4c60c87bef55b8d95
    Related-Bug: #1462270

[Doug Hellmann (doug-hellmann)]

This issue was fixed in the openstack/murano 3.0.0.0b1 development milestone.

[Doug Hellmann (doug-hellmann)]

This issue was fixed in the openstack/murano 2.0.1 release.

[Doug Hellmann (doug-hellmann)]

This issue was fixed in the openstack/murano 1.0.3 release.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/murano 1.0.3 release.