RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 1962053 - Blockcopy --pivot succeeds but get incorrect disk source image
Summary: Blockcopy --pivot succeeds but get incorrect disk source image
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat Enterprise Linux 9
Classification: Red Hat
Component: libvirt
Version: 9.0
Hardware: Unspecified
OS: Unspecified
high
unspecified
Target Milestone: beta
: ---
Assignee: Peter Krempa
QA Contact: Meina Li
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2021-05-19 09:08 UTC by Meina Li
Modified: 2021-12-07 22:01 UTC (History)
4 users (show)

Fixed In Version: libvirt-7.3.0-1.el9
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2021-12-07 21:57:54 UTC
Type: Bug
Target Upstream Version: 7.3.0
Embargoed:

Attachments (Terms of Use)
libvirtd.log (900.53 KB, text/plain)
2021-05-21 01:14 UTC, Meina Li 		no flags Details
View All

Description Meina Li 2021-05-19 09:08:32 UTC 
Description of problem:
Blockcopy --pivot succeeds but get incorrect disk source image 

Version-Release number of selected component (if applicable):
libvirt-7.0.0-6.el9.x86_64
qemu-kvm-6.0.0-2.el9.x86_64

How reproducible:
100%

Steps to Reproduce:
1. Create an image and attach it to a guest.
# qemu-img create /var/lib/libvirt/images/source.raw 100M
Formatting '/var/lib/libvirt/images/source.raw', fmt=raw size=104857600
# virsh attach-disk lmn /var/lib/libvirt/images/source.raw vdb --config
Disk attached successfully
# virsh start lmn
Domain 'lmn' started
# virsh domstate lmn
running

2. Prepare a dest xml.
# cat dest.xml
<disk type="file" device="disk">
  <driver name="qemu" type="raw"/>
  <source file="/var/lib/libvirt/images/dest">
  </source>
  <target dev="vdb" bus="virtio"/>
</disk>

3. Blockcopy to the dest xm file with --pivot flag.
# virsh blockcopy lmn vdb --xml dest.xml --transient-job --verbose --wait --pivot
Block Copy: [100 %]
Successfully pivoted

4. Check the guest dumpxml.Blockcopy --pivot succeeds but get incorrect disk source image 
# ll /var/lib/libvirt/images/dest
-rw-------. 1 root root 104857600 May 18 23:50 /var/lib/libvirt/images/dest
# virsh dumpxml lmn | grep /disk -B8
...
    <disk type='file' device='disk'>
      <driver name='qemu' type='raw'/>
      <source file='/var/lib/libvirt/images/source.raw' index='1'/>
      <backingStore/>
      <target dev='vdb' bus='virtio'/>
      <alias name='virtio-disk1'/>
      <address type='pci' domain='0x0000' bus='0x07' slot='0x00' function='0x0'/>
    </disk>

Actual results:
Blockcopy --pivot succeeds with the source.raw image in guest

Expected results:
Blockcopy --pivot succeeds with the dest image in guest

Additional info:
Comment 1 Peter Krempa 2021-05-19 11:04:41 UTC 
Please also attach the debug logs of libvirtd.
Comment 2 Meina Li 2021-05-21 01:14:28 UTC 
Created attachment 1785386 [details]
libvirtd.log
Comment 3 Peter Krempa 2021-05-21 13:30:41 UTC 
Okay, according to the debug log this is the same cause as https://bugzilla.redhat.com/show_bug.cgi?id=1951507 which is fixed by upstream commit:

