--postcopy-bandwidth is not hornored when recovering postcopy migration

Software environment

  • Operating system:Fedora36
  • Architecture:x86_64
  • kernel version:kernel-5.18.5-200.fc36.x86_64
  • libvirt version:libvirt-8.5.0-1.fc36.x86_64(self-built)
  • Hypervisor and version:qemu-kvm-7.0.0-6.fc37.x86_64

Description of problem

When recovering postcopy migration, --postcopy-bandwidth is not hornored.

Steps to reproduce

  1. Start a guest
  2. Migrate guest to target host
    # virsh migrate vm111 qemu+tcp://xxxxxx/system --live --verbose --p2p --undefinesource --persistent --bandwidth 10 --postcopy-bandwidth 5 --postcopy
  3. After migration switches to postcopy, abort migration
  4. Recover postcopy migration with a new value for --postcopy-bandwidth
    # virsh migrate vm111 qemu+tcp://xxxxxx/system --live --verbose --p2p --undefinesource --persistent --bandwidth 10 --postcopy-bandwidth 20 --postcopy --postcopy-resume
  5. Check domjobinfo, the "Memory bandwidth" is around 5MiB/s

Additional information

  1. I don't see qemu monitor command to set postcopy bandwidth when recovering migration. See the logs as below:
    1-1 Logs on src host:
