yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1718295] Re: Live migration fails with qemu-img >= 2.10: "Failed to get shared "write" lock\nIs another process using the image?"

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: OpenStack Infra <1718295@xxxxxxxxxxxxxxxxxx>
Date: Mon, 02 Oct 2017 09:18:33 -0000
Reply-to: Bug 1718295 <1718295@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Reviewed:  https://review.openstack.org/505673
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=807579755c4a116309eca5b2bcdbab9d1f393bab
Submitter: Zuul
Branch:    master

commit 807579755c4a116309eca5b2bcdbab9d1f393bab
Author: Matt Riedemann <mriedem.os@xxxxxxxxx>
Date:   Wed Sep 20 10:44:11 2017 -0400

    Support qemu >= 2.10
    
    Qemu 2.10 added the requirement of a --force-share flag to qemu-img
    info when reading information about a disk that is in use by a
    guest. We do this a lot in Nova for operations like gathering
    information before live migration.
    
    Up until this point all qemu/libvirt version matching has been solely
    inside the libvirt driver, however all the image manip code was moved
    out to nova.virt.images. We need the version of QEMU available there.
    
    This does it by initializing that version on driver init host. The net
    effect is also that broken libvirt connections are figured out
    earlier, as there is an active probe for this value.
    
    Co-Authored-By: Sean Dague <sean@xxxxxxxxx>
    
    Change-Id: Iae2962bb86100f03fd3ad9aac3767da876291e74
    Closes-Bug: #1718295


** Changed in: nova
       Status: In Progress => Fix Released

-- 
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/1718295

Title:
  Live migration fails with qemu-img >= 2.10: "Failed to get shared
  "write" lock\nIs another process using the image?"

Status in devstack:
  Fix Released
Status in OpenStack Compute (nova):
  Fix Released
Status in qemu package in Ubuntu:
  Won't Fix

