Bug 1119385 - The default behavor of abort block job with pivot flag isn't sync
Summary: The default behavor of abort block job with pivot flag isn't sync
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: libvirt
Version: 6.6
Hardware: x86_64
OS: Linux
unspecified
unspecified
Target Milestone: rc
: ---
Assignee: Eric Blake
QA Contact: Virtualization Bugs
URL:
Whiteboard:
Depends On: 1119173
Blocks: 1119387
TreeView+ depends on / blocked
 
Reported: 2014-07-14 16:25 UTC by Eric Blake
Modified: 2014-10-14 04:23 UTC (History)
9 users (show)

Fixed In Version: libvirt-0.10.2-41.el6
Doc Type: Bug Fix
Doc Text:
Clone Of: 1119173
: 1119387 (view as bug list)
Environment:
Last Closed: 2014-10-14 04:23:11 UTC


Attachments (Terms of Use)


Links
System ID Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2014:1374 normal SHIPPED_LIVE libvirt bug fix and enhancement update 2014-10-14 08:11:54 UTC

Description Eric Blake 2014-07-14 16:25:49 UTC
Cloning to RHEL 6 - 'virsh blockcopy' is not obeying its docs.

+++ This bug was initially created as a clone of Bug #1119173 +++

Description of problem:
http://libvirt.org/html/libvirt-libvirt.html#virDomainBlockJobAbort

The API virDomainBlockJobAbort should be sync default. But with VIR_DOMAIN_BLOCK_JOB_ABORT_PIVOT flag, the api is async, not sync.


    if (disk->mirror && mode == BLOCK_JOB_ABORT &&
        (flags & VIR_DOMAIN_BLOCK_JOB_ABORT_PIVOT)) {
        ret = qemuDomainBlockPivot(conn, driver, vm, device, disk);
        goto endjob;
    }

After called qemuDomainBlockPivot, the code goto the endjob. That skip the
block simulation code.

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

How reproducible:


Steps to Reproduce:
1. virDomainBlockRebase with VIR_DOMAIN_BLOCK_REBASE_COPY flag
2. virDomainBlockJobAbort with VIR_DOMAIN_BLOCK_JOB_ABORT_PIVOT flag


Actual results:
virDomainBlockJobAbort is async

Expected results:
virDomainBlockJobAbort is sync

Additional info:

--- Additional comment from Peter Krempa on 2014-07-14 02:37:40 MDT ---

From what I understand, the "block-job-complete" qmp command called by qemuDomainBlockPivot() is inherently synchronous and thus we don't need to simulate the blocking of the API.

--- Additional comment from Xu He Jie on 2014-07-14 07:13:26 MDT ---

From this test code http://git.qemu.org/?p=qemu.git;a=blob_plain;f=tests/qemu-iotests/041;hb=HEAD to see, the block-job-complete is async. Even if you are right 'block-job-complete' is sync, that also means VIR_DOMAIN_BLOCK_JOB_ABORT_ASYNC flag doesn't work.

--- Additional comment from Eric Blake on 2014-07-14 09:59:54 MDT ---

Blech.  qemu's block-job-complete is inherently async - it merely requests the end of a job and returns control immediately; but the job may take a while longer to actually end because of time spent flushing sectors to disk.  Looks like I introduced the bug when adding blockcopy in commit eaba79d, and that I merely need to update where the goto jumps.

--- Additional comment from Eric Blake on 2014-07-14 10:10:03 MDT ---

We've explicitly documented that the VIR_DOMAIN_BLOCK_JOB_ABORT_ASYNC flag can, but not must, return control before the job has actually ended.  Ignoring the async flag is not a problem. But when the flag is not present, and we have promised sync behavior, then libvirt does need to wait for the event.

--- Additional comment from Eric Blake on 2014-07-14 10:24:23 MDT ---

Upstream patch proposed:
https://www.redhat.com/archives/libvir-list/2014-July/msg00664.html

Comment 3 Shanzhi Yu 2014-07-22 08:46:51 UTC
Reproduce this bug with libvirt-0.10.2-40.el6.x86_64

# time virsh blockjob rhel6 vda --pivot 

real	0m0.231s
user	0m0.024s
sys	0m0.014s

Verify with libvirt-0.10.2-41.el6.x86_64

# time virsh blockjob rhel6 vda --pivot 

real	0m32.676s
user	0m0.022s
sys	0m0.011s

virDomainBlockJobAbort with VIR_DOMAIN_BLOCK_JOB_ABORT_PIVOT flag became sync with this fix. So I would set this bug to VERIFIED status.

Eric, need you confirm this before change to VERIFIED

Comment 4 Eric Blake 2014-07-22 12:24:43 UTC
(In reply to Shanzhi Yu from comment #3)
> Reproduce this bug with libvirt-0.10.2-40.el6.x86_64
> 
> # time virsh blockjob rhel6 vda --pivot 
> 
> real	0m0.231s
> user	0m0.024s
> sys	0m0.014s
> 
> Verify with libvirt-0.10.2-41.el6.x86_64
> 
> # time virsh blockjob rhel6 vda --pivot 
> 
> real	0m32.676s
> user	0m0.022s
> sys	0m0.011s
> 
> virDomainBlockJobAbort with VIR_DOMAIN_BLOCK_JOB_ABORT_PIVOT flag became
> sync with this fix. So I would set this bug to VERIFIED status.

What you've listed merely shows that the command took longer (30 seconds longer!).  But since libvirt is polling for the job completion every 50 ms at the API level and every 500ms at the virsh level, the only explanation for being this much longer is that you must have been doing something to artificially slow down qemu to not complete that fast.  I'd feel a bit more comfortable knowing what you did to slow qemu down, so that we are sure libvirt isn't waiting too long.

Verifying the bug might be easier if you can turn libvirt debug logs on, and prove that pre-patch, the completion event is occurring after control is returned to the user, while post-patch libvirt is polling job status before returning control to the user.

Another idea: if you are artificially slowing down qemu's job completion, then both pre-patch and post-patch should show roughly the same amount of time between requesting the pivot and when an event is delivered (alas, the example python script that libvirt ships for listening to events was not coded to display blockjob events as of the RHEL build, and that also pre-dates 'virsh event'; so you'd have to do a bit of work coding your own event listener), but with a difference of whether the virsh command returns immediately or blocks until after the event.

