[Bug 1994002] Re: [SRU] migration was active, but no RAM info was set

Thu Mar 30 20:51:59 UTC 2023

Verification done for bionic-proposed.

bionic-updates: FAIL (status: active)

	(qemu) info migrate
	info migrate
	globals: store-global-state=1, only_migratable=0, send-configuration=1, send-section-footer=1
	capabilities: xbzrle: off rdma-pin-all: off auto-converge: off zero-blocks: off compress: off events: off postcopy-ram: off x-colo: off release-ram: off block: off return-path: off pause-before-switchover: off x-multifd: off
	Migration status: active
	total time: 0 milliseconds

bionic-proposed: PASS (status: setup)

	(qemu) info migrate
	info migrate
	globals: store-global-state=1, only_migratable=0, send-configuration=1, send-section-footer=1
	capabilities: xbzrle: off rdma-pin-all: off auto-converge: off zero-blocks: off compress: off events: off postcopy-ram: off x-colo: off release-ram: off block: off return-path: off pause-before-switchover: off x-multifd: off
	Migration status: setup
	total time: 0 milliseconds

Details:
=======

$ lsb_release -cs
bionic

bionic-updates: FAIL
--------------

$ curl http://ddebs.ubuntu.com/dbgsym-release-key.asc | sudo apt-key add -
OK
$ sudo add-apt-repository -y 'deb http://ddebs.ubuntu.com/ubuntu bionic-updates main'

$ sudo apt install --yes qemu-system-x86 qemu-system-x86-dbgsym

$ dpkg -s qemu-system-x86 | grep Version:
Version: 1:2.11+dfsg-1ubuntu7.41

$ dpkg -s qemu-system-x86-dbgsym | grep Version:
Version: 1:2.11+dfsg-1ubuntu7.41

...

$ sudo add-apt-repository -ys 'deb http://archive.ubuntu.com/ubuntu bionic-updates main'
$ apt source qemu
$ head -n1 qemu-*/debian/changelog
qemu (1:2.11+dfsg-1ubuntu7.41) bionic-security; urgency=medium

$ vim qemu-*/migration/migration.c
 594 MigrationInfo *qmp_query_migrate(Error **errp)
 ...
 603     case MIGRATION_STATUS_SETUP:
 604         info->has_status = true;
 605         info->has_total_time = false;
 606         break;
...

T1)

$ qemu-system-x86_64 -nodefaults -nographic -S -incoming tcp:0:4444

T2)

(gdb) b migrate_set_state
Breakpoint 1 at 0x58dd60: file ./migration/migration.c, line 1025.

(gdb) b migration/migration.c:603
Breakpoint 2 at 0x58d670: file ./migration/migration.c, line 603.

# Using 603 vs 606 as the code didn't break on 606 for some reason.

(gdb) run -nodefaults -nographic -S -monitor tcp:0:3333,server,wait=off

T3)

$ nc 127.0.0.1 3333

(qemu) migrate -d tcp:127.0.0.1:4444

T2)

Thread 1 "qemu-system-x86" hit Breakpoint 1, migrate_set_state (state=0x5555566ac6f0, old_state=0, new_state=1) at ./migration/migration.c:1025
1025    ./migration/migration.c: No such file or directory.
(gdb) p (MigrationStatus) 0
$1 = MIGRATION_STATUS_NONE
(gdb) p (MigrationStatus) 1
$2 = MIGRATION_STATUS_SETUP
(gdb) c
Continuing.
[New Thread 0x7fffcf9ff700 (LWP 4909)]
[New Thread 0x7fffcf1fe700 (LWP 4910)]
[Thread 0x7fffcf9ff700 (LWP 4909) exited]

Thread 5 "qemu-system-x86" hit Breakpoint 1, migrate_set_state (state=0x5555566ac6f0, old_state=1, new_state=4) at ./migration/migration.c:1025
1025    in ./migration/migration.c
(gdb) p (MigrationStatus) 1
$3 = MIGRATION_STATUS_SETUP
(gdb) p (MigrationStatus) 4
$4 = MIGRATION_STATUS_ACTIVE

T3)

(qemu) info migrate

T2)

Thread 1 "qemu-system-x86" hit Breakpoint 2, qmp_query_migrate (errp=errp at entry=0x0) at ./migration/migration.c:604
604     in ./migration/migration.c
(gdb) p (MigrationStatus) s.state
value has been optimized out
(gdb) p info.status
$1 = MIGRATION_STATUS_NONE

(gdb) info threads
  Id   Target Id         Frame
* 1    Thread 0x7ffff7fc1cc0 (LWP 4916) "qemu-system-x86" qmp_query_migrate (errp=errp at entry=0x0) at ./migration/migration.c:604
  2    Thread 0x7fffdf7ff700 (LWP 4920) "qemu-system-x86" (running)
  3    Thread 0x7fffdcffe700 (LWP 4921) "qemu-system-x86" (running)
  5    Thread 0x7fffcf9ff700 (LWP 4924) "qemu-system-x86" migrate_set_state (state=0x5555566ac6f0, old_state=1, new_state=4) at ./migration/migration.c:1025

