HELP! Overcloud nodes' introspection always times out.
Hello! I am deploying Openstack in a RHEL 8.2 environment using RHOSP 16.1.
For the procedures, I used the official RedHat doc
I have successfully installed the Undercloud, but I encountered errors during introspection of the Overcloud nodes.
After the introspection (with --provide option), the nodes are expected be in the 'available' state, but during our execution, it stayed in 'available' state.
The introspection retry limit was reached. The error was "introspection timeout" as seen in the Mistral logs.
Do you have any idea as to what caused the error?
I have tried these countermeasures to no avail:
- Disabled selinux
- Recreated the Overcloud nodes (via virsh)
- Confirmed that the Overcloud nodes can be accessed and controlled from Undercloud (via ipmitool)
My wild guess is that the issue was most likely caused by permissions between services (nova->neutron, nova->ironic, etc.).
However, it is weird if this really was the cause since there is no manual configurations of the services performed during undercloud installation.
Or are I missing something? Like packages or prerequisites?
Hoping that somebody could help me out. Thank you!
Right here are the
undercloud.confovercloud-stackenv.json(undercloud) [stack@undercloud ~]$ cat undercloud.conf [DEFAULT] container_images_file = /home/stack/containers-prepare-parameter.yaml deployment_user = stack enabled_hardware_types = ipmi,redfish,ilo,idrac,manual-management generate_service_certificate = false inspection_interface = br-ctlplane ipxe_enabled = true local_interface = ens4 local_ip = 10.10.10.10/24 local_subnet = ctlplane-subnet overcloud_domain_name = overcloud.domain subnets = ctlplane-subnet undercloud_hostname = undercloud.home undercloud_log_file = install-undercloud.log [ctlplane-subnet] cidr = 10.10.10.0/24 dhcp_end = 10.10.10.100 dhcp_start = 10.10.10.20 gateway = 10.10.10.10 inspection_iprange = 10.10.10.101,10.10.10.150 masquerade = true (undercloud) [stack@undercloud ~]$ cat overcloud-stackenv.json { "nodes": [ { "arch": "x86_64", "disk": "80", "memory": "12288", "name": "new-overcloud-compute", "pm_user": "admin", "pm_addr": "10.10.10.10", "pm_password": "password", "pm_port": "6001", "pm_type": "pxe_ipmitool", "mac": [ "52:54:00:b4:c6:f0" ], "cpu": "2", "capabilities": "profile:compute,boot_option:local" }, { "arch": "x86_64", "disk": "80", "memory": "12288", "name": "new-overcloud-controller", "pm_user": "admin", "pm_addr": "10.10.10.10", "pm_password": "password", "pm_port": "6002", "pm_type": "pxe_ipmitool", "mac": [ "52:54:00:b4:c6:f8" ], "cpu": "2", "capabilities": "profile:control,boot_option:local" } ] }
I have also tried to change the
pm_typeipmitoolOutput of
vbmc list(undercloud) [stack@undercloud ~]$ vbmc list +--------------------------+---------+-------------+------+ | Domain name | Status | Address | Port | +--------------------------+---------+-------------+------+ | new-overcloud-compute | running | 10.10.10.10 | 6001 | | new-overcloud-controller | running | 10.10.10.10 | 6002 | +--------------------------+---------+-------------+------+
As for the actual errors encountered, please see details below:
(undercloud) [stack@undercloud ~]$ openstack overcloud node import --introspect --provide overcloud-stackenv.json Waiting for messages on queue 'tripleo' with no timeout. 2 node(s) successfully moved to the "manageable" state. Successfully registered node UUID 2b4db183-7bbf-488c-8754-54174f0ba47e Successfully registered node UUID 8aa29d4b-dd52-42a7-9b25-05d0999fbe3e Waiting for introspection to finish... Waiting for messages on queue 'tripleo' with no timeout. Introspection of node attempt failed:8aa29d4b-dd52-42a7-9b25-05d0999fbe3e. Introspection of node attempt failed:2b4db183-7bbf-488c-8754-54174f0ba47e. Retrying 2 nodes that failed introspection. Attempt 1 of 3 Introspection of node attempt failed:2b4db183-7bbf-488c-8754-54174f0ba47e. Introspection of node attempt failed:8aa29d4b-dd52-42a7-9b25-05d0999fbe3e. Retrying 2 nodes that failed introspection. Attempt 2 of 3 Introspection of node attempt failed:2b4db183-7bbf-488c-8754-54174f0ba47e. Introspection of node attempt failed:8aa29d4b-dd52-42a7-9b25-05d0999fbe3e. Retrying 2 nodes that failed introspection. Attempt 3 of 3 Introspection of node attempt failed:8aa29d4b-dd52-42a7-9b25-05d0999fbe3e. Introspection of node attempt failed:2b4db183-7bbf-488c-8754-54174f0ba47e. Retry limit reached with 2 nodes still failing introspection Introspection completed with errors: Retry limit reached with 2 nodes still failing introspection sys:1: ResourceWarning: unclosedsys:1: ResourceWarning: unclosed
I can control/access the nodes via
ipmitool(undercloud) [stack@undercloud ~]$ ipmitool -I lanplus -U admin -P password -H 10.10.10.10 -p 6001 power status Chassis Power is on (undercloud) [stack@undercloud ~]$ ipmitool -I lanplus -U admin -P password -H 10.10.10.10 -p 6002 power status Chassis Power is on
Notice that the nodes are still in 'manageable' state.
(undercloud) [stack@undercloud ~]$ openstack baremetal node list +--------------------------------------+--------------------------+---------------+-------------+--------------------+-------------+ | UUID | Name | Instance UUID | Power State | Provisioning State | Maintenance | +--------------------------------------+--------------------------+---------------+-------------+--------------------+-------------+ | 2b4db183-7bbf-488c-8754-54174f0ba47e | new-overcloud-compute | None | power on | manageable | False | | 8aa29d4b-dd52-42a7-9b25-05d0999fbe3e | new-overcloud-controller | None | power on | manageable | False | +--------------------------------------+--------------------------+---------------+-------------+--------------------+-------------+ (undercloud) [stack@undercloud ~]$ nova service-list +--------------------------------------+----------------+-----------------------------+----------+---------+-------+----------------------------+-----------------+-------------+ | Id | Binary | Host | Zone | Status | State | Updated_at | Disabled Reason | Forced down | +--------------------------------------+----------------+-----------------------------+----------+---------+-------+----------------------------+-----------------+-------------+ | a0e54463-0afa-49b0-bc1b-2af14ad7eb63 | nova-conductor | undercloud.overcloud.domain | internal | enabled | up | 2020-09-28T07:39:51.000000 | - | False | | 88f4bf62-e052-4e3a-8114-f6d492001cf6 | nova-scheduler | undercloud.overcloud.domain | internal | enabled | up | 2020-09-28T07:39:48.000000 | - | False | | ef9ccd89-f74e-4628-a1fc-4f4aed8bb422 | nova-compute | undercloud.overcloud.domain | nova | enabled | up | 2020-09-28T07:39:50.000000 | - | False | +--------------------------------------+----------------+-----------------------------+----------+---------+-------+----------------------------+-----------------+-------------+ (undercloud) [stack@undercloud ~]$ nova hypervisor-list +--------------------------------------+--------------------------------------+-------+---------+ | ID | Hypervisor hostname | State | Status | +--------------------------------------+--------------------------------------+-------+---------+ | 8aa29d4b-dd52-42a7-9b25-05d0999fbe3e | 8aa29d4b-dd52-42a7-9b25-05d0999fbe3e | up | enabled | | 2b4db183-7bbf-488c-8754-54174f0ba47e | 2b4db183-7bbf-488c-8754-54174f0ba47e | up | enabled | +--------------------------------------+--------------------------------------+-------+---------+
MISTRAL ENGINE LOGS
[root@undercloud containers]# grep -iE "(fail|error|warn|denied)" mistral/engine.log 2020-09-28 12:06:47.089 6 WARNING tripleo_common.utils.nodes [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Key mac is deprecated, please use ports. 2020-09-28 12:06:47.089 6 WARNING tripleo_common.utils.nodes [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Key mac is deprecated, please use ports. 2020-09-28 12:06:47.295 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=7ae59068-499b-4330-a376-7a975c4bf31f, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:06:47.320 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'tripleo.baremetal.validate_nodes' (7ae59068-499b-4330-a376-7a975c4bf31f)(task=validate_nodes) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:06:47.651 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=08811237-c02d-442b-981d-99dbc6f07b99, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:06:47.680 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (08811237-c02d-442b-981d-99dbc6f07b99)(task=merge_payload) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:06:47.978 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=7330828b-7759-41a8-bd76-5fad45eb26b9, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:06:48.030 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (7330828b-7759-41a8-bd76-5fad45eb26b9)(task=prepare_messages) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:06:48.256 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=bb3397f0-6d2d-45d4-96de-663b05a1aadc, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:06:48.281 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (bb3397f0-6d2d-45d4-96de-663b05a1aadc)(task=branch_workflow) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:06:48.692 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=8e5d2881-0f7d-4643-b591-85ef573ecc70, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:06:48.759 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (8e5d2881-0f7d-4643-b591-85ef573ecc70)(task=complete_swift) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:06:51.002 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=9b5e54ab-046e-40b9-8a77-11d52a0a57fc, result=Result [data={'resources': ['/v2/queues/tripleo/messages/0925835c-0140-11eb-bb7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 12:06:51.044 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'zaqar.queue_post' (9b5e54ab-046e-40b9-8a77-11d52a0a57fc)(task=send_message) [RUNNING -> SUCCESS, Result [data={'resources': ['/v2/queues/tripleo/messages/0925835c-0140-11eb-bb7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 12:06:52.095 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=bc08beb4-7818-475e-b8d6-eeda005217d5, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:06:52.111 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (bc08beb4-7818-475e-b8d6-eeda005217d5)(task=check_status) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:06:52.138 6 DEBUG mistral.expressions.yaql_expression [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.get('status') = "FAILED" %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:06:52.462 6 WARNING tripleo_common.utils.nodes [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Key mac is deprecated, please use ports. 2020-09-28 12:06:52.462 6 WARNING tripleo_common.utils.nodes [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Key mac is deprecated, please use ports. 2020-09-28 12:06:56.288 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=80c1f917-8fbb-46a3-b98a-cdfae674ff16, result=Result [data=[{'manager': {'api': {'os_ironic_api_version': '1.58', 'api_version_select_state': 'user', 'confl..., error=None, cancel=False]] 2020-09-28 12:06:56.309 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'tripleo.baremetal.register_or_update_nodes' (80c1f917-8fbb-46a3-b98a-cdfae674ff16)(task=register_or_update_nodes) [RUNNING -> SUCCESS, Result [data=[{'manager': {'api': {'os_ironic_api_version': '1.58', 'api_version_select_state': 'user', 'confl..., error=None, cancel=False]] 2020-09-28 12:06:57.920 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=ccd9ef5d-42d6-4a10-ade7-6c2bcacbf566, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:06:57.941 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'ironic.node_set_provision_state' (ccd9ef5d-42d6-4a10-ade7-6c2bcacbf566)(task=set_provision_state) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:06:58.084 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=fa77e4b5-b19f-4705-9c6f-e7e06626a0a3, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:06:58.174 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'ironic.node_set_provision_state' (fa77e4b5-b19f-4705-9c6f-e7e06626a0a3)(task=set_provision_state) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:06:58.703 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=53b159d1-927c-4583-b6ef-86b8d7d6884e, result=Result [data={'manager': {'api': {'os_ironic_api_version': '1.34', 'api_version_select_state': 'user', 'confli..., error=None, cancel=False]] 2020-09-28 12:06:58.799 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'ironic.node_get' (53b159d1-927c-4583-b6ef-86b8d7d6884e)(task=wait_for_provision_state) [RUNNING -> SUCCESS, Result [data={'manager': {'api': {'os_ironic_api_version': '1.34', 'api_version_select_state': 'user', 'confli..., error=None, cancel=False]] 2020-09-28 12:06:58.991 6 DEBUG mistral.expressions.yaql_expression [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% not task().result.provision_state in [$.target_state] + $.error_states %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:06:59.093 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=299c5f9c-ecd0-4fd1-9879-bbd4ec501b7a, result=Result [data={'manager': {'api': {'os_ironic_api_version': '1.34', 'api_version_select_state': 'user', 'confli..., error=None, cancel=False]] 2020-09-28 12:06:59.178 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'ironic.node_get' (299c5f9c-ecd0-4fd1-9879-bbd4ec501b7a)(task=wait_for_provision_state) [RUNNING -> SUCCESS, Result [data={'manager': {'api': {'os_ironic_api_version': '1.34', 'api_version_select_state': 'user', 'confli..., error=None, cancel=False]] 2020-09-28 12:06:59.292 6 DEBUG mistral.expressions.yaql_expression [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% not task().result.provision_state in [$.target_state] + $.error_states %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:07:02.991 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=515881f8-c2e1-4b35-a53e-36ba4bd4c431, result=Result [data={'manager': {'api': {'os_ironic_api_version': '1.34', 'api_version_select_state': 'user', 'confli..., error=None, cancel=False]] 2020-09-28 12:07:03.008 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'ironic.node_get' (515881f8-c2e1-4b35-a53e-36ba4bd4c431)(task=wait_for_provision_state) [RUNNING -> SUCCESS, Result [data={'manager': {'api': {'os_ironic_api_version': '1.34', 'api_version_select_state': 'user', 'confli..., error=None, cancel=False]] 2020-09-28 12:07:03.039 6 DEBUG mistral.expressions.yaql_expression [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% not task().result.provision_state in [$.target_state] + $.error_states %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:07:03.180 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=51e88369-a9d1-4469-b714-b8580c5be64d, result=Result [data={'manager': {'api': {'os_ironic_api_version': '1.34', 'api_version_select_state': 'user', 'confli..., error=None, cancel=False]] 2020-09-28 12:07:03.197 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'ironic.node_get' (51e88369-a9d1-4469-b714-b8580c5be64d)(task=wait_for_provision_state) [RUNNING -> SUCCESS, Result [data={'manager': {'api': {'os_ironic_api_version': '1.34', 'api_version_select_state': 'user', 'confli..., error=None, cancel=False]] 2020-09-28 12:07:03.238 6 DEBUG mistral.expressions.yaql_expression [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% not task().result.provision_state in [$.target_state] + $.error_states %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:07:04.420 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=165a5742-1e4e-4e57-87a1-d44f79e2ad32, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:04.441 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (165a5742-1e4e-4e57-87a1-d44f79e2ad32)(task=merge_payload) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:04.558 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=45b7a878-286b-42ab-b038-03399d6ca4f6, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:04.575 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (45b7a878-286b-42ab-b038-03399d6ca4f6)(task=prepare_messages) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:04.694 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=2ce03b78-3b0d-4b88-8dda-4d2e56dbd3d1, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:04.707 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (2ce03b78-3b0d-4b88-8dda-4d2e56dbd3d1)(task=branch_workflow) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:04.828 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=3dec3eb3-ff14-4143-b7a6-c35364c3f0c1, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:04.897 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (3dec3eb3-ff14-4143-b7a6-c35364c3f0c1)(task=complete_swift) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:06.106 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=2fdba55b-4e9c-48a1-8a31-ba5b06e3881a, result=Result [data={'resources': ['/v2/queues/tripleo/messages/12273022-0140-11eb-9c7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 12:07:06.139 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'zaqar.queue_post' (2fdba55b-4e9c-48a1-8a31-ba5b06e3881a)(task=send_message) [RUNNING -> SUCCESS, Result [data={'resources': ['/v2/queues/tripleo/messages/12273022-0140-11eb-9c7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 12:07:07.013 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=95da3e3e-e292-45bf-9fb5-90fc9682f370, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:07.033 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (95da3e3e-e292-45bf-9fb5-90fc9682f370)(task=check_status) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:07.062 6 DEBUG mistral.expressions.yaql_expression [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.get('status') = "FAILED" %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:07:07.677 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=543496b5-a18f-4a3f-8c0e-7e70df7a5a47, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:07.693 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (543496b5-a18f-4a3f-8c0e-7e70df7a5a47)(task=merge_payload) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:07.843 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=d2734c35-2fd8-4a01-bdb8-f9f4818eea2d, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:07.861 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (d2734c35-2fd8-4a01-bdb8-f9f4818eea2d)(task=prepare_messages) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:08.269 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=48b6dd7a-a1c9-499d-a7b9-ce61bd12b622, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:08.291 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (48b6dd7a-a1c9-499d-a7b9-ce61bd12b622)(task=branch_workflow) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:08.576 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=dc193828-8807-477e-a6a1-35c56b583255, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:08.647 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (dc193828-8807-477e-a6a1-35c56b583255)(task=complete_swift) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:09.124 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=ff3a6eb1-d54c-4af9-9128-01d7f85c6aa2, result=Result [data={'resources': ['/v2/queues/tripleo/messages/13e446ca-0140-11eb-bb7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 12:07:09.282 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'zaqar.queue_post' (ff3a6eb1-d54c-4af9-9128-01d7f85c6aa2)(task=send_message) [RUNNING -> SUCCESS, Result [data={'resources': ['/v2/queues/tripleo/messages/13e446ca-0140-11eb-bb7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 12:07:10.344 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=2427e733-23e7-4c40-b9f7-f4cf818ca281, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:10.380 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (2427e733-23e7-4c40-b9f7-f4cf818ca281)(task=initialize) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:11.234 6 INFO mistral.engine.engine_server [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=16d0a659-e1fc-45ac-a2fd-fa46ef6cb8e5, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:11.280 6 INFO workflow_trace [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (16d0a659-e1fc-45ac-a2fd-fa46ef6cb8e5)(task=check_status) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:11.364 6 DEBUG mistral.expressions.yaql_expression [req-71c08be9-8822-45fe-a080-38ebebed9157 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.get('status') = "FAILED" %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:07:13.917 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=269f50d1-db28-4b29-8963-a86fcd887795, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:13.961 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.introspect' (269f50d1-db28-4b29-8963-a86fcd887795)(task=start_introspection) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:16.383 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=1ab26749-2f2a-4c51-897e-72a35f154c6e, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:07:16.431 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.introspect' (1ab26749-2f2a-4c51-897e-72a35f154c6e)(task=start_introspection) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:26:58.522 6 DEBUG mistral.services.legacy_scheduler [req-02272ea3-36ec-49a7-9042-e7917691b87c 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Preparing next delayed call. [ID=0f6146b6-e4c9-4936-8721-93b5bf97ca8f, factory_method_path=None, target_method_name=mistral.engine.policies._fail_task_if_incomplete, method_arguments={'task_ex_id': '21c3f6be-0ec9-4f2b-88a2-468e4a9adbcd', 'timeout': 1200}] _prepare_calls /usr/lib/python3.6/site-packages/mistral/services/legacy_scheduler.py:238 2020-09-28 12:26:58.523 6 DEBUG mistral.services.legacy_scheduler [req-02272ea3-36ec-49a7-9042-e7917691b87c 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Preparing next delayed call. [ID=57337e5e-a242-4d42-96f9-109ca25f2678, factory_method_path=None, target_method_name=mistral.engine.policies._fail_task_if_incomplete, method_arguments={'task_ex_id': '847f0372-d799-4545-90c8-236314cb68d5', 'timeout': 1200}] _prepare_calls /usr/lib/python3.6/site-packages/mistral/services/legacy_scheduler.py:238 2020-09-28 12:27:18.391 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=320af4f7-3a08-4cfd-922f-84c6d9489d9b, result=Result [data=None, error=The action raised an exception [action_ex_id=320af4f7-3a08-4cfd-922f-84c6d9489d9b, msg='BaremetalInt..., cancel=False]] 2020-09-28 12:27:18.415 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.wait_for_finish' (320af4f7-3a08-4cfd-922f-84c6d9489d9b)(task=wait_for_introspection_to_finish) [RUNNING -> ERROR, Result [data=None, error=The action raised an exception [action_ex_id=320af4f7-3a08-4cfd-922f-84c6d9489d9b, msg='BaremetalInt..., cancel=False]] 2020-09-28 12:27:18.454 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'wait_for_introspection_to_finish' (e10b843c-2655-4369-8e43-33287d51e6cf) [RUNNING -> ERROR, msg=The action raised an exception [action_ex_id=320af4f7-3a08-4cfd-922f-84c6d9489d9b, msg='BaremetalIntrospectionAction.wait_for_finish failed: Timeout while waiting for introspection of nodes ['8aa29d4b-dd52-42a7-9b25-05d0999fbe3e']', action_cls='', attributes='{'client_method_name': 'wait_for_finish'}', params='{'uuids': ['8aa29d4b-dd52-42a7-9b25-05d0999fbe3e'], 'max_retries': 120, 'retry_interval': 10}']] (execution_id=776922d5-e93b-4e4b-b56f-a1752fa3d4e5) 2020-09-28 12:27:18.475 6 DEBUG mistral.workflow.direct_workflow [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Run task [workflow=tripleo.baremetal.v1._introspect, task=wait_for_introspection_to_finish_error, waif_flag=False, triggered_by=[{'task_id': 'e10b843c-2655-4369-8e43-33287d51e6cf', 'event': 'on-error'}]]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 12:27:18.483 6 DEBUG mistral.engine.tasks [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting task [name=wait_for_introspection_to_finish_error, init_state=RUNNING, workflow_name=tripleo.baremetal.v1._introspect, execution_id=776922d5-e93b-4e4b-b56f-a1752fa3d4e5] _run_new /usr/lib/python3.6/site-packages/mistral/engine/tasks.py:525 2020-09-28 12:27:18.624 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=91e2ee3f-6974-4546-9ee7-da56430128c9, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:18.659 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (91e2ee3f-6974-4546-9ee7-da56430128c9)(task=wait_for_introspection_to_finish_error) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:18.698 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'wait_for_introspection_to_finish_error' (6d7e98d1-f525-439f-bc66-a521fed3ca3d) [RUNNING -> SUCCESS, msg=None] (execution_id=776922d5-e93b-4e4b-b56f-a1752fa3d4e5) 2020-09-28 12:27:18.708 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% "Introspection of node attempt failed:{0}.".format($.node_uuid) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:27:18.776 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting workflow [name=tripleo.messaging.v1.send, input={'queue_name': 'tripleo', 'type': 'tripleo.baremetal.v1._introspect', 'status': 'FAILED', 'messag...] 2020-09-28 12:27:18.914 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=bcd79121-3bef-4500-8ed6-2dc55d00db1a, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:18.928 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (bcd79121-3bef-4500-8ed6-2dc55d00db1a)(task=merge_payload) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:19.024 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=31833650-824b-4f85-8e50-680307c89b1e, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:19.039 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (31833650-824b-4f85-8e50-680307c89b1e)(task=prepare_messages) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:19.145 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=7c12b24e-607c-487d-b29f-0241fbeb5a41, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:19.160 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (7c12b24e-607c-487d-b29f-0241fbeb5a41)(task=branch_workflow) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:19.314 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=71f58cf6-e61c-4c93-a85f-a23a13baef8c, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:19.406 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (71f58cf6-e61c-4c93-a85f-a23a13baef8c)(task=complete_swift) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:19.543 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=9854df3b-1266-46ae-928a-a591535956ea, result=Result [data=None, error=The action raised an exception [action_ex_id=9854df3b-1266-46ae-928a-a591535956ea, msg='BaremetalInt..., cancel=False]] 2020-09-28 12:27:19.595 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.wait_for_finish' (9854df3b-1266-46ae-928a-a591535956ea)(task=wait_for_introspection_to_finish) [RUNNING -> ERROR, Result [data=None, error=The action raised an exception [action_ex_id=9854df3b-1266-46ae-928a-a591535956ea, msg='BaremetalInt..., cancel=False]] 2020-09-28 12:27:19.649 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'wait_for_introspection_to_finish' (4617e108-b2ac-4535-9da3-0219dfd99d55) [RUNNING -> ERROR, msg=The action raised an exception [action_ex_id=9854df3b-1266-46ae-928a-a591535956ea, msg='BaremetalIntrospectionAction.wait_for_finish failed: Timeout while waiting for introspection of nodes ['2b4db183-7bbf-488c-8754-54174f0ba47e']', action_cls=' ', attributes='{'client_method_name': 'wait_for_finish'}', params='{'uuids': ['2b4db183-7bbf-488c-8754-54174f0ba47e'], 'max_retries': 120, 'retry_interval': 10}']] (execution_id=929ac675-0af2-40ae-ba89-977f5b358987) 2020-09-28 12:27:19.718 6 DEBUG mistral.workflow.direct_workflow [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Run task [workflow=tripleo.baremetal.v1._introspect, task=wait_for_introspection_to_finish_error, waif_flag=False, triggered_by=[{'task_id': '4617e108-b2ac-4535-9da3-0219dfd99d55', 'event': 'on-error'}]]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 12:27:19.746 6 DEBUG mistral.engine.tasks [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting task [name=wait_for_introspection_to_finish_error, init_state=RUNNING, workflow_name=tripleo.baremetal.v1._introspect, execution_id=929ac675-0af2-40ae-ba89-977f5b358987] _run_new /usr/lib/python3.6/site-packages/mistral/engine/tasks.py:525 2020-09-28 12:27:19.849 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=c2aa18c3-ed33-4164-8846-19ad3a2a5bd7, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:19.903 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (c2aa18c3-ed33-4164-8846-19ad3a2a5bd7)(task=wait_for_introspection_to_finish_error) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:19.937 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'wait_for_introspection_to_finish_error' (c9cb4636-b0ca-43b2-b7da-bc2c2f9e8c18) [RUNNING -> SUCCESS, msg=None] (execution_id=929ac675-0af2-40ae-ba89-977f5b358987) 2020-09-28 12:27:19.970 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% "Introspection of node attempt failed:{0}.".format($.node_uuid) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:27:20.192 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting workflow [name=tripleo.messaging.v1.send, input={'queue_name': 'tripleo', 'type': 'tripleo.baremetal.v1._introspect', 'status': 'FAILED', 'messag...] 2020-09-28 12:27:20.452 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=896bbc4a-64e7-4d5c-a80b-a85b8af8b774, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:20.516 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (896bbc4a-64e7-4d5c-a80b-a85b8af8b774)(task=merge_payload) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:20.719 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=5025305b-5d78-4b29-9a51-544c7076cb03, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:20.739 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (5025305b-5d78-4b29-9a51-544c7076cb03)(task=prepare_messages) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:20.789 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=33bcc266-30f7-4e03-8d62-6b220d1881c9, result=Result [data={'resources': ['/v2/queues/tripleo/messages/e625ffd2-0142-11eb-9c7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 12:27:20.810 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'zaqar.queue_post' (33bcc266-30f7-4e03-8d62-6b220d1881c9)(task=send_message) [RUNNING -> SUCCESS, Result [data={'resources': ['/v2/queues/tripleo/messages/e625ffd2-0142-11eb-9c7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 12:27:20.942 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=66748860-82e3-4764-b143-1b642014d16d, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:20.959 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (66748860-82e3-4764-b143-1b642014d16d)(task=branch_workflow) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:21.097 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=bba945bf-f7de-426f-8630-345a7d13d8ea, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:21.172 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (bba945bf-f7de-426f-8630-345a7d13d8ea)(task=complete_swift) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:21.635 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=da34fc2c-666f-4d45-ba5f-18b11bda22ec, result=Result [data={'resources': ['/v2/queues/tripleo/messages/e6addc36-0142-11eb-bb7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 12:27:21.653 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'zaqar.queue_post' (da34fc2c-666f-4d45-ba5f-18b11bda22ec)(task=send_message) [RUNNING -> SUCCESS, Result [data={'resources': ['/v2/queues/tripleo/messages/e6addc36-0142-11eb-bb7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 12:27:21.717 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=0b5dd6ce-0ba9-4bf6-ac0c-e3a26c2b2f0a, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:21.742 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (0b5dd6ce-0ba9-4bf6-ac0c-e3a26c2b2f0a)(task=check_status) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:21.792 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.get('status') = "FAILED" %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:27:21.798 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% "Workflow failed due to message status. Status:{} Message:{}".format($.get('status'), $.get('message')) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:27:21.805 6 DEBUG mistral.workflow.direct_workflow [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Fail [workflow=tripleo.messaging.v1.send]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 12:27:21.840 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Workflow 'tripleo.messaging.v1.send' [RUNNING -> ERROR, msg=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:8aa29d4b-dd52-42a7-9b25-05d0999fbe3e.] (execution_id=5e930a41-038a-4437-9902-fcf2c1fe448d) 2020-09-28 12:27:21.866 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=5e930a41-038a-4437-9902-fcf2c1fe448d, result=Result [data=None, error=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:8a..., cancel=False]] 2020-09-28 12:27:21.886 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'send_message' (d715dad0-cc81-4ed2-9430-19a66fbb6a42) [RUNNING -> ERROR, msg=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:8aa29d4b-dd52-42a7-9b25-05d0999fbe3e.] (execution_id=776922d5-e93b-4e4b-b56f-a1752fa3d4e5) 2020-09-28 12:27:21.965 6 WARNING oslo_db.sqlalchemy.utils [-] Unique keys not in sort_keys. The sorting order may be unstable. 2020-09-28 12:27:22.007 6 INFO workflow_trace [-] Workflow 'tripleo.baremetal.v1._introspect' [RUNNING -> ERROR, msg=Failure caused by error in tasks: send_message send_message [task_ex_id=d715dad0-cc81-4ed2-9430-19a66fbb6a42] -> Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:8aa29d4b-dd52-42a7-9b25-05d0999fbe3e. [wf_ex_id=5e930a41-038a-4437-9902-fcf2c1fe448d, idx=0]: Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:8aa29d4b-dd52-42a7-9b25-05d0999fbe3e. 2020-09-28 12:27:22.025 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=776922d5-e93b-4e4b-b56f-a1752fa3d4e5, result=Result [data=None, error=Failure caused by error in tasks: send_message 2020-09-28 12:27:22.905 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=50877926-0aaf-4928-9189-a9f8b4033736, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:22.932 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (50877926-0aaf-4928-9189-a9f8b4033736)(task=check_status) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:22.967 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.get('status') = "FAILED" %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:27:22.973 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% "Workflow failed due to message status. Status:{} Message:{}".format($.get('status'), $.get('message')) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:27:22.978 6 DEBUG mistral.workflow.direct_workflow [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Fail [workflow=tripleo.messaging.v1.send]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 12:27:23.020 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Workflow 'tripleo.messaging.v1.send' [RUNNING -> ERROR, msg=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:2b4db183-7bbf-488c-8754-54174f0ba47e.] (execution_id=7cb64ff7-4b6a-42e8-bdff-5b36edfd03a3) 2020-09-28 12:27:23.053 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=7cb64ff7-4b6a-42e8-bdff-5b36edfd03a3, result=Result [data=None, error=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:2b..., cancel=False]] 2020-09-28 12:27:23.084 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'send_message' (38a8700d-e1c7-481f-807e-23e3431ff6d6) [RUNNING -> ERROR, msg=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:2b4db183-7bbf-488c-8754-54174f0ba47e.] (execution_id=929ac675-0af2-40ae-ba89-977f5b358987) 2020-09-28 12:27:23.165 6 WARNING oslo_db.sqlalchemy.utils [-] Unique keys not in sort_keys. The sorting order may be unstable. 2020-09-28 12:27:23.208 6 INFO workflow_trace [-] Workflow 'tripleo.baremetal.v1._introspect' [RUNNING -> ERROR, msg=Failure caused by error in tasks: send_message send_message [task_ex_id=38a8700d-e1c7-481f-807e-23e3431ff6d6] -> Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:2b4db183-7bbf-488c-8754-54174f0ba47e. [wf_ex_id=7cb64ff7-4b6a-42e8-bdff-5b36edfd03a3, idx=0]: Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:2b4db183-7bbf-488c-8754-54174f0ba47e. 2020-09-28 12:27:23.232 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=929ac675-0af2-40ae-ba89-977f5b358987, result=Result [data=None, error=Failure caused by error in tasks: send_message 2020-09-28 12:27:24.148 6 INFO workflow_trace [req-02272ea3-36ec-49a7-9042-e7917691b87c 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'introspect_nodes' (b8ab391f-3b4c-4ae7-9b5f-b426f1acf755) [RUNNING -> ERROR, msg=One or more actions had failed.] (execution_id=43188fcc-e4a0-489e-9032-a33fd8ae6902) 2020-09-28 12:27:24.168 6 DEBUG mistral.workflow.direct_workflow [req-02272ea3-36ec-49a7-9042-e7917691b87c 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Run task [workflow=tripleo.baremetal.v1.introspect, task=get_introspection_status, waif_flag=False, triggered_by=[{'task_id': 'b8ab391f-3b4c-4ae7-9b5f-b426f1acf755', 'event': 'on-error'}]]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 12:27:24.349 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=7a95c681-2379-4c3c-a0fa-95da19fb987f, result=Result [data={'error': None, 'finished': False, 'finished_at': None, 'links': [{'href': 'http://10.10.10.10:50..., error=None, cancel=False]] 2020-09-28 12:27:24.379 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=4056deae-94c4-47fd-855f-720e6ce5c5b1, result=Result [data={'error': None, 'finished': False, 'finished_at': None, 'links': [{'href': 'http://10.10.10.10:50..., error=None, cancel=False]] 2020-09-28 12:27:24.404 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.get_status' (7a95c681-2379-4c3c-a0fa-95da19fb987f)(task=get_introspection_status) [RUNNING -> SUCCESS, Result [data={'error': None, 'finished': False, 'finished_at': None, 'links': [{'href': 'http://10.10.10.10:50..., error=None, cancel=False]] 2020-09-28 12:27:24.445 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.get_status' (4056deae-94c4-47fd-855f-720e6ce5c5b1)(task=get_introspection_status) [RUNNING -> SUCCESS, Result [data={'error': None, 'finished': False, 'finished_at': None, 'links': [{'href': 'http://10.10.10.10:50..., error=None, cancel=False]] 2020-09-28 12:27:25.508 6 DEBUG mistral.expressions.yaql_expression [req-02272ea3-36ec-49a7-9042-e7917691b87c 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% task().result.where($.finished = true and $.error != null).select($.uuid) + task().result.where($.finished = false).select($.uuid) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:27:25.535 6 DEBUG mistral.expressions.yaql_expression [req-02272ea3-36ec-49a7-9042-e7917691b87c 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.failed_introspection.len() = 0 %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:27:25.540 6 DEBUG mistral.expressions.yaql_expression [req-02272ea3-36ec-49a7-9042-e7917691b87c 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.failed_introspection.len() > 0 %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:27:25.626 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=e0afea36-b1b0-46c6-9060-1e7270b0e115, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:25.650 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (e0afea36-b1b0-46c6-9060-1e7270b0e115)(task=increase_attempt_counter) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:25.687 6 DEBUG mistral.workflow.direct_workflow [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Run task [workflow=tripleo.baremetal.v1.introspect, task=retry_failed_nodes, waif_flag=False, triggered_by=[{'task_id': '8fd2585d-cfcf-48fc-80e1-9f6be61677b8', 'event': 'on-complete'}]]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 12:27:25.697 6 DEBUG mistral.engine.tasks [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting task [name=retry_failed_nodes, init_state=RUNNING, workflow_name=tripleo.baremetal.v1.introspect, execution_id=43188fcc-e4a0-489e-9032-a33fd8ae6902] _run_new /usr/lib/python3.6/site-packages/mistral/engine/tasks.py:525 2020-09-28 12:27:25.758 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=2614b8cc-0b9e-43d0-926b-83f3739ea640, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:25.776 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (2614b8cc-0b9e-43d0-926b-83f3739ea640)(task=retry_failed_nodes) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:25.790 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'retry_failed_nodes' (3e79bdc8-1dd1-43b8-a254-86a33e01bc8e) [RUNNING -> SUCCESS, msg=None] (execution_id=43188fcc-e4a0-489e-9032-a33fd8ae6902) 2020-09-28 12:27:25.796 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% 'Retrying {0} nodes that failed introspection. Attempt {1} of {2} '.format($.failed_introspection.len(), $.introspection_attempt, $.max_retry_attempts + 1) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:27:25.804 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.failed_introspection %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:27:26.034 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% { introspected_nodes => $.get('introspected_nodes', []), failed_introspection => $.get('failed_introspection', []) } %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:27:26.231 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=dd304b5d-a02a-4361-b0d7-5dd6eac371b1, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:26.274 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (dd304b5d-a02a-4361-b0d7-5dd6eac371b1)(task=merge_payload) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:26.512 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=98ead23d-0303-4f6b-80fb-0d1d92350ef5, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:26.552 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (98ead23d-0303-4f6b-80fb-0d1d92350ef5)(task=prepare_messages) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:26.846 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=70a56952-3fdc-407d-9a4e-cee943b6e3d5, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:26.901 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (70a56952-3fdc-407d-9a4e-cee943b6e3d5)(task=branch_workflow) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:27.425 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=376341d9-2726-4cc3-843c-a0db6dd22410, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:27.579 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (376341d9-2726-4cc3-843c-a0db6dd22410)(task=complete_swift) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:27.981 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=b8f62f9b-c113-4dee-8f10-1445950cf5e3, result=Result [data={'resources': ['/v2/queues/tripleo/messages/ea6bfaec-0142-11eb-9c7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 12:27:28.139 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'zaqar.queue_post' (b8f62f9b-c113-4dee-8f10-1445950cf5e3)(task=send_message) [RUNNING -> SUCCESS, Result [data={'resources': ['/v2/queues/tripleo/messages/ea6bfaec-0142-11eb-9c7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 12:27:29.320 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=ca74c02f-ee41-49e7-a82c-d0abeb41494c, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:29.359 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (ca74c02f-ee41-49e7-a82c-d0abeb41494c)(task=check_status) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:29.413 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.get('status') = "FAILED" %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:27:33.789 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=a8a3e3cc-90c0-46e0-873e-d809f748ad6b, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:33.877 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.introspect' (a8a3e3cc-90c0-46e0-873e-d809f748ad6b)(task=start_introspection) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:34.227 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=25ee8f9a-b66b-4f13-a772-77cd2cc29319, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:27:34.248 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.introspect' (25ee8f9a-b66b-4f13-a772-77cd2cc29319)(task=start_introspection) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:38.470 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=6ca28bb7-94fa-42d9-a8c2-80278dd2e4fd, result=Result [data=None, error=The action raised an exception [action_ex_id=6ca28bb7-94fa-42d9-a8c2-80278dd2e4fd, msg='BaremetalInt..., cancel=False]] 2020-09-28 12:47:38.500 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=15192e77-861f-44e9-8e09-f1dda85779f6, result=Result [data=None, error=The action raised an exception [action_ex_id=15192e77-861f-44e9-8e09-f1dda85779f6, msg='BaremetalInt..., cancel=False]] 2020-09-28 12:47:38.507 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.wait_for_finish' (6ca28bb7-94fa-42d9-a8c2-80278dd2e4fd)(task=wait_for_introspection_to_finish) [RUNNING -> ERROR, Result [data=None, error=The action raised an exception [action_ex_id=6ca28bb7-94fa-42d9-a8c2-80278dd2e4fd, msg='BaremetalInt..., cancel=False]] 2020-09-28 12:47:38.520 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.wait_for_finish' (15192e77-861f-44e9-8e09-f1dda85779f6)(task=wait_for_introspection_to_finish) [RUNNING -> ERROR, Result [data=None, error=The action raised an exception [action_ex_id=15192e77-861f-44e9-8e09-f1dda85779f6, msg='BaremetalInt..., cancel=False]] 2020-09-28 12:47:38.534 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'wait_for_introspection_to_finish' (3ab166b7-1080-4e47-8409-e92393295b73) [RUNNING -> ERROR, msg=The action raised an exception [action_ex_id=6ca28bb7-94fa-42d9-a8c2-80278dd2e4fd, msg='BaremetalIntrospectionAction.wait_for_finish failed: Timeout while waiting for introspection of nodes ['2b4db183-7bbf-488c-8754-54174f0ba47e']', action_cls=' ', attributes='{'client_method_name': 'wait_for_finish'}', params='{'uuids': ['2b4db183-7bbf-488c-8754-54174f0ba47e'], 'max_retries': 120, 'retry_interval': 10}']] (execution_id=8fc90761-6387-4a26-b97a-5524aefb6a27) 2020-09-28 12:47:38.543 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'wait_for_introspection_to_finish' (199544f6-e305-405a-a292-551296abdee2) [RUNNING -> ERROR, msg=The action raised an exception [action_ex_id=15192e77-861f-44e9-8e09-f1dda85779f6, msg='BaremetalIntrospectionAction.wait_for_finish failed: Timeout while waiting for introspection of nodes ['8aa29d4b-dd52-42a7-9b25-05d0999fbe3e']', action_cls=' ', attributes='{'client_method_name': 'wait_for_finish'}', params='{'uuids': ['8aa29d4b-dd52-42a7-9b25-05d0999fbe3e'], 'max_retries': 120, 'retry_interval': 10}']] (execution_id=d51bb8c4-89e2-4c6e-ba1a-11c5de341264) 2020-09-28 12:47:38.581 6 DEBUG mistral.workflow.direct_workflow [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Run task [workflow=tripleo.baremetal.v1._introspect, task=wait_for_introspection_to_finish_error, waif_flag=False, triggered_by=[{'task_id': '3ab166b7-1080-4e47-8409-e92393295b73', 'event': 'on-error'}]]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 12:47:38.587 6 DEBUG mistral.workflow.direct_workflow [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Run task [workflow=tripleo.baremetal.v1._introspect, task=wait_for_introspection_to_finish_error, waif_flag=False, triggered_by=[{'task_id': '199544f6-e305-405a-a292-551296abdee2', 'event': 'on-error'}]]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 12:47:38.599 6 DEBUG mistral.engine.tasks [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting task [name=wait_for_introspection_to_finish_error, init_state=RUNNING, workflow_name=tripleo.baremetal.v1._introspect, execution_id=8fc90761-6387-4a26-b97a-5524aefb6a27] _run_new /usr/lib/python3.6/site-packages/mistral/engine/tasks.py:525 2020-09-28 12:47:38.606 6 DEBUG mistral.engine.tasks [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting task [name=wait_for_introspection_to_finish_error, init_state=RUNNING, workflow_name=tripleo.baremetal.v1._introspect, execution_id=d51bb8c4-89e2-4c6e-ba1a-11c5de341264] _run_new /usr/lib/python3.6/site-packages/mistral/engine/tasks.py:525 2020-09-28 12:47:38.689 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=6874205b-0f33-492e-8033-3c7be664d99e, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:38.735 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=451aeaef-8bb7-489b-9ea1-c739479c45fc, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:38.745 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (6874205b-0f33-492e-8033-3c7be664d99e)(task=wait_for_introspection_to_finish_error) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:38.756 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (451aeaef-8bb7-489b-9ea1-c739479c45fc)(task=wait_for_introspection_to_finish_error) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:38.802 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'wait_for_introspection_to_finish_error' (118c0089-8a58-499a-8dad-de56486b2f5d) [RUNNING -> SUCCESS, msg=None] (execution_id=d51bb8c4-89e2-4c6e-ba1a-11c5de341264) 2020-09-28 12:47:38.813 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'wait_for_introspection_to_finish_error' (e51a0650-126a-483d-96de-b2f1c91aa202) [RUNNING -> SUCCESS, msg=None] (execution_id=8fc90761-6387-4a26-b97a-5524aefb6a27) 2020-09-28 12:47:38.824 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% "Introspection of node attempt failed:{0}.".format($.node_uuid) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:47:38.840 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% "Introspection of node attempt failed:{0}.".format($.node_uuid) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:47:38.961 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting workflow [name=tripleo.messaging.v1.send, input={'queue_name': 'tripleo', 'type': 'tripleo.baremetal.v1._introspect', 'status': 'FAILED', 'messag...] 2020-09-28 12:47:38.984 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting workflow [name=tripleo.messaging.v1.send, input={'queue_name': 'tripleo', 'type': 'tripleo.baremetal.v1._introspect', 'status': 'FAILED', 'messag...] 2020-09-28 12:47:39.130 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=6d8c4e7d-77b9-4a06-8abc-48ecc67162a5, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:39.174 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=f91b8a79-cb6b-4e0b-9a09-8dcb3bfd7ce4, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:39.187 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (6d8c4e7d-77b9-4a06-8abc-48ecc67162a5)(task=merge_payload) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:39.206 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (f91b8a79-cb6b-4e0b-9a09-8dcb3bfd7ce4)(task=merge_payload) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:39.424 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=8d1587fa-f9e3-4f5e-baf4-4652bfcda2c7, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:39.470 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=81f921f5-a08c-4612-b957-91ecb7e7bfa5, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:39.495 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (8d1587fa-f9e3-4f5e-baf4-4652bfcda2c7)(task=prepare_messages) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:39.508 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (81f921f5-a08c-4612-b957-91ecb7e7bfa5)(task=prepare_messages) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:39.695 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=7a25fb2d-4dcf-429b-a9d7-0f60729de978, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:39.745 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=ad8193da-fc31-4cef-8e83-ddf8a8b4e66b, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:39.751 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (7a25fb2d-4dcf-429b-a9d7-0f60729de978)(task=branch_workflow) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:39.773 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (ad8193da-fc31-4cef-8e83-ddf8a8b4e66b)(task=branch_workflow) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:39.982 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=7cad2a9f-b44b-46d4-b7c9-e6d698c4a703, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:40.138 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=fb42774c-60a7-4638-b3f9-be4a220b3e14, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:40.163 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (7cad2a9f-b44b-46d4-b7c9-e6d698c4a703)(task=complete_swift) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:40.321 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (fb42774c-60a7-4638-b3f9-be4a220b3e14)(task=complete_swift) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:42.018 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=a35f3651-38fb-4d15-8330-5fe16242d171, result=Result [data={'resources': ['/v2/queues/tripleo/messages/be119986-0145-11eb-9c7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 12:47:42.055 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'zaqar.queue_post' (a35f3651-38fb-4d15-8330-5fe16242d171)(task=send_message) [RUNNING -> SUCCESS, Result [data={'resources': ['/v2/queues/tripleo/messages/be119986-0145-11eb-9c7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 12:47:42.110 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=3753c53e-c130-4aa2-a05b-59964ec5ff1e, result=Result [data={'resources': ['/v2/queues/tripleo/messages/be0e7c1a-0145-11eb-bb7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 12:47:42.132 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'zaqar.queue_post' (3753c53e-c130-4aa2-a05b-59964ec5ff1e)(task=send_message) [RUNNING -> SUCCESS, Result [data={'resources': ['/v2/queues/tripleo/messages/be0e7c1a-0145-11eb-bb7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 12:47:42.614 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=357c773d-4dd1-460f-bbc7-294ef081c809, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:42.634 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (357c773d-4dd1-460f-bbc7-294ef081c809)(task=check_status) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:42.682 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.get('status') = "FAILED" %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:47:42.690 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% "Workflow failed due to message status. Status:{} Message:{}".format($.get('status'), $.get('message')) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:47:42.696 6 DEBUG mistral.workflow.direct_workflow [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Fail [workflow=tripleo.messaging.v1.send]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 12:47:42.758 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Workflow 'tripleo.messaging.v1.send' [RUNNING -> ERROR, msg=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:2b4db183-7bbf-488c-8754-54174f0ba47e.] (execution_id=db0385c7-2799-48ff-b9e6-1dac1d37b2cd) 2020-09-28 12:47:42.807 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=db0385c7-2799-48ff-b9e6-1dac1d37b2cd, result=Result [data=None, error=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:2b..., cancel=False]] 2020-09-28 12:47:42.849 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=1a55f077-66ce-4b73-87c5-760d02de2d43, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:42.896 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'send_message' (1fc62f7f-199e-455b-8b6e-eed963a660ea) [RUNNING -> ERROR, msg=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:2b4db183-7bbf-488c-8754-54174f0ba47e.] (execution_id=8fc90761-6387-4a26-b97a-5524aefb6a27) 2020-09-28 12:47:42.902 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (1a55f077-66ce-4b73-87c5-760d02de2d43)(task=check_status) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:42.978 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.get('status') = "FAILED" %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:47:42.983 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% "Workflow failed due to message status. Status:{} Message:{}".format($.get('status'), $.get('message')) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:47:42.989 6 DEBUG mistral.workflow.direct_workflow [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Fail [workflow=tripleo.messaging.v1.send]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 12:47:43.030 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Workflow 'tripleo.messaging.v1.send' [RUNNING -> ERROR, msg=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:8aa29d4b-dd52-42a7-9b25-05d0999fbe3e.] (execution_id=d7e4cd4f-dcea-4a62-a8ff-4e8d3e730fdb) 2020-09-28 12:47:43.098 6 WARNING oslo_db.sqlalchemy.utils [-] Unique keys not in sort_keys. The sorting order may be unstable. 2020-09-28 12:47:43.109 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=d7e4cd4f-dcea-4a62-a8ff-4e8d3e730fdb, result=Result [data=None, error=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:8a..., cancel=False]] 2020-09-28 12:47:43.170 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'send_message' (aab6e89e-4812-4831-aee0-747fdadbc13d) [RUNNING -> ERROR, msg=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:8aa29d4b-dd52-42a7-9b25-05d0999fbe3e.] (execution_id=d51bb8c4-89e2-4c6e-ba1a-11c5de341264) 2020-09-28 12:47:43.187 6 INFO workflow_trace [-] Workflow 'tripleo.baremetal.v1._introspect' [RUNNING -> ERROR, msg=Failure caused by error in tasks: send_message send_message [task_ex_id=1fc62f7f-199e-455b-8b6e-eed963a660ea] -> Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:2b4db183-7bbf-488c-8754-54174f0ba47e. [wf_ex_id=db0385c7-2799-48ff-b9e6-1dac1d37b2cd, idx=0]: Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:2b4db183-7bbf-488c-8754-54174f0ba47e. 2020-09-28 12:47:43.218 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=8fc90761-6387-4a26-b97a-5524aefb6a27, result=Result [data=None, error=Failure caused by error in tasks: send_message 2020-09-28 12:47:43.302 6 WARNING oslo_db.sqlalchemy.utils [-] Unique keys not in sort_keys. The sorting order may be unstable. 2020-09-28 12:47:43.364 6 INFO workflow_trace [-] Workflow 'tripleo.baremetal.v1._introspect' [RUNNING -> ERROR, msg=Failure caused by error in tasks: send_message send_message [task_ex_id=aab6e89e-4812-4831-aee0-747fdadbc13d] -> Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:8aa29d4b-dd52-42a7-9b25-05d0999fbe3e. [wf_ex_id=d7e4cd4f-dcea-4a62-a8ff-4e8d3e730fdb, idx=0]: Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:8aa29d4b-dd52-42a7-9b25-05d0999fbe3e. 2020-09-28 12:47:43.383 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=d51bb8c4-89e2-4c6e-ba1a-11c5de341264, result=Result [data=None, error=Failure caused by error in tasks: send_message 2020-09-28 12:47:44.007 6 INFO workflow_trace [req-02272ea3-36ec-49a7-9042-e7917691b87c 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'introspect_nodes' (25349a60-982c-4e20-830d-a8f3daf8f97f) [RUNNING -> ERROR, msg=One or more actions had failed.] (execution_id=43188fcc-e4a0-489e-9032-a33fd8ae6902) 2020-09-28 12:47:44.029 6 DEBUG mistral.workflow.direct_workflow [req-02272ea3-36ec-49a7-9042-e7917691b87c 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Run task [workflow=tripleo.baremetal.v1.introspect, task=get_introspection_status, waif_flag=False, triggered_by=[{'task_id': '25349a60-982c-4e20-830d-a8f3daf8f97f', 'event': 'on-error'}]]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 12:47:44.203 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=f6f9e860-513a-4727-81ec-f4a9b91ac470, result=Result [data={'error': None, 'finished': False, 'finished_at': None, 'links': [{'href': 'http://10.10.10.10:50..., error=None, cancel=False]] 2020-09-28 12:47:44.239 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.get_status' (f6f9e860-513a-4727-81ec-f4a9b91ac470)(task=get_introspection_status) [RUNNING -> SUCCESS, Result [data={'error': None, 'finished': False, 'finished_at': None, 'links': [{'href': 'http://10.10.10.10:50..., error=None, cancel=False]] 2020-09-28 12:47:44.241 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=79b8645e-08e9-4122-99be-948ba70ee429, result=Result [data={'error': None, 'finished': False, 'finished_at': None, 'links': [{'href': 'http://10.10.10.10:50..., error=None, cancel=False]] 2020-09-28 12:47:44.270 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.get_status' (79b8645e-08e9-4122-99be-948ba70ee429)(task=get_introspection_status) [RUNNING -> SUCCESS, Result [data={'error': None, 'finished': False, 'finished_at': None, 'links': [{'href': 'http://10.10.10.10:50..., error=None, cancel=False]] 2020-09-28 12:47:45.410 6 DEBUG mistral.expressions.yaql_expression [req-02272ea3-36ec-49a7-9042-e7917691b87c 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% task().result.where($.finished = true and $.error != null).select($.uuid) + task().result.where($.finished = false).select($.uuid) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:47:45.438 6 DEBUG mistral.expressions.yaql_expression [req-02272ea3-36ec-49a7-9042-e7917691b87c 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.failed_introspection.len() = 0 %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:47:45.443 6 DEBUG mistral.expressions.yaql_expression [req-02272ea3-36ec-49a7-9042-e7917691b87c 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.failed_introspection.len() > 0 %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:47:45.514 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=29468ab4-0dab-4130-a37f-027bc508e2bd, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:45.536 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (29468ab4-0dab-4130-a37f-027bc508e2bd)(task=increase_attempt_counter) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:45.577 6 DEBUG mistral.workflow.direct_workflow [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Run task [workflow=tripleo.baremetal.v1.introspect, task=retry_failed_nodes, waif_flag=False, triggered_by=[{'task_id': '5cae59df-0e0d-49c9-ac61-25cae2d17dd4', 'event': 'on-complete'}]]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 12:47:45.585 6 DEBUG mistral.engine.tasks [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting task [name=retry_failed_nodes, init_state=RUNNING, workflow_name=tripleo.baremetal.v1.introspect, execution_id=43188fcc-e4a0-489e-9032-a33fd8ae6902] _run_new /usr/lib/python3.6/site-packages/mistral/engine/tasks.py:525 2020-09-28 12:47:45.649 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=e6038d5c-5613-4e05-9afc-cbfb9dbc4461, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:45.662 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (e6038d5c-5613-4e05-9afc-cbfb9dbc4461)(task=retry_failed_nodes) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:45.678 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'retry_failed_nodes' (94f3d14f-f498-4bfd-afe5-6b19bf5ba39b) [RUNNING -> SUCCESS, msg=None] (execution_id=43188fcc-e4a0-489e-9032-a33fd8ae6902) 2020-09-28 12:47:45.684 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% 'Retrying {0} nodes that failed introspection. Attempt {1} of {2} '.format($.failed_introspection.len(), $.introspection_attempt, $.max_retry_attempts + 1) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:47:45.691 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.failed_introspection %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:47:45.926 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% { introspected_nodes => $.get('introspected_nodes', []), failed_introspection => $.get('failed_introspection', []) } %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:47:46.130 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=b3f72ac4-334f-49a8-8c07-0c0b5d6abe60, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:46.163 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (b3f72ac4-334f-49a8-8c07-0c0b5d6abe60)(task=merge_payload) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:46.404 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=fe61baba-e849-4015-834a-ee1da9eee3a4, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:46.443 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (fe61baba-e849-4015-834a-ee1da9eee3a4)(task=prepare_messages) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:46.668 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=42f78ecc-e0d5-44bf-a9ca-4c54e728d65d, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:46.707 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (42f78ecc-e0d5-44bf-a9ca-4c54e728d65d)(task=branch_workflow) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:47.038 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=2d8e5843-e0ef-4e45-a131-68d3a54e6ea6, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:47.133 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (2d8e5843-e0ef-4e45-a131-68d3a54e6ea6)(task=complete_swift) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:47.527 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=4ca08c3f-3253-46cb-bc00-731350842270, result=Result [data={'resources': ['/v2/queues/tripleo/messages/c1580d6e-0145-11eb-9c7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 12:47:47.585 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'zaqar.queue_post' (4ca08c3f-3253-46cb-bc00-731350842270)(task=send_message) [RUNNING -> SUCCESS, Result [data={'resources': ['/v2/queues/tripleo/messages/c1580d6e-0145-11eb-9c7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 12:47:48.129 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=e0ba2706-97ef-4115-a545-976b3c7586bf, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:48.167 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (e0ba2706-97ef-4115-a545-976b3c7586bf)(task=check_status) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:48.255 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.get('status') = "FAILED" %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 12:47:51.770 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=f096663c-43b4-42fd-bd54-053c970d9916, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:51.806 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.introspect' (f096663c-43b4-42fd-bd54-053c970d9916)(task=start_introspection) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:51.886 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=8c268be5-7624-4448-a121-2be740d57932, result=Result [data=None, error=None, cancel=False]] 2020-09-28 12:47:51.943 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.introspect' (8c268be5-7624-4448-a121-2be740d57932)(task=start_introspection) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:07:57.074 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=3f74443e-509e-43ee-8c51-17e67194c993, result=Result [data=None, error=The action raised an exception [action_ex_id=3f74443e-509e-43ee-8c51-17e67194c993, msg='BaremetalInt..., cancel=False]] 2020-09-28 13:07:57.116 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=4259f32e-f419-49c5-b49e-952d68767c36, result=Result [data=None, error=The action raised an exception [action_ex_id=4259f32e-f419-49c5-b49e-952d68767c36, msg='BaremetalInt..., cancel=False]] 2020-09-28 13:07:57.159 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.wait_for_finish' (3f74443e-509e-43ee-8c51-17e67194c993)(task=wait_for_introspection_to_finish) [RUNNING -> ERROR, Result [data=None, error=The action raised an exception [action_ex_id=3f74443e-509e-43ee-8c51-17e67194c993, msg='BaremetalInt..., cancel=False]] 2020-09-28 13:07:57.176 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.wait_for_finish' (4259f32e-f419-49c5-b49e-952d68767c36)(task=wait_for_introspection_to_finish) [RUNNING -> ERROR, Result [data=None, error=The action raised an exception [action_ex_id=4259f32e-f419-49c5-b49e-952d68767c36, msg='BaremetalInt..., cancel=False]] 2020-09-28 13:07:57.194 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'wait_for_introspection_to_finish' (94299bd8-5603-4b06-bfbc-6d3f806230fb) [RUNNING -> ERROR, msg=The action raised an exception [action_ex_id=3f74443e-509e-43ee-8c51-17e67194c993, msg='BaremetalIntrospectionAction.wait_for_finish failed: Timeout while waiting for introspection of nodes ['2b4db183-7bbf-488c-8754-54174f0ba47e']', action_cls=' ', attributes='{'client_method_name': 'wait_for_finish'}', params='{'uuids': ['2b4db183-7bbf-488c-8754-54174f0ba47e'], 'max_retries': 120, 'retry_interval': 10}']] (execution_id=5e73e143-c659-435d-8b9e-d33714169720) 2020-09-28 13:07:57.198 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'wait_for_introspection_to_finish' (19b22c9a-da39-479a-a48e-72a2181037a1) [RUNNING -> ERROR, msg=The action raised an exception [action_ex_id=4259f32e-f419-49c5-b49e-952d68767c36, msg='BaremetalIntrospectionAction.wait_for_finish failed: Timeout while waiting for introspection of nodes ['8aa29d4b-dd52-42a7-9b25-05d0999fbe3e']', action_cls=' ', attributes='{'client_method_name': 'wait_for_finish'}', params='{'uuids': ['8aa29d4b-dd52-42a7-9b25-05d0999fbe3e'], 'max_retries': 120, 'retry_interval': 10}']] (execution_id=89d926f4-0c2a-428e-992e-83ef2e6a81d6) 2020-09-28 13:07:57.231 6 DEBUG mistral.workflow.direct_workflow [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Run task [workflow=tripleo.baremetal.v1._introspect, task=wait_for_introspection_to_finish_error, waif_flag=False, triggered_by=[{'task_id': '19b22c9a-da39-479a-a48e-72a2181037a1', 'event': 'on-error'}]]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 13:07:57.253 6 DEBUG mistral.workflow.direct_workflow [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Run task [workflow=tripleo.baremetal.v1._introspect, task=wait_for_introspection_to_finish_error, waif_flag=False, triggered_by=[{'task_id': '94299bd8-5603-4b06-bfbc-6d3f806230fb', 'event': 'on-error'}]]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 13:07:57.255 6 DEBUG mistral.engine.tasks [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting task [name=wait_for_introspection_to_finish_error, init_state=RUNNING, workflow_name=tripleo.baremetal.v1._introspect, execution_id=89d926f4-0c2a-428e-992e-83ef2e6a81d6] _run_new /usr/lib/python3.6/site-packages/mistral/engine/tasks.py:525 2020-09-28 13:07:57.270 6 DEBUG mistral.engine.tasks [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting task [name=wait_for_introspection_to_finish_error, init_state=RUNNING, workflow_name=tripleo.baremetal.v1._introspect, execution_id=5e73e143-c659-435d-8b9e-d33714169720] _run_new /usr/lib/python3.6/site-packages/mistral/engine/tasks.py:525 2020-09-28 13:07:57.382 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=b6ed0976-05dd-42c6-8e1a-7e592f33af89, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:07:57.454 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=41b14494-c403-450a-a441-868bda8435d8, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:07:57.469 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (b6ed0976-05dd-42c6-8e1a-7e592f33af89)(task=wait_for_introspection_to_finish_error) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:07:57.486 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (41b14494-c403-450a-a441-868bda8435d8)(task=wait_for_introspection_to_finish_error) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:07:57.496 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'wait_for_introspection_to_finish_error' (1c14a33d-a701-4ce1-a7ed-f3b8b07b216f) [RUNNING -> SUCCESS, msg=None] (execution_id=89d926f4-0c2a-428e-992e-83ef2e6a81d6) 2020-09-28 13:07:57.511 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'wait_for_introspection_to_finish_error' (dfad81cb-f02f-4842-ac38-5d1c8f2b5d75) [RUNNING -> SUCCESS, msg=None] (execution_id=5e73e143-c659-435d-8b9e-d33714169720) 2020-09-28 13:07:57.514 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% "Introspection of node attempt failed:{0}.".format($.node_uuid) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:07:57.542 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% "Introspection of node attempt failed:{0}.".format($.node_uuid) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:07:57.656 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting workflow [name=tripleo.messaging.v1.send, input={'queue_name': 'tripleo', 'type': 'tripleo.baremetal.v1._introspect', 'status': 'FAILED', 'messag...] 2020-09-28 13:07:57.701 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting workflow [name=tripleo.messaging.v1.send, input={'queue_name': 'tripleo', 'type': 'tripleo.baremetal.v1._introspect', 'status': 'FAILED', 'messag...] 2020-09-28 13:07:57.890 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=598b5caa-c6df-4b33-8a5d-95b025e3f5da, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:07:57.933 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=d1d949ac-e624-4311-b906-a73268f58a21, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:07:57.942 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (598b5caa-c6df-4b33-8a5d-95b025e3f5da)(task=merge_payload) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:07:57.964 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (d1d949ac-e624-4311-b906-a73268f58a21)(task=merge_payload) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:07:58.115 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=40420ca5-6257-4593-9b83-e0136dc6bbfe, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:07:58.154 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=aac2f357-62f4-462c-b9f6-1b7f72fe3fc3, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:07:58.176 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (aac2f357-62f4-462c-b9f6-1b7f72fe3fc3)(task=prepare_messages) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:07:58.180 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (40420ca5-6257-4593-9b83-e0136dc6bbfe)(task=prepare_messages) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:07:58.356 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=726505b7-80b8-46b2-85c5-8f34fbbec6b0, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:07:58.393 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=cdb6b7ec-b6a8-42d1-ba78-17f2731fb461, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:07:58.415 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (726505b7-80b8-46b2-85c5-8f34fbbec6b0)(task=branch_workflow) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:07:58.461 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (cdb6b7ec-b6a8-42d1-ba78-17f2731fb461)(task=branch_workflow) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:07:58.833 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=579e7761-1b99-4689-9b40-d13715d3bcf1, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:07:59.004 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=a0a73bb3-5ba8-4398-ba90-d5ba4efc6d0c, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:07:59.037 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (579e7761-1b99-4689-9b40-d13715d3bcf1)(task=complete_swift) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:07:59.194 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (a0a73bb3-5ba8-4398-ba90-d5ba4efc6d0c)(task=complete_swift) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:00.756 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=63675460-07c3-4d9c-ad62-ddcdea27da63, result=Result [data={'resources': ['/v2/queues/tripleo/messages/946c7738-0148-11eb-9c7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 13:08:00.784 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'zaqar.queue_post' (63675460-07c3-4d9c-ad62-ddcdea27da63)(task=send_message) [RUNNING -> SUCCESS, Result [data={'resources': ['/v2/queues/tripleo/messages/946c7738-0148-11eb-9c7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 13:08:00.810 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=cb95f3c1-976e-4b23-9a09-30c6543e89b8, result=Result [data={'resources': ['/v2/queues/tripleo/messages/9480e3b2-0148-11eb-bb7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 13:08:00.825 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'zaqar.queue_post' (cb95f3c1-976e-4b23-9a09-30c6543e89b8)(task=send_message) [RUNNING -> SUCCESS, Result [data={'resources': ['/v2/queues/tripleo/messages/9480e3b2-0148-11eb-bb7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 13:08:02.060 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=a7bee595-c5c1-4815-bb9b-edfff9da6146, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:02.079 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (a7bee595-c5c1-4815-bb9b-edfff9da6146)(task=check_status) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:02.128 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.get('status') = "FAILED" %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:08:02.133 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% "Workflow failed due to message status. Status:{} Message:{}".format($.get('status'), $.get('message')) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:08:02.150 6 DEBUG mistral.workflow.direct_workflow [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Fail [workflow=tripleo.messaging.v1.send]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 13:08:02.207 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Workflow 'tripleo.messaging.v1.send' [RUNNING -> ERROR, msg=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:2b4db183-7bbf-488c-8754-54174f0ba47e.] (execution_id=09cb7197-8ba2-4ce4-a5c7-aa1da1c8cb82) 2020-09-28 13:08:02.249 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=09cb7197-8ba2-4ce4-a5c7-aa1da1c8cb82, result=Result [data=None, error=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:2b..., cancel=False]] 2020-09-28 13:08:02.295 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=5e4e2ec8-2b94-417f-9a53-1587d0cff357, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:02.315 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (5e4e2ec8-2b94-417f-9a53-1587d0cff357)(task=check_status) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:02.325 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'send_message' (0b16dc05-a210-4d22-8a2a-519a9703b44d) [RUNNING -> ERROR, msg=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:2b4db183-7bbf-488c-8754-54174f0ba47e.] (execution_id=5e73e143-c659-435d-8b9e-d33714169720) 2020-09-28 13:08:02.383 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.get('status') = "FAILED" %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:08:02.388 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% "Workflow failed due to message status. Status:{} Message:{}".format($.get('status'), $.get('message')) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:08:02.394 6 DEBUG mistral.workflow.direct_workflow [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Fail [workflow=tripleo.messaging.v1.send]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 13:08:02.453 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Workflow 'tripleo.messaging.v1.send' [RUNNING -> ERROR, msg=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:8aa29d4b-dd52-42a7-9b25-05d0999fbe3e.] (execution_id=ff8bd6f5-a9c5-42e6-b718-06f18f58e6be) 2020-09-28 13:08:02.498 6 WARNING oslo_db.sqlalchemy.utils [-] Unique keys not in sort_keys. The sorting order may be unstable. 2020-09-28 13:08:02.547 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=ff8bd6f5-a9c5-42e6-b718-06f18f58e6be, result=Result [data=None, error=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:8a..., cancel=False]] 2020-09-28 13:08:02.576 6 INFO workflow_trace [-] Workflow 'tripleo.baremetal.v1._introspect' [RUNNING -> ERROR, msg=Failure caused by error in tasks: send_message send_message [task_ex_id=0b16dc05-a210-4d22-8a2a-519a9703b44d] -> Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:2b4db183-7bbf-488c-8754-54174f0ba47e. [wf_ex_id=09cb7197-8ba2-4ce4-a5c7-aa1da1c8cb82, idx=0]: Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:2b4db183-7bbf-488c-8754-54174f0ba47e. 2020-09-28 13:08:02.584 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'send_message' (0df712cb-ee12-4d7f-a3bf-4c904b23ee25) [RUNNING -> ERROR, msg=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:8aa29d4b-dd52-42a7-9b25-05d0999fbe3e.] (execution_id=89d926f4-0c2a-428e-992e-83ef2e6a81d6) 2020-09-28 13:08:02.618 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=5e73e143-c659-435d-8b9e-d33714169720, result=Result [data=None, error=Failure caused by error in tasks: send_message 2020-09-28 13:08:02.732 6 WARNING oslo_db.sqlalchemy.utils [-] Unique keys not in sort_keys. The sorting order may be unstable. 2020-09-28 13:08:02.783 6 INFO workflow_trace [-] Workflow 'tripleo.baremetal.v1._introspect' [RUNNING -> ERROR, msg=Failure caused by error in tasks: send_message send_message [task_ex_id=0df712cb-ee12-4d7f-a3bf-4c904b23ee25] -> Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:8aa29d4b-dd52-42a7-9b25-05d0999fbe3e. [wf_ex_id=ff8bd6f5-a9c5-42e6-b718-06f18f58e6be, idx=0]: Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:8aa29d4b-dd52-42a7-9b25-05d0999fbe3e. 2020-09-28 13:08:02.810 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=89d926f4-0c2a-428e-992e-83ef2e6a81d6, result=Result [data=None, error=Failure caused by error in tasks: send_message 2020-09-28 13:08:03.417 6 INFO workflow_trace [req-02272ea3-36ec-49a7-9042-e7917691b87c 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'introspect_nodes' (324c1e3f-3705-4e6c-9a74-1f7eefcc3efc) [RUNNING -> ERROR, msg=One or more actions had failed.] (execution_id=43188fcc-e4a0-489e-9032-a33fd8ae6902) 2020-09-28 13:08:03.438 6 DEBUG mistral.workflow.direct_workflow [req-02272ea3-36ec-49a7-9042-e7917691b87c 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Run task [workflow=tripleo.baremetal.v1.introspect, task=get_introspection_status, waif_flag=False, triggered_by=[{'task_id': '324c1e3f-3705-4e6c-9a74-1f7eefcc3efc', 'event': 'on-error'}]]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 13:08:03.650 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=8b46df3a-c777-474f-ab35-f3d3b3906102, result=Result [data={'error': None, 'finished': False, 'finished_at': None, 'links': [{'href': 'http://10.10.10.10:50..., error=None, cancel=False]] 2020-09-28 13:08:03.671 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=1b67cf4d-321d-452c-980c-292e6e8aaaba, result=Result [data={'error': None, 'finished': False, 'finished_at': None, 'links': [{'href': 'http://10.10.10.10:50..., error=None, cancel=False]] 2020-09-28 13:08:03.685 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.get_status' (8b46df3a-c777-474f-ab35-f3d3b3906102)(task=get_introspection_status) [RUNNING -> SUCCESS, Result [data={'error': None, 'finished': False, 'finished_at': None, 'links': [{'href': 'http://10.10.10.10:50..., error=None, cancel=False]] 2020-09-28 13:08:03.689 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.get_status' (1b67cf4d-321d-452c-980c-292e6e8aaaba)(task=get_introspection_status) [RUNNING -> SUCCESS, Result [data={'error': None, 'finished': False, 'finished_at': None, 'links': [{'href': 'http://10.10.10.10:50..., error=None, cancel=False]] 2020-09-28 13:08:04.662 6 DEBUG mistral.expressions.yaql_expression [req-02272ea3-36ec-49a7-9042-e7917691b87c 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% task().result.where($.finished = true and $.error != null).select($.uuid) + task().result.where($.finished = false).select($.uuid) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:08:04.691 6 DEBUG mistral.expressions.yaql_expression [req-02272ea3-36ec-49a7-9042-e7917691b87c 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.failed_introspection.len() = 0 %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:08:04.695 6 DEBUG mistral.expressions.yaql_expression [req-02272ea3-36ec-49a7-9042-e7917691b87c 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.failed_introspection.len() > 0 %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:08:04.806 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=b72c1cfe-6854-48dd-8d90-a7264d833654, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:04.878 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (b72c1cfe-6854-48dd-8d90-a7264d833654)(task=increase_attempt_counter) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:04.981 6 DEBUG mistral.workflow.direct_workflow [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Run task [workflow=tripleo.baremetal.v1.introspect, task=retry_failed_nodes, waif_flag=False, triggered_by=[{'task_id': '432b9a84-b892-44ec-a407-3318dcb805c2', 'event': 'on-complete'}]]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 13:08:05.016 6 DEBUG mistral.engine.tasks [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting task [name=retry_failed_nodes, init_state=RUNNING, workflow_name=tripleo.baremetal.v1.introspect, execution_id=43188fcc-e4a0-489e-9032-a33fd8ae6902] _run_new /usr/lib/python3.6/site-packages/mistral/engine/tasks.py:525 2020-09-28 13:08:05.123 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=6ca00aaf-69dd-43ed-850f-b908c434c22e, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:05.153 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (6ca00aaf-69dd-43ed-850f-b908c434c22e)(task=retry_failed_nodes) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:05.196 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'retry_failed_nodes' (32454dd5-6825-43b5-b540-d4082156e604) [RUNNING -> SUCCESS, msg=None] (execution_id=43188fcc-e4a0-489e-9032-a33fd8ae6902) 2020-09-28 13:08:05.209 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% 'Retrying {0} nodes that failed introspection. Attempt {1} of {2} '.format($.failed_introspection.len(), $.introspection_attempt, $.max_retry_attempts + 1) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:08:05.221 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.failed_introspection %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:08:05.782 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% { introspected_nodes => $.get('introspected_nodes', []), failed_introspection => $.get('failed_introspection', []) } %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:08:06.118 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=114c50c5-4c78-4140-8897-bf6891c12812, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:06.226 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (114c50c5-4c78-4140-8897-bf6891c12812)(task=merge_payload) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:06.582 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=641804fd-8ac5-4004-af77-258abca1c679, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:06.643 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (641804fd-8ac5-4004-af77-258abca1c679)(task=prepare_messages) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:07.098 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=dbe89c5a-7006-42a9-aa5a-af4896537fce, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:07.153 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (dbe89c5a-7006-42a9-aa5a-af4896537fce)(task=branch_workflow) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:07.799 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=9b3b97b3-73f7-462c-8dd3-dd37894820ab, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:07.937 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (9b3b97b3-73f7-462c-8dd3-dd37894820ab)(task=complete_swift) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:08.124 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=4ee42105-62ee-4762-882a-d6f379621baf, result=Result [data={'resources': ['/v2/queues/tripleo/messages/98e442dc-0148-11eb-9c7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 13:08:08.170 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'zaqar.queue_post' (4ee42105-62ee-4762-882a-d6f379621baf)(task=send_message) [RUNNING -> SUCCESS, Result [data={'resources': ['/v2/queues/tripleo/messages/98e442dc-0148-11eb-9c7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 13:08:09.321 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=b18092ac-5c7b-4c87-98b8-96bb7de72c2f, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:09.355 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (b18092ac-5c7b-4c87-98b8-96bb7de72c2f)(task=check_status) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:09.406 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.get('status') = "FAILED" %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:08:10.826 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=97857958-793f-4100-9392-f72e27417cee, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:10.866 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.introspect' (97857958-793f-4100-9392-f72e27417cee)(task=start_introspection) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:11.037 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=440a4d68-1b5c-4a0c-acce-e900116ffbc9, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:08:11.057 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.introspect' (440a4d68-1b5c-4a0c-acce-e900116ffbc9)(task=start_introspection) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:15.588 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=0dde2d3f-87e8-4278-8e98-0a24ec0f916b, result=Result [data=None, error=The action raised an exception [action_ex_id=0dde2d3f-87e8-4278-8e98-0a24ec0f916b, msg='BaremetalInt..., cancel=False]] 2020-09-28 13:28:15.627 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=7aefe54e-46c7-41f1-abfe-cd8dca9336c9, result=Result [data=None, error=The action raised an exception [action_ex_id=7aefe54e-46c7-41f1-abfe-cd8dca9336c9, msg='BaremetalInt..., cancel=False]] 2020-09-28 13:28:15.636 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.wait_for_finish' (0dde2d3f-87e8-4278-8e98-0a24ec0f916b)(task=wait_for_introspection_to_finish) [RUNNING -> ERROR, Result [data=None, error=The action raised an exception [action_ex_id=0dde2d3f-87e8-4278-8e98-0a24ec0f916b, msg='BaremetalInt..., cancel=False]] 2020-09-28 13:28:15.648 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'baremetal_introspection.wait_for_finish' (7aefe54e-46c7-41f1-abfe-cd8dca9336c9)(task=wait_for_introspection_to_finish) [RUNNING -> ERROR, Result [data=None, error=The action raised an exception [action_ex_id=7aefe54e-46c7-41f1-abfe-cd8dca9336c9, msg='BaremetalInt..., cancel=False]] 2020-09-28 13:28:15.664 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'wait_for_introspection_to_finish' (511a5d94-27f7-4733-ac0d-efb917635a83) [RUNNING -> ERROR, msg=The action raised an exception [action_ex_id=0dde2d3f-87e8-4278-8e98-0a24ec0f916b, msg='BaremetalIntrospectionAction.wait_for_finish failed: Timeout while waiting for introspection of nodes ['8aa29d4b-dd52-42a7-9b25-05d0999fbe3e']', action_cls=' ', attributes='{'client_method_name': 'wait_for_finish'}', params='{'uuids': ['8aa29d4b-dd52-42a7-9b25-05d0999fbe3e'], 'max_retries': 120, 'retry_interval': 10}']] (execution_id=39407fb5-354f-4989-88e5-cf627b12f2d6) 2020-09-28 13:28:15.670 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'wait_for_introspection_to_finish' (f9946a8c-9fa1-4ae1-b2c5-d7a03ddcc6ce) [RUNNING -> ERROR, msg=The action raised an exception [action_ex_id=7aefe54e-46c7-41f1-abfe-cd8dca9336c9, msg='BaremetalIntrospectionAction.wait_for_finish failed: Timeout while waiting for introspection of nodes ['2b4db183-7bbf-488c-8754-54174f0ba47e']', action_cls=' ', attributes='{'client_method_name': 'wait_for_finish'}', params='{'uuids': ['2b4db183-7bbf-488c-8754-54174f0ba47e'], 'max_retries': 120, 'retry_interval': 10}']] (execution_id=5e0c77f6-9f54-4fa7-bbfe-908ceab17e7e) 2020-09-28 13:28:15.697 6 DEBUG mistral.workflow.direct_workflow [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Run task [workflow=tripleo.baremetal.v1._introspect, task=wait_for_introspection_to_finish_error, waif_flag=False, triggered_by=[{'task_id': '511a5d94-27f7-4733-ac0d-efb917635a83', 'event': 'on-error'}]]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 13:28:15.715 6 DEBUG mistral.workflow.direct_workflow [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Run task [workflow=tripleo.baremetal.v1._introspect, task=wait_for_introspection_to_finish_error, waif_flag=False, triggered_by=[{'task_id': 'f9946a8c-9fa1-4ae1-b2c5-d7a03ddcc6ce', 'event': 'on-error'}]]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 13:28:15.722 6 DEBUG mistral.engine.tasks [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting task [name=wait_for_introspection_to_finish_error, init_state=RUNNING, workflow_name=tripleo.baremetal.v1._introspect, execution_id=39407fb5-354f-4989-88e5-cf627b12f2d6] _run_new /usr/lib/python3.6/site-packages/mistral/engine/tasks.py:525 2020-09-28 13:28:15.728 6 DEBUG mistral.engine.tasks [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting task [name=wait_for_introspection_to_finish_error, init_state=RUNNING, workflow_name=tripleo.baremetal.v1._introspect, execution_id=5e0c77f6-9f54-4fa7-bbfe-908ceab17e7e] _run_new /usr/lib/python3.6/site-packages/mistral/engine/tasks.py:525 2020-09-28 13:28:15.835 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=de458dc6-ac3b-4faf-b95c-3a8470124be1, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:15.874 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=18196feb-82b5-4305-a494-6216dee1726a, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:15.886 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (de458dc6-ac3b-4faf-b95c-3a8470124be1)(task=wait_for_introspection_to_finish_error) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:15.908 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (18196feb-82b5-4305-a494-6216dee1726a)(task=wait_for_introspection_to_finish_error) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:15.911 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'wait_for_introspection_to_finish_error' (0a1304a0-b7a7-4dd6-a19e-e9003d7fb028) [RUNNING -> SUCCESS, msg=None] (execution_id=5e0c77f6-9f54-4fa7-bbfe-908ceab17e7e) 2020-09-28 13:28:15.927 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% "Introspection of node attempt failed:{0}.".format($.node_uuid) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:28:15.939 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'wait_for_introspection_to_finish_error' (c8540105-a4ab-4a77-91cb-cd3e5a2a1735) [RUNNING -> SUCCESS, msg=None] (execution_id=39407fb5-354f-4989-88e5-cf627b12f2d6) 2020-09-28 13:28:15.961 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% "Introspection of node attempt failed:{0}.".format($.node_uuid) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:28:16.082 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting workflow [name=tripleo.messaging.v1.send, input={'queue_name': 'tripleo', 'type': 'tripleo.baremetal.v1._introspect', 'status': 'FAILED', 'messag...] 2020-09-28 13:28:16.109 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting workflow [name=tripleo.messaging.v1.send, input={'queue_name': 'tripleo', 'type': 'tripleo.baremetal.v1._introspect', 'status': 'FAILED', 'messag...] 2020-09-28 13:28:16.246 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=f53cd320-a6ab-4ba0-bc41-d3dd7c04f512, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:16.287 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=853c5281-073f-4c8b-8821-ca7d5937e4e0, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:16.296 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (f53cd320-a6ab-4ba0-bc41-d3dd7c04f512)(task=merge_payload) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:16.316 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (853c5281-073f-4c8b-8821-ca7d5937e4e0)(task=merge_payload) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:16.475 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=610d7abf-3dc2-4bb7-aeb5-dc2c214591cb, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:16.514 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=4b181267-88c6-4879-9120-852d4d555208, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:16.526 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (610d7abf-3dc2-4bb7-aeb5-dc2c214591cb)(task=prepare_messages) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:16.547 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (4b181267-88c6-4879-9120-852d4d555208)(task=prepare_messages) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:16.706 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=b7316877-684d-4f9a-b123-ad6be97b7721, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:16.721 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (b7316877-684d-4f9a-b123-ad6be97b7721)(task=branch_workflow) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:16.769 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=45e6d2cf-648b-4345-b2d9-d6d289558e08, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:16.793 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (45e6d2cf-648b-4345-b2d9-d6d289558e08)(task=branch_workflow) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:16.978 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=a8ea91b3-7102-4c8b-99ed-cdc79dc7714a, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:17.049 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (a8ea91b3-7102-4c8b-99ed-cdc79dc7714a)(task=complete_swift) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:17.229 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=a5979c40-f87e-4781-9b82-bc32785e8ee0, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:17.381 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (a5979c40-f87e-4781-9b82-bc32785e8ee0)(task=complete_swift) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:18.569 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=2317dd39-bf64-4b51-bf25-44a874849494, result=Result [data={'resources': ['/v2/queues/tripleo/messages/6a56301c-014b-11eb-9c7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 13:28:18.618 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'zaqar.queue_post' (2317dd39-bf64-4b51-bf25-44a874849494)(task=send_message) [RUNNING -> SUCCESS, Result [data={'resources': ['/v2/queues/tripleo/messages/6a56301c-014b-11eb-9c7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 13:28:18.664 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=3f196e4e-87e7-4138-ab19-f39e0d3b8a1f, result=Result [data={'resources': ['/v2/queues/tripleo/messages/6a68c9c0-014b-11eb-bb7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 13:28:18.700 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'zaqar.queue_post' (3f196e4e-87e7-4138-ab19-f39e0d3b8a1f)(task=send_message) [RUNNING -> SUCCESS, Result [data={'resources': ['/v2/queues/tripleo/messages/6a68c9c0-014b-11eb-bb7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 13:28:18.968 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=bad2d47c-9661-4a2d-8874-77d1de79ca9d, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:18.985 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (bad2d47c-9661-4a2d-8874-77d1de79ca9d)(task=check_status) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:19.014 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.get('status') = "FAILED" %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:28:19.019 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% "Workflow failed due to message status. Status:{} Message:{}".format($.get('status'), $.get('message')) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:28:19.026 6 DEBUG mistral.workflow.direct_workflow [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Fail [workflow=tripleo.messaging.v1.send]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 13:28:19.058 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Workflow 'tripleo.messaging.v1.send' [RUNNING -> ERROR, msg=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:2b4db183-7bbf-488c-8754-54174f0ba47e.] (execution_id=ff5cf8ee-52f6-4b3c-b4a3-0a9ec220c52a) 2020-09-28 13:28:19.111 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=ff5cf8ee-52f6-4b3c-b4a3-0a9ec220c52a, result=Result [data=None, error=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:2b..., cancel=False]] 2020-09-28 13:28:19.146 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'send_message' (c4b3466b-34b1-4889-a84a-f38a8ec913db) [RUNNING -> ERROR, msg=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:2b4db183-7bbf-488c-8754-54174f0ba47e.] (execution_id=5e0c77f6-9f54-4fa7-bbfe-908ceab17e7e) 2020-09-28 13:28:19.284 6 WARNING oslo_db.sqlalchemy.utils [-] Unique keys not in sort_keys. The sorting order may be unstable. 2020-09-28 13:28:19.330 6 INFO workflow_trace [-] Workflow 'tripleo.baremetal.v1._introspect' [RUNNING -> ERROR, msg=Failure caused by error in tasks: send_message send_message [task_ex_id=c4b3466b-34b1-4889-a84a-f38a8ec913db] -> Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:2b4db183-7bbf-488c-8754-54174f0ba47e. [wf_ex_id=ff5cf8ee-52f6-4b3c-b4a3-0a9ec220c52a, idx=0]: Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:2b4db183-7bbf-488c-8754-54174f0ba47e. 2020-09-28 13:28:19.349 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=5e0c77f6-9f54-4fa7-bbfe-908ceab17e7e, result=Result [data=None, error=Failure caused by error in tasks: send_message 2020-09-28 13:28:20.126 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=0d02fd62-adf9-4db8-a942-df47c7236e65, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:20.148 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (0d02fd62-adf9-4db8-a942-df47c7236e65)(task=check_status) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:20.192 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.get('status') = "FAILED" %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:28:20.196 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% "Workflow failed due to message status. Status:{} Message:{}".format($.get('status'), $.get('message')) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:28:20.203 6 DEBUG mistral.workflow.direct_workflow [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Fail [workflow=tripleo.messaging.v1.send]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 13:28:20.243 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Workflow 'tripleo.messaging.v1.send' [RUNNING -> ERROR, msg=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:8aa29d4b-dd52-42a7-9b25-05d0999fbe3e.] (execution_id=83375607-678b-4654-acc9-a8c36edace4b) 2020-09-28 13:28:20.275 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=83375607-678b-4654-acc9-a8c36edace4b, result=Result [data=None, error=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:8a..., cancel=False]] 2020-09-28 13:28:20.299 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'send_message' (e339574e-2cd8-4c0a-9d26-d5826d90bdbc) [RUNNING -> ERROR, msg=Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:8aa29d4b-dd52-42a7-9b25-05d0999fbe3e.] (execution_id=39407fb5-354f-4989-88e5-cf627b12f2d6) 2020-09-28 13:28:20.389 6 WARNING oslo_db.sqlalchemy.utils [-] Unique keys not in sort_keys. The sorting order may be unstable. 2020-09-28 13:28:20.434 6 INFO workflow_trace [-] Workflow 'tripleo.baremetal.v1._introspect' [RUNNING -> ERROR, msg=Failure caused by error in tasks: send_message send_message [task_ex_id=e339574e-2cd8-4c0a-9d26-d5826d90bdbc] -> Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:8aa29d4b-dd52-42a7-9b25-05d0999fbe3e. [wf_ex_id=83375607-678b-4654-acc9-a8c36edace4b, idx=0]: Workflow failed due to message status. Status:FAILED Message:Introspection of node attempt failed:8aa29d4b-dd52-42a7-9b25-05d0999fbe3e. 2020-09-28 13:28:20.455 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=39407fb5-354f-4989-88e5-cf627b12f2d6, result=Result [data=None, error=Failure caused by error in tasks: send_message 2020-09-28 13:28:21.336 6 INFO workflow_trace [req-02272ea3-36ec-49a7-9042-e7917691b87c 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'introspect_nodes' (79017565-04d9-499a-93f9-cd15aca38765) [RUNNING -> ERROR, msg=One or more actions had failed.] (execution_id=43188fcc-e4a0-489e-9032-a33fd8ae6902) 2020-09-28 13:28:21.356 6 DEBUG mistral.workflow.direct_workflow [req-02272ea3-36ec-49a7-9042-e7917691b87c 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Run task [workflow=tripleo.baremetal.v1.introspect, task=max_retry_attempts_reached, waif_flag=False, triggered_by=[{'task_id': '79017565-04d9-499a-93f9-cd15aca38765', 'event': 'on-error'}]]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 13:28:21.418 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=0c23a7fb-af8e-44f5-b0c4-a9f0094d599c, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:21.434 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (0c23a7fb-af8e-44f5-b0c4-a9f0094d599c)(task=max_retry_attempts_reached) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:21.460 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% 'Retry limit reached with {0} nodes still failing introspection'.format($.failed_introspection.len()) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:28:21.517 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% { introspected_nodes => $.get('introspected_nodes', []), failed_introspection => $.get('failed_introspection', []) } %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:28:21.546 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting workflow [name=tripleo.messaging.v1.send, input={'queue_name': 'tripleo', 'type': 'tripleo.baremetal.v1.introspect', 'status': 'FAILED', 'message...] 2020-09-28 13:28:21.636 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=0b230564-4b6e-4389-bdc4-5aa2c5d32f6f, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:21.649 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (0b230564-4b6e-4389-bdc4-5aa2c5d32f6f)(task=merge_payload) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:21.767 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=95094406-2d9f-4669-8a18-a0b2a8e24fb2, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:21.780 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (95094406-2d9f-4669-8a18-a0b2a8e24fb2)(task=prepare_messages) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:21.906 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=d523afbb-6a57-4ae2-9604-3f888d9e2bdb, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:21.922 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (d523afbb-6a57-4ae2-9604-3f888d9e2bdb)(task=branch_workflow) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:22.105 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=0491ee34-8db7-45c4-9d9c-2f9a92f42cd7, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:22.172 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (0491ee34-8db7-45c4-9d9c-2f9a92f42cd7)(task=complete_swift) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:22.792 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=31d33370-06dc-4ccd-ada3-c4e636c58539, result=Result [data={'resources': ['/v2/queues/tripleo/messages/6ccbfb60-014b-11eb-9c7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 13:28:22.820 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'zaqar.queue_post' (31d33370-06dc-4ccd-ada3-c4e636c58539)(task=send_message) [RUNNING -> SUCCESS, Result [data={'resources': ['/v2/queues/tripleo/messages/6ccbfb60-014b-11eb-9c7d-525400c2818d']}, error=None, cancel=False]] 2020-09-28 13:28:23.829 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=4737689a-2276-4e80-a646-ff800febac74, result=Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:23.847 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Action 'std.noop' (4737689a-2276-4e80-a646-ff800febac74)(task=check_status) [RUNNING -> SUCCESS, Result [data=None, error=None, cancel=False]] 2020-09-28 13:28:23.874 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% $.get('status') = "FAILED" %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:28:23.881 6 DEBUG mistral.expressions.yaql_expression [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Starting to evaluate YAQL expression. [expression='% "Workflow failed due to message status. Status:{} Message:{}".format($.get('status'), $.get('message')) %>'] evaluate /usr/lib/python3.6/site-packages/mistral/expressions/yaql_expression.py:175 2020-09-28 13:28:23.887 6 DEBUG mistral.workflow.direct_workflow [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Found commands: [Fail [workflow=tripleo.messaging.v1.send]] _find_next_commands_for_task /usr/lib/python3.6/site-packages/mistral/workflow/direct_workflow.py:157 2020-09-28 13:28:23.918 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Workflow 'tripleo.messaging.v1.send' [RUNNING -> ERROR, msg=Workflow failed due to message status. Status:FAILED Message:Retry limit reached with 2 nodes still failing introspection] (execution_id=89c35cc0-c179-490e-ad7c-b50bc2a1c36c) 2020-09-28 13:28:23.945 6 INFO mistral.engine.engine_server [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'on_action_complete'[action_ex_id=89c35cc0-c179-490e-ad7c-b50bc2a1c36c, result=Result [data=None, error=Workflow failed due to message status. Status:FAILED Message:Retry limit reached with 2 nodes still ..., cancel=False]] 2020-09-28 13:28:23.966 6 INFO workflow_trace [req-b0904acf-a4e2-41bb-a82c-8d4e4e7c68de 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Task 'send_message' (c7218062-acc2-4baa-be01-ad7ebf5fef27) [RUNNING -> ERROR, msg=Workflow failed due to message status. Status:FAILED Message:Retry limit reached with 2 nodes still failing introspection] (execution_id=43188fcc-e4a0-489e-9032-a33fd8ae6902) 2020-09-28 13:28:24.052 6 WARNING oslo_db.sqlalchemy.utils [-] Unique keys not in sort_keys. The sorting order may be unstable. 2020-09-28 13:28:24.099 6 INFO workflow_trace [-] Workflow 'tripleo.baremetal.v1.introspect' [RUNNING -> ERROR, msg=Failure caused by error in tasks: send_message send_message [task_ex_id=c7218062-acc2-4baa-be01-ad7ebf5fef27] -> Workflow failed due to message status. Status:FAILED Message:Retry limit reached with 2 nodes still failing introspection [wf_ex_id=89c35cc0-c179-490e-ad7c-b50bc2a1c36c, idx=0]: Workflow failed due to message status. Status:FAILED Message:Retry limit reached with 2 nodes still failing introspection
MISTRAL EXECUTOR LOGS
[root@undercloud containers]# grep -iE "(fail|error|warn|denied)" mistral/executor.log 2020-09-28 12:06:52.602 6 WARNING tripleo_common.utils.nodes [req-331aca0d-d9b8-4a7c-8836-3fcdc9eea72b 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Replacing deprecated driver pxe_ipmitool with the hardware type ipmi, please update your inventory 2020-09-28 12:06:54.870 6 WARNING tripleo_common.utils.nodes [req-331aca0d-d9b8-4a7c-8836-3fcdc9eea72b 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Replacing deprecated driver pxe_ipmitool with the hardware type ipmi, please update your inventory 2020-09-28 12:06:58.411 6 DEBUG mistral.executors.executor_server [req-331aca0d-d9b8-4a7c-8836-3fcdc9eea72b 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'run_action'[action_ex_id=53b159d1-927c-4583-b6ef-86b8d7d6884e, action_cls_str=mistral.actions.openstack.actions.IronicAction, action_cls_attrs={'client_method_name': 'node.get'}, params={'node_id': '8aa29d4b-dd52-42a7-9b25-05d0999fbe3e', 'fields': ['provision_state', 'last_error']}, timeout=1200] run_action /usr/lib/python3.6/site-packages/mistral/executors/executor_server.py:94 2020-09-28 12:06:58.866 6 DEBUG mistral.executors.executor_server [req-331aca0d-d9b8-4a7c-8836-3fcdc9eea72b 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'run_action'[action_ex_id=299c5f9c-ecd0-4fd1-9879-bbd4ec501b7a, action_cls_str=mistral.actions.openstack.actions.IronicAction, action_cls_attrs={'client_method_name': 'node.get'}, params={'node_id': '2b4db183-7bbf-488c-8754-54174f0ba47e', 'fields': ['provision_state', 'last_error']}, timeout=1200] run_action /usr/lib/python3.6/site-packages/mistral/executors/executor_server.py:94 2020-09-28 12:07:02.854 6 DEBUG mistral.executors.executor_server [req-fda60dfa-6dfb-41b3-b7c8-ff0baa8ff9bc 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'run_action'[action_ex_id=515881f8-c2e1-4b35-a53e-36ba4bd4c431, action_cls_str=mistral.actions.openstack.actions.IronicAction, action_cls_attrs={'client_method_name': 'node.get'}, params={'node_id': '2b4db183-7bbf-488c-8754-54174f0ba47e', 'fields': ['provision_state', 'last_error']}, timeout=1200] run_action /usr/lib/python3.6/site-packages/mistral/executors/executor_server.py:94 2020-09-28 12:07:03.063 6 DEBUG mistral.executors.executor_server [req-fda60dfa-6dfb-41b3-b7c8-ff0baa8ff9bc 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Received RPC request 'run_action'[action_ex_id=51e88369-a9d1-4469-b714-b8580c5be64d, action_cls_str=mistral.actions.openstack.actions.IronicAction, action_cls_attrs={'client_method_name': 'node.get'}, params={'node_id': '8aa29d4b-dd52-42a7-9b25-05d0999fbe3e', 'fields': ['provision_state', 'last_error']}, timeout=1200] run_action /usr/lib/python3.6/site-packages/mistral/executors/executor_server.py:94 2020-09-28 12:27:18.382 6 WARNING mistral.actions.openstack.base [req-fda60dfa-6dfb-41b3-b7c8-ff0baa8ff9bc 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Traceback (most recent call last): ... 2020-09-28 13:28:15.618 6 WARNING mistral.actions.openstack.base [req-02272ea3-36ec-49a7-9042-e7917691b87c 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] Traceback (most recent call last): ironic_inspector_client.v1.WaitTimeoutError: Timeout while waiting for introspection of nodes ['2b4db183-7bbf-488c-8754-54174f0ba47e'] : ironic_inspector_client.v1.WaitTimeoutError: Timeout while waiting for introspection of nodes ['2b4db183-7bbf-488c-8754-54174f0ba47e'] 2020-09-28 13:28:15.619 6 WARNING mistral.executors.default_executor [req-02272ea3-36ec-49a7-9042-e7917691b87c 51b4a4f00e7c402ab3671cbbb83efab9 d12e223fba6945e6ac286da962231bcb - default default] The action raised an exception [action_ex_id=7aefe54e-46c7-41f1-abfe-cd8dca9336c9, msg='BaremetalIntrospectionAction.wait_for_finish failed: Timeout while waiting for introspection of nodes ['2b4db183-7bbf-488c-8754-54174f0ba47e']', action_cls='', attributes='{'client_method_name': 'wait_for_finish'}', params='{'uuids': ['2b4db183-7bbf-488c-8754-54174f0ba47e'], 'max_retries': 120, 'retry_interval': 10}']: mistral.exceptions.ActionException: BaremetalIntrospectionAction.wait_for_finish failed: Timeout while waiting for introspection of nodes ['2b4db183-7bbf-488c-8754-54174f0ba47e'] 2020-09-28 13:28:15.619 6 ERROR mistral.executors.default_executor Traceback (most recent call last): 2020-09-28 13:28:15.619 6 ERROR mistral.executors.default_executor File "/usr/lib/python3.6/site-packages/mistral/actions/openstack/base.py", line 117, in run 2020-09-28 13:28:15.619 6 ERROR mistral.executors.default_executor result = method(**self._kwargs_for_run) 2020-09-28 13:28:15.619 6 ERROR mistral.executors.default_executor File "/usr/lib/python3.6/site-packages/ironic_inspector_client/v1.py", line 265, in wait_for_finish 2020-09-28 13:28:15.619 6 ERROR mistral.executors.default_executor "of nodes %s") % new_active_node_ids) 2020-09-28 13:28:15.619 6 ERROR mistral.executors.default_executor ironic_inspector_client.v1.WaitTimeoutError: Timeout while waiting for introspection of nodes ['2b4db183-7bbf-488c-8754-54174f0ba47e'] 2020-09-28 13:28:15.619 6 ERROR mistral.executors.default_executor 2020-09-28 13:28:15.619 6 ERROR mistral.executors.default_executor During handling of the above exception, another exception occurred: 2020-09-28 13:28:15.619 6 ERROR mistral.executors.default_executor 2020-09-28 13:28:15.619 6 ERROR mistral.executors.default_executor Traceback (most recent call last): 2020-09-28 13:28:15.619 6 ERROR mistral.executors.default_executor File "/usr/lib/python3.6/site-packages/mistral/executors/default_executor.py", line 133, in _do_run_action 2020-09-28 13:28:15.619 6 ERROR mistral.executors.default_executor result = action.run(action_ctx) 2020-09-28 13:28:15.619 6 ERROR mistral.executors.default_executor File "/usr/lib/python3.6/site-packages/mistral/actions/openstack/base.py", line 130, in run 2020-09-28 13:28:15.619 6 ERROR mistral.executors.default_executor (self.__class__.__name__, self.client_method_name, str(e)) 2020-09-28 13:28:15.619 6 ERROR mistral.executors.default_executor mistral.exceptions.ActionException: BaremetalIntrospectionAction.wait_for_finish failed: Timeout while waiting for introspection of nodes ['2b4db183-7bbf-488c-8754-54174f0ba47e'] 2020-09-28 13:28:15.619 6 ERROR mistral.executors.default_executor
NOVA-COMPUTE LOGS
[root@undercloud containers]# grep -iE "(fail|error|warn|denied)" nova/nova-compute.log 2020-09-28 12:07:15.103 6 ERROR nova.compute.manager [req-76b53cba-540c-4069-bb12-85b5f2b71f14 - - - - -] No compute node record for host undercloud.overcloud.domain: nova.exception_Remote.ComputeHostNotFound_Remote: Compute host undercloud.overcloud.domain could not be found. 2020-09-28 12:07:15.143 6 WARNING nova.compute.resource_tracker [req-76b53cba-540c-4069-bb12-85b5f2b71f14 - - - - -] No compute node record for undercloud.overcloud.domain:8aa29d4b-dd52-42a7-9b25-05d0999fbe3e: nova.exception_Remote.ComputeHostNotFound_Remote: Compute host undercloud.overcloud.domain could not be found. 2020-09-28 12:07:16.805 6 WARNING nova.compute.resource_tracker [req-76b53cba-540c-4069-bb12-85b5f2b71f14 - - - - -] No compute node record for undercloud.overcloud.domain:2b4db183-7bbf-488c-8754-54174f0ba47e: nova.exception_Remote.ComputeHostNotFound_Remote: Compute host undercloud.overcloud.domain could not be found.
Responses