yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1718295] Re: 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?

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Sean Dague <sean@xxxxxxxxx>
Date: Wed, 20 Sep 2017 12:56:18 -0000
Reply-to: Bug 1718295 <1718295@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
This appears like it might be an issue with the ppa in pike

** Also affects: qemu
   Importance: Undecided
       Status: New

** Project changed: qemu => ubuntu

** Package changed: ubuntu => qemu (Ubuntu)

-- 
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:
  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?

Status in devstack:
  Fix Released
Status in OpenStack Compute (nova):
  Invalid
Status in qemu package in Ubuntu:
  New

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