yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1840159] [NEW] nova-grenade-live-migration intermittently fails with "Error monitoring migration: Timed out during operation: cannot acquire state change lock (held by remoteDispatchDomainMigratePerform3Params)"

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Matt Riedemann <mriedem.os@xxxxxxxxx>
Date: Wed, 14 Aug 2019 15:21:59 -0000
Reply-to: Bug 1840159 <1840159@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

Seen here:

https://logs.opendev.org/21/655721/14/check/nova-grenade-live-
migration/2ee634d/logs/subnode-2/screen-n-cpu.txt.gz?level=TRACE#_Aug_13_10_03_49_974378

Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: WARNING nova.virt.libvirt.driver [-] [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6] Error monitoring migration: Timed out during operation: cannot acquire state change lock (held by remoteDispatchDomainMigratePerform3Params): libvirtError: Timed out during operation: cannot acquire state change lock (held by remoteDispatchDomainMigratePerform3Params)
Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6] Traceback (most recent call last):
Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]   File "/opt/stack/old/nova/nova/virt/libvirt/driver.py", line 8052, in _live_migration
Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]     finish_event, disk_paths)
Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]   File "/opt/stack/old/nova/nova/virt/libvirt/driver.py", line 7857, in _live_migration_monitor
Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]     info = guest.get_job_info()
Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]   File "/opt/stack/old/nova/nova/virt/libvirt/guest.py", line 709, in get_job_info
Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]     stats = self._domain.jobStats()
Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]   File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 190, in doit
Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]     result = proxy_call(self._autowrap, f, *args, **kwargs)
Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]   File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 148, in proxy_call
Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]     rv = execute(f, *args, **kwargs)
Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]   File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 129, in execute
Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]     six.reraise(c, e, tb)
Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]   File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 83, in tworker
Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]     rv = meth(*args, **kwargs)
Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]   File "/usr/local/lib/python2.7/dist-packages/libvirt.py", line 1403, in jobStats
Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]     if ret is None: raise libvirtError ('virDomainGetJobStats() failed', dom=self)
Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6] libvirtError: Timed out during operation: cannot acquire state change lock (held by remoteDispatchDomainMigratePerform3Params)
Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6] 
Aug 13 10:03:49.977652 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.compute.manager [-] [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6] Live migration failed.: libvirtError: Timed out during operation: cannot acquire state change lock (held by remoteDispatchDomainMigratePerform3Params)

I thought we had another bug for this but I couldn't find one. This
doesn't show up often, only 1 hit in 10 days:

http://logstash.openstack.org/#/dashboard/file/logstash.json?query=message:%5C%22Error%20monitoring%20migration:%20Timed%20out%20during%20operation:%20cannot%20acquire%20state%20change%20lock%20(held%20by%20remoteDispatchDomainMigratePerform3Params)%5C%22%20AND%20tags:%5C%22screen-n-cpu.txt%5C%22&from=10d

** Affects: nova
     Importance: Undecided
         Status: New


** Tags: gate-failure libvirt live-migration

** Tags added: gate-failure libvirt live-migration

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

Title:
  nova-grenade-live-migration intermittently fails with "Error
  monitoring migration: Timed out during operation: cannot acquire state
  change lock (held by remoteDispatchDomainMigratePerform3Params)"

Status in OpenStack Compute (nova):
  New

Bug description:
  Seen here:

  https://logs.opendev.org/21/655721/14/check/nova-grenade-live-
  migration/2ee634d/logs/subnode-2/screen-n-cpu.txt.gz?level=TRACE#_Aug_13_10_03_49_974378

  Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: WARNING nova.virt.libvirt.driver [-] [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6] Error monitoring migration: Timed out during operation: cannot acquire state change lock (held by remoteDispatchDomainMigratePerform3Params): libvirtError: Timed out during operation: cannot acquire state change lock (held by remoteDispatchDomainMigratePerform3Params)
  Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6] Traceback (most recent call last):
  Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]   File "/opt/stack/old/nova/nova/virt/libvirt/driver.py", line 8052, in _live_migration
  Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]     finish_event, disk_paths)
  Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]   File "/opt/stack/old/nova/nova/virt/libvirt/driver.py", line 7857, in _live_migration_monitor
  Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]     info = guest.get_job_info()
  Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]   File "/opt/stack/old/nova/nova/virt/libvirt/guest.py", line 709, in get_job_info
  Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]     stats = self._domain.jobStats()
  Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]   File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 190, in doit
  Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]     result = proxy_call(self._autowrap, f, *args, **kwargs)
  Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]   File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 148, in proxy_call
  Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]     rv = execute(f, *args, **kwargs)
  Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]   File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 129, in execute
  Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]     six.reraise(c, e, tb)
  Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]   File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 83, in tworker
  Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]     rv = meth(*args, **kwargs)
  Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]   File "/usr/local/lib/python2.7/dist-packages/libvirt.py", line 1403, in jobStats
  Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6]     if ret is None: raise libvirtError ('virDomainGetJobStats() failed', dom=self)
  Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6] libvirtError: Timed out during operation: cannot acquire state change lock (held by remoteDispatchDomainMigratePerform3Params)
  Aug 13 10:03:49.974378 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.virt.libvirt.driver [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6] 
  Aug 13 10:03:49.977652 ubuntu-bionic-limestone-regionone-0010083920 nova-compute[25863]: ERROR nova.compute.manager [-] [instance: a1637e8b-6f2d-4127-9799-31cefb3f43a6] Live migration failed.: libvirtError: Timed out during operation: cannot acquire state change lock (held by remoteDispatchDomainMigratePerform3Params)

  I thought we had another bug for this but I couldn't find one. This
  doesn't show up often, only 1 hit in 10 days:

  http://logstash.openstack.org/#/dashboard/file/logstash.json?query=message:%5C%22Error%20monitoring%20migration:%20Timed%20out%20during%20operation:%20cannot%20acquire%20state%20change%20lock%20(held%20by%20remoteDispatchDomainMigratePerform3Params)%5C%22%20AND%20tags:%5C%22screen-n-cpu.txt%5C%22&from=10d

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1840159/+subscriptions
Follow ups

[Bug 1840159] Re: nova-grenade-(live-migration|multinode) intermittently fails with "Error monitoring migration: Timed out during operation: cannot acquire state change lock (held by remoteDispatchDomainMigratePerform3Params)"
From: Launchpad Bug Tracker, 2021-08-10