(gdb) thread 5
[Switching to thread 5 (Thread 0x7fffcf9ff700 (LWP 4924))]
#0  migrate_set_state (state=0x5555566ac6f0, old_state=1, new_state=4) at ./migration/migration.c:1025
1025    in ./migration/migration.c
(gdb) continue &
Continuing.

(gdb) info threads
  Id   Target Id         Frame
  1    Thread 0x7ffff7fc1cc0 (LWP 4916) "qemu-system-x86" qmp_query_migrate (errp=errp at entry=0x0) at ./migration/migration.c:604
  2    Thread 0x7fffdf7ff700 (LWP 4920) "qemu-system-x86" (running)
  3    Thread 0x7fffdcffe700 (LWP 4921) "qemu-system-x86" (running)
* 5    Thread 0x7fffcf9ff700 (LWP 4924) "qemu-system-x86" (running)

(gdb) thread 1
[Switching to thread 1 (Thread 0x7ffff7fc1cc0 (LWP 4916))]
#0  qmp_query_migrate (errp=errp at entry=0x0) at ./migration/migration.c:604
604     in ./migration/migration.c
(gdb) p (MigrationStatus) s.state
value has been optimized out
(gdb) c

T3)

(qemu) info migrate
info migrate
globals: store-global-state=1, only_migratable=0, send-configuration=1, send-section-footer=1
capabilities: xbzrle: off rdma-pin-all: off auto-converge: off zero-blocks: off compress: off events: off postcopy-ram: off x-colo: off release-ram: off block: off return-path: off pause-before-switchover: off x-multifd: off
Migration status: active
total time: 0 milliseconds

Migration status is active, without any RAM statistics.

bionic-proposed: PASS
---------------

$ sudo add-apt-repository -ys 'deb http://archive.ubuntu.com/ubuntu bionic-proposed main'
$ sudo add-apt-repository -y 'deb http://ddebs.ubuntu.com/ubuntu bionic-proposed main'

$ sudo apt install --yes qemu-system-x86 qemu-system-x86-dbgsym

$ dpkg -s qemu-system-x86 | grep Version:
Version: 1:2.11+dfsg-1ubuntu7.42

$ dpkg -s qemu-system-x86-dbgsym | grep Version:
Version: 1:2.11+dfsg-1ubuntu7.42

$ rm -rf qemu*
$ apt source qemu

$ head -n1 qemu-*/debian/changelog
qemu (1:2.11+dfsg-1ubuntu7.42) bionic; urgency=medium

$ vim qemu-*/migration/migration.c
 594 MigrationInfo *qmp_query_migrate(Error **errp)
...
 604     case MIGRATION_STATUS_SETUP:
 605         info->has_status = true;
 606         info->has_total_time = false;
 607         break;

T1)

$ qemu-system-x86_64 -nodefaults -nographic -S -incoming tcp:0:4444

T2)

gdb \
  -ex 'set non-stop on' -ex 'set pagination off' -ex 'set confirm off' \
  qemu-system-x86_64

(gdb) b migrate_set_state
Breakpoint 1 at 0x58de30: file ./migration/migration.c, line 1026.

(gdb) b migration/migration.c:604
Breakpoint 2 at 0x58d748: file ./migration/migration.c, line 604.

(gdb) run -nodefaults -nographic -S -monitor tcp:0:3333,server,wait=off

T3)

nc 127.0.0.1 3333

(qemu) migrate -d tcp:127.0.0.1:4444

T2)

Thread 1 "qemu-system-x86" hit Breakpoint 1, migrate_set_state (state=0x5555566ac6f0, old_state=0, new_state=1) at ./migration/migration.c:1026
1026    ./migration/migration.c: No such file or directory.
(gdb) p (MigrationStatus) 0
$1 = MIGRATION_STATUS_NONE
(gdb) p (MigrationStatus) 1
$2 = MIGRATION_STATUS_SETUP
(gdb) c
Continuing.
[New Thread 0x7fffcf9ff700 (LWP 6525)]
[New Thread 0x7fffcf1fe700 (LWP 6526)]
[Thread 0x7fffcf9ff700 (LWP 6525) exited]

Thread 5 "qemu-system-x86" hit Breakpoint 1, migrate_set_state (state=0x5555566ac6f0, old_state=1, new_state=4) at ./migration/migration.c:1026
1026    in ./migration/migration.c
(gdb) p (MigrationStatus) 1
$3 = MIGRATION_STATUS_SETUP
(gdb) p (MigrationStatus) 4
$4 = MIGRATION_STATUS_ACTIVE

T3)

(qemu) info migrate

T2)

Thread 1 "qemu-system-x86" hit Breakpoint 2, qmp_query_migrate (errp=errp at entry=0x0) at ./migration/migration.c:605
605     in ./migration/migration.c
(gdb) p (MigrationStatus) s.state
value has been optimized out
(gdb) p info.status
$5 = MIGRATION_STATUS_NONE

