Description
===========
A new issue with ironic and ipmi has cropped up today. It would seem that ironic has no problems turning the node on and off for inspection, but when it comes time to clean it throws the following errors. Doesn't seem to matter if I am using virt hosts or real metal.
ipmi has been pretty reliable in the past, and I even have an instance of tripleo/stein that works just fine.
Expected/actual result
===============
does work / doesn't work
Environment
===========
Tripleo/Stein
Logs
===========
Here is the log output.
(undercloud) [stack@tripleo ~]$ openstack overcloud node import --introspect --provide instackenv.json
Waiting for messages on queue 'tripleo' with no timeout.
1 node(s) successfully moved to the "manageable" state.
Successfully registered node UUID 28dc0fbb-644b-4648-b5f6-f0065d367cf3
Waiting for introspection to finish...
Waiting for messages on queue 'tripleo' with no timeout.
Introspection of node 28dc0fbb-644b-4648-b5f6-f0065d367cf3 completed. Status:SUCCESS. Errors:None
Successfully introspected 1 node(s).
Waiting for messages on queue 'tripleo' with no timeout.
[{u'result': u'Node 28dc0fbb-644b-4648-b5f6-f0065d367cf3 did not reach state "available", the state is "clean failed", error: Failed to prepare node 28dc0fbb-644b-4648-b5f6-f0065d367cf3 for cleaning: Failed to set node power state to power on.'}]
Failed to set nodes to available state: Node 28dc0fbb-644b-4648-b5f6-f0065d367cf3 did not reach state "available", the state is "clean failed", error: Failed to prepare node 28dc0fbb-644b-4648-b5f6-f0065d367cf3 for cleaning: Failed to set node power state to power on.
Here is the log from /var/log/containers/ironic/ironic-conductor.log
2019-07-24 11:49:51.014 6 ERROR oslo.service.loopingcall [-] Dynamic backoff interval looping call 'ironic.conductor.utils._wait' failed: LoopingCallTimeOut: Looping call timed out after 21.32 seconds
2019-07-24 11:49:51.014 6 ERROR oslo.service.loopingcall Traceback (most recent call last):
2019-07-24 11:49:51.014 6 ERROR oslo.service.loopingcall File "/usr/lib/python2.7/site-packages/oslo_service/loopingcall.py", line 154, in _run_loop
2019-07-24 11:49:51.014 6 ERROR oslo.service.loopingcall idle = idle_for_func(result, self._elapsed(watch))
2019-07-24 11:49:51.014 6 ERROR oslo.service.loopingcall File "/usr/lib/python2.7/site-packages/oslo_service/loopingcall.py", line 351, in _idle_for
2019-07-24 11:49:51.014 6 ERROR oslo.service.loopingcall % self._error_time)
2019-07-24 11:49:51.014 6 ERROR oslo.service.loopingcall LoopingCallTimeOut: Looping call timed out after 21.32 seconds
2019-07-24 11:49:51.014 6 ERROR oslo.service.loopingcall
2019-07-24 11:49:51.017 6 ERROR ironic.conductor.utils [req-ffaaa189-73e8-4923-94c4-5bb27ed77ebf dd532b95d67a4b44819ed754258ba37a 6dbc2de320cd4a3f9b7fd66c164961b4 - default default] Timed out after 30 secs waiting for power on on node 28dc0fbb-644b-4648-b5f6-f0065d367cf3.: LoopingCallTimeOut: Looping call timed out after 21.32 seconds
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager [req-ffaaa189-73e8-4923-94c4-5bb27ed77ebf dd532b95d67a4b44819ed754258ba37a 6dbc2de320cd4a3f9b7fd66c164961b4 - default default] Failed to prepare node 28dc0fbb-644b-4648-b5f6-f0065d367cf3 for cleaning: Failed to set node power state to power on.: PowerStateFailure: Failed to set node power state to power on.
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager Traceback (most recent call last):
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/conductor/manager.py", line 1325, in _do_node_clean
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager prepare_result = task.driver.deploy.prepare_cleaning(task)
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic_lib/metrics.py", line 60, in wrapped
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager result = f(*args, **kwargs)
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/drivers/modules/iscsi_deploy.py", line 596, in prepare_cleaning
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager task, manage_boot=True)
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/drivers/modules/deploy_utils.py", line 928, in prepare_inband_cleaning
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager manager_utils.node_power_action(task, states.REBOOT)
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py", line 148, in wrapper
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager return f(*args, **kwargs)
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/conductor/utils.py", line 301, in node_power_action
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager fields.NotificationStatus.ERROR, new_state)
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager self.force_reraise()
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager six.reraise(self.type_, self.value, self.tb)
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/conductor/utils.py", line 288, in node_power_action
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager task.driver.power.reboot(task, timeout=timeout)
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic_lib/metrics.py", line 60, in wrapped
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager result = f(*args, **kwargs)
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py", line 148, in wrapper
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager return f(*args, **kwargs)
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/drivers/modules/ipmitool.py", line 928, in reboot
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager _power_on(task, driver_info, timeout=timeout)
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/drivers/modules/ipmitool.py", line 600, in _power_on
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager return _set_and_wait(task, states.POWER_ON, driver_info, timeout=timeout)
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/drivers/modules/ipmitool.py", line 587, in _set_and_wait
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager timeout=timeout)
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager File "/usr/lib/python2.7/site-packages/ironic/conductor/utils.py", line 154, in node_wait_for_power_state
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager raise exception.PowerStateFailure(pstate=new_state)
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager PowerStateFailure: Failed to set node power state to power on.
2019-07-24 11:49:51.067 6 ERROR ironic.conductor.manager