commit 81e770c2f152635219cec76585c770fb9f6ce030
Author: Peter Krempa <pkrempa>
Date:   Tue Apr 20 12:58:28 2021 +0200

    qemu: blockjob: Transition into 'ready' state only from expected states
    
    In certain rare occasions qemu can transition a block job which was
    already 'ready' into 'standby' and then back. If this happens in the
    following order libvirt will get confused about the actual job state:
    
    1) the block copy job is 'ready' (job->state == QEMU_BLOCKJOB_STATE_READY)
    
    2) user calls qemuDomainBlockJobAbort with VIR_DOMAIN_BLOCK_JOB_ABORT_PIVOT
       flag but without VIR_DOMAIN_BLOCK_JOB_ABORT_ASYNC
    
    3) the block job is switched to synchronous event handling
    
    4) the block job blips to 'standby' and back to 'ready', the event is
       not processed since the blockjob is in sync mode for now
    
    5) qemuDomainBlockJobPivot is called:
        5.1) 'job-complete' QMP command is issued
        5.2) job->state is set to QEMU_BLOCKJOB_STATE_PIVOTING
    
    6) code for synchronous-wait for the job completion in qemuDomainBlockJobAbort
       is invoked
    
    7) the waiting loop calls qemuBlockJobUpdate:
    
        7.1) job->newstate is QEMU_BLOCKJOB_STATE_READY due to 4)
        7.2) qemuBlockJobEventProcess is called
        7.3) the handler for QEMU_BLOCKJOB_STATE_READY overwrites
             job->state from QEMU_BLOCKJOB_STATE_PIVOTING to QEMU_BLOCKJOB_STATE_READY
    
    8) qemuDomainBlockJobAbort is looking for a finished job, so waits again
    
    9) qemu finishes the blockjob and transitions it into 'concluded' state
    
    10) qemuBlockJobUpdate is triggered again, this time finalizing the job.
        10.1) job->newstate is = QEMU_BLOCKJOB_STATE_CONCLUDED
              job->state is = QEMU_BLOCKJOB_STATE_READY
        10.2) qemuBlockJobEventProcessConcluded is called, the function
              checks whether there was an error with the blockjob. Since
              there was no error job->newstate becomes
              QEMU_BLOCKJOB_STATE_COMPLETED.
        10.3) qemuBlockJobEventProcessConcludedTransition selects the action
              for the appropriate block job type where we have:
    
        case QEMU_BLOCKJOB_TYPE_COPY:
            if (job->state == QEMU_BLOCKJOB_STATE_PIVOTING && success)
                qemuBlockJobProcessEventConcludedCopyPivot(driver, vm, job, asyncJob);
            else
                qemuBlockJobProcessEventConcludedCopyAbort(driver, vm, job, asyncJob);
            break;
    
              Since job->state is QEMU_BLOCKJOB_STATE_READY,
              qemuBlockJobProcessEventConcludedCopyAbort is called.
    
    This patch forbids transitions to QEMU_BLOCKJOB_STATE_READY if the
    previous job state isn't QEMU_BLOCKJOB_STATE_RUNNING or
    QEMU_BLOCKJOB_STATE_NEW.
    
    Resolves: https://bugzilla.redhat.com/show_bug.cgi?id=1951507
    Signed-off-by: Peter Krempa <pkrempa>
    Reviewed-by: Michal Privoznik <mprivozn>


The following debug log analysis references key points with same numbers as the commit message outlines:

2021-05-21 01:06:29.234+0000: 97910: debug : qemuProcessHandleJobStatusChange:1007 : job 'copy-vdb-libvirt-1-format'(domain: 0x7f43280db0b0,lmn) state changed to 'ready'(4)

 1)

2021-05-21 01:06:29.719+0000: 97770: debug : virDomainBlockJobAbort:10058 : dom=0x7f4360003100, (VM: name=lmn, uuid=f1195008-e72b-4df5-b30f-7f8b29b2f14c), disk=vdb, flags=0x2

 2)

2021-05-21 01:06:29.719+0000: 97770: debug : qemuBlockJobSyncBegin:1772 : disk=vdb

 3)

2021-05-21 01:06:29.719+0000: 97770: debug : qemuDomainObjEnterMonitorInternal:5700 : Entering monitor (mon=0x7f437003d060 vm=0x7f43280db0b0 name=lmn)
2021-05-21 01:06:29.719+0000: 97770: debug : qemuMonitorTransaction:3219 : actions=0x7f4360004500
2021-05-21 01:06:29.719+0000: 97770: debug : qemuMonitorTransaction:3221 : mon:0x7f437003d060 vm:0x7f43280db0b0 fd:35
2021-05-21 01:06:29.719+0000: 97770: info : qemuMonitorSend:948 : QEMU_MONITOR_SEND_MSG: mon=0x7f437003d060 msg={"execute":"transaction","arguments":{"actions":[{"type":"block-dirty-bitmap-add","data":{"node":"libvirt-3-format","name":"libvirt-tmp-activewrite","persistent":false,"disabled":false}}]},"id":"libvirt-395"}
 fd=-1