Comment 5 Shanzhi Yu 2014-07-28 03:33:22 UTC
(In reply to Eric Blake from comment #4)
> (In reply to Shanzhi Yu from comment #3)

> > virDomainBlockJobAbort with VIR_DOMAIN_BLOCK_JOB_ABORT_PIVOT flag became
> > sync with this fix. So I would set this bug to VERIFIED status.
> 
> What you've listed merely shows that the command took longer (30 seconds
> longer!).  But since libvirt is polling for the job completion every 50 ms
> at the API level and every 500ms at the virsh level, the only explanation
> for being this much longer is that you must have been doing something to
> artificially slow down qemu to not complete that fast.  I'd feel a bit more
> comfortable knowing what you did to slow qemu down, so that we are sure
> libvirt isn't waiting too long.
> 

Yes. After blockcopy job is done(in mirroring phase), I login guest and touch a file by "dd if=/dev/zero of=/mnt/test.img bs=1M count=400), then I do "blockjob --pivot"

> Verifying the bug might be easier if you can turn libvirt debug logs on, and
> prove that pre-patch, the completion event is occurring after control is
> returned to the user, while post-patch libvirt is polling job status before
> returning control to the user.
> 

After I turn debug logs on, with 0.10.2-41.el6.x86_64 I can see line "2014-07-27 09:39:40.104+0000: 33017: debug : qemuMonitorBlockJob:3046 : mon=0x7fbea4008610, device=drive-virtio-disk0, base=(null), bandwidth=0M, info=0x7fbeb95bb940, mode=1, modern=1"  while with 0.10.2-40.el6.x86_64 I can't find "qemuMonitorBlockJob" related line.

And There is debug log "query-block-jobs" in post-patch libvirt, while pre-patch there is so such logs. 

Should this also prove this patch works? If not, can you show me more details how to verify this bug? 

Thanks

> Another idea: if you are artificially slowing down qemu's job completion,
> then both pre-patch and post-patch should show roughly the same amount of
> time between requesting the pivot and when an event is delivered (alas, the
> example python script that libvirt ships for listening to events was not
> coded to display blockjob events as of the RHEL build, and that also
> pre-dates 'virsh event'; so you'd have to do a bit of work coding your own
> event listener), but with a difference of whether the virsh command returns
> immediately or blocks until after the event.

Comment 6 Eric Blake 2014-07-28 16:57:34 UTC
(In reply to Shanzhi Yu from comment #5)
> (In reply to Eric Blake from comment #4)
> > (In reply to Shanzhi Yu from comment #3)
> 
> > > virDomainBlockJobAbort with VIR_DOMAIN_BLOCK_JOB_ABORT_PIVOT flag became
> > > sync with this fix. So I would set this bug to VERIFIED status.
> > 
> > What you've listed merely shows that the command took longer (30 seconds
> > longer!).  But since libvirt is polling for the job completion every 50 ms
> > at the API level and every 500ms at the virsh level, the only explanation
> > for being this much longer is that you must have been doing something to
> > artificially slow down qemu to not complete that fast.  I'd feel a bit more
> > comfortable knowing what you did to slow qemu down, so that we are sure
> > libvirt isn't waiting too long.
> > 
> 
> Yes. After blockcopy job is done(in mirroring phase), I login guest and
> touch a file by "dd if=/dev/zero of=/mnt/test.img bs=1M count=400), then I
> do "blockjob --pivot"

Okay, so you were using an I/O-intensive dd operation in the guest as something that would dramatically dirty the file system fast enough to cause a noticeable delay for the command completion.  Nice trick - I'll have to use it myself in testing further patches.

> 
> > Verifying the bug might be easier if you can turn libvirt debug logs on, and
> > prove that pre-patch, the completion event is occurring after control is
> > returned to the user, while post-patch libvirt is polling job status before
> > returning control to the user.
> > 
> 
> After I turn debug logs on, with 0.10.2-41.el6.x86_64 I can see line
> "2014-07-27 09:39:40.104+0000: 33017: debug : qemuMonitorBlockJob:3046 :
> mon=0x7fbea4008610, device=drive-virtio-disk0, base=(null), bandwidth=0M,
> info=0x7fbeb95bb940, mode=1, modern=1"  while with 0.10.2-40.el6.x86_64 I
> can't find "qemuMonitorBlockJob" related line.
> 
> And There is debug log "query-block-jobs" in post-patch libvirt, while
> pre-patch there is so such logs. 
> 
> Should this also prove this patch works? If not, can you show me more
> details how to verify this bug? 

Those log entries are good - they prove that libvirt was polling for job completion.  I think you have verified the bug.

Comment 7 Shanzhi Yu 2014-07-29 00:33:04 UTC
Eric, Thanks

Change this bug to VERIFIED status

Comment 9 errata-xmlrpc 2014-10-14 04:23:11 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, and where to find the updated
files, follow the link below.

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

http://rhn.redhat.com/errata/RHBA-2014-1374.html


Note You need to log in before you can comment on or make changes to this bug.