Stderr: Set Chassis Power Control to Up/On failed: Command not supported in present state: ProcessExecutionError: Unexpected error while running command.

attached log running w/ --debug on

To recreate:

export WD=/var/tmp/cicentos; ./quickstart.sh --release tripleo-ci/master --clean --tags all --no-clone -w $WD $VIRTHOST

()[ironic@undercloud /]$ ls -la /var/lib/ironic/httpboot/
total 387580
drwxr-xr-x. 2 root root 86 Jul 17 17:11 .
drwxr-xr-x. 4 ironic ironic 59 Jul 17 17:31 ..
-rwxr-xr-x. 1 root root 6233824 Jul 17 17:11 agent.kernel
-rw-r--r--. 1 root root 390638373 Jul 17 17:11 agent.ramdisk
-rw-r--r--. 1 ironic ironic 758 Jul 17 17:00 boot.ipxe
-rw-r--r--. 1 ironic-inspector ironic-inspector 470 Jul 17 16:35 inspector.ipxe

()[ironic@undercloud /]$ ls -Z /var/lib/ironic/httpboot/
-rwxr-xr-x. root root unconfined_u:object_r:var_lib_t:s0 agent.kernel
-rw-r--r--. root root unconfined_u:object_r:var_lib_t:s0 agent.ramdisk
-rw-r--r--. ironic ironic system_u:object_r:var_lib_t:s0 boot.ipxe
-rw-r--r--. ironic-inspector ironic-inspector system_u:object_r:var_lib_t:s0 inspector.ipxe
()[ironic@undercloud /]$

()[ironic@undercloud /]$ getenforce
Permissive
()[ironic@undercloud /]$ exit
exit
(undercloud) [stack@undercloud ~]$ getenforce
Permissive
(undercloud) [stack@undercloud ~]$

@Wes please link to the promotion job where this is failing, it cannot be promotion-blocker w/o that, also release is affected, master only?

@Alan.. I will as soon as jenkins in rdo p2 starts cooperating :)
Until then I'll have to use my local test rig. I'm working the situation

This may be due to the RHEL libvirt issue which is fixed in a 7.5z release - https://bugzilla.redhat.com/show_bug.cgi?id=1581364