2022-06-27 03:04:36.364+0000: 56611: info : qemuMonitorSend:887 : QEMU_MONITOR_SEND_MSG: mon=0x7f762c084740 msg={"execute":"query-migrate","id":"libvirt-523"}  
2022-06-27 03:04:36.366+0000: 64608: debug : qemuMonitorJSONIOProcessLine:195 : Line [{"return": {"expected-downtime": 387716, "status": "postcopy-paused", "setup-time": 4, "total-time": 264843, "ram": {"total": 2156732416, "postcopy-requests": 1245, "dirty-sync-count": 2, "multifd-bytes": 0, "pages-per-second": 1280, "downtime-bytes": 0, "page-size": 4096, "remaining": 1790152704, "postcopy-bytes": 160794163, "mbps": 42.026400000000002, "transferred": 260627124, "precopy-bytes": 99832961, "duplicate": 26364, "dirty-pages-rate": 32, "skipped": 0, "normal-bytes": 259878912, "normal": 63447}}, "id": "libvirt-523"}]  
2022-06-27 03:04:36.367+0000: 64608: info : qemuMonitorJSONIOProcessLine:214 : QEMU_MONITOR_RECV_REPLY: mon=0x7f762c084740 reply={"return": {"expected-downtime": 387716, "status": "postcopy-paused", "setup-time": 4, "total-time": 264843, "ram": {"total": 2156732416, "postcopy-requests": 1245, "dirty-sync-count": 2, "multifd-bytes": 0, "pages-per-second": 1280, "downtime-bytes": 0, "page-size": 4096, "remaining": 1790152704, "postcopy-bytes": 160794163, "mbps": 42.026400000000002, "transferred": 260627124, "precopy-bytes": 99832961, "duplicate": 26364, "dirty-pages-rate": 32, "skipped": 0, "normal-bytes": 259878912, "normal": 63447}}, "id": "libvirt-523"}  
2022-06-27 03:04:36.409+0000: 56611: debug : qemuMonitorSendFileHandle:2600 : fdname=migrate fd=30  
2022-06-27 03:04:36.409+0000: 56611: debug : qemuMonitorSendFileHandle:2602 : mon:0x7f762c084740 vm:0x7f762c091c00 fd:28  
2022-06-27 03:04:36.410+0000: 56611: info : qemuMonitorSend:887 : QEMU_MONITOR_SEND_MSG: mon=0x7f762c084740 msg={"execute":"getfd","arguments":{"fdname":"migrate"},"id":"libvirt-524"}
2022-06-27 03:04:36.412+0000: 64608: debug : qemuMonitorJSONIOProcessLine:195 : Line [{"return": {}, "id": "libvirt-524"}]
2022-06-27 03:04:36.412+0000: 64608: info : qemuMonitorJSONIOProcessLine:214 : QEMU_MONITOR_RECV_REPLY: mon=0x7f762c084740 reply={"return": {}, "id": "libvirt-524"}
2022-06-27 03:04:36.413+0000: 56611: info : qemuMonitorSend:887 : QEMU_MONITOR_SEND_MSG: mon=0x7f762c084740 msg={"execute":"migrate","arguments":{"detach":true,"blk":false,"inc":false,"resume":true,"uri":"fd:migrate"},"id":"libvirt-525"}
2022-06-27 03:04:36.416+0000: 64608: debug : qemuMonitorJSONIOProcessLine:195 : Line [{"timestamp": {"seconds": 1656299076, "microseconds": 416491}, "event": "MIGRATION", "data": {"status": "postcopy-recover"}}]
2022-06-27 03:04:36.416+0000: 64608: info : qemuMonitorJSONIOProcessLine:209 : QEMU_MONITOR_RECV_EVENT: mon=0x7f762c084740 event={"timestamp": {"seconds": 1656299076, "microseconds": 416491}, "event": "MIGRATION", "data": {"status": "postcopy-recover"}}
2022-06-27 03:04:36.416+0000: 64608: debug : qemuMonitorJSONIOProcessEvent:158 : mon=0x7f762c084740 obj=0x7f762c3136c0
2022-06-27 03:04:36.417+0000: 64608: debug : qemuMonitorJSONIOProcessEvent:181 : handle MIGRATION handler=0x7f7670d34560 data=0x7f762c09bb00
2022-06-27 03:04:36.419+0000: 64608: debug : qemuMonitorJSONIOProcessLine:195 : Line [{"return": {}, "id": "libvirt-525"}]
2022-06-27 03:04:36.419+0000: 64608: info : qemuMonitorJSONIOProcessLine:214 : QEMU_MONITOR_RECV_REPLY: mon=0x7f762c084740 reply={"return": {}, "id": "libvirt-525"}
2022-06-27 03:04:36.420+0000: 64608: debug : qemuMonitorJSONIOProcessLine:195 : Line [{"timestamp": {"seconds": 1656299076, "microseconds": 418689}, "event": "MIGRATION", "data": {"status": "postcopy-active"}}]
2022-06-27 03:04:36.421+0000: 64608: info : qemuMonitorJSONIOProcessLine:209 : QEMU_MONITOR_RECV_EVENT: mon=0x7f762c084740 event={"timestamp": {"seconds": 1656299076, "microseconds": 418689}, "event": "MIGRATION", "data": {"status": "postcopy-active"}}
2022-06-27 03:04:36.421+0000: 64608: debug : qemuMonitorJSONIOProcessEvent:158 : mon=0x7f762c084740 obj=0x7f762c0963e0
2022-06-27 03:04:36.421+0000: 64608: debug : qemuMonitorJSONIOProcessEvent:181 : handle MIGRATION handler=0x7f7670d34560 data=0x7f762c33ef60
2022-06-27 03:04:36.840+0000: 56610: info : qemuMonitorSend:887 : QEMU_MONITOR_SEND_MSG: mon=0x7f762c084740 msg={"execute":"query-migrate","id":"libvirt-526"}
2022-06-27 03:04:36.842+0000: 64608: debug : qemuMonitorJSONIOProcessLine:195 : Line [{"return": {"expected-downtime": 387716, "status": "postcopy-active", "setup-time": 4, "total-time": 265319, "ram": {"total": 2156732416, "postcopy-requests": 1281, "dirty-sync-count": 2, "multifd-bytes": 0, "pages-per-second": 1280, "downtime-bytes": 0, "page-size": 4096, "remaining": 1787269120, "postcopy-bytes": 163421466, "mbps": 42.026400000000002, "transferred": 263254427, "precopy-bytes": 99832961, "duplicate": 26428, "dirty-pages-rate": 32, "skipped": 0, "normal-bytes": 262500352, "normal": 64087}}, "id": "libvirt-526"}]
2022-06-27 03:04:36.843+0000: 64608: info : qemuMonitorJSONIOProcessLine:214 : QEMU_MONITOR_RECV_REPLY: mon=0x7f762c084740 reply={"return": {"expected-downtime": 387716, "status": "postcopy-active", "setup-time": 4, "total-time": 265319, "ram": {"total": 2156732416, "postcopy-requests": 1281, "dirty-sync-count": 2, "multifd-bytes": 0, "pages-per-second": 1280, "downtime-bytes": 0, "page-size": 4096, "remaining": 1787269120, "postcopy-bytes": 163421466, "mbps": 42.026400000000002, "transferred": 263254427, "precopy-bytes": 99832961, "duplicate": 26428, "dirty-pages-rate": 32, "skipped": 0, "normal-bytes": 262500352, "normal": 64087}}, "id": "libvirt-526"}

1-2 Logs on target host

