When using Ironic ovirt driver, "openstack baremetal node reboot <uuid>" when node is powered on, it does not reboot Env: openstack-ironic-staging-drivers-0.9.0-4.el7ost.noarch How reproducible: 100% Steps: PreReq: RHV environment with undercloud 1) Config undercloud.conf and Install undercloud with osp13 latest in RHV environment 2) Configure /etc/ironic.conf Add staging-ovirt and credentials for ovirt ----> enabled_hardware_types=redfish,ipmi,idrac,ilo,staging-ovirt enabled_management_interfaces=redfish,ilo,idrac,ipmitool,fake,staging-ovirt enabled_power_interfaces=redfish,ilo,idrac,ipmitool,fake,staging-ovirt 3) install drivers sudo yum install -y gcc python-devel libxml2-devel libcurl-devel python-enum34 -y wget http://download.eng.bos.redhat.com/brewroot/packages/python-ovirt-engine-sdk4/4.2.6/1.el7ev/x86_64/python-ovirt-engine-sdk4-4.2.6-1.el7ev.x86_64.rpm rpm -ihv python-ovirt-engine-sdk4-4.2.6-1.el7ev.x86_64.rpm 4) import / introspect 5) with any node powered up; run openstack baremetal node reboot <uuid> Actual results: The node remains powered up Expected results: It is expected that it reboots (off/on) Additional info: 2018-05-08 15:20:14.987 36396 DEBUG ironic.conductor.manager [req-9610c785-3e80-49b6-a20a-4070aadbd02e e0749763684d475aadb1def62c071429 acdd32457726432e9181ceadb42227fb - default default] RPC change_node_power_state called for node abde7a98-b259-4002-a900-6c628c4a8c38. The desired new state is rebooting. change_node_power_state /usr/lib/python2.7/site-packages/ironic/conductor/manager.py:243 2018-05-08 15:20:14.998 36396 DEBUG ironic.conductor.task_manager [req-9610c785-3e80-49b6-a20a-4070aadbd02e e0749763684d475aadb1def62c071429 acdd32457726432e9181ceadb42227fb - default default] Attempting to get exclusive lock on node abde7a98-b259-4002-a900-6c628c4a8c38 (for changing node power state) __init__ /usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py:225 2018-05-08 15:20:15.012 36396 DEBUG ironic.conductor.task_manager [req-9610c785-3e80-49b6-a20a-4070aadbd02e e0749763684d475aadb1def62c071429 acdd32457726432e9181ceadb42227fb - default default] Node abde7a98-b259-4002-a900-6c628c4a8c38 successfully reserved for changing node power state (took 0.01 seconds) reserve_node /usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py:273 2018-05-08 15:20:15.287 36396 INFO ironic.conductor.utils [req-9610c785-3e80-49b6-a20a-4070aadbd02e e0749763684d475aadb1def62c071429 acdd32457726432e9181ceadb42227fb - default default] Successfully set node abde7a98-b259-4002-a900-6c628c4a8c38 power state to power on by rebooting. 2018-05-08 15:20:15.292 36396 DEBUG ironic.conductor.task_manager [req-9610c785-3e80-49b6-a20a-4070aadbd02e e0749763684d475aadb1def62c071429 acdd32457726432e9181ceadb42227fb - default default] Successfully released exclusive lock for changing node power state on node abde7a98-b259-4002-a900-6c628c4a8c38 (lock was held 0.28 sec) release_resources /usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py:352 2018-05-08 15:20:18.003 36396 DEBUG futurist.periodics [-] Submitting periodic callback 'ironic.conductor.manager.ConductorManager._send_sensor_data' _process_scheduled /usr/lib/python2.7/site-packages/futurist/periodics.py:639 2018-05-08 15:20:18.517 36396 DEBUG futurist.periodics [-] Submitting periodic callback 'ironic.drivers.modules.drac.raid.DracRAID._query_raid_config_job_status' _process_scheduled /usr/lib/python2.7/site-packages/futurist/periodics.py:639 2018-05-08 15:20:18.531 36396 DEBUG ironic.conductor.task_manager [req-0a3feb7e-c3cc-40c9-a5ea-c3cd9b271b97 - - - - -] Attempting to get shared lock on node abde7a98-b259-4002-a900-6c628c4a8c38 (for checking async raid configuration jobs) __init__ /usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py:225 2018-05-08 15:20:18.545 36396 DEBUG ironic.conductor.task_manager [req-0a3feb7e-c3cc-40c9-a5ea-c3cd9b271b97 - - - - -] Successfully released shared lock for checking async raid configuration jobs on node abde7a98-b259-4002-a900-6c628c4a8c38 (lock was held 0.01 sec) release_resources /usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py:352 2018-05-08 15:20:18.554 36396 DEBUG ironic.conductor.task_manager [req-0a3feb7e-c3cc-40c9-a5ea-c3cd9b271b97 - - - - -] Attempting to get shared lock on node 4bc48435-587c-41ab-819a-9d055d108cd6 (for checking async raid configuration jobs) __init__ /usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py:225 2018-05-08 15:20:18.568 36396 DEBUG ironic.conductor.task_manager [req-0a3feb7e-c3cc-40c9-a5ea-c3cd9b271b97 - - - - -] Successfully released shared lock for checking async raid configuration jobs on node 4bc48435-587c-41ab-819a-9d055d108cd6 (lock was held 0.01 sec) release_resources /usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py:352 2018-05-08 15:20:18.577 36396 DEBUG ironic.conductor.task_manager [req-0a3feb7e-c3cc-40c9-a5ea-c3cd9b271b97 - - - - -] Attempting to get shared lock on node 77cb3fe4-f7af-4ffe-831a-f81b10d90c13 (for checking async raid configuration jobs) __init__ /usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py:225 2018-05-08 15:20:18.590 36396 DEBUG ironic.conductor.task_manager [req-0a3feb7e-c3cc-40c9-a5ea-c3cd9b271b97 - - - - -] Successfully released shared lock for checking async raid configuration jobs on node 77cb3fe4-f7af-4ffe-831a-f81b10d90c13 (lock was held 0.01 sec) release_resources /usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py:352 2018-05-08 15:20:18.602 36396 DEBUG ironic.conductor.task_manager [req-0a3feb7e-c3cc-40c9-a5ea-c3cd9b271b97 - - - - -] Attempting to get shared lock on node 48da76b5-768e-4595-bb50-d45ecbd50fd4 (for checking async raid configuration jobs) __init__ /usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py:225 2018-05-08 15:20:18.616 36396 DEBUG ironic.conductor.task_manager [req-0a3feb7e-c3cc-40c9-a5ea-c3cd9b271b97 - - - - -] Successfully released shared lock for checking async raid configuration jobs on node 48da76b5-768e-4595-bb50-d45ecbd50fd4 (lock was held 0.01 sec) release_resources /usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py:352 2018-05-08 15:20:21.576 36396 DEBUG futurist.periodics [-] Submitting periodic callback 'ironic.conductor.manager.ConductorManager._sync_local_state' _process_scheduled /usr/lib/python2.7/site-packages/futurist/periodics.py:639 2018-05-08 15:20:21.705 36396 DEBUG futurist.periodics [-] Submitting periodic callback 'ironic.conductor.manager.ConductorManager._check_cleanwait_timeouts' _process_scheduled /usr/lib/python2.7/site-packages/futurist/periodics.py:639 2018-05-08 15:20:21.712 36396 DEBUG futurist.periodics [-] Submitting periodic callback 'ironic.conductor.manager.ConductorManager._check_deploy_timeouts' _process_scheduled /usr/lib/python2.7/site-packages/futurist/periodics.py:639 2018-05-08 15:20:21.715 36396 DEBUG futurist.periodics [-] Submitting periodic callback 'ironic.conductor.manager.ConductorManager._check_inspect_timeouts' _process_scheduled /usr/lib/python2.7/site-packages/futurist/periodics.py:639 2018-05-08 15:20:21.719 36396 DEBUG futurist.periodics [-] Submitting periodic callback 'ironic.conductor.manager.ConductorManager._check_orphan_nodes' _process_scheduled /usr/lib/python2.7/site-packages/futurist/periodics.py:639 2018-05-08 15:20:21.721 36396 DEBUG futurist.periodics [-] Submitting periodic callback 'ironic.conductor.manager.ConductorManager._check_rescuewait_timeouts' _process_scheduled /usr/lib/python2.7/site-packages/futurist/periodics.py:639 2018-05-08 15:20:21.726 36396 DEBUG futurist.periodics [-] Submitting periodic callback 'ironic.conductor.manager.ConductorManager._sync_power_states' _process_scheduled /usr/lib/python2.7/site-packages/futurist/periodics.py:639 2018-05-08 15:20:21.738 36396 DEBUG ironic.conductor.task_manager [req-0a3feb7e-c3cc-40c9-a5ea-c3cd9b271b97 - - - - -] Attempting to get shared lock on node abde7a98-b259-4002-a900-6c628c4a8c38 (for power state sync) __init__ /usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py:225 2018-05-08 15:20:21.945 36396 DEBUG ironic.conductor.task_manager [req-0a3feb7e-c3cc-40c9-a5ea-c3cd9b271b97 - - - - -] Successfully released shared lock for power state sync on node abde7a98-b259-4002-a900-6c628c4a8c38 (lock was held 0.21 sec) release_resources /usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py:352 2018-05-08 15:20:21.955 36396 DEBUG ironic.conductor.task_manager [req-0a3feb7e-c3cc-40c9-a5ea-c3cd9b271b97 - - - - -] Attempting to get shared lock on node 4bc48435-587c-41ab-819a-9d055d108cd6 (for power state sync) __init__ /usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py:225 2018-05-08 15:20:22.093 36396 DEBUG ironic.conductor.task_manager [req-0a3feb7e-c3cc-40c9-a5ea-c3cd9b271b97 - - - - -] Successfully released shared lock for power state sync on node 4bc48435-587c-41ab-819a-9d055d108cd6 (lock was held 0.14 sec) release_resources /usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py:352 2018-05-08 15:20:22.103 36396 DEBUG ironic.conductor.task_manager [req-0a3feb7e-c3cc-40c9-a5ea-c3cd9b271b97 - - - - -] Attempting to get shared lock on node 77cb3fe4-f7af-4ffe-831a-f81b10d90c13 (for power state sync) __init__ /usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py:225 2018-05-08 15:20:22.238 36396 DEBUG ironic.conductor.task_manager [req-0a3feb7e-c3cc-40c9-a5ea-c3cd9b271b97 - - - - -] Successfully released shared lock for power state sync on node 77cb3fe4-f7af-4ffe-831a-f81b10d90c13 (lock was held 0.13 sec) release_resources /usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py:352 2018-05-08 15:20:22.263 36396 DEBUG ironic.conductor.task_manager [req-0a3feb7e-c3cc-40c9-a5ea-c3cd9b271b97 - - - - -] Attempting to get shared lock on node 48da76b5-768e-4595-bb50-d45ecbd50fd4 (for power state sync) __init__ /usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py:225 2018-05-08 15:20:22.405 36396 DEBUG ironic.conductor.task_manager [req-0a3feb7e-c3cc-40c9-a5ea-c3cd9b271b97 - - - - -] Successfully released shared lock for power state sync on node 48da76b5-768e-4595-bb50-d45ecbd50fd4 (lock was held 0.14 sec) release_resources /usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py:352 2018-05-08 15:20:25.412 36396 DEBUG futurist.periodics [-] Submitting periodic callback 'ironic.drivers.modules.inspector.Inspector._periodic_check_result' _process_scheduled /usr/lib/python2.7/site-packages/futurist/periodics.py:639
Can this bug be a duplicate of BZ#1568442?
> Can this bug be a duplicate of BZ#1568442? I don't believe so as Mike was testing with the fix for that BZ when he came across this issue.
I have two suspects: 1. we don't understand how reboot() works 2. we need to split reboot into on, then off, waiting for each result. Without any oVirt expertise I cannot judge further.
Using the same package versions mentioned above python-ovirt-engine-sdk4-4.2.6-1.el7ev.x86_64 openstack-ironic-staging-drivers-0.9.0-4.el7ost.noarch oVirt version 4.2.6.4-1.el7 and following the steps described, the node successfully reboots(multiple attempts). The node as remains active during the reboot, | aae6b830-4bde-4e90-a98d-df07d3923824 | ironic-0 | 0969cbca-ad8c-42d9-86c3-4c77ca145bf6 | power on | active | False | @mlammon if you were looking at the output of "openstack baremetal node list" it wouldn't have shown the node rebooting, was this the case? Or were you ssh'd onto the node?
Closing as we have no current reproducer, will reopen if its observed happening again.