This issue is seen in Ironic HPE CI jobs https://15.184.0.52/28/372428/18/check/gate-tempest-ironic-ilo-driver-iscsi_ilo/3d53e55/ See relevant portions of n-sch.log, n-cpu.log and key.log below. n-sch.log ---------- 2017-01-03 23:35:05.933 25579 DEBUG oslo_concurrency.lockutils [req-7ac1f5ec-68a1-47e1-b4a6-0e850839da16 tempest-BaremetalBasicOps-1350158805 tempest-BaremetalBasicOps-1350158805] Lock "(u'jenkins-slave1', u'c25e2761-3b47-4dee-9737-8bb99c469a4b')" acquired by "nova.scheduler.host_manager._locked_update" :: waited 0.000s inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:270 2017-01-03 23:35:05.935 25579 DEBUG nova.scheduler.host_manager [req-7ac1f5ec-68a1-47e1-b4a6-0e850839da16 tempest-BaremetalBasicOps-1350158805 tempest-BaremetalBasicOps-1350158805] Update host state from compute node: ComputeNode(cpu_allocation_ratio=16.0,cpu_info='',created_at=2017-01-03T23:32:43Z,current_workload=None,deleted=False,deleted_at=None,disk_allocation_ratio=1.0,disk_available_least=99,free_disk_gb=None,free_ram_mb=None,host='jenkins-slave1',host_ip=10.13.120.197,hypervisor_hostname='c25e2761-3b47-4dee-9737-8bb99c469a4b',hypervisor_type='ironic',hypervisor_version=1,id=1,local_gb=99,local_gb_used=0,memory_mb=16384,memory_mb_used=0,metrics=None,numa_topology=None,pci_device_pools=PciDevicePoolList,ram_allocation_ratio=1.0,running_vms=None,service_id=None,stats={boot_mode='bios',cpu_arch='x86_64'},supported_hv_specs=[HVSpec],updated_at=2017-01-03T23:34:44Z,uuid=93e176d6-dca2-46c4-bd41-b41570e61e2c,vcpus=2,vcpus_used=0) _locked_update /opt/stack/nova/nova/scheduler/host_manager.py:168 2017-01-03 23:35:05.938 25579 DEBUG oslo_concurrency.lockutils [req-7ac1f5ec-68a1-47e1-b4a6-0e850839da16 tempest-BaremetalBasicOps-1350158805 tempest-BaremetalBasicOps-1350158805] Lock "(u'jenkins-slave1', u'c25e2761-3b47-4dee-9737-8bb99c469a4b')" released by "nova.scheduler.host_manager._locked_update" :: held 0.005s inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:282 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server [req-7ac1f5ec-68a1-47e1-b4a6-0e850839da16 tempest-BaremetalBasicOps-1350158805 tempest-BaremetalBasicOps-1350158805] Exception during message handling 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server Traceback (most recent call last): 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/server.py", line 155, in _process_incoming 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message) 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 222, in dispatch 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server return self._do_dispatch(endpoint, method, ctxt, args) 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 192, in _do_dispatch 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server result = func(ctxt, **new_args) 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/server.py", line 218, in inner 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server return func(*args, **kwargs) 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/scheduler/manager.py", line 84, in select_destinations 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server dests = self.driver.select_destinations(ctxt, spec_obj) 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/scheduler/filter_scheduler.py", line 51, in select_destinations 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server selected_hosts = self._schedule(context, spec_obj) 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/scheduler/filter_scheduler.py", line 96, in _schedule 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server hosts = self._get_all_host_states(elevated) 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/scheduler/filter_scheduler.py", line 134, in _get_all_host_states 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server return self.host_manager.get_all_host_states(context) 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/scheduler/host_manager.py", line 610, in get_all_host_states 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server self._get_instance_info(context, compute)) 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/scheduler/host_manager.py", line 180, in update 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server return _locked_update(self, compute, service, aggregates, inst_dict) 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py", line 271, in inner 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server return f(*args, **kwargs) 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/scheduler/host_manager.py", line 169, in _locked_update 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server self._update_from_compute_node(compute) 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/scheduler/ironic_host_manager.py", line 46, in _update_from_compute_node 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server self.free_disk_mb = compute.free_disk_gb * 1024 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server TypeError: unsupported operand type(s) for *: 'NoneType' and 'int' 2017-01-03 23:35:05.938 25579 ERROR oslo_messaging.rpc.server n-cpu.log ----------- 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager [req-004a8db8-093a-485c-b429-b22c1a69be83 - -] Error updating resources for node c25e2761-3b47-4dee-9737-8bb99c469a4b. 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager Traceback (most recent call last): 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/opt/stack/nova/nova/compute/manager.py", line 6537, in update_available_resource_for_node 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager rt.update_available_resource(context, nodename) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/opt/stack/nova/nova/compute/resource_tracker.py", line 540, in update_available_resource 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager self._update_available_resource(context, resources) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py", line 271, in inner 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager return f(*args, **kwargs) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/opt/stack/nova/nova/compute/resource_tracker.py", line 564, in _update_available_resource 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager self._init_compute_node(context, resources) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/opt/stack/nova/nova/compute/resource_tracker.py", line 451, in _init_compute_node 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager self.scheduler_client.update_resource_stats(self.compute_node) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/opt/stack/nova/nova/scheduler/client/__init__.py", line 60, in update_resource_stats 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager self.reportclient.update_resource_stats(compute_node) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/opt/stack/nova/nova/scheduler/client/__init__.py", line 37, in __run_method 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager return getattr(self.instance, __name)(*args, **kwargs) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/opt/stack/nova/nova/scheduler/client/report.py", line 369, in update_resource_stats 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager compute_node.hypervisor_hostname) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/opt/stack/nova/nova/scheduler/client/report.py", line 258, in _ensure_resource_provider 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager rp = self._get_resource_provider(uuid) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/opt/stack/nova/nova/scheduler/client/report.py", line 44, in wrapper 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager return f(self, *a, **k) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/opt/stack/nova/nova/scheduler/client/report.py", line 171, in _get_resource_provider 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager resp = self.get("/resource_providers/%s" % uuid) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/opt/stack/nova/nova/scheduler/client/report.py", line 136, in get 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager endpoint_filter=self.ks_filter, raise_exc=False) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/keystoneauth1/session.py", line 710, in get 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager return self.request(url, 'GET', **kwargs) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/positional/__init__.py", line 101, in inner 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager return wrapped(*args, **kwargs) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/keystoneauth1/session.py", line 467, in request 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager auth_headers = self.get_auth_headers(auth) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/keystoneauth1/session.py", line 770, in get_auth_headers 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager return auth.get_headers(self, **kwargs) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/keystoneauth1/plugin.py", line 90, in get_headers 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager token = self.get_token(session) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/keystoneauth1/identity/base.py", line 90, in get_token 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager return self.get_access(session).auth_token 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/keystoneauth1/identity/base.py", line 136, in get_access 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager self.auth_ref = self.get_auth_ref(session) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/keystoneauth1/identity/generic/base.py", line 198, in get_auth_ref 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager return self._plugin.get_auth_ref(session, **kwargs) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/keystoneauth1/identity/v3/base.py", line 167, in get_auth_ref 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager authenticated=False, log=False, **rkwargs) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/keystoneauth1/session.py", line 718, in post 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager return self.request(url, 'POST', **kwargs) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/positional/__init__.py", line 101, in inner 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager return wrapped(*args, **kwargs) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/keystoneauth1/session.py", line 607, in request 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager raise exceptions.from_response(resp, method, url) 2017-01-03 23:32:43.667 29444 ERROR nova.compute.manager Unauthorized: The request you have made requires authentication. (HTTP 401) (Request-ID: req-5ff4d23d-9909-4694-b441-d25c36fde7a2) key.log ----------- 2017-01-03 23:32:43.632 9144 INFO keystone.common.wsgi [req-aa116edf-2720-4d03-a94a-999feb18e46a - - - - -] GET http://10.13.120.197:35357/v3/ 2017-01-03 23:32:43.639 9138 DEBUG keystone.middleware.auth [req-5ff4d23d-9909-4694-b441-d25c36fde7a2 - - - - -] There is either no auth token in the request or the certificate issuer is not trusted. No auth context will be set. fill_context /opt/stack/keystone/keystone/middleware/auth.py:188 2017-01-03 23:32:43.640 9138 INFO keystone.common.wsgi [req-5ff4d23d-9909-4694-b441-d25c36fde7a2 - - - - -] POST http://10.13.120.197/identity/v3/auth/tokens 2017-01-03 23:32:43.658 9138 WARNING keystone.auth.plugins.core [req-5ff4d23d-9909-4694-b441-d25c36fde7a2 - - - - -] Could not find user: placement