There were many vbmc issues with the same IPMI error message (for example see
https://bugzilla.redhat.com/show_bug.cgi?id=1596946#c2) that have been resolved with this libvirt fix.

Ok.. in the latest builds the error we were previously seeing no longer happens, however inspection still times out.

Latest update:

https://ci.centos.org/artifacts/rdo/jenkins-tripleo-quickstart-promote-master-current-tripleo-delorean-minimal-379/undercloud/home/stack/overcloud_prep_images.log.gz

2018-07-18 17:28:31.110 ERROR /var/log/containers/mistral/executor.log: 8 ERROR mistral.executors.default_executor File "/usr/lib/python2.7/site-packages/mistral/executors/default_executor.py", line 114, in run_action
2018-07-18 17:28:31.110 ERROR /var/log/containers/mistral/executor.log: 8 ERROR mistral.executors.default_executor result = action.run(action_ctx)
2018-07-18 17:28:31.110 ERROR /var/log/containers/mistral/executor.log: 8 ERROR mistral.executors.default_executor File "/usr/lib/python2.7/site-packages/mistral/actions/openstack/base.py", line 130, in run
2018-07-18 17:28:31.110 ERROR /var/log/containers/mistral/executor.log: 8 ERROR mistral.executors.default_executor (self.__class__.__name__, self.client_method_name, str(e))
2018-07-18 17:28:31.110 ERROR /var/log/containers/mistral/executor.log: 8 ERROR mistral.executors.default_executor ActionException: BaremetalIntrospectionAction.wait_for_finish failed: Timeout while waiting for introspection of nodes [u'2063ccfa-3b9a-499b-acbd-1c36a8a8252e']

https://ci.centos.org/artifacts/rdo/jenkins-tripleo-quickstart-promote-master-current-tripleo-delorean-minimal-379/undercloud/var/log/extra/errors.txt.gz

https://ci.centos.org/artifacts/rdo/jenkins-tripleo-quickstart-promote-master-current-tripleo-delorean-minimal-379/undercloud/var/log/containers/ironic/ironic-conductor.log.gz

/usr/lib/python2.7/site-packages/ironic/common/utils.py:76
2018-07-18 17:58:17.926 8 DEBUG ironic.common.utils [req-c3ade8ab-2168-4f02-a795-09dcc1ee4a6d - - - - -] Command stdout is: "Chassis Power is on
" execute /usr/lib/python2.7/site-packages/ironic/common/utils.py:77
2018-07-18 17:58:17.927 8 DEBUG ironic.common.utils [req-c3ade8ab-2168-4f02-a795-09dcc1ee4a6d - - - - -] Command stderr is: "" execute /usr/lib/python2.7/site-packages/ironic/common/utils.py:78

This is hitting quite a few people now.. adding alert

FYI.. if deployments are required one can use
http://tripleo.org/contributor/reproduce-ci.html until this issue is resolved

Seeing this in ironic-conductor.log:
018-07-18 16:14:02.638 7 ERROR oslo_service.service [req-cdc2bb58-3a04-4f7d-a5a6-2dbbc55341f6 - - - - -] Error starting thread.: DriverLoadError: Driver, hardware type or interface ilo-pxe could not be loaded. Reason: [Errno 13] Permission denied: '/var/lib/ironic/httpboot/boot.ipxe'.

2018-07-18 16:14:02.638 7 ERROR oslo_service.service Traceback (most recent call last):
2018-07-18 16:14:02.638 7 ERROR oslo_service.service File "/usr/lib/python2.7/site-packages/oslo_service/service.py", line 792, in run_service
2018-07-18 16:14:02.638 7 ERROR oslo_service.service service.start()
2018-07-18 16:14:02.638 7 ERROR oslo_service.service File "/usr/lib/python2.7/site-packages/ironic/common/rpc_service.py", line 54, in start
2018-07-18 16:14:02.638 7 ERROR oslo_service.service self.manager.init_host(admin_context)
2018-07-18 16:14:02.638 7 ERROR oslo_service.service File "/usr/lib/python2.7/site-packages/ironic/conductor/base_manager.py", line 140, in init_host
2018-07-18 16:14:02.638 7 ERROR oslo_service.service self._collect_periodic_tasks(admin_context)
2018-07-18 16:14:02.638 7 ERROR oslo_service.service File "/usr/lib/python2.7/site-packages/ironic/conductor/base_manager.py", line 268, in _collect_periodic_tasks
2018-07-18 16:14:02.638 7 ERROR oslo_service.service for ifaces in driver_factory.all_interfaces().values():
2018-07-18 16:14:02.638 7 ERROR oslo_service.service File "/usr/lib/python2.7/site-packages/ironic/common/driver_factory.py", line 271, in all_interfaces
2018-07-18 16:14:02.638 7 ERROR oslo_service.service return {iface: interfaces(iface) for iface in _INTERFACE_LOADERS}
2018-07-18 16:14:02.638 7 ERROR oslo_service.service File "/usr/lib/python2.7/site-packages/ironic/common/driver_factory.py", line 271, in <dictcomp>
2018-07-18 16:14:02.638 7 ERROR oslo_service.service return {iface: interfaces(iface) for iface in _INTERFACE_LOADERS}
2018-07-18 16:14:02.638 7 ERROR oslo_service.service File "/usr/lib/python2.7/site-packages/ironic/common/driver_factory.py", line 262, in interfaces
2018-07-18 16:14:02.638 7 ERROR oslo_service.service return _get_all_drivers(_INTERFACE_LOADERS[interface_type]())
2018-07-18 16:14:02.638 7 ERROR oslo_service.service File "/usr/lib/python2.7/site-packages/ironic/common/driver_factory.py", line 323, in __init__
2018-07-18 16:14:02.638 7 ERROR oslo_service.service self.__class__._init_extension_manager()
2018-07-18 16:14:02.638 7 ERROR oslo_service.service File "/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py", line 274, in inner
2018-07-18 16:14:02.638 7 ERROR oslo_service.service return f(*args, **kwargs)
2018-07-18 16:14:02.638 7 ERROR oslo_service.service File "/usr/lib/python2.7/site-packages/ironic/common/driver_factory.py", line 393, in _init_extension_manager
2018-07-18 16:14:02.638 7 ERROR oslo_service.service on_missing_entrypoints_callback=missing_callback))
2018-07-18 16:14:02.638 7 ERROR oslo_service.service File "/usr/lib/python2.7/site-packages/stevedore/named.py", line 81, in __init__
2018-07-18 16:14:02.638 7 ERROR oslo_service.service verify_requirements)
2018-07-18 1...