2021-05-21 01:06:29.719+0000: 97910: info : qemuMonitorIOWrite:435 : QEMU_MONITOR_IO_WRITE: mon=0x7f437003d060 buf={"execute":"transaction","arguments":{"actions":[{"type":"block-dirty-bitmap-add","data":{"node":"libvirt-3-format","name":"libvirt-tmp-activewrite","persistent":false,"disabled":false}}]},"id":"libvirt-395"}
 len=210 ret=210 errno=0
2021-05-21 01:06:29.720+0000: 97910: debug : qemuMonitorJSONIOProcessLine:222 : Line [{"timestamp": {"seconds": 1621559189, "microseconds": 720934}, "event": "JOB_STATUS_CHANGE", "data": {"status": "standby", "id": "copy-vdb-libvirt-1-format"}}]
2021-05-21 01:06:29.720+0000: 97910: info : qemuMonitorJSONIOProcessLine:236 : QEMU_MONITOR_RECV_EVENT: mon=0x7f437003d060 event={"timestamp": {"seconds": 1621559189, "microseconds": 720934}, "event": "JOB_STATUS_CHANGE", "data": {"status": "standby", "id": "copy-vdb-libvirt-1-format"}}

 4) state to standby

2021-05-21 01:06:29.720+0000: 97910: debug : qemuMonitorJSONIOProcessEvent:183 : mon=0x7f437003d060 obj=0x7f4314010470
2021-05-21 01:06:29.720+0000: 97910: debug : qemuMonitorEmitEvent:1159 : mon=0x7f437003d060 event=JOB_STATUS_CHANGE
2021-05-21 01:06:29.720+0000: 97910: debug : qemuProcessHandleEvent:557 : vm=0x7f43280db0b0
2021-05-21 01:06:29.721+0000: 97910: debug : qemuMonitorJSONIOProcessEvent:207 : handle JOB_STATUS_CHANGE handler=0x7f43742f6be0 data=0x7f431400ef50
2021-05-21 01:06:29.721+0000: 97910: debug : qemuMonitorEmitJobStatusChange:1369 : mon=0x7f437003d060
2021-05-21 01:06:29.721+0000: 97910: debug : qemuProcessHandleJobStatusChange:1007 : job 'copy-vdb-libvirt-1-format'(domain: 0x7f43280db0b0,lmn) state changed to 'standby'(5)
2021-05-21 01:06:29.721+0000: 97910: debug : qemuMonitorJSONIOProcessLine:222 : Line [{"timestamp": {"seconds": 1621559189, "microseconds": 720962}, "event": "JOB_STATUS_CHANGE", "data": {"status": "ready", "id": "copy-vdb-libvirt-1-format"}}]
2021-05-21 01:06:29.721+0000: 97910: info : qemuMonitorJSONIOProcessLine:236 : QEMU_MONITOR_RECV_EVENT: mon=0x7f437003d060 event={"timestamp": {"seconds": 1621559189, "microseconds": 720962}, "event": "JOB_STATUS_CHANGE", "data": {"status": "ready", "id": "copy-vdb-libvirt-1-format"}}

  4) state to READY again

2021-05-21 01:06:29.721+0000: 97910: debug : qemuMonitorJSONIOProcessEvent:183 : mon=0x7f437003d060 obj=0x7f4314010470
2021-05-21 01:06:29.721+0000: 97910: debug : qemuMonitorEmitEvent:1159 : mon=0x7f437003d060 event=JOB_STATUS_CHANGE
2021-05-21 01:06:29.721+0000: 97910: debug : qemuProcessHandleEvent:557 : vm=0x7f43280db0b0
2021-05-21 01:06:29.721+0000: 97910: debug : qemuMonitorJSONIOProcessEvent:207 : handle JOB_STATUS_CHANGE handler=0x7f43742f6be0 data=0x7f4314008b90
2021-05-21 01:06:29.721+0000: 97910: debug : qemuMonitorEmitJobStatusChange:1369 : mon=0x7f437003d060
2021-05-21 01:06:29.721+0000: 97910: debug : qemuProcessHandleJobStatusChange:1007 : job 'copy-vdb-libvirt-1-format'(domain: 0x7f43280db0b0,lmn) state changed to 'ready'(4)
2021-05-21 01:06:29.721+0000: 97910: debug : qemuProcessHandleJobStatusChange:1027 : job 'copy-vdb-libvirt-1-format' handled synchronously

  4) job is in sync mode

