Bug 2111070

Summary: --postcopy-bandwidth is not hornored when recovering postcopy migration
Product: Red Hat Enterprise Linux 9 Reporter: Jiri Denemark <jdenemar>
Component: libvirtAssignee: Jiri Denemark <jdenemar>
libvirt sub component: Live Migration QA Contact: Fangge Jin <fjin>
Status: CLOSED ERRATA Docs Contact:
Severity: unspecified    
Priority: unspecified CC: jdenemar, lmen, virt-maint, xuzhang
Version: 9.1Keywords: AutomationTriaged, Triaged, Upstream
Target Milestone: rc   
Target Release: 9.1   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: libvirt-8.5.0-4.el9 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2022-11-15 10:04:47 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version: 8.6.0
Embargoed:

Description Jiri Denemark 2022-07-26 12:26:40 UTC 
Description of problem:

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

Version-Release number of selected component (if applicable):

libvirt-8.5.0-1.el9

How reproducible:

always

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

Actual results:

"Memory bandwidth" is around 5MiB/s

Expected results:

"Memory bandwidth" should be around 20MiB/s

Additional info:

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"}}
Comment 1 Jiri Denemark 2022-07-26 12:39:13 UTC 
Fixed upstream by

commit 0eae541257cd4f01c9d90db62056ad8d03c5af23
Refs: v8.5.0-3-g0eae541257
Author:     Jiri Denemark <jdenemar>
AuthorDate: Wed Jun 29 12:00:03 2022 +0200
Commit:     Jiri Denemark <jdenemar>
CommitDate: Fri Jul 1 11:28:34 2022 +0200

    qemu: Pass migration flags to qemuMigrationParamsApply

    The flags will later be used to determine which parameters should
    actually be applied.

    Signed-off-by: Jiri Denemark <jdenemar>
    Reviewed-by: Michal Privoznik <mprivozn>

commit 184749691f27f30a39f6f6c77828ffb951af0255
Refs: v8.5.0-4-g184749691f
Author:     Jiri Denemark <jdenemar>
AuthorDate: Wed Jun 29 15:12:20 2022 +0200
Commit:     Jiri Denemark <jdenemar>
CommitDate: Fri Jul 1 11:28:34 2022 +0200

    qemu_migration_params: Replace qemuMigrationParamTypes array

    We will need to annotate individual parameters a bit more than just
    noting their type. Let's introduce qemuMigrationParamInfo replacing
    simple qemuMigrationParamTypes with an array of structs.

    Signed-off-by: Jiri Denemark <jdenemar>
    Reviewed-by: Michal Privoznik <mprivozn>

commit 8c335b5530194dbcef719a4d88c89b8723b831a5
Refs: v8.5.0-5-g8c335b5530
Author:     Jiri Denemark <jdenemar>
AuthorDate: Thu Jun 30 12:51:55 2022 +0200
Commit:     Jiri Denemark <jdenemar>
CommitDate: Fri Jul 1 11:28:34 2022 +0200

    qemu_migration: Pass migParams to qemuMigrationSrcResume

    So the we can apply selected migration parameters even when resuming
    post-copy migration.

    Signed-off-by: Jiri Denemark <jdenemar>
    Reviewed-by: Michal Privoznik <mprivozn>

commit 766abdc291ba606379a7d197bff477fef25fb508
Refs: v8.5.0-6-g766abdc291
Author:     Jiri Denemark <jdenemar>
AuthorDate: Thu Jun 30 12:52:38 2022 +0200
Commit:     Jiri Denemark <jdenemar>
CommitDate: Fri Jul 1 11:28:34 2022 +0200

    qemu_migration: Apply max-postcopy-bandwidth on post-copy resume

    When resuming post-copy migration users may want to limit the bandwidth
    used by the migration and use a value that is different from the one
    specified when the migration was originally started.

    Resolves: https://gitlab.com/libvirt/libvirt/-/issues/333

    Signed-off-by: Jiri Denemark <jdenemar>
    Reviewed-by: Michal Privoznik <mprivozn>
Comment 2 Jiri Denemark 2022-07-26 13:16:50 UTC 
Backported: https://gitlab.com/redhat/rhel/src/libvirt/-/merge_requests/40
Comment 3 Fangge Jin 2022-08-01 06:00:37 UTC 
Versions:
libvirt-8.5.0-4.el9.x86_64
qemu-kvm-7.0.0-9.el9.x86_64

Tested both p2p and p2p, passed.
Comment 6 Fangge Jin 2022-08-11 05:11:30 UTC 
Verified with:
libvirt-8.5.0-5.el9.x86_64
qemu-kvm-7.0.0-10.el9.x86_64
Comment 8 errata-xmlrpc 2022-11-15 10:04:47 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (Low: libvirt security, bug fix, and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHSA-2022:8003