On Marius's system with the same error messages "Permission denied" error messages it looks like the ironic user has not been created.

[root@undercloud-0 log]# ls -al /var/lib/ironic/httpboot/
total 421720
drwxr-xr-x. 3 42422 42422 106 Jul 19 11:43 .
drwxr-xr-x. 4 42422 42422 38 Jul 19 10:35 ..
-rwxr-xr-x. 1 root root 6390064 Jul 19 10:48 agent.kernel
-rw-r--r--. 1 root root 425438363 Jul 19 10:48 agent.ramdisk
-rw-r--r--. 1 42422 42422 758 Jul 19 10:43 boot.ipxe
-rw-r--r--. 1 42422 42422 470 Jul 19 10:35 inspector.ipxe
drwxr-xr-x. 2 42422 42422 6 Jul 19 11:43 pxelinux.cfg

[root@undercloud-0 log]# cat /etc/passwd | grep ironic
[root@undercloud-0 log]#

@Bob, containerized UC has no more openstack service users (but heat) defined on host system. Instead, those now live in Kolla containers. The error message [Errno 13] Permission denied: '/var/lib/ironic/httpboot/boot.ipxe' may be the root cause, or a red herring as well - it is being ovserved for quite a while, like a several months or so. Anyway, it should be fixed, indeed.

I think we need something similar to https://review.openstack.org/#/c/577855/ but made for /var/lib/ironic. The issues for the permission denied should be gone then.

Or even more simple, like it had been originally made for nova_container and /var/lib/nova, let's just make ironic_conductor's container kolla config setting the ownership of /var/lib/ironic to ironic:ironic on startup. We need no that complex mixed ownership solution, like https://review.openstack.org/#/c/577855/, as there is no mixed owners to /var/lib/ironic (lucky us!).

Just checked that on my containerized UC:

$ docker exec -it ironic_conductor findmnt -o TARGET,PROPAGATION /var/lib/ironic
TARGET PROPAGATION
/var/lib/ironic private

it has to be shared, in order to make the recursive owner changes effective on the host as well.

Related fix proposed to branch: master
Review: https://review.openstack.org/584265

Grepping conductor log [1] for the failed node `04e86289-e615-47c2-ab77-d790a5c0aa5e` does not reveal any IPMI errors any more. So this is likely not the libvirt issue any more.

From the inspector log [2] it looks like the node has never come up for introspection. Hooking on VM's console may probably shed some light on what's happening.

1. https://ci.centos.org/artifacts/rdo/jenkins-tripleo-quickstart-promote-master-current-tripleo-delorean-minimal-379/undercloud/var/log/containers/ironic/ironic-conductor.log.gz
2. https://ci.centos.org/artifacts/rdo/jenkins-tripleo-quickstart-promote-master-current-tripleo-delorean-minimal-379/undercloud/var/log/containers/ironic-inspector/ironic-inspector.log.gz

FYI.. I recreated the issue w/ a RHEL BM virthost and centos undercloud/overcloud nodes.

Reviewed: https://review.openstack.org/584265
Committed: https://git.openstack.org/cgit/openstack/tripleo-heat-templates/commit/?id=90a7a22f157b0f50d024d730e8b97ba268bc58ad
Submitter: Zuul
Branch: master