2022-06-27 03:03:24.932+0000: 39229: info : qemuMonitorSend:887 : QEMU_MONITOR_SEND_MSG: mon=0x7f9bac084460 msg={"execute":"migrate-recover","arguments":{"uri":"tcp:[::]:49154"},"id":"libvirt-415"}
^C
[root@dell-per740-03 ~]# tail -f /var/log/libvirt/virtqemud.log |grep -E "qemuMonitorSend|qemuMonitorJSONIO"
2022-06-27 03:04:36.396+0000: 39226: info : qemuMonitorSend:887 : QEMU_MONITOR_SEND_MSG: mon=0x7f9bac084460 msg={"execute":"query-migrate","id":"libvirt-416"}
2022-06-27 03:04:36.398+0000: 39374: debug : qemuMonitorJSONIOProcessLine:195 : Line [{"return": {"status": "postcopy-paused", "socket-address": [{"port": "49154", "ipv6": true, "host": "::", "type": "inet"}, {"port": "49153", "ipv6": true, "host": "::", "type": "inet"}, {"port": "49152", "ipv6": true, "host": "::", "type": "inet"}]}, "id": "libvirt-416"}]
2022-06-27 03:04:36.399+0000: 39374: info : qemuMonitorJSONIOProcessLine:214 : QEMU_MONITOR_RECV_REPLY: mon=0x7f9bac084460 reply={"return": {"status": "postcopy-paused", "socket-address": [{"port": "49154", "ipv6": true, "host": "::", "type": "inet"}, {"port": "49153", "ipv6": true, "host": "::", "type": "inet"}, {"port": "49152", "ipv6": true, "host": "::", "type": "inet"}]}, "id": "libvirt-416"}
2022-06-27 03:04:36.400+0000: 39226: info : qemuMonitorSend:887 : QEMU_MONITOR_SEND_MSG: mon=0x7f9bac084460 msg={"execute":"migrate-recover","arguments":{"uri":"tcp:[::]:49155"},"id":"libvirt-417"}
2022-06-27 03:04:36.402+0000: 39374: debug : qemuMonitorJSONIOProcessLine:195 : Line [{"timestamp": {"seconds": 1656299076, "microseconds": 402720}, "event": "MIGRATION", "data": {"status": "setup"}}]
2022-06-27 03:04:36.403+0000: 39374: info : qemuMonitorJSONIOProcessLine:209 : QEMU_MONITOR_RECV_EVENT: mon=0x7f9bac084460 event={"timestamp": {"seconds": 1656299076, "microseconds": 402720}, "event": "MIGRATION", "data": {"status": "setup"}}
2022-06-27 03:04:36.403+0000: 39374: debug : qemuMonitorJSONIOProcessEvent:158 : mon=0x7f9bac084460 obj=0x7f9bac2e7080
2022-06-27 03:04:36.403+0000: 39374: debug : qemuMonitorJSONIOProcessEvent:181 : handle MIGRATION handler=0x7f9bedd34560 data=0x7f9bac2fca60
2022-06-27 03:04:36.403+0000: 39374: debug : qemuMonitorJSONIOProcessLine:195 : Line [{"return": {}, "id": "libvirt-417"}]
2022-06-27 03:04:36.404+0000: 39374: info : qemuMonitorJSONIOProcessLine:214 : QEMU_MONITOR_RECV_REPLY: mon=0x7f9bac084460 reply={"return": {}, "id": "libvirt-417"}
2022-06-27 03:04:36.408+0000: 39374: debug : qemuMonitorJSONIOProcessLine:195 : Line [{"timestamp": {"seconds": 1656299076, "microseconds": 408264}, "event": "MIGRATION", "data": {"status": "postcopy-recover"}}]
2022-06-27 03:04:36.408+0000: 39374: info : qemuMonitorJSONIOProcessLine:209 : QEMU_MONITOR_RECV_EVENT: mon=0x7f9bac084460 event={"timestamp": {"seconds": 1656299076, "microseconds": 408264}, "event": "MIGRATION", "data": {"status": "postcopy-recover"}}
2022-06-27 03:04:36.408+0000: 39374: debug : qemuMonitorJSONIOProcessEvent:158 : mon=0x7f9bac084460 obj=0x7f9bac2ee6f0
2022-06-27 03:04:36.408+0000: 39374: debug : qemuMonitorJSONIOProcessEvent:181 : handle MIGRATION handler=0x7f9bedd34560 data=0x7f9bac2ed200
2022-06-27 03:04:36.418+0000: 39374: debug : qemuMonitorJSONIOProcessLine:195 : Line [{"timestamp": {"seconds": 1656299076, "microseconds": 418356}, "event": "MIGRATION", "data": {"status": "postcopy-active"}}]
2022-06-27 03:04:36.418+0000: 39374: info : qemuMonitorJSONIOProcessLine:209 : QEMU_MONITOR_RECV_EVENT: mon=0x7f9bac084460 event={"timestamp": {"seconds": 1656299076, "microseconds": 418356}, "event": "MIGRATION", "data": {"status": "postcopy-active"}}
Edited by Fangge Jin