Bug description:
  Looks like this is pretty new:

  http://logs.openstack.org/01/503601/7/check/gate-tempest-dsvm-
  multinode-live-migration-ubuntu-
  xenial/b19b77c/logs/screen-n-api.txt.gz?level=TRACE#_Sep_19_17_47_11_508623

  Sep 19 17:47:11.508623 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]: ERROR nova.api.openstack.extensions [None req-e31fde7b-317f-4db9-b225-10b6e11b2dff tempest-LiveMigrationTest-1678596498 tempest-LiveMigrationTest-1678596498] Unexpected exception in API method: MigrationError_Remote: Migration error: Disk info file is invalid: qemu-img failed to execute on /opt/stack/data/nova/instances/806812af-bf9e-4dc1-8e0c-11603ccd9f62/disk : Unexpected error while running command.
  Sep 19 17:47:11.508805 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]: Command: /usr/bin/python2 -m oslo_concurrency.prlimit --as=1073741824 --cpu=30 -- env LC_ALL=C LANG=C qemu-img info /opt/stack/data/nova/instances/806812af-bf9e-4dc1-8e0c-11603ccd9f62/disk
  Sep 19 17:47:11.508946 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]: Exit code: 1
  Sep 19 17:47:11.509079 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]: Stdout: u''
  Sep 19 17:47:11.509233 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]: Stderr: u'qemu-img: Could not open \'/opt/stack/data/nova/instances/806812af-bf9e-4dc1-8e0c-11603ccd9f62/disk\': Failed to get shared "write" lock\nIs another process using the image?\n'
  Sep 19 17:47:11.509487 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]: Traceback (most recent call last):
  Sep 19 17:47:11.509649 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/server.py", line 160, in _process_incoming
  Sep 19 17:47:11.509789 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:     res = self.dispatcher.dispatch(message)
  Sep 19 17:47:11.510231 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 222, in dispatch
  Sep 19 17:47:11.510418 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:     return self._do_dispatch(endpoint, method, ctxt, args)
  Sep 19 17:47:11.510555 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 192, in _do_dispatch
  Sep 19 17:47:11.510687 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:     result = func(ctxt, **new_args)
  Sep 19 17:47:11.510829 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:   File "/opt/stack/new/nova/nova/exception_wrapper.py", line 76, in wrapped
  Sep 19 17:47:11.510959 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:     function_name, call_dict, binary)
  Sep 19 17:47:11.511194 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
  Sep 19 17:47:11.511713 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:     self.force_reraise()
  Sep 19 17:47:11.511852 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
  Sep 19 17:47:11.512037 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:     six.reraise(self.type_, self.value, self.tb)
  Sep 19 17:47:11.512687 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:   File "/opt/stack/new/nova/nova/exception_wrapper.py", line 67, in wrapped
  Sep 19 17:47:11.516811 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:     return f(self, context, *args, **kw)
  Sep 19 17:47:11.516966 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:   File "/opt/stack/new/nova/nova/compute/utils.py", line 876, in decorated_function
  Sep 19 17:47:11.517110 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:     return function(self, context, *args, **kwargs)
  Sep 19 17:47:11.525392 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:   File "/opt/stack/new/nova/nova/compute/manager.py", line 217, in decorated_function
  Sep 19 17:47:11.525526 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:     kwargs['instance'], e, sys.exc_info())
  Sep 19 17:47:11.525654 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
  Sep 19 17:47:11.525783 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:     self.force_reraise()
  Sep 19 17:47:11.525909 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
  Sep 19 17:47:11.526057 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:     six.reraise(self.type_, self.value, self.tb)
  Sep 19 17:47:11.526186 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:   File "/opt/stack/new/nova/nova/compute/manager.py", line 205, in decorated_function
  Sep 19 17:47:11.526314 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:     return function(self, context, *args, **kwargs)
  Sep 19 17:47:11.529795 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:   File "/opt/stack/new/nova/nova/compute/manager.py", line 5378, in check_can_live_migrate_source
  Sep 19 17:47:11.529952 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:     block_device_info)
  Sep 19 17:47:11.530083 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 5960, in check_can_live_migrate_source
  Sep 19 17:47:11.530446 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:     block_device_info)
  Sep 19 17:47:11.530587 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 6060, in _assert_dest_node_has_enough_disk
  Sep 19 17:47:11.530720 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:     disk_infos = self._get_instance_disk_info(instance, block_device_info)
  Sep 19 17:47:11.531945 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 7254, in _get_instance_disk_info
  Sep 19 17:47:11.532099 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:     block_device_info)
  Sep 19 17:47:11.532234 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 7222, in _get_instance_disk_info_from_config
  Sep 19 17:47:11.532366 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:     backing_file = libvirt_utils.get_disk_backing_file(path)
  Sep 19 17:47:11.532496 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:   File "/opt/stack/new/nova/nova/virt/libvirt/utils.py", line 197, in get_disk_backing_file
  Sep 19 17:47:11.532627 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:     backing_file = images.qemu_img_info(path, format).backing_file
  Sep 19 17:47:11.532755 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:   File "/opt/stack/new/nova/nova/virt/images.py", line 72, in qemu_img_info
  Sep 19 17:47:11.532896 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]:     raise exception.InvalidDiskInfo(reason=msg)
  Sep 19 17:47:11.533373 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]: InvalidDiskInfo: Disk info file is invalid: qemu-img failed to execute on /opt/stack/data/nova/instances/806812af-bf9e-4dc1-8e0c-11603ccd9f62/disk : Unexpected error while running command.
  Sep 19 17:47:11.534451 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]: Command: /usr/bin/python2 -m oslo_concurrency.prlimit --as=1073741824 --cpu=30 -- env LC_ALL=C LANG=C qemu-img info /opt/stack/data/nova/instances/806812af-bf9e-4dc1-8e0c-11603ccd9f62/disk
  Sep 19 17:47:11.534670 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]: Exit code: 1
  Sep 19 17:47:11.534902 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]: Stdout: u''
  Sep 19 17:47:11.541303 ubuntu-xenial-2-node-rax-ord-10997038 devstack@n-api.service[28339]: Stderr: u'qemu-img: Could not open \'/opt/stack/data/nova/instances/806812af-bf9e-4dc1-8e0c-11603ccd9f62/disk\': Failed to get shared "write" lock\nIs another process using the image?\n'

  http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22Unexpected%20exception%20in%20API%20method%3A%20MigrationError_Remote%3A%20Migration%20error%3A%20Disk%20info%20file%20is%20invalid%3A
  %20qemu-
  img%20failed%20to%20execute%20on%5C%22%20AND%20tags%3A%5C%22screen-n-api.txt%5C%22&from=7d

  252 hits starting on 9/19, check and gate, all failures.

To manage notifications about this bug go to:
https://bugs.launchpad.net/devstack/+bug/1718295/+subscriptions
References

[Bug 1718295] [NEW] Unexpected exception in API method: MigrationError_Remote: Migration error: Disk info file is invalid: qemu-img failed to execute - Failed to get shared "write" lock\nIs another process using the image?
From: Matt Riedemann, 2017-09-19