2021-05-21 01:06:29.721+0000: 97910: debug : qemuMonitorJSONIOProcessLine:222 : Line [{"return": {}, "id": "libvirt-395"}]
2021-05-21 01:06:29.721+0000: 97910: info : qemuMonitorJSONIOProcessLine:241 : QEMU_MONITOR_RECV_REPLY: mon=0x7f437003d060 reply={"return": {}, "id": "libvirt-395"}
2021-05-21 01:06:29.721+0000: 97770: debug : qemuMonitorJobComplete:3437 : jobname=copy-vdb-libvirt-1-format
2021-05-21 01:06:29.721+0000: 97770: debug : qemuMonitorJobComplete:3439 : mon:0x7f437003d060 vm:0x7f43280db0b0 fd:35
2021-05-21 01:06:29.721+0000: 97770: info : qemuMonitorSend:948 : QEMU_MONITOR_SEND_MSG: mon=0x7f437003d060 msg={"execute":"job-complete","arguments":{"id":"copy-vdb-libvirt-1-format"},"id":"libvirt-396"}
 fd=-1
2021-05-21 01:06:29.721+0000: 97910: info : qemuMonitorIOWrite:435 : QEMU_MONITOR_IO_WRITE: mon=0x7f437003d060 buf={"execute":"job-complete","arguments":{"id":"copy-vdb-libvirt-1-format"},"id":"libvirt-396"}
 len=94 ret=94 errno=0
 
  5)
 
