image not found warning in logs when instance is deleted during snapshot

[Matt Riedemann]

Related to bug 1722571 (and bug 1737024), when an instance is deleted while nova is creating an image of it, there is some cleanup code in the compute manager that tries to delete the image, which might not exist, and we log a warning:

http://logs.openstack.org/74/511074/6/check/tempest-full/39df584/controller/logs/screen-n-cpu.txt#_Mar_06_23_34_23_166597

Mar 06 23:34:23.058201 ubuntu-xenial-rax-dfw-0002817722 nova-compute[12626]: INFO nova.virt.libvirt.driver [None req-fcf19cc8-3566-4f62-9d8a-6e9733fd0bef tempest-ImagesTestJSON-1528672258 tempest-ImagesTestJSON-1528672258] [instance: 5946fa5a-f91f-4878-8cc1-fc6e248ef38b] Deletion of /opt/stack/data/nova/instances/5946fa5a-f91f-4878-8cc1-fc6e248ef38b_del complete
Mar 06 23:34:23.116179 ubuntu-xenial-rax-dfw-0002817722 nova-compute[12626]: INFO nova.virt.libvirt.driver [None req-fcf19cc8-3566-4f62-9d8a-6e9733fd0bef tempest-ImagesTestJSON-1528672258 tempest-ImagesTestJSON-1528672258] [instance: 5946fa5a-f91f-4878-8cc1-fc6e248ef38b] Instance instance-00000022 disappeared while taking snapshot of it: [Error Code 42] Domain not found: no domain with matching uuid '5946fa5a-f91f-4878-8cc1-fc6e248ef38b' (instance-00000022)
Mar 06 23:34:23.116411 ubuntu-xenial-rax-dfw-0002817722 nova-compute[12626]: DEBUG nova.compute.manager [None req-fcf19cc8-3566-4f62-9d8a-6e9733fd0bef tempest-ImagesTestJSON-1528672258 tempest-ImagesTestJSON-1528672258] [instance: 5946fa5a-f91f-4878-8cc1-fc6e248ef38b] Instance disappeared during snapshot {{(pid=12626) _snapshot_instance /opt/stack/nova/nova/compute/manager.py:3372}}
Mar 06 23:34:23.166597 ubuntu-xenial-rax-dfw-0002817722 nova-compute[12626]: WARNING nova.compute.manager [None req-fcf19cc8-3566-4f62-9d8a-6e9733fd0bef tempest-ImagesTestJSON-1528672258 tempest-ImagesTestJSON-1528672258] [instance: 5946fa5a-f91f-4878-8cc1-fc6e248ef38b] Error while trying to clean up image 263b517a-3fc0-4486-a292-9cf8a4865282: ImageNotFound: Image 263b517a-3fc0-4486-a292-9cf8a4865282 could not be found.

That warning comes from this code:

https://github.com/openstack/nova/blob/489a8f5bf3e50944ced253283c15e77310a56e40/nova/compute/manager.py#L3378

We should be able to handle an ImageNotFound exception specifically in that try/except block and not log a warning for it.

[jichenjc (jichenjc)]

I actually saw this in our z/VM CI time to time and it leads to some confusion to me

in our case, this kind of race condition might lead to some potential image captured in driver layer to be orphaned

steps:
1) capture the instance
2) during same time, start to delete
3) capture still in progress but instance disappeared
4) snapshot function will report instance not found issue
5) might lead some dirty data in compute node (the image snapshotted)

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/567522

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/567522
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=1c56ef6b5db25b78e515fbe6a12a8dedefbd6941
Submitter: Zuul
Branch: master

commit 1c56ef6b5db25b78e515fbe6a12a8dedefbd6941
Author: jichen <email address hidden>
Date: Thu May 10 16:53:51 2018 +0800

    Avoid warning log when image not exist

    when doing snapshot nova try to get image info and
    normal case is image doesn't exist but nova shows
    a warning log ,this patch change the mechanism to
    only log unexpected exception as warning.

    Change-Id: I49618a6dafbe00b9516ff37172b6aea68a42deba
    Closes-Bug: 1754071

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/nova 18.0.0.0b2 development milestone.