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: OpenStack Infra <1718295@xxxxxxxxxxxxxxxxxx>
Date: Wed, 20 Sep 2017 08:37:50 -0000
Reply-to: Bug 1718295 <1718295@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Reviewed:  https://review.openstack.org/505446
Committed: https://git.openstack.org/cgit/openstack-dev/devstack/commit/?id=ee22ca8373abd3b5a4c44a9c5c4da39c511195c8
Submitter: Jenkins
Branch:    master

commit ee22ca8373abd3b5a4c44a9c5c4da39c511195c8
Author: Matt Riedemann <mriedem.os@xxxxxxxxx>
Date:   Wed Sep 20 00:29:36 2017 +0000

    Revert "Update to using pike cloud-archive"
    
    This reverts commit a7e9a5d447b3eeacfb52d7ddc94445058a8d6fd1.
    
    The jobs that run live migration tests are failing at about
    a rate of 50% since this merged. There are no recent changes
    to nova in the last 24 hours that are related to live
    migration, and this is failing on the master branch only,
    so I suspect the failures are due to new qemu packages
    getting pulled in from this change.
    
    Change-Id: Ic8481539c6a0cc7af08a736a625b672979435908
    Closes-Bug: #1718295


** Changed in: devstack
       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:
  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

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