curiously, while trying to do some testing on pxe, i noticed starlingx bootstrap times out in a VM, i found this in sysinv.log TASK [bootstrap/persist-config : debug] *********************************************************************************************************************** Monday 09 May 2022 11:27:51 +0000 (0:29:57.887) 0:39:28.205 ************ ok: [localhost] => populate_result: changed: true failed: false failed_when_result: false msg: non-zero return code rc: 1 stderr: |- Traceback (most recent call last): File "/tmp/.ansible-sysadmin/tmp/ansible-tmp-1652093873.31-134751541330122/populate_initial_config.py", line 1119, in <module> inventory_config_complete_wait(client, controller) File "/tmp/.ansible-sysadmin/tmp/ansible-tmp-1652093873.31-134751541330122/populate_initial_config.py", line 1073, in inventory_config_complete_wait wait_initial_inventory_complete(client, controller) File "/tmp/.ansible-sysadmin/tmp/ansible-tmp-1652093873.31-134751541330122/populate_initial_config.py", line 1064, in wait_initial_inventory_complete raise ConfigFail('Timeout waiting for controller inventory ' __main__.ConfigFail: Timeout waiting for controller inventory completion stderr_lines: - 'Traceback (most recent call last):' - ' File "/tmp/.ansible-sysadmin/tmp/ansible-tmp-1652093873.31-134751541330122/populate_initial_config.py", line 1119, in <module>' - ' inventory_config_complete_wait(client, controller)' - ' File "/tmp/.ansible-sysadmin/tmp/ansible-tmp-1652093873.31-134751541330122/populate_initial_config.py", line 1073, in inventory_config_complete_wait' - ' wait_initial_inventory_complete(client, controller)' - ' File "/tmp/.ansible-sysadmin/tmp/ansible-tmp-1652093873.31-134751541330122/populate_initial_config.py", line 1064, in wait_initial_inventory_complete' - ' raise ConfigFail(''Timeout waiting for controller inventory ''' - '__main__.ConfigFail: Timeout waiting for controller inventory completion' stdout: |- Populating system config... System config completed. Populating load config... Load config completed. Populating management network... Populating pxeboot network... Populating oam network... Populating multicast network... Populating cluster host network... Populating cluster pod network... Populating cluster service network... Network config completed. Populating/Updating DNS config... DNS config completed. Populating/Updating docker registry config... Docker registry config completed. Populating/Updating kubernetes san list... Populating/Updating kubernetes config... Kubernetes config completed. Management mac = 00:00:00:00:00:00 Root fs device = /dev/disk/by-path/pci-0000:02:02.0-ata-2.0 Boot device = /dev/disk/by-path/pci-0000:02:02.0-ata-2.0 Console = tty0 Tboot = false Install output = text Host values = {'tboot': 'false', 'install_output': 'text', 'rootfs_device': '/dev/disk/by-path/pci-0000:02:02.0-ata-2.0', 'boot_device': '/dev/disk/by-path/pci-0000:02:02.0-ata-2.0', 'availability': 'offline', 'mgmt_mac': '00:00:00:00:00:00', 'console': 'tty0', 'mgmt_ip': '192.168.204.2', 'hostname': 'controller-0', 'operational': 'disabled', 'invprovision': 'provisioning', 'administrative': 'locked', 'personality': 'controller'} Host controller-0 created. Failed to update the initial system config. stdout_lines: - Populating system config... - System config completed. - Populating load config... - Load config completed. - Populating management network... - Populating pxeboot network... - Populating oam network... - Populating multicast network... - Populating cluster host network... - Populating cluster pod network... - Populating cluster service network... - Network config completed. - Populating/Updating DNS config... - DNS config completed. - Populating/Updating docker registry config... - Docker registry config completed. - Populating/Updating kubernetes san list... - Populating/Updating kubernetes config... - Kubernetes config completed. - Management mac = 00:00:00:00:00:00 - Root fs device = /dev/disk/by-path/pci-0000:02:02.0-ata-2.0 - Boot device = /dev/disk/by-path/pci-0000:02:02.0-ata-2.0 - Console = tty0 - Tboot = false - Install output = text - 'Host values = {''tboot'': ''false'', ''install_output'': ''text'', ''rootfs_device'': ''/dev/disk/by-path/pci-0000:02:02.0-ata-2.0'', ''boot_device'': ''/dev/disk/by-path/pci-0000:02:02.0-ata-2.0'', ''availability'': ''offline'', ''mgmt_mac'': ''00:00:00:00:00:00'', ''console'': ''tty0'', ''mgmt_ip'': ''192.168.204.2'', ''hostname'': ''controller-0'', ''operational'': ''disabled'', ''invprovision'': ''provisioning'', ''administrative'': ''locked'', ''personality'': ''controller''}' - Host controller-0 created. - Failed to update the initial system config. TASK [bootstrap/persist-config : Fail if populate config script throws an exception] ************************************************************************** Monday 09 May 2022 11:27:51 +0000 (0:00:00.069) 0:39:28.275 ************ fatal: [localhost]: FAILED! => changed=false msg: Failed to provision initial system configuration. will fail the timeout sysinv 2022-05-09 11:24:21.703 98797 ERROR sysinv.conductor.kube_app [-] Kubernetes is not configured. API operations will not be available.: KubeNotConfigured: Kubernetes is not configured. API operations will not be available. sysinv 2022-05-09 11:25:03.484 91940 INFO sysinv.agent.manager [-] _report_to_conductor initial_reports_required=set(['disk', 'lvg', 'pv', 'memory']) sysinv 2022-05-09 11:25:03.485 91940 INFO sysinv.agent.manager [-] Sysinv Agent audit running inv_get_and_report. sysinv 2022-05-09 11:25:04.395 91940 WARNING sysinv.agent.pci [-] Enabling device ens5 to query link speed: CalledProcessError: Command '['query_pci_id', '-v 0x8086', '-d 0x100e']' returned non-zero exit status 1 sysinv 2022-05-09 11:25:04.403 91940 WARNING sysinv.agent.pci [-] ATTR speed unknown for: ens5 (flags: 0x1002): IOError: [Errno 22] Invalid argument sysinv 2022-05-09 11:25:04.404 91940 WARNING sysinv.agent.pci [-] Disabling device ens5 after querying link speed: IOError: [Errno 22] Invalid argument sysinv 2022-05-09 11:25:04.527 98797 INFO sysinv.conductor.manager [-] Updating platform data for host: 7be69b7e-5660-48d8-ad95-28af6222da2e with: {u'first_report': True} sysinv 2022-05-09 11:25:04.549 91940 INFO sysinv.agent.manager [-] Sysinv Agent platform update by host: {'first_report': True} sysinv 2022-05-09 11:25:04.549 91940 INFO sysinv.agent.manager [-] Agent found matching ihost: 7be69b7e-5660-48d8-ad95-28af6222da2e sysinv 2022-05-09 11:25:04.550 91940 INFO sysinv.agent.manager [-] _report_to_conductor initial_reports_required=set(['disk', 'lvg', 'pv', 'memory']) sysinv 2022-05-09 11:25:05.106 98797 INFO sysinv.conductor.manager [-] port 852027ed-3a24-4658-aa62-6f8273ce39bb update attr: {'speed': u'1000', 'sriov_vfs_pci_address': u'', 'sriov_totalvfs': None, 'sriov_vf_pdevice_id': None, 'dpdksupport': False, 'sriov_numvfs': 0, 'driver': u'e1000', 'sriov_vf_driver': None} sysinv 2022-05-09 11:25:05.289 98797 INFO sysinv.conductor.manager [-] port 8a1db02d-ad08-4eb2-b4a7-a42ca5bfcfef update attr: {'speed': None, 'sriov_vfs_pci_address': u'', 'sriov_totalvfs': None, 'sriov_vf_pdevice_id': None, 'dpdksupport': False, 'sriov_numvfs': 0, 'driver': u'e1000', 'sriov_vf_driver': None} sysinv 2022-05-09 11:25:05.376 98797 INFO sysinv.conductor.manager [-] update 0000:00:01.1 attr: {'sriov_numvfs': 0, 'driver': u'ata_piix', 'sriov_vf_driver': None, 'sriov_vf_pdevice_id': None, 'psvendor': u'XenSource, Inc.', 'extra_info': None, 'pdevice_id': u'7010', 'pclass': u'IDE interface', 'psdevice': u'Device 0001', 'sriov_vfs_pci_address': u'', 'pvendor': u'Intel Corporation', 'pvendor_id': u'8086', 'pclass_id': u'010180', 'sriov_totalvfs': None} sysinv 2022-05-09 11:25:05.404 98797 INFO sysinv.conductor.manager [-] update 0000:00:01.2 attr: {'sriov_numvfs': 0, 'driver': u'uhci_hcd', 'sriov_vf_driver': None, 'sriov_vf_pdevice_id': None, 'psvendor': u'XenSource, Inc.', 'extra_info': None, 'pdevice_id': u'7020', 'pclass': u'USB controller', 'psdevice': u'Device 0001', 'sriov_vfs_pci_address': u'', 'pvendor': u'Intel Corporation', 'pvendor_id': u'8086', 'pclass_id': u'0c0300', 'sriov_totalvfs': None} sysinv 2022-05-09 11:25:05.432 98797 INFO sysinv.conductor.manager [-] update 0000:00:02.0 attr: {'sriov_numvfs': 0, 'driver': None, 'sriov_vf_driver': None, 'sriov_vf_pdevice_id': None, 'psvendor': u'Device 0001', 'extra_info': None, 'pdevice_id': u'1111', 'pclass': u'VGA compatible controller', 'psdevice': u'Device 0001', 'sriov_vfs_pci_address': u'', 'pvendor': u'Vendor 1234', 'pvendor_id': u'1234', 'pclass_id': u'030000', 'sriov_totalvfs': None} sysinv 2022-05-09 11:25:05.460 98797 INFO sysinv.conductor.manager [-] update 0000:00:03.0 attr: {'sriov_numvfs': 0, 'driver': None, 'sriov_vf_driver': None, 'sriov_vf_pdevice_id': None, 'psvendor': u'XenSource, Inc.', 'extra_info': None, 'pdevice_id': u'0001', 'pclass': u'SCSI storage controller', 'psdevice': u'Xen Platform Device', 'sriov_vfs_pci_address': u'', 'pvendor': u'XenSource, Inc.', 'pvendor_id': u'5853', 'pclass_id': u'010000', 'sriov_totalvfs': None} sysinv 2022-05-09 11:25:05.545 98797 INFO sysinv.conductor.manager [-] Already in db numa_node=0 mynuma_nodes=[0, 2, 4, 6, 8, 10, 12, 14] sysinv 2022-05-09 11:25:05.545 98797 INFO sysinv.conductor.manager [-] Already in db numa_node=2 mynuma_nodes=[0, 2, 4, 6, 8, 10, 12, 14] sysinv 2022-05-09 11:25:05.545 98797 INFO sysinv.conductor.manager [-] Already in db numa_node=4 mynuma_nodes=[0, 2, 4, 6, 8, 10, 12, 14] sysinv 2022-05-09 11:25:05.546 98797 INFO sysinv.conductor.manager [-] Already in db numa_node=6 mynuma_nodes=[0, 2, 4, 6, 8, 10, 12, 14] sysinv 2022-05-09 11:25:05.548 98797 INFO sysinv.conductor.manager [-] Already in db numa_node=8 mynuma_nodes=[0, 2, 4, 6, 8, 10, 12, 14] sysinv 2022-05-09 11:25:05.548 98797 INFO sysinv.conductor.manager [-] Already in db numa_node=10 mynuma_nodes=[0, 2, 4, 6, 8, 10, 12, 14] sysinv 2022-05-09 11:25:05.549 98797 INFO sysinv.conductor.manager [-] Already in db numa_node=12 mynuma_nodes=[0, 2, 4, 6, 8, 10, 12, 14] sysinv 2022-05-09 11:25:05.549 98797 INFO sysinv.conductor.manager [-] Already in db numa_node=14 mynuma_nodes=[0, 2, 4, 6, 8, 10, 12, 14] sysinv 2022-05-09 11:25:05.598 98797 INFO sysinv.conductor.manager [-] Logical CPU topology: host:controller-0 (controller,worker,lowlatency), sockets:8, cores/socket=1, threads/core=1, reference:current (unchanged) sysinv 2022-05-09 11:25:05.598 98797 INFO sysinv.conductor.manager [-] cpu_id : 0 1 2 3 4 5 6 7 sysinv 2022-05-09 11:25:05.599 98797 INFO sysinv.conductor.manager [-] socket_id : 0 2 4 6 8 10 12 14 sysinv 2022-05-09 11:25:05.600 98797 INFO sysinv.conductor.manager [-] core_id : 0 0 0 0 0 0 0 0 sysinv 2022-05-09 11:25:05.601 98797 INFO sysinv.conductor.manager [-] thread_id : 0 0 0 0 0 0 0 0 sysinv 2022-05-09 11:25:05.615 98797 INFO sysinv.conductor.manager [-] update_grub_config, host uuid: (7be69b7e-5660-48d8-ad95-28af6222da2e), force: (False) sysinv 2022-05-09 11:25:05.616 98797 INFO sysinv.conductor.manager [-] _config_update_hosts personalities=['controller', 'worker'] host_uuids=[u'7be69b7e-5660-48d8-ad95-28af6222da2e'] reboot=False config_uuid=0fd14450-6057-43bc-a429-17de31115a16 tb= File "/usr/lib64/python2.7/site-packages/sysinv/conductor/manager.py", line 9644, in update_grub_config host_uuids=[host_uuid]) sysinv 2022-05-09 11:25:05.630 98797 INFO sysinv.conductor.manager [-] Setting config target of host 'controller-0' to '8fd14450-6057-43bc-a429-17de31115a16'. sysinv 2022-05-09 11:25:05.662 98797 INFO sysinv.conductor.manager [-] _config_update_hosts config_uuid=0fd14450-6057-43bc-a429-17de31115a16 sysinv 2022-05-09 11:25:05.668 98797 INFO sysinv.conductor.manager [-] applying runtime manifest config_uuid=0fd14450-6057-43bc-a429-17de31115a16, classes: ['platform::compute::grub::runtime', 'platform::compute::config::runtime'] sysinv 2022-05-09 11:25:05.685 98797 INFO sysinv.conductor.manager [-] Cannot generate the configuration for controller-0, the host is not inventoried yet. sysinv 2022-05-09 11:25:05.685 98797 INFO sysinv.conductor.manager [-] Evaluating apps reapply {'type': 'runtime-apply-puppet'} sysinv 2022-05-09 11:25:05.685 98797 INFO sysinv.conductor.manager [-] Apps reapply order: [] sysinv 2022-05-09 11:25:05.687 98797 INFO sysinv.agent.rpcapi [-] config_apply_runtime_manifest: fanout_cast: sending config 0fd14450-6057-43bc-a429-17de31115a16 {'classes': ['platform::compute::grub::runtime', 'platform::compute::config::runtime'], 'force': False, 'personalities': ['controller', 'worker'], 'host_uuids': [u'7be69b7e-5660-48d8-ad95-28af6222da2e']} to agent sysinv 2022-05-09 11:25:05.699 91940 ERROR sysinv.openstack.common.periodic_task [-] Error during AgentManager._agent_audit: [Errno 2] No such file or directory: '/sys/devices/system/node/node1/hugepages': OSError: [Errno 2] No such file or directory: '/sys/devices/system/node/node1/hugepages' 2022-05-09 11:25:05.699 91940 ERROR sysinv.openstack.common.periodic_task Traceback (most recent call last): 2022-05-09 11:25:05.699 91940 ERROR sysinv.openstack.common.periodic_task File "/usr/lib64/python2.7/site-packages/sysinv/openstack/common/periodic_task.py", line 180, in run_periodic_tasks 2022-05-09 11:25:05.699 91940 ERROR sysinv.openstack.common.periodic_task task(self, context) 2022-05-09 11:25:05.699 91940 ERROR sysinv.openstack.common.periodic_task File "/usr/lib64/python2.7/site-packages/sysinv/agent/manager.py", line 1253, in _agent_audit 2022-05-09 11:25:05.699 91940 ERROR sysinv.openstack.common.periodic_task force_updates=None) 2022-05-09 11:25:05.699 91940 ERROR sysinv.openstack.common.periodic_task File "/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py", line 328, in inner 2022-05-09 11:25:05.699 91940 ERROR sysinv.openstack.common.periodic_task return f(*args, **kwargs) 2022-05-09 11:25:05.699 91940 ERROR sysinv.openstack.common.periodic_task File "/usr/lib64/python2.7/site-packages/sysinv/agent/manager.py", line 1272, in agent_audit 2022-05-09 11:25:05.699 91940 ERROR sysinv.openstack.common.periodic_task self.ihost_inv_get_and_report(icontext) 2022-05-09 11:25:05.699 91940 ERROR sysinv.openstack.common.periodic_task File "/usr/lib64/python2.7/site-packages/sysinv/agent/manager.py", line 878, in ihost_inv_get_and_report 2022-05-09 11:25:05.699 91940 ERROR sysinv.openstack.common.periodic_task imemory = self._inode_operator.inodes_get_imemory() 2022-05-09 11:25:05.699 91940 ERROR sysinv.openstack.common.periodic_task File "/usr/lib64/python2.7/site-packages/sysinv/agent/node.py", line 566, in inodes_get_imemory 2022-05-09 11:25:05.699 91940 ERROR sysinv.openstack.common.periodic_task imemory = self._inode_get_memory_hugepages() 2022-05-09 11:25:05.699 91940 ERROR sysinv.openstack.common.periodic_task File "/usr/lib64/python2.7/site-packages/sysinv/agent/node.py", line 347, in _inode_get_memory_hugepages 2022-05-09 11:25:05.699 91940 ERROR sysinv.openstack.common.periodic_task subdirs = self._get_immediate_subdirs(hugepages) 2022-05-09 11:25:05.699 91940 ERROR sysinv.openstack.common.periodic_task File "/usr/lib64/python2.7/site-packages/sysinv/agent/node.py", line 279, in _get_immediate_subdirs 2022-05-09 11:25:05.699 91940 ERROR sysinv.openstack.common.periodic_task return [name for name in listdir(dir) 2022-05-09 11:25:05.699 91940 ERROR sysinv.openstack.common.periodic_task OSError: [Errno 2] No such file or directory: '/sys/devices/system/node/node1/hugepages' 2022-05-09 11:25:05.699 91940 ERROR sysinv.openstack.common.periodic_task sysinv 2022-05-09 11:25:21.715 98797 ERROR sysinv.conductor.kube_app [-] Kubernetes is not configured. API operations will not be available.: KubeNotConfigured: Kubernetes is not configured. API operations will not be available.