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.conf and overcloud-stackenv.json files used during undercloud installation and node import, respectively:

(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_type value to ipmitool, but issue encountered is still the same.

Output 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: unclosed <socket.socket fd=4, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('10.10.10.10', 60614)>
sys:1: ResourceWarning: unclosed <socket.socket fd=6, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('10.10.10.10', 48436)>

I can control/access the nodes via ipmitool command.

(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='<class 'mistral.actions.action_factory.BaremetalIntrospectionAction'>', 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='<class 'mistral.actions.action_factory.BaremetalIntrospectionAction'>', 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='<class 'mistral.actions.action_factory.BaremetalIntrospectionAction'>', 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='<class 'mistral.actions.action_factory.BaremetalIntrospectionAction'>', 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='<class 'mistral.actions.action_factory.BaremetalIntrospectionAction'>', 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='<class 'mistral.actions.action_factory.BaremetalIntrospectionAction'>', 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='<class 'mistral.actions.action_factory.BaremetalIntrospectionAction'>', 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='<class 'mistral.actions.action_factory.BaremetalIntrospectionAction'>', 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='<class 'mistral.actions.action_factory.BaremetalIntrospectionAction'>', 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.