I got the following errors in a tempest test at http://logs.openstack.org/97/62397/1/check/check-tempest-dsvm-full/3f7b8c3:
2013-12-16 16:07:52.189 27621 DEBUG nova.openstack.common.processutils [-] Result was 1 execute /opt/stack/new/nova/nova/openstack/common/processutils.py:172
2013-12-16 16:07:52.189 27621 ERROR nova.openstack.common.periodic_task [-] Error during ComputeManager._run_image_cache_manager_pass: Unexpected error while running command.
Command: env LC_ALL=C LANG=C qemu-img info /opt/stack/data/nova/instances/95dbf14f-3abb-42c7-94c5-dd7355ecd78a/disk
Exit code: 1
Stdout: ''
Stderr: "qemu-img: Could not open '/opt/stack/data/nova/instances/95dbf14f-3abb-42c7-94c5-dd7355ecd78a/disk': No such file or directory\n"
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task Traceback (most recent call last):
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task File "/opt/stack/new/nova/nova/openstack/common/periodic_task.py", line 180, in run_periodic_tasks
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task task(self, context)
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task File "/opt/stack/new/nova/nova/compute/manager.py", line 5210, in _run_image_cache_manager_pass
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task self.driver.manage_image_cache(context, filtered_instances)
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 4650, in manage_image_cache
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task self.image_cache_manager.verify_base_images(context, all_instances)
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task File "/opt/stack/new/nova/nova/virt/libvirt/imagecache.py", line 603, in verify_base_images
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task inuse_backing_images = self._list_backing_images()
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task File "/opt/stack/new/nova/nova/virt/libvirt/imagecache.py", line 345, in _list_backing_images
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task backing_file = virtutils.get_disk_backing_file(disk_path)
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task File "/opt/stack/new/nova/nova/virt/libvirt/utils.py", line 442, in get_disk_backing_file
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task backing_file = images.qemu_img_info(path).backing_file
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task File "/opt/stack/new/nova/nova/virt/images.py", line 56, in qemu_img_info
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task 'qemu-img', 'info', path)
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task File "/opt/stack/new/nova/nova/utils.py", line 175, in execute
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task return processutils.execute(*cmd, **kwargs)
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task File "/opt/stack/new/nova/nova/openstack/common/processutils.py", line 178, in execute
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task cmd=' '.join(cmd))
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task ProcessExecutionError: Unexpected error while running command.
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task Command: env LC_ALL=C LANG=C qemu-img info /opt/stack/data/nova/instances/95dbf14f-3abb-42c7-94c5-dd7355ecd78a/disk
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task Exit code: 1
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task Stdout: ''
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task Stderr: "qemu-img: Could not open '/opt/stack/data/nova/instances/95dbf14f-3abb-42c7-94c5-dd7355ecd78a/disk': No such file or directory\n"
2013-12-16 16:07:52.189 27621 TRACE nova.openstack.common.periodic_task
from the log screen-n-cpu.txt
2013-12-16 16:07:52.132</a> 27621 DEBUG nova.openstack. common. processutils [-] Running cmd (subprocess): env LC_ALL=C LANG=C qemu-img info /opt/stack/ data/nova/ instances/ 95dbf14f- 3abb-42c7- 94c5-dd7355ecd7 8a/disk execute /opt/stack/ new/nova/ nova/openstack/ common/ processutils. py:147 181[instance: 95dbf14f- 3abb-42c7- 94c5-dd7355ecd7 8a] Deleting instance files /opt/stack/ data/nova/ instances/ 95dbf14f- 3abb-42c7- 94c5-dd7355ecd7 8a 3abb-42c7- 94c5-dd7355ecd7 8a] Deletion of /opt/stack/ data/nova/ instances/ 95dbf14f- 3abb-42c7- 94c5-dd7355ecd7 8a complete 16_16_07_ 52_189' ><a name='_ 2013-12- 16_16_07_ 52_189' class='date' href='# _2013-12- 16_16_07_ 52_189' >2013-12- 16 16:07:52.189</a> 27621 DEBUG nova.openstack. common. processutils [-] Result was 1 execute /opt/stack/ new/nova/ nova/openstack/ common/ processutils. py:172
2013-12-16 16:07:52.
2013-12-16 16:07:52.185 [instance: 95dbf14f-
</span><span class='DEBUG _2013-12-
this is a very rare case that the instance 95dbf14f- 3abb-42c7- 94c5-dd7355ecd7 8a was deleted between check disk file and get qemu info from it , at 16:07:52.132, t's still there (because the file exist check logic before), but at 16:07:52.181, it was deleted
then the process switch back to original one , it find the file was gone and return a error
the solution with lock might be a candidate, but catch the exception and ignore it is much more simple