Nova compute automatically down when I delete an instance as admin

Bug #1520396 reported by codbla
10
This bug affects 2 people
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Expired
Undecided
Unassigned

Bug Description

When I use to terminate an instance as admin user. The compute node of where the VMs/Instance is located will turn to 'down' state.

I am using the following:
CentOS Linux release 7.1.1503 (Core)

openstack-nova-compute-2015.1.0-3.el7.noarch
libvirt-client-1.2.8-16.el7_1.3.x86_64
openstack-neutron-openvswitch-2015.1.0-1.el7.noarch
ceph-0.94.2-0.el7.x86_64

I don't know if it also related to ceph, as it still on the replicating at the moments when done those steps. I tried more than 5 same results.

But the remedy is restart both nova and neutron, but you keeps on monitoring once you deleted. Sill monitoring up no next week if still occur.
> service neutron-openvswitch-agent restart
> service openstack-nova-compute restart

Logs:

InstanceInfoCacheNotFound: Info cache for instance e3575681-1ea7-45f4-97b4-cf00cfc0fa00 could not be found.

2015-11-27 14:49:44.593 19796 INFO nova.compute.manager [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] [instance: 28c73c43-d3a0-4640-9e8a-ce6a09fd0cd4] Destroying instance with name label 'instance-000000c1' which is marked as DELETED but still present on host.
2015-11-27 14:49:44.605 19796 INFO nova.compute.manager [req-e24f56f0-a0c4-44d2-b7f8-865e753c3bbc - - - - -] [instance: 28c73c43-d3a0-4640-9e8a-ce6a09fd0cd4] Terminating instance
2015-11-27 14:49:44.660 19796 INFO nova.virt.libvirt.driver [-] [instance: 28c73c43-d3a0-4640-9e8a-ce6a09fd0cd4] Instance destroyed successfully.
[root@Compute16 nova]# tail nova-compute.log -n 100
2015-11-27 14:42:32.680 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Total usable vcpus: 8, total allocated vcpus: 23
2015-11-27 14:42:32.681 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Final resource view: name=Compute16 phys_ram=23939MB used_ram=26112MB phys_disk=16760GB used_disk=474GB total_vcpus=8 used_vcpus=23 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x48775d0>
2015-11-27 14:42:32.703 19796 INFO nova.scheduler.client.report [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Compute_service record updated for ('Compute16', 'Compute16')
2015-11-27 14:42:32.703 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Compute_service record updated for Compute16:Compute16
2015-11-27 14:43:31.705 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Auditing locally available compute resources for node Compute16
2015-11-27 14:43:32.346 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Total usable vcpus: 8, total allocated vcpus: 23
2015-11-27 14:43:32.347 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Final resource view: name=Compute16 phys_ram=23939MB used_ram=26112MB phys_disk=16760GB used_disk=474GB total_vcpus=8 used_vcpus=23 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x48775d0>
2015-11-27 14:43:32.364 19796 INFO nova.scheduler.client.report [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Compute_service record updated for ('Compute16', 'Compute16')
2015-11-27 14:43:32.365 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Compute_service record updated for Compute16:Compute16
2015-11-27 14:44:31.706 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Auditing locally available compute resources for node Compute16
2015-11-27 14:44:32.363 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Total usable vcpus: 8, total allocated vcpus: 23
2015-11-27 14:44:32.363 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Final resource view: name=Compute16 phys_ram=23939MB used_ram=26112MB phys_disk=16760GB used_disk=474GB total_vcpus=8 used_vcpus=23 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x48775d0>
2015-11-27 14:44:32.381 19796 INFO nova.scheduler.client.report [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Compute_service record updated for ('Compute16', 'Compute16')
2015-11-27 14:44:32.382 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Compute_service record updated for Compute16:Compute16
2015-11-27 14:45:32.705 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Auditing locally available compute resources for node Compute16
2015-11-27 14:45:33.424 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Total usable vcpus: 8, total allocated vcpus: 23
2015-11-27 14:45:33.424 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Final resource view: name=Compute16 phys_ram=23939MB used_ram=26112MB phys_disk=16760GB used_disk=474GB total_vcpus=8 used_vcpus=23 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x48775d0>
2015-11-27 14:45:33.443 19796 INFO nova.scheduler.client.report [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Compute_service record updated for ('Compute16', 'Compute16')
2015-11-27 14:45:33.443 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Compute_service record updated for Compute16:Compute16
2015-11-27 14:46:33.705 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Auditing locally available compute resources for node Compute16
2015-11-27 14:46:34.384 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Total usable vcpus: 8, total allocated vcpus: 23
2015-11-27 14:46:34.384 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Final resource view: name=Compute16 phys_ram=23939MB used_ram=26112MB phys_disk=16760GB used_disk=474GB total_vcpus=8 used_vcpus=23 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x48775d0>
2015-11-27 14:46:34.414 19796 INFO nova.scheduler.client.report [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Compute_service record updated for ('Compute16', 'Compute16')
2015-11-27 14:46:34.414 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Compute_service record updated for Compute16:Compute16
2015-11-27 14:47:34.705 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Auditing locally available compute resources for node Compute16
2015-11-27 14:47:35.346 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Total usable vcpus: 8, total allocated vcpus: 23
2015-11-27 14:47:35.347 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Final resource view: name=Compute16 phys_ram=23939MB used_ram=26112MB phys_disk=16760GB used_disk=474GB total_vcpus=8 used_vcpus=23 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x48775d0>
2015-11-27 14:47:35.364 19796 INFO nova.scheduler.client.report [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Compute_service record updated for ('Compute16', 'Compute16')
2015-11-27 14:47:35.364 19796 INFO nova.compute.resource_tracker [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] Compute_service record updated for Compute16:Compute16
2015-11-27 14:48:10.746 19796 INFO nova.compute.manager [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] Destroying instance with name label 'instance-000000c9' which is marked as DELETED but still present on host.
2015-11-27 14:48:10.758 19796 INFO nova.compute.manager [req-e24f56f0-a0c4-44d2-b7f8-865e753c3bbc - - - - -] [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] Terminating instance
2015-11-27 14:48:10.809 19796 INFO nova.virt.libvirt.driver [-] [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] Instance destroyed successfully.
2015-11-27 14:49:44.311 19796 INFO nova.virt.libvirt.driver [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] Deletion of /var/lib/nova/instances/e3575681-1ea7-45f4-97b4-cf00cfc0fa00_del complete
2015-11-27 14:49:44.510 19796 ERROR nova.network.base_api [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] Failed storing info cache
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] Traceback (most recent call last):
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] File "/usr/lib/python2.7/site-packages/nova/network/base_api.py", line 49, in update_instance_cache_with_nw_info
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] ic.save(update_cells=update_cells)
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] File "/usr/lib/python2.7/site-packages/nova/objects/base.py", line 192, in wrapper
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] self._context, self, fn.__name__, args, kwargs)
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] File "/usr/lib/python2.7/site-packages/nova/conductor/rpcapi.py", line 340, in object_action
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] objmethod=objmethod, args=args, kwargs=kwargs)
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 156, in call
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] retry=self.retry)
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] File "/usr/lib/python2.7/site-packages/oslo_messaging/transport.py", line 90, in _send
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] timeout=timeout, retry=retry)
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 350, in send
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] retry=retry)
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 341, in _send
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] raise result
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] InstanceInfoCacheNotFound_Remote: Info cache for instance e3575681-1ea7-45f4-97b4-cf00cfc0fa00 could not be found.
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] Traceback (most recent call last):
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00]
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] File "/usr/lib/python2.7/site-packages/nova/conductor/manager.py", line 422, in _object_dispatch
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] return getattr(target, method)(*args, **kwargs)
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00]
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] File "/usr/lib/python2.7/site-packages/nova/objects/base.py", line 208, in wrapper
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] return fn(self, *args, **kwargs)
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00]
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] File "/usr/lib/python2.7/site-packages/nova/objects/instance_info_cache.py", line 95, in save
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] {'network_info': nw_info_json})
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00]
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] File "/usr/lib/python2.7/site-packages/nova/db/api.py", line 888, in instance_info_cache_update
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] return IMPL.instance_info_cache_update(context, instance_uuid, values)
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00]
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 233, in wrapper
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] return f(*args, **kwargs)
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00]
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 2624, in instance_info_cache_update
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] instance_uuid=instance_uuid)
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00]
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] InstanceInfoCacheNotFound: Info cache for instance e3575681-1ea7-45f4-97b4-cf00cfc0fa00 could not be found.
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00]
2015-11-27 14:49:44.510 19796 TRACE nova.network.base_api [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00]
2015-11-27 14:49:44.513 19796 ERROR nova.compute.manager [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] Failed to deallocate network for instance.
2015-11-27 14:49:44.593 19796 WARNING nova.compute.manager [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] [instance: e3575681-1ea7-45f4-97b4-cf00cfc0fa00] Periodic cleanup failed to delete instance: Info cache for instance e3575681-1ea7-45f4-97b4-cf00cfc0fa00 could not be found.
Traceback (most recent call last):

  File "/usr/lib/python2.7/site-packages/nova/conductor/manager.py", line 422, in _object_dispatch
    return getattr(target, method)(*args, **kwargs)

  File "/usr/lib/python2.7/site-packages/nova/objects/base.py", line 208, in wrapper
    return fn(self, *args, **kwargs)

  File "/usr/lib/python2.7/site-packages/nova/objects/instance_info_cache.py", line 95, in save
    {'network_info': nw_info_json})

  File "/usr/lib/python2.7/site-packages/nova/db/api.py", line 888, in instance_info_cache_update
    return IMPL.instance_info_cache_update(context, instance_uuid, values)

  File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 233, in wrapper
    return f(*args, **kwargs)

  File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 2624, in instance_info_cache_update
    instance_uuid=instance_uuid)