commit 90a7a22f157b0f50d024d730e8b97ba268bc58ad
Author: Bogdan Dobrelya <email address hidden>
Date: Fri Jul 20 10:45:34 2018 +0300

    Fix containerized ironic bind-mounts

    We obvserve errors "DriverLoadError: Driver, hardware type or interface
    ilo-pxe could not be loaded" as it uses the host level access to
    /var/lib/ironic, which is owned by root. When we have the
    host/container(s) shared access to a bind mounted dir, it needs to be
    shared instead of the default private mode.

    Additionally, fix the missing /var/lib/ironic ownership change in
    the ironix-pxe's kolla config.

    Related-bug: #1782267

    Change-Id: I5ad4956174346f024945852da09f3841c3378c2b
    Signed-off-by: Bogdan Dobrelya <email address hidden>

It's worth checking if https://review.openstack.org/584265 resolved the original issue, although I think it did not.

I tried manually to run the overcloud-prep-images.sh file and I could see that still it is getting failed at introspection step. Ultimately it is getting timed out.

The screen of one node on the overcloud while running introspection
===============================================================================
Booting from ROM
iPXE (PCI 00:03.0) starting execution...ok
iPXE initialising device...ok

iPXE 1.0.0+ (4e85b27) -- Open Source Network Boot Firmware -- http://ipxe.org
Feature: DNS HTTP iSCSI TFTP Aoe ELF MBOOT PXE bzImage Menu PXEXT

net0: 00:c9:be:00:11:d4 using virtio-net on 0000:00:03.0 (open)
  [Link:up, TX:0 TXE:0 RX:0 RXE:0]
Configuring (net0 00:c9:be:00:11:d4)...........................................
...................No configuration metods succeeded (https://ipxe.org/040ee119
)
No more network devices

No bootable device.
===============================================================================

(undercloud) [stack@undercloud ~]$ openstack baremetal port list
+--------------------------------------+-------------------+
| UUID | Address |
+--------------------------------------+-------------------+
| 4d1b5e3a-5570-4a82-ad97-4aa14df9c076 | 00:c9:be:00:11:d4 |
| 25557c46-68e9-475b-a6a4-df13cbe8e849 | 00:c9:be:00:11:d8 |
| 394d79e8-8c0e-4a1c-ba0a-2c6364110bb9 | 00:c9:be:00:11:dc |
| 7c4752d8-820b-4a82-b403-fd90747947ac | 00:c9:be:00:11:e0 |
| 547eaf2e-001a-4ffb-af6e-ac094d447361 | 00:c9:be:00:11:e4 |
| ea246898-d07b-494f-b986-86cdd7607f3b | 00:c9:be:00:11:e8 |
+--------------------------------------+-------------------+

other tests:

(undercloud) [stack@undercloud tmp]$ curl -O http://192.168.24.1:8088/agent.kernel
  % Total % Received % Xferd Average Speed Time Time Time Current
                                 Dload Upload Total Spent Left Speed
100 6087k 100 6087k 0 0 1002M 0 --:--:-- --:--:-- --:--:-- 1189M
(undercloud) [stack@undercloud tmp]$ curl -O http://192.168.24.1:8088/agent.kernel
  % Total % Received % Xferd Average Speed Time Time Time Current
                                 Dload Upload Total Spent Left Speed
100 6087k 100 6087k 0 0 452M 0 --:--:-- --:--:-- --:--:-- 495M
(undercloud) [stack@undercloud tmp]$ curl -O http://192.168.24.1:8088/agent.ramdisk
  % Total % Received % Xferd Average Speed Time Time Time Current
                                 Dload Upload Total Spent Left Speed
100 372M 100 372M 0 0 1249M 0 --:--:-- --:--:-- --:--:-- 1250M
(undercloud) [stack@undercloud tmp]$ curl -O http://192.168.24.1:8088/boot.ipxe
  % Total % Received % Xferd Average Speed Time Time Time Current
                                 Dload Upload Total Spent Left Speed