2021-05-21 01:06:29.721+0000: 97910: debug : qemuMonitorJSONIOProcessLine:222 : Line [{"return": {}, "id": "libvirt-396"}]
2021-05-21 01:06:29.721+0000: 97910: info : qemuMonitorJSONIOProcessLine:241 : QEMU_MONITOR_RECV_REPLY: mon=0x7f437003d060 reply={"return": {}, "id": "libvirt-396"}
2021-05-21 01:06:29.721+0000: 97770: debug : qemuDomainObjExitMonitorInternal:5725 : Exited monitor (mon=0x7f437003d060 vm=0x7f43280db0b0 name=lmn)
2021-05-21 01:06:29.721+0000: 97910: debug : qemuMonitorJSONIOProcessLine:222 : Line [{"timestamp": {"seconds": 1621559189, "microseconds": 721751}, "event": "JOB_STATUS_CHANGE", "data": {"status": "waiting", "id": "copy-vdb-libvirt-1-format"}}]
2021-05-21 01:06:29.721+0000: 97910: info : qemuMonitorJSONIOProcessLine:236 : QEMU_MONITOR_RECV_EVENT: mon=0x7f437003d060 event={"timestamp": {"seconds": 1621559189, "microseconds": 721751}, "event": "JOB_STATUS_CHANGE", "data": {"status": "waiting", "id": "copy-vdb-libvirt-1-format"}}
2021-05-21 01:06:29.721+0000: 97910: debug : qemuMonitorJSONIOProcessEvent:183 : mon=0x7f437003d060 obj=0x7f4314010470
2021-05-21 01:06:29.721+0000: 97910: debug : qemuMonitorEmitEvent:1159 : mon=0x7f437003d060 event=JOB_STATUS_CHANGE
2021-05-21 01:06:29.721+0000: 97910: debug : qemuProcessHandleEvent:557 : vm=0x7f43280db0b0
2021-05-21 01:06:29.722+0000: 97910: debug : qemuMonitorJSONIOProcessEvent:207 : handle JOB_STATUS_CHANGE handler=0x7f43742f6be0 data=0x7f43141e1be0
2021-05-21 01:06:29.722+0000: 97910: debug : qemuMonitorEmitJobStatusChange:1369 : mon=0x7f437003d060
2021-05-21 01:06:29.722+0000: 97910: debug : qemuProcessHandleJobStatusChange:1007 : job 'copy-vdb-libvirt-1-format'(domain: 0x7f43280db0b0,lmn) state changed to 'waiting'(6)
2021-05-21 01:06:29.722+0000: 97910: debug : qemuMonitorJSONIOProcessLine:222 : Line [{"timestamp": {"seconds": 1621559189, "microseconds": 721777}, "event": "JOB_STATUS_CHANGE", "data": {"status": "pending", "id": "copy-vdb-libvirt-1-format"}}]
2021-05-21 01:06:29.722+0000: 97910: info : qemuMonitorJSONIOProcessLine:236 : QEMU_MONITOR_RECV_EVENT: mon=0x7f437003d060 event={"timestamp": {"seconds": 1621559189, "microseconds": 721777}, "event": "JOB_STATUS_CHANGE", "data": {"status": "pending", "id": "copy-vdb-libvirt-1-format"}}
2021-05-21 01:06:29.722+0000: 97910: debug : qemuMonitorJSONIOProcessEvent:183 : mon=0x7f437003d060 obj=0x7f4314010470
2021-05-21 01:06:29.722+0000: 97910: debug : qemuMonitorEmitEvent:1159 : mon=0x7f437003d060 event=JOB_STATUS_CHANGE
2021-05-21 01:06:29.722+0000: 97910: debug : qemuProcessHandleEvent:557 : vm=0x7f43280db0b0
2021-05-21 01:06:29.722+0000: 97910: debug : qemuMonitorJSONIOProcessEvent:207 : handle JOB_STATUS_CHANGE handler=0x7f43742f6be0 data=0x7f43141c9460
2021-05-21 01:06:29.722+0000: 97910: debug : qemuMonitorEmitJobStatusChange:1369 : mon=0x7f437003d060
2021-05-21 01:06:29.722+0000: 97910: debug : qemuProcessHandleJobStatusChange:1007 : job 'copy-vdb-libvirt-1-format'(domain: 0x7f43280db0b0,lmn) state changed to 'pending'(7)
2021-05-21 01:06:29.722+0000: 97910: debug : qemuMonitorJSONIOProcessLine:222 : Line [{"timestamp": {"seconds": 1621559189, "microseconds": 721879}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "copy-vdb-libvirt-1-format", "len": 104857600, "offset": 104857600, "speed": 0, "type": "mirror"}}]
2021-05-21 01:06:29.722+0000: 97910: info : qemuMonitorJSONIOProcessLine:236 : QEMU_MONITOR_RECV_EVENT: mon=0x7f437003d060 event={"timestamp": {"seconds": 1621559189, "microseconds": 721879}, "event": "BLOCK_JOB_COMPLETED", "data": {"device": "copy-vdb-libvirt-1-format", "len": 104857600, "offset": 104857600, "speed": 0, "type": "mirror"}}
2021-05-21 01:06:29.722+0000: 97910: debug : qemuMonitorJSONIOProcessEvent:183 : mon=0x7f437003d060 obj=0x7f431400a750
2021-05-21 01:06:29.722+0000: 97910: debug : qemuMonitorEmitEvent:1159 : mon=0x7f437003d060 event=BLOCK_JOB_COMPLETED
2021-05-21 01:06:29.722+0000: 97910: debug : qemuProcessHandleEvent:557 : vm=0x7f43280db0b0
2021-05-21 01:06:29.722+0000: 97910: debug : qemuMonitorJSONIOProcessEvent:207 : handle BLOCK_JOB_COMPLETED handler=0x7f43742f6bb0 data=0x7f43141e1be0
2021-05-21 01:06:29.722+0000: 97910: debug : qemuMonitorEmitBlockJob:1355 : mon=0x7f437003d060
2021-05-21 01:06:29.722+0000: 97910: debug : qemuMonitorJSONIOProcessLine:222 : Line [{"timestamp": {"seconds": 1621559189, "microseconds": 721901}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "copy-vdb-libvirt-1-format"}}]
2021-05-21 01:06:29.722+0000: 97910: info : qemuMonitorJSONIOProcessLine:236 : QEMU_MONITOR_RECV_EVENT: mon=0x7f437003d060 event={"timestamp": {"seconds": 1621559189, "microseconds": 721901}, "event": "JOB_STATUS_CHANGE", "data": {"status": "concluded", "id": "copy-vdb-libvirt-1-format"}}

 9) 