InstanceInfoCacheNotFound: Info cache for instance e3575681-1ea7-45f4-97b4-cf00cfc0fa00 could not be found.

2015-11-27 14:49:44.593 19796 INFO nova.compute.manager [req-bc5bab4c-bcf6-407b-8f6e-5ecfb89e3609 - - - - -] [instance: 28c73c43-d3a0-4640-9e8a-ce6a09fd0cd4] Destroying instance with name label 'instance-000000c1' which is marked as DELETED but still present on host.
2015-11-27 14:49:44.605 19796 INFO nova.compute.manager [req-e24f56f0-a0c4-44d2-b7f8-865e753c3bbc - - - - -] [instance: 28c73c43-d3a0-4640-9e8a-ce6a09fd0cd4] Terminating instance
2015-11-27 14:49:44.660 19796 INFO nova.virt.libvirt.driver [-] [instance: 28c73c43-d3a0-4640-9e8a-ce6a09fd0cd4] Instance destroyed successfully.

Other logs
   Compute06 nova]# tail nova-compute.log
2015-11-27 14:54:33.197 4927 INFO nova.scheduler.client.report [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Compute_service record updated for ('Compute06', 'Compute06')
2015-11-27 14:54:33.198 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Compute_service record updated for Compute06:Compute06
2015-11-27 14:55:30.327 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Auditing locally available compute resources for node Compute06
2015-11-27 14:55:34.095 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Total usable vcpus: 8, total allocated vcpus: 22
2015-11-27 14:55:34.095 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Final resource view: name=Compute06 phys_ram=23939MB used_ram=29184MB phys_disk=16760GB used_disk=532GB total_vcpus=8 used_vcpus=22 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x4b6fc90>
2015-11-27 14:55:34.114 4927 INFO nova.scheduler.client.report [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Compute_service record updated for ('Compute06', 'Compute06')
2015-11-27 14:55:34.114 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Compute_service record updated for Compute06:Compute06
2015-11-27 14:55:57.358 4927 INFO nova.compute.manager [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] Destroying instance with name label 'instance-00000103' which is marked as DELETED but still present on host.
2015-11-27 14:55:57.370 4927 INFO nova.compute.manager [req-edeebef0-82ba-4647-90ef-12ecbbfb88da - - - - -] [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] Terminating instance
2015-11-27 14:55:57.419 4927 INFO nova.virt.libvirt.driver [-] [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] Instance destroyed successfully.
[root@Compute06 nova]# tail nova-compute.log -n 100
2015-11-27 14:49:25.118 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Compute_service record updated for Compute06:Compute06
2015-11-27 14:50:23.327 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Auditing locally available compute resources for node Compute06
2015-11-27 14:50:27.076 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Total usable vcpus: 8, total allocated vcpus: 22
2015-11-27 14:50:27.077 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Final resource view: name=Compute06 phys_ram=23939MB used_ram=29184MB phys_disk=16760GB used_disk=532GB total_vcpus=8 used_vcpus=22 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x4b6fc90>
2015-11-27 14:50:27.095 4927 INFO nova.scheduler.client.report [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Compute_service record updated for ('Compute06', 'Compute06')
2015-11-27 14:50:27.096 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Compute_service record updated for Compute06:Compute06
2015-11-27 14:51:24.524 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Auditing locally available compute resources for node Compute06
2015-11-27 14:51:28.313 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Total usable vcpus: 8, total allocated vcpus: 22
2015-11-27 14:51:28.314 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Final resource view: name=Compute06 phys_ram=23939MB used_ram=29184MB phys_disk=16760GB used_disk=532GB total_vcpus=8 used_vcpus=22 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x4b6fc90>
2015-11-27 14:51:28.334 4927 INFO nova.scheduler.client.report [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Compute_service record updated for ('Compute06', 'Compute06')
2015-11-27 14:51:28.334 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Compute_service record updated for Compute06:Compute06
2015-11-27 14:52:26.429 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Auditing locally available compute resources for node Compute06
2015-11-27 14:52:30.207 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Total usable vcpus: 8, total allocated vcpus: 22
2015-11-27 14:52:30.207 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Final resource view: name=Compute06 phys_ram=23939MB used_ram=29184MB phys_disk=16760GB used_disk=532GB total_vcpus=8 used_vcpus=22 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x4b6fc90>
2015-11-27 14:52:30.224 4927 INFO nova.scheduler.client.report [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Compute_service record updated for ('Compute06', 'Compute06')
2015-11-27 14:52:30.225 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Compute_service record updated for Compute06:Compute06
2015-11-27 14:53:28.476 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Auditing locally available compute resources for node Compute06
2015-11-27 14:53:32.188 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Total usable vcpus: 8, total allocated vcpus: 22
2015-11-27 14:53:32.188 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Final resource view: name=Compute06 phys_ram=23939MB used_ram=29184MB phys_disk=16760GB used_disk=532GB total_vcpus=8 used_vcpus=22 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x4b6fc90>
2015-11-27 14:53:32.206 4927 INFO nova.scheduler.client.report [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Compute_service record updated for ('Compute06', 'Compute06')
2015-11-27 14:53:32.206 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Compute_service record updated for Compute06:Compute06
2015-11-27 14:54:29.476 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Auditing locally available compute resources for node Compute06
2015-11-27 14:54:33.178 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Total usable vcpus: 8, total allocated vcpus: 22
2015-11-27 14:54:33.178 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Final resource view: name=Compute06 phys_ram=23939MB used_ram=29184MB phys_disk=16760GB used_disk=532GB total_vcpus=8 used_vcpus=22 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x4b6fc90>
2015-11-27 14:54:33.197 4927 INFO nova.scheduler.client.report [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Compute_service record updated for ('Compute06', 'Compute06')
2015-11-27 14:54:33.198 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Compute_service record updated for Compute06:Compute06
2015-11-27 14:55:30.327 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Auditing locally available compute resources for node Compute06
2015-11-27 14:55:34.095 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Total usable vcpus: 8, total allocated vcpus: 22
2015-11-27 14:55:34.095 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Final resource view: name=Compute06 phys_ram=23939MB used_ram=29184MB phys_disk=16760GB used_disk=532GB total_vcpus=8 used_vcpus=22 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x4b6fc90>
2015-11-27 14:55:34.114 4927 INFO nova.scheduler.client.report [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Compute_service record updated for ('Compute06', 'Compute06')
2015-11-27 14:55:34.114 4927 INFO nova.compute.resource_tracker [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] Compute_service record updated for Compute06:Compute06
2015-11-27 14:55:57.358 4927 INFO nova.compute.manager [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] Destroying instance with name label 'instance-00000103' which is marked as DELETED but still present on host.
2015-11-27 14:55:57.370 4927 INFO nova.compute.manager [req-edeebef0-82ba-4647-90ef-12ecbbfb88da - - - - -] [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] Terminating instance
2015-11-27 14:55:57.419 4927 INFO nova.virt.libvirt.driver [-] [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] Instance destroyed successfully.
2015-11-27 15:01:43.712 4927 INFO nova.virt.libvirt.driver [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] Deletion of /var/lib/nova/instances/d26e6e47-68b0-4914-bbd8-6d3d2cc577b9_del complete
2015-11-27 15:01:43.880 4927 ERROR nova.network.base_api [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] Failed storing info cache
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] Traceback (most recent call last):
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] File "/usr/lib/python2.7/site-packages/nova/network/base_api.py", line 49, in update_instance_cache_with_nw_info
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] ic.save(update_cells=update_cells)
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] File "/usr/lib/python2.7/site-packages/nova/objects/base.py", line 192, in wrapper
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] self._context, self, fn.__name__, args, kwargs)
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] File "/usr/lib/python2.7/site-packages/nova/conductor/rpcapi.py", line 340, in object_action
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] objmethod=objmethod, args=args, kwargs=kwargs)
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 156, in call
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] retry=self.retry)
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] File "/usr/lib/python2.7/site-packages/oslo_messaging/transport.py", line 90, in _send
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] timeout=timeout, retry=retry)
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 350, in send
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] retry=retry)
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 341, in _send
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] raise result
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] InstanceInfoCacheNotFound_Remote: Info cache for instance d26e6e47-68b0-4914-bbd8-6d3d2cc577b9 could not be found.
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] Traceback (most recent call last):
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9]
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] File "/usr/lib/python2.7/site-packages/nova/conductor/manager.py", line 422, in _object_dispatch
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] return getattr(target, method)(*args, **kwargs)
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9]
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] File "/usr/lib/python2.7/site-packages/nova/objects/base.py", line 208, in wrapper
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] return fn(self, *args, **kwargs)
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9]
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] File "/usr/lib/python2.7/site-packages/nova/objects/instance_info_cache.py", line 95, in save
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] {'network_info': nw_info_json})
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9]
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] File "/usr/lib/python2.7/site-packages/nova/db/api.py", line 888, in instance_info_cache_update
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] return IMPL.instance_info_cache_update(context, instance_uuid, values)
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9]
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 233, in wrapper
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] return f(*args, **kwargs)
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9]
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 2624, in instance_info_cache_update
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] instance_uuid=instance_uuid)
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9]
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] InstanceInfoCacheNotFound: Info cache for instance d26e6e47-68b0-4914-bbd8-6d3d2cc577b9 could not be found.
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9]
2015-11-27 15:01:43.880 4927 TRACE nova.network.base_api [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9]
2015-11-27 15:01:43.943 4927 ERROR nova.compute.manager [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] Failed to deallocate network for instance.
2015-11-27 15:01:44.000 4927 WARNING nova.compute.manager [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] [instance: d26e6e47-68b0-4914-bbd8-6d3d2cc577b9] Periodic cleanup failed to delete instance: Info cache for instance d26e6e47-68b0-4914-bbd8-6d3d2cc577b9 could not be found.
Traceback (most recent call last):

  File "/usr/lib/python2.7/site-packages/nova/conductor/manager.py", line 422, in _object_dispatch
    return getattr(target, method)(*args, **kwargs)

  File "/usr/lib/python2.7/site-packages/nova/objects/base.py", line 208, in wrapper
    return fn(self, *args, **kwargs)

  File "/usr/lib/python2.7/site-packages/nova/objects/instance_info_cache.py", line 95, in save
    {'network_info': nw_info_json})

  File "/usr/lib/python2.7/site-packages/nova/db/api.py", line 888, in instance_info_cache_update
    return IMPL.instance_info_cache_update(context, instance_uuid, values)

  File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 233, in wrapper
    return f(*args, **kwargs)

  File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 2624, in instance_info_cache_update
    instance_uuid=instance_uuid)