(gdb) info threads
  Id   Target Id         Frame
* 1    Thread 0x7ffff7fc1cc0 (LWP 6518) "qemu-system-x86" qmp_query_migrate (errp=errp at entry=0x0) at ./migration/migration.c:605
  2    Thread 0x7fffdf7ff700 (LWP 6522) "qemu-system-x86" (running)
  3    Thread 0x7fffdcffe700 (LWP 6523) "qemu-system-x86" (running)
  5    Thread 0x7fffcf1fe700 (LWP 6526) "qemu-system-x86" migrate_set_state (state=0x5555566ac6f0, old_state=1, new_state=4) at ./migration/migration.c:1026
(gdb) thread 5
[Switching to thread 5 (Thread 0x7fffcf1fe700 (LWP 6526))]
#0  migrate_set_state (state=0x5555566ac6f0, old_state=1, new_state=4) at ./migration/migration.c:1026
1026    in ./migration/migration.c
(gdb) continue &
Continuing.
(gdb) info threads
  Id   Target Id         Frame
  1    Thread 0x7ffff7fc1cc0 (LWP 6518) "qemu-system-x86" qmp_query_migrate (errp=errp at entry=0x0) at ./migration/migration.c:605
  2    Thread 0x7fffdf7ff700 (LWP 6522) "qemu-system-x86" (running)
  3    Thread 0x7fffdcffe700 (LWP 6523) "qemu-system-x86" (running)
* 5    Thread 0x7fffcf1fe700 (LWP 6526) "qemu-system-x86" (running)

(gdb) thread 1
[Switching to thread 1 (Thread 0x7ffff7fc1cc0 (LWP 6518))]
#0  qmp_query_migrate (errp=errp at entry=0x0) at ./migration/migration.c:605
605     in ./migration/migration.c
(gdb) p (MigrationStatus) s.state
value has been optimized out

(gdb) c

T3)

(qemu) info migrate
info migrate
globals: store-global-state=1, only_migratable=0, send-configuration=1, send-section-footer=1
capabilities: xbzrle: off rdma-pin-all: off auto-converge: off zero-blocks: off compress: off events: off postcopy-ram: off x-colo: off release-ram: off block: off return-path: off pause-before-switchover: off x-multifd: off
Migration status: setup
total time: 0 milliseconds

Status is now still 'SETUP' (which is not expected to have RAM
statistics), not 'ACTIVE' (which is, and caused the issue).

(qemu) quit
(gdb) quit

Terminal 1)

Ctrl-C

** Tags removed: verification-needed verification-needed-bionic
** Tags added: verification-done verification-done-bionic

-- 
You received this bug notification because you are a member of Ubuntu
OpenStack, which is subscribed to Ubuntu Cloud Archive.
https://bugs.launchpad.net/bugs/1994002

Title:
  [SRU] migration was active, but no RAM info was set

Status in Ubuntu Cloud Archive:
  New
Status in Ubuntu Cloud Archive ussuri series:
  New
Status in qemu package in Ubuntu:
  Fix Released
Status in qemu source package in Bionic:
  Fix Committed
Status in qemu source package in Focal:
  Fix Committed
Status in qemu source package in Jammy:
  Fix Committed
Status in qemu source package in Kinetic:
  Fix Released

Bug description:
  [Impact]

   * While live-migrating many instances concurrently, libvirt sometimes
  return `internal error: migration was active, but no RAM info was
  set:`

   * Effects of this bug are mostly observed in large scale clusters
  with a lot of live migration activity.

   * Has second order effects for consumers of migration monitor such as
  libvirt and openstack.

  [Test Case]

  Synthetic reproducer with GDB in comment #21.

  Steps to Reproduce:
  1. live evacuate a compute
  2. live migration of one or more instances fails with the above error

  N.B Due to the nature of this bug it is difficult consistently reproduce.
  In an environment where it has been observed it is estimated to occur approximately 1/1000 migrations.

  [Where problems could occur]
   * In the event of a regression the migration monitor may report an inconsistent state.

  [Original Bug Description]

  While live-migrating many instances concurrently, libvirt sometimes return internal error: migration was active, but no RAM info was set:
  ~~~
  2022-03-30 06:08:37.197 7 WARNING nova.virt.libvirt.driver [req-5c3296cf-88ee-4af6-ae6a-ddba99935e23 - - - - -] [instance: af339c99-1182-4489-b15c-21e52f50f724] Error monitoring migration: internal error: migration was active, but no RAM info was set: libvirt.libvirtError: internal error: migration was active, but no RAM info was set
  ~~~

  From upstream bug: https://bugzilla.redhat.com/show_bug.cgi?id=2074205

  [Other Information]
  Related bug: https://bugs.launchpad.net/nova/+bug/1982284

To manage notifications about this bug go to:
https://bugs.launchpad.net/cloud-archive/+bug/1994002/+subscriptions