2021-05-21 01:06:29.722+0000: 97910: debug : qemuMonitorJSONIOProcessEvent:183 : mon=0x7f437003d060 obj=0x7f431400a750
2021-05-21 01:06:29.722+0000: 97910: debug : qemuMonitorEmitEvent:1159 : mon=0x7f437003d060 event=JOB_STATUS_CHANGE
2021-05-21 01:06:29.722+0000: 97910: debug : qemuProcessHandleEvent:557 : vm=0x7f43280db0b0
2021-05-21 01:06:29.722+0000: 97910: debug : qemuMonitorJSONIOProcessEvent:207 : handle JOB_STATUS_CHANGE handler=0x7f43742f6be0 data=0x7f43141e02e0
2021-05-21 01:06:29.722+0000: 97910: debug : qemuMonitorEmitJobStatusChange:1369 : mon=0x7f437003d060
2021-05-21 01:06:29.722+0000: 97910: debug : qemuProcessHandleJobStatusChange:1007 : job 'copy-vdb-libvirt-1-format'(domain: 0x7f43280db0b0,lmn) state changed to 'concluded'(9)
2021-05-21 01:06:29.722+0000: 97910: debug : qemuProcessHandleJobStatusChange:1027 : job 'copy-vdb-libvirt-1-format' handled synchronously
2021-05-21 01:06:29.722+0000: 97770: debug : qemuDomainObjEnterMonitorInternal:5700 : Entering monitor (mon=0x7f437003d060 vm=0x7f43280db0b0 name=lmn)
2021-05-21 01:06:29.722+0000: 97770: debug : qemuMonitorGetJobInfo:4601 : mon:0x7f437003d060 vm:0x7f43280db0b0 fd:35
2021-05-21 01:06:29.722+0000: 97770: info : qemuMonitorSend:948 : QEMU_MONITOR_SEND_MSG: mon=0x7f437003d060 msg={"execute":"query-jobs","id":"libvirt-397"}
 fd=-1
2021-05-21 01:06:29.722+0000: 97910: info : qemuMonitorIOWrite:435 : QEMU_MONITOR_IO_WRITE: mon=0x7f437003d060 buf={"execute":"query-jobs","id":"libvirt-397"}
 len=45 ret=45 errno=0
2021-05-21 01:06:29.723+0000: 97910: debug : qemuMonitorJSONIOProcessLine:222 : Line [{"return": [{"current-progress": 104857600, "status": "concluded", "total-progress": 104857600, "type": "mirror", "id": "copy-vdb-libvirt-1-format"}], "id": "libvirt-397"}]
2021-05-21 01:06:29.723+0000: 97910: info : qemuMonitorJSONIOProcessLine:241 : QEMU_MONITOR_RECV_REPLY: mon=0x7f437003d060 reply={"return": [{"current-progress": 104857600, "status": "concluded", "total-progress": 104857600, "type": "mirror", "id": "copy-vdb-libvirt-1-format"}], "id": "libvirt-397"}
2021-05-21 01:06:29.723+0000: 97770: debug : qemuMonitorJobDismiss:3412 : jobname=copy-vdb-libvirt-1-format
2021-05-21 01:06:29.723+0000: 97770: debug : qemuMonitorJobDismiss:3414 : mon:0x7f437003d060 vm:0x7f43280db0b0 fd:35
2021-05-21 01:06:29.723+0000: 97770: info : qemuMonitorSend:948 : QEMU_MONITOR_SEND_MSG: mon=0x7f437003d060 msg={"execute":"job-dismiss","arguments":{"id":"copy-vdb-libvirt-1-format"},"id":"libvirt-398"}
 fd=-1
2021-05-21 01:06:29.723+0000: 97910: info : qemuMonitorIOWrite:435 : QEMU_MONITOR_IO_WRITE: mon=0x7f437003d060 buf={"execute":"job-dismiss","arguments":{"id":"copy-vdb-libvirt-1-format"},"id":"libvirt-398"}
 len=93 ret=93 errno=0
