We found a bug in the conntrack helper used by live migration with --with-conntrack-state. It stops about 1 % of our live migrations. I could not find it reported, so I am posting the details here.
Environment: PVE 9.2.9, qemu-server 9.2.4 to 9.2.14, pve-qemu-kvm 11.0.3-1, two clusters. The helper script has the same checksum on all those versions, and the same code is in current git.
The cause
In /usr/libexec/qemu-server/dbus-vmstate, Save checks the size before it adds the mark to the line:
The added " --mark <vmid>\n" is not counted. When a VM has more than 1 MiB of conntrack state, the last accepted line can bring the total up to 14 bytes over the limit, and QEMU refuses it.
Source node log
Target node log
Migration task log
The RAM copy finishes, the target QEMU dies, and the VM is left stopped. Reading QEMU's dbus-vmstate.c, it looks like the source writes an element count of 1 but no element, so the target reads an empty Id. We have not traced that step further.
How often
Over two days, 7 of 582 live migrations failed this way. 92 of the 582 hit the size limit, and 7 of those landed in the 14-byte window. Each of the 7 failures matches an over-limit transfer to the second. The sizes were 1048577, 1048579, 1048582, 1048582, 1048586, 1048588 and 1048590.
The error only shows on the source node. On the target it looks like the other "resume failed" bugs, so it may have been reported under those.
Reproduction without a VM
Load the script's package, put a fake conntrack in PATH that prints more than 1 MiB of lines of 140 to 200 bytes, and call Save.
Current code: 9 of 150 runs over the limit, largest 1048589.
With the fix below: 0 of 150, largest 1048576. Small and empty tables gave the expected output on both versions.
Fix
We have applied this line on our nodes. It is too early to report production results.
Also seen
The same script uses /(\d) flow entries/, which keeps only the last digit. The log line "migrated N conntrack state entries" is therefore wrong for 10 entries or more.
Environment: PVE 9.2.9, qemu-server 9.2.4 to 9.2.14, pve-qemu-kvm 11.0.3-1, two clusters. The helper script has the same checksum on all those versions, and the same code is in current git.
The cause
In /usr/libexec/qemu-server/dbus-vmstate, Save checks the size before it adds the mark to the line:
Code:
if ((length($text) + length($line)) > DBUS_VMSTATE_SIZE_LIMIT) {
syslog('warn', 'conntrack state too large, ignoring further entries');
$truncated = 1;
return;
}
...
$text .= "$line --mark $self->{vmid}\n";
The added " --mark <vmid>\n" is not counted. When a VM has more than 1 MiB of conntrack state, the last accepted line can bring the total up to 14 bytes over the limit, and QEMU refuses it.
Source node log
Code:
dbus-vmstate[1625176]: conntrack state too large, ignoring further entries
dbus-vmstate[1625176]: transferring 1048586 bytes of conntrack state
QEMU[240988]: kvm: dbus_save_state_proxy: Too large vmstate data to save: 1048586
Target node log
Code:
QEMU[654635]: kvm: dbus_vmstate_post_load: Failed to find proxy Id ''
QEMU[654635]: kvm: load of migration failed: Operation not permitted: error while loading state for instance 0x0 of device 'dbus-vmstate/dbus-vmstate': post load hook failed for: dbus-vmstate, version_id: 0, minimum_version: 0, ret: -1
Migration task log
Code:
migration status: completed
ERROR: tunnel replied 'ERR: resume failed - VM 14174 qmp command 'query-status' failed - client closed connection' to command 'resume 14174'
ERROR: migration finished with problems (duration 00:00:26)
TASK ERROR: migration problems
The RAM copy finishes, the target QEMU dies, and the VM is left stopped. Reading QEMU's dbus-vmstate.c, it looks like the source writes an element count of 1 but no element, so the target reads an empty Id. We have not traced that step further.
How often
Over two days, 7 of 582 live migrations failed this way. 92 of the 582 hit the size limit, and 7 of those landed in the 14-byte window. Each of the 7 failures matches an over-limit transfer to the second. The sizes were 1048577, 1048579, 1048582, 1048582, 1048586, 1048588 and 1048590.
The error only shows on the source node. On the target it looks like the other "resume failed" bugs, so it may have been reported under those.
Reproduction without a VM
Load the script's package, put a fake conntrack in PATH that prints more than 1 MiB of lines of 140 to 200 bytes, and call Save.
Current code: 9 of 150 runs over the limit, largest 1048589.
With the fix below: 0 of 150, largest 1048576. Small and empty tables gave the expected output on both versions.
Fix
Code:
if ((length($text) + length($line) + length(" --mark $self->{vmid}\n")) > DBUS_VMSTATE_SIZE_LIMIT) {
We have applied this line on our nodes. It is too early to report production results.
Also seen
The same script uses /(\d) flow entries/, which keeps only the last digit. The log line "migrated N conntrack state entries" is therefore wrong for 10 entries or more.