Timeouts creating plan via mistral

[Steven Hardy]

2016-09-28 02:18:59.655977 | 2016-09-28 02:17:27.000 | Created flavor "block-storage" with profile "block-storage"
2016-09-28 02:18:59.656008 | 2016-09-28 02:17:27.000 | Created flavor "swift-storage" with profile "swift-storage"
2016-09-28 02:18:59.656048 | 2016-09-28 02:18:59.000 | Timed out waiting for execution cd09eac2-777d-47c0-aedf-06defc2450bb to finish. State: RUNNING
2016-09-28 02:18:59.656072 | 2016-09-28 02:18:59.000 | Traceback (most recent call last):
2016-09-28 02:18:59.656097 | 2016-09-28 02:18:59.000 | File "<string>", line 1, in <module>
2016-09-28 02:18:59.656138 | 2016-09-28 02:18:59.000 | File "/usr/lib/python2.7/site-packages/instack_undercloud/undercloud.py", line 1189, in install
2016-09-28 02:18:59.656161 | 2016-09-28 02:18:59.000 | _post_config(instack_env)
2016-09-28 02:18:59.656204 | 2016-09-28 02:18:59.000 | File "/usr/lib/python2.7/site-packages/instack_undercloud/undercloud.py", line 1171, in _post_config
2016-09-28 02:18:59.656227 | 2016-09-28 02:18:59.000 | _post_config_mistral(mistral)
2016-09-28 02:18:59.656273 | 2016-09-28 02:18:59.000 | File "/usr/lib/python2.7/site-packages/instack_undercloud/undercloud.py", line 1146, in _post_config_mistral
2016-09-28 02:18:59.656297 | 2016-09-28 02:18:59.000 | _create_default_plan(mistral)
2016-09-28 02:18:59.656343 | 2016-09-28 02:18:59.000 | File "/usr/lib/python2.7/site-packages/instack_undercloud/undercloud.py", line 1136, in _create_default_plan
2016-09-28 02:18:59.656377 | 2016-09-28 02:18:59.000 | "Timed out creating the default Deployment Plan. Please check "
2016-09-28 02:18:59.656441 | 2016-09-28 02:18:59.000 | RuntimeError: Timed out creating the default Deployment Plan. Please check the create_default_deployment_plan execution in Mistral with `openstack workflow execution list`.

[Steven Hardy (shardy)]

Seen in https://review.openstack.org/#/c/376633

[Dougal Matthews (d0ugal)]

From the Mistral logs in the review the workflow was started here:

2016-09-28 02:17:28.600 313 INFO workflow_trace [-] Workflow 'tripleo.plan_management.v1.create_default_deployment_plan' [IDLE -> RUNNING, msg=None] (execution_id=cd09eac2-777d-47c0-aedf-06defc2450bb)

and then finished:

2016-09-28 02:19:19.425 313 INFO workflow_trace [-] Workflow 'tripleo.plan_management.v1.create_default_deployment_plan' [RUNNING -> SUCCESS, msg=None] (execution_id=cd09eac2-777d-47c0-aedf-06defc2450bb)

This means it took 111 seconds. At the moment we are only waiting a maximum of 90 seconds. I'll increase the maximum wait to 180 seconds, or three minutes.

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/378467
Committed: https://git.openstack.org/cgit/openstack/instack-undercloud/commit/?id=0c86110ef1499db20e816c43c700716417752bdd
Submitter: Jenkins
Branch: master

commit 0c86110ef1499db20e816c43c700716417752bdd
Author: Dougal Matthews <email address hidden>
Date: Wed Sep 28 10:27:38 2016 +0100

    Double the maximum waiting time for default plan creation

    In some CI runs we have been hitting the limit but from the Mistral logs
    it has then continued to complete successfully. In such cases it has
    been taking around 120 seconds. Increasing the maximum waiting time to
    180 seconds gives quite a bit of extra time beyond that.

    Since we poll every 5 seconds this change shouldn't impact any users
    except for the edge cases that previously timed out.

    Change-Id: I7d866520ed6192441c7a6835f838689f1e18f6b1
    Closes-Bug: #1628388

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/instack-undercloud 5.0.0.0rc2 release candidate.