InstanceInfoCacheNotFound: Info cache for instance d26e6e47-68b0-4914-bbd8-6d3d2cc577b9 could not be found.

2015-11-27 15:01:44.107 4927 WARNING nova.compute.manager [req-52e5a18d-9429-4cde-b2c4-5503a1d8abf5 - - - - -] While synchronizing instance power states, found 28 instances in the database and 29 instances on the hypervisor.

 Other Log

 sed_vcpus=18 pci_stats=<nova.pci.stats.PciDeviceStats object at 0x4ba0d10>
2015-11-27 15:13:20.584 17205 INFO nova.scheduler.client.report [req-95072099-fdd4-42c2-bd28-50813a0df37b - - - - -] Compute_service record updated for ('Compute05', u'Compute05')
2015-11-27 15:13:20.584 17205 INFO nova.compute.resource_tracker [req-95072099-fdd4-42c2-bd28-50813a0df37b - - - - -] Compute_service record updated for Compute05:Compute05
2015-11-27 15:14:02.876 17205 INFO nova.compute.manager [req-95072099-fdd4-42c2-bd28-50813a0df37b - - - - -] [instance: 714390bc-f342-42f9-a01a-15b63ab794d5] Destroying instance with name label 'instance-00000070' which is marked as DELETED but still present on host.
2015-11-27 15:14:02.892 17205 INFO nova.compute.manager [req-944a9b01-e8dd-48fa-a7b6-29f946b78196 - - - - -] [instance: 714390bc-f342-42f9-a01a-15b63ab794d5] Terminating instance
2015-11-27 15:14:02.959 17205 INFO nova.virt.libvirt.driver [-] [instance: 714390bc-f342-42f9-a01a-15b63ab794d5] Instance destroyed successfully.

codbla (codbla)
description: updated
Revision history for this message
Matt Riedemann (mriedem) wrote :

There is nothing in here that would explain a sigterm of the nova-compute process, are there other errors in the logs when the nova-compute process dies?

What about errors in the neutron agent logs?

Changed in nova:
status: New → Incomplete
Revision history for this message
Launchpad Janitor (janitor) wrote :

[Expired for OpenStack Compute (nova) because there has been no activity for 60 days.]

Changed in nova:
status: Incomplete → Expired
Revision history for this message
Fan Yang (roymaztang) wrote :
Fan Yang (roymaztang)
Changed in nova:
status: Expired → Incomplete
Revision history for this message
Launchpad Janitor (janitor) wrote :

[Expired for OpenStack Compute (nova) because there has been no activity for 60 days.]

Changed in nova:
status: Incomplete → Expired
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.