100 758 100 758 0 0 458k 0 --:--:-- --:--:-- --:--:-- 740k
(undercloud) [stack@undercloud tmp]$ curl -O http://192.168.24.1:8088/inspector.ipxe
  % Total % Received % Xferd Average Speed Time Time Time Current
                                 Dload Upload Total Spent Left Speed
100 470 100 470 0 0 649k 0 --:--:-- --:--:-- --:--:-- 458k

I'm seeing the same problem locally, e.g the ipxe fails, but there's no ProcessExecutionError in the logs AFAICS.

So as folks posted on IRC,

2:35:34 PM GMT+3 - etingof: why it can happen that eth1 (local_interface) is not added to br-ctlplane in containerized ucloud?
2:36:31 PM GMT+3 - etingof: that ^ causes introspection to stuck

that should be cuz of the bad value for netconfig http://paste.openstack.org/show/726513/

it should be using t-h-t defaults https://review.openstack.org/#/c/352037/24/environments/undercloud.yaml@4
which also fits the ovb defaults https://review.openstack.org/#/c/542556/102/config/general_config/featureset001.yml@36 (btw, we can prolly remove that now from featuresets and just use t-h-t default UC netconfig)

Workaround:
 Addind the eth1 into ctrl place bridge solved the problem on the UC

 ovs-vsctl add-port br-ctlplane eth1

So we need to fix neconfig used for that job, see https://ci.centos.org/artifacts/rdo/jenkins-tripleo-quickstart-promote-master-current-tripleo-delorean-minimal-379/undercloud/home/stack/undercloud-parameter-defaults.yaml.gz

In quickstart, this is controlled like in this example https://review.openstack.org/#/c/542556/102/config/general_config/featureset001.yml@36

Let's fix the value and retry. I don't know where the job configuration lives :(

@Bogdan, the config for this job is here: https://github.com/openstack/tripleo-quickstart/blob/596d1177349eed027b939a2fee6d82bbbab69eb5/config/general_config/minimal.yml

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

Change abandoned by Emilien Macchi (<email address hidden>) on branch: master
Review: https://review.openstack.org/585741
Reason: tripleo gate is now broken, I'm clearing the gate. Please do not recheck or restore this patch, I'll take care of it when things work again.

Reviewed: https://review.openstack.org/585741
Committed: https://git.openstack.org/cgit/openstack/tripleo-quickstart/commit/?id=9e45cceaa8d123eba5c7dbd5c245fbd4bb4aa30f
Submitter: Zuul
Branch: master

commit 9e45cceaa8d123eba5c7dbd5c245fbd4bb4aa30f
Author: Bogdan Dobrelya <email address hidden>
Date: Wed Jul 25 16:01:29 2018 +0300

    Use net-config-undercloud for UC in minimal config

    config/general_config/minimal.yml tests Ironic provisioning
    of VMs, therefore it requires eth1 to be included into br-ctlplane
    bridge. T-h-t default net-config-undercloud.yaml provides that
    functionality, while the one from
    ci/common/net-config-simple-bridge.yaml does not.

    Closes-Bug: #1782267

    Change-Id: I460b2e0e47be737dfdfd84bbace81f7ee2f4f733
    Signed-off-by: Bogdan Dobrelya <email address hidden>

Wes commented https://review.openstack.org/585741 didn't fix it afaict https://ci.centos.org/artifacts/rdo/jenkins-tripleo-quickstart-gate-master-delorean-quick-basic-6514/undercloud/home/stack/overcloud_prep_images.log.gz

AFAICT, that error in the log above points out to another issue.

2018-07-25 14:56:41 | cp: cannot create regular file ‘/var/lib/ironic/httpboot/agent.kernel’: No such file or directory

and it have been addressed by Emilien via a downstream cherry-pick.

Fix proposed to branch: stable/queens
Review: https://review.openstack.org/586196

Please disregard https://review.openstack.org/586196 it's not related to this bug

This issue was fixed in the openstack/tripleo-quickstart 2.1.1 release.