yahoo-eng-team team mailing list archive
-
yahoo-eng-team team
-
Mailing list archive
-
Message #20874
[Bug 1367845] [NEW] Traceback is logged when delete an instance.
Public bug reported:
OpenStack version: Icehouse
Issue: traceback is logged in nova-compute.log when delete an instance.
Setup: 3 nodes, namely Controller, Compute and Network; with nova-
compute running solely on Compute node.
Steps to reproduce:
1. Create an instance using image cirrus 0.3.2.
2. Verify instance is running: nova list
3. Delete the instance: nova delete <name>
4. Check nova-compute.log at Compute node.
root@Controller:/home/guest# nova --version
2.17.0
root@Controller:/home/guest# nova service-list
+------------------+------------+----------+---------+-------+----------------------------+-----------------+
| Binary | Host | Zone | Status | State | Updated_at | Disabled Reason |
+------------------+------------+----------+---------+-------+----------------------------+-----------------+
| nova-cert | Controller | internal | enabled | up | 2014-09-10T17:12:34.000000 | - |
| nova-conductor | Controller | internal | enabled | up | 2014-09-10T17:12:26.000000 | - |
| nova-consoleauth | Controller | internal | enabled | up | 2014-09-10T17:12:28.000000 | - |
| nova-scheduler | Controller | internal | enabled | up | 2014-09-10T17:12:31.000000 | - |
| nova-compute | Compute | nova | enabled | up | 2014-09-10T17:12:34.000000 | - |
+------------------+------------+----------+---------+-------+----------------------------+-----------------+
root@Controller:/home/guest# nova boot --image cirros-0.3.2-x86_64 --flavor 1 --nic net-id=75375f9b-0f26-4e1a-aedc-24457192f265 cirros
+--------------------------------------+------------------------------------------------------------+
| Property | Value |
+--------------------------------------+------------------------------------------------------------+
| OS-DCF:diskConfig | MANUAL |
| OS-EXT-AZ:availability_zone | nova |
| OS-EXT-SRV-ATTR:host | - |
| OS-EXT-SRV-ATTR:hypervisor_hostname | - |
| OS-EXT-SRV-ATTR:instance_name | instance-00000046 |
| OS-EXT-STS:power_state | 0 |
| OS-EXT-STS:task_state | scheduling |
| OS-EXT-STS:vm_state | building |
| OS-SRV-USG:launched_at | - |
| OS-SRV-USG:terminated_at | - |
| accessIPv4 | |
| accessIPv6 | |
| adminPass | jFmNDB5Jsd77 |
| config_drive | |
| created | 2014-09-10T17:13:06Z |
| flavor | m1.tiny (1) |
| hostId | |
| id | bc01c570-c40f-4088-a17c-0278fc6c3315 |
| image | cirros-0.3.2-x86_64 (38f00c62-f9df-4133-abf2-7c9ba948d414) |
| key_name | - |
| metadata | {} |
| name | cirros |
| os-extended-volumes:volumes_attached | [] |
| progress | 0 |
| security_groups | default |
| status | BUILD |
| tenant_id | 73a095bf078443c9b340d871deaabcc3 |
| updated | 2014-09-10T17:13:06Z |
| user_id | 77bdd3f911744f72af7038d40d722439 |
+--------------------------------------+------------------------------------------------------------+
root@Controller:/home/guest# nova list
+--------------------------------------+--------+--------+------------+-------------+---------------------+
| ID | Name | Status | Task State | Power State | Networks |
+--------------------------------------+--------+--------+------------+-------------+---------------------+
| bc01c570-c40f-4088-a17c-0278fc6c3315 | cirros | ACTIVE | - | Running | int-net=172.16.1.48 |
+--------------------------------------+--------+--------+------------+-------------+---------------------+
root@Controller:/home/guest# nova delete cirros
root@Controller:/home/guest# nova list
+----+------+--------+------------+-------------+----------+
| ID | Name | Status | Task State | Power State | Networks |
+----+------+--------+------------+-------------+----------+
+----+------+--------+------------+-------------+----------+
root@Controller:/home/guest#
Snippet of nova-compute.log:
2014-09-10 13:13:06.521 1893 AUDIT nova.compute.manager [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Starting instance...
2014-09-10 13:13:06.607 1893 AUDIT nova.compute.claims [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Attempting claim: memory 512 MB, disk 1 GB, VCPUs 1
2014-09-10 13:13:06.610 1893 AUDIT nova.compute.claims [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Total memory: 7985 MB, used: 512.00 MB
2014-09-10 13:13:06.611 1893 AUDIT nova.compute.claims [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] memory limit: 11977.50 MB, free: 11465.50 MB
2014-09-10 13:13:06.611 1893 AUDIT nova.compute.claims [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Total disk: 9 GB, used: 0.00 GB
2014-09-10 13:13:06.612 1893 AUDIT nova.compute.claims [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] disk limit not specified, defaulting to unlimited
2014-09-10 13:13:06.612 1893 AUDIT nova.compute.claims [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Total CPUs: 1 VCPUs, used: 0.00 VCPUs
2014-09-10 13:13:06.612 1893 AUDIT nova.compute.claims [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] CPUs limit not specified, defaulting to unlimited
2014-09-10 13:13:06.613 1893 AUDIT nova.compute.claims [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Claim successful
2014-09-10 13:13:07.044 1893 INFO nova.virt.libvirt.driver [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Creating image
2014-09-10 13:13:07.256 1893 WARNING nova.virt.disk.vfs.guestfs [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] Failed to close augeas aug_close: call launch before using this function
(in guestfish, don't forget to use the 'run' command)
2014-09-10 13:13:09.306 1893 INFO nova.compute.manager [-] Lifecycle event 0 on VM bc01c570-c40f-4088-a17c-0278fc6c3315
2014-09-10 13:13:09.327 1893 INFO nova.virt.libvirt.driver [-] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Instance spawned successfully.
2014-09-10 13:13:09.441 1893 INFO nova.compute.manager [-] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] During sync_power_state the instance has a pending task (spawning). Skip.
2014-09-10 13:13:23.031 1893 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-09-10 13:13:23.202 1893 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 6961
2014-09-10 13:13:23.203 1893 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 8
2014-09-10 13:13:23.204 1893 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 0
2014-09-10 13:13:23.222 1893 INFO nova.compute.resource_tracker [-] Compute_service record updated for Compute:compute
2014-09-10 13:13:44.709 1893 AUDIT nova.compute.manager [req-6c9a4f5f-d9e7-4e12-b5c2-8ee7716fe97a 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Terminating instance
2014-09-10 13:13:45.269 1893 INFO nova.compute.manager [-] Lifecycle event 1 on VM bc01c570-c40f-4088-a17c-0278fc6c3315
2014-09-10 13:13:45.276 1893 INFO nova.virt.libvirt.driver [-] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Instance destroyed successfully.
2014-09-10 13:13:45.391 1893 ERROR nova.virt.driver [-] Exception dispatching event <nova.virt.event.LifecycleEvent object at 0x7fc7e4178490>: Info cache for instance bc01c570-c40f-4088-a17c-0278fc6c3315 could not be found.
Traceback (most recent call last):
File "/usr/lib/python2.7/dist-packages/nova/conductor/manager.py", line 597, in _object_dispatch
return getattr(target, method)(context, *args, **kwargs)
File "/usr/lib/python2.7/dist-packages/nova/objects/base.py", line 151, in wrapper
return fn(self, ctxt, *args, **kwargs)
File "/usr/lib/python2.7/dist-packages/nova/objects/instance.py", line 500, in refresh
self.info_cache.refresh()
File "/usr/lib/python2.7/dist-packages/nova/objects/base.py", line 151, in wrapper
return fn(self, ctxt, *args, **kwargs)
File "/usr/lib/python2.7/dist-packages/nova/objects/instance_info_cache.py", line 103, in refresh
self.instance_uuid)
File "/usr/lib/python2.7/dist-packages/nova/objects/base.py", line 112, in wrapper
result = fn(cls, context, *args, **kwargs)
File "/usr/lib/python2.7/dist-packages/nova/objects/instance_info_cache.py", line 70, in get_by_instance_uuid
instance_uuid=instance_uuid)
InstanceInfoCacheNotFound: Info cache for instance bc01c570-c40f-4088
-a17c-0278fc6c3315 could not be found.
2014-09-10 13:13:45.946 1893 INFO nova.virt.libvirt.driver [req-6c9a4f5f-d9e7-4e12-b5c2-8ee7716fe97a 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Deleting instance files /var/lib/nova/instances/bc01c570-c40f-4088-a17c-0278fc6c3315
2014-09-10 13:13:45.947 1893 INFO nova.virt.libvirt.driver [req-6c9a4f5f-d9e7-4e12-b5c2-8ee7716fe97a 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Deletion of /var/lib/nova/instances/bc01c570-c40f-4088-a17c-0278fc6c3315 complete
** Affects: nova
Importance: Undecided
Status: New
--
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1367845
Title:
Traceback is logged when delete an instance.
Status in OpenStack Compute (Nova):
New
Bug description:
OpenStack version: Icehouse
Issue: traceback is logged in nova-compute.log when delete an
instance.
Setup: 3 nodes, namely Controller, Compute and Network; with nova-
compute running solely on Compute node.
Steps to reproduce:
1. Create an instance using image cirrus 0.3.2.
2. Verify instance is running: nova list
3. Delete the instance: nova delete <name>
4. Check nova-compute.log at Compute node.
root@Controller:/home/guest# nova --version
2.17.0
root@Controller:/home/guest# nova service-list
+------------------+------------+----------+---------+-------+----------------------------+-----------------+
| Binary | Host | Zone | Status | State | Updated_at | Disabled Reason |
+------------------+------------+----------+---------+-------+----------------------------+-----------------+
| nova-cert | Controller | internal | enabled | up | 2014-09-10T17:12:34.000000 | - |
| nova-conductor | Controller | internal | enabled | up | 2014-09-10T17:12:26.000000 | - |
| nova-consoleauth | Controller | internal | enabled | up | 2014-09-10T17:12:28.000000 | - |
| nova-scheduler | Controller | internal | enabled | up | 2014-09-10T17:12:31.000000 | - |
| nova-compute | Compute | nova | enabled | up | 2014-09-10T17:12:34.000000 | - |
+------------------+------------+----------+---------+-------+----------------------------+-----------------+
root@Controller:/home/guest# nova boot --image cirros-0.3.2-x86_64 --flavor 1 --nic net-id=75375f9b-0f26-4e1a-aedc-24457192f265 cirros
+--------------------------------------+------------------------------------------------------------+
| Property | Value |
+--------------------------------------+------------------------------------------------------------+
| OS-DCF:diskConfig | MANUAL |
| OS-EXT-AZ:availability_zone | nova |
| OS-EXT-SRV-ATTR:host | - |
| OS-EXT-SRV-ATTR:hypervisor_hostname | - |
| OS-EXT-SRV-ATTR:instance_name | instance-00000046 |
| OS-EXT-STS:power_state | 0 |
| OS-EXT-STS:task_state | scheduling |
| OS-EXT-STS:vm_state | building |
| OS-SRV-USG:launched_at | - |
| OS-SRV-USG:terminated_at | - |
| accessIPv4 | |
| accessIPv6 | |
| adminPass | jFmNDB5Jsd77 |
| config_drive | |
| created | 2014-09-10T17:13:06Z |
| flavor | m1.tiny (1) |
| hostId | |
| id | bc01c570-c40f-4088-a17c-0278fc6c3315 |
| image | cirros-0.3.2-x86_64 (38f00c62-f9df-4133-abf2-7c9ba948d414) |
| key_name | - |
| metadata | {} |
| name | cirros |
| os-extended-volumes:volumes_attached | [] |
| progress | 0 |
| security_groups | default |
| status | BUILD |
| tenant_id | 73a095bf078443c9b340d871deaabcc3 |
| updated | 2014-09-10T17:13:06Z |
| user_id | 77bdd3f911744f72af7038d40d722439 |
+--------------------------------------+------------------------------------------------------------+
root@Controller:/home/guest# nova list
+--------------------------------------+--------+--------+------------+-------------+---------------------+
| ID | Name | Status | Task State | Power State | Networks |
+--------------------------------------+--------+--------+------------+-------------+---------------------+
| bc01c570-c40f-4088-a17c-0278fc6c3315 | cirros | ACTIVE | - | Running | int-net=172.16.1.48 |
+--------------------------------------+--------+--------+------------+-------------+---------------------+
root@Controller:/home/guest# nova delete cirros
root@Controller:/home/guest# nova list
+----+------+--------+------------+-------------+----------+
| ID | Name | Status | Task State | Power State | Networks |
+----+------+--------+------------+-------------+----------+
+----+------+--------+------------+-------------+----------+
root@Controller:/home/guest#
Snippet of nova-compute.log:
2014-09-10 13:13:06.521 1893 AUDIT nova.compute.manager [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Starting instance...
2014-09-10 13:13:06.607 1893 AUDIT nova.compute.claims [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Attempting claim: memory 512 MB, disk 1 GB, VCPUs 1
2014-09-10 13:13:06.610 1893 AUDIT nova.compute.claims [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Total memory: 7985 MB, used: 512.00 MB
2014-09-10 13:13:06.611 1893 AUDIT nova.compute.claims [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] memory limit: 11977.50 MB, free: 11465.50 MB
2014-09-10 13:13:06.611 1893 AUDIT nova.compute.claims [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Total disk: 9 GB, used: 0.00 GB
2014-09-10 13:13:06.612 1893 AUDIT nova.compute.claims [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] disk limit not specified, defaulting to unlimited
2014-09-10 13:13:06.612 1893 AUDIT nova.compute.claims [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Total CPUs: 1 VCPUs, used: 0.00 VCPUs
2014-09-10 13:13:06.612 1893 AUDIT nova.compute.claims [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] CPUs limit not specified, defaulting to unlimited
2014-09-10 13:13:06.613 1893 AUDIT nova.compute.claims [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Claim successful
2014-09-10 13:13:07.044 1893 INFO nova.virt.libvirt.driver [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Creating image
2014-09-10 13:13:07.256 1893 WARNING nova.virt.disk.vfs.guestfs [req-4de48240-de8f-4fce-ab6c-28e3b9541131 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] Failed to close augeas aug_close: call launch before using this function
(in guestfish, don't forget to use the 'run' command)
2014-09-10 13:13:09.306 1893 INFO nova.compute.manager [-] Lifecycle event 0 on VM bc01c570-c40f-4088-a17c-0278fc6c3315
2014-09-10 13:13:09.327 1893 INFO nova.virt.libvirt.driver [-] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Instance spawned successfully.
2014-09-10 13:13:09.441 1893 INFO nova.compute.manager [-] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] During sync_power_state the instance has a pending task (spawning). Skip.
2014-09-10 13:13:23.031 1893 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2014-09-10 13:13:23.202 1893 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 6961
2014-09-10 13:13:23.203 1893 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 8
2014-09-10 13:13:23.204 1893 AUDIT nova.compute.resource_tracker [-] Free VCPUS: 0
2014-09-10 13:13:23.222 1893 INFO nova.compute.resource_tracker [-] Compute_service record updated for Compute:compute
2014-09-10 13:13:44.709 1893 AUDIT nova.compute.manager [req-6c9a4f5f-d9e7-4e12-b5c2-8ee7716fe97a 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Terminating instance
2014-09-10 13:13:45.269 1893 INFO nova.compute.manager [-] Lifecycle event 1 on VM bc01c570-c40f-4088-a17c-0278fc6c3315
2014-09-10 13:13:45.276 1893 INFO nova.virt.libvirt.driver [-] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Instance destroyed successfully.
2014-09-10 13:13:45.391 1893 ERROR nova.virt.driver [-] Exception dispatching event <nova.virt.event.LifecycleEvent object at 0x7fc7e4178490>: Info cache for instance bc01c570-c40f-4088-a17c-0278fc6c3315 could not be found.
Traceback (most recent call last):
File "/usr/lib/python2.7/dist-packages/nova/conductor/manager.py", line 597, in _object_dispatch
return getattr(target, method)(context, *args, **kwargs)
File "/usr/lib/python2.7/dist-packages/nova/objects/base.py", line 151, in wrapper
return fn(self, ctxt, *args, **kwargs)
File "/usr/lib/python2.7/dist-packages/nova/objects/instance.py", line 500, in refresh
self.info_cache.refresh()
File "/usr/lib/python2.7/dist-packages/nova/objects/base.py", line 151, in wrapper
return fn(self, ctxt, *args, **kwargs)
File "/usr/lib/python2.7/dist-packages/nova/objects/instance_info_cache.py", line 103, in refresh
self.instance_uuid)
File "/usr/lib/python2.7/dist-packages/nova/objects/base.py", line 112, in wrapper
result = fn(cls, context, *args, **kwargs)
File "/usr/lib/python2.7/dist-packages/nova/objects/instance_info_cache.py", line 70, in get_by_instance_uuid
instance_uuid=instance_uuid)
InstanceInfoCacheNotFound: Info cache for instance bc01c570-c40f-4088
-a17c-0278fc6c3315 could not be found.
2014-09-10 13:13:45.946 1893 INFO nova.virt.libvirt.driver [req-6c9a4f5f-d9e7-4e12-b5c2-8ee7716fe97a 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Deleting instance files /var/lib/nova/instances/bc01c570-c40f-4088-a17c-0278fc6c3315
2014-09-10 13:13:45.947 1893 INFO nova.virt.libvirt.driver [req-6c9a4f5f-d9e7-4e12-b5c2-8ee7716fe97a 77bdd3f911744f72af7038d40d722439 73a095bf078443c9b340d871deaabcc3] [instance: bc01c570-c40f-4088-a17c-0278fc6c3315] Deletion of /var/lib/nova/instances/bc01c570-c40f-4088-a17c-0278fc6c3315 complete
To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1367845/+subscriptions
Follow ups
References