2021-05-21 01:06:29.723+0000: 97910: debug : qemuMonitorJSONIOProcessLine:222 : Line [{"timestamp": {"seconds": 1621559189, "microseconds": 723552}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "copy-vdb-libvirt-1-format"}}]
2021-05-21 01:06:29.723+0000: 97910: info : qemuMonitorJSONIOProcessLine:236 : QEMU_MONITOR_RECV_EVENT: mon=0x7f437003d060 event={"timestamp": {"seconds": 1621559189, "microseconds": 723552}, "event": "JOB_STATUS_CHANGE", "data": {"status": "null", "id": "copy-vdb-libvirt-1-format"}}
2021-05-21 01:06:29.723+0000: 97910: debug : qemuMonitorJSONIOProcessEvent:183 : mon=0x7f437003d060 obj=0x7f43141e4360
2021-05-21 01:06:29.723+0000: 97910: debug : qemuMonitorEmitEvent:1159 : mon=0x7f437003d060 event=JOB_STATUS_CHANGE
2021-05-21 01:06:29.723+0000: 97910: debug : qemuProcessHandleEvent:557 : vm=0x7f43280db0b0
2021-05-21 01:06:29.723+0000: 97910: debug : qemuMonitorJSONIOProcessEvent:207 : handle JOB_STATUS_CHANGE handler=0x7f43742f6be0 data=0x7f43141d09a0
2021-05-21 01:06:29.723+0000: 97910: debug : qemuMonitorEmitJobStatusChange:1369 : mon=0x7f437003d060
2021-05-21 01:06:29.723+0000: 97910: debug : qemuProcessHandleJobStatusChange:1007 : job 'copy-vdb-libvirt-1-format'(domain: 0x7f43280db0b0,lmn) state changed to 'null'(11)
2021-05-21 01:06:29.723+0000: 97910: debug : qemuMonitorJSONIOProcessLine:222 : Line [{"return": {}, "id": "libvirt-398"}]
2021-05-21 01:06:29.723+0000: 97910: info : qemuMonitorJSONIOProcessLine:241 : QEMU_MONITOR_RECV_REPLY: mon=0x7f437003d060 reply={"return": {}, "id": "libvirt-398"}
2021-05-21 01:06:29.723+0000: 97770: debug : qemuDomainObjExitMonitorInternal:5725 : Exited monitor (mon=0x7f437003d060 vm=0x7f43280db0b0 name=lmn)
2021-05-21 01:06:29.723+0000: 97770: debug : virFileMakePathHelper:3035 : path=/run/libvirt/qemu mode=0777
2021-05-21 01:06:29.724+0000: 97770: debug : qemuBlockJobEventProcessConcluded:1657 : handling job 'copy-vdb-libvirt-1-format' state '3' newstate '0'

 10.1), 10.2)

2021-05-21 01:06:29.724+0000: 97770: debug : qemuBlockJobProcessEventConcludedCopyAbort:1402 : copy job 'copy-vdb-libvirt-1-format' on VM 'lmn' aborted
 
 10.3)

Moving to POST.
Comment 6 Meina Li 2021-06-09 02:42:39 UTC 
Verified Version:
libvirt-7.3.0-1.el9.x86_64
qemu-kvm-6.0.0-3.el9.x86_64

Verified Steps:
1. Create an image and attach it to a guest.
# qemu-img create /var/lib/libvirt/images/source.raw 100M
Formatting '/var/lib/libvirt/images/source.raw', fmt=raw size=104857600
# virsh attach-disk lmn /var/lib/libvirt/images/source.raw vdb --config
Disk attached successfully
# virsh start lmn
Domain 'lmn' started
# virsh domstate lmn
running

2. Prepare a dest xml.
# cat dest.xml
<disk type="file" device="disk">
  <driver name="qemu" type="raw"/>
  <source file="/var/lib/libvirt/images/dest">
  </source>
  <target dev="vdb" bus="virtio"/>
</disk>

3. Blockcopy to the dest xm file with --pivot flag.
# virsh blockcopy lmn vdb --xml dest.xml --transient-job --verbose --wait --pivot
Block Copy: [100 %]
Successfully pivoted

4. Check the guest dumpxml.Blockcopy --pivot succeeds but get incorrect disk source image 
# ll /var/lib/libvirt/images/dest
-rw-------. 1 qemu qemu 104857600 Jun  8 22:17 /var/lib/libvirt/images/dest
# virsh dumpxml lmn | grep /disk -B8
...
    <disk type='file' device='disk'>
      <driver name='qemu' type='raw'/>
      <source file='/var/lib/libvirt/images/dest' index='3'/>
      <backingStore/>
      <target dev='vdb' bus='virtio'/>
      <alias name='virtio-disk1'/>
      <address type='pci' domain='0x0000' bus='0x07' slot='0x00' function='0x0'/>
    </disk>
Note You need to log in before you can comment on or make changes to this bug.