Bug 727502 - Error output for virsh blockjob/blockpull command
Summary: Error output for virsh blockjob/blockpull command
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: libvirt
Version: 6.2
Hardware: x86_64
OS: Linux
high
medium
Target Milestone: rc
: ---
Assignee: Osier Yang
QA Contact: Virtualization Bugs
URL:
Whiteboard:
Depends On:
Blocks: 633374
TreeView+ depends on / blocked
 
Reported: 2011-08-02 10:19 UTC by Alex Jia
Modified: 2011-12-06 11:20 UTC (History)
10 users (show)

Fixed In Version: libvirt-0.9.4-6.el6
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2011-12-06 11:20:41 UTC
Target Upstream Version:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2011:1513 0 normal SHIPPED_LIVE libvirt bug fix and enhancement update 2011-12-06 01:23:30 UTC

Description Alex Jia 2011-08-02 10:19:20 UTC
Description of problem:
when run virsh blockjob/blockpull with some options for a active guest, virsh return value is 1, but can't see any error information on terminal and can't also find these errors in libvirtd.log.


Version-Release number of selected component (if applicable):
# uname -r
2.6.32-160.el6.x86_64

# rpm -q libvirt
libvirt-0.9.4-0rc2.el6.x86_64

# rpm -q qemu-kvm
qemu-kvm-0.12.1.2-2.169.el6.x86_64 

How reproducible:
always

Steps to Reproduce:
1. create a qcow2 disk with backing file
2. define a guest from xml with above disk image then start this guest
3. run virsh blockjob/blockpull with/without options
4. get virsh return value by echo $?
5. check actual libvirtd.log 
  
Actual results:

# virsh blockjob demo /tmp/disk1.qcow2 --info
error: internal error Unexpected error

# echo $?
1

Note: this is expected result and can find the following error in libvirtd.log:
error : qemuMonitorJSONBlockJob:3045 : internal error Unexpected error

# virsh blockjob demo /tmp/disk1.qcow2 --info --bandwidth 10M

Note: without any error information, although the following virsh return value is 1, if you mix these options, you can get the same result.

# echo $?
1

Note: and can't find any error in libvirtd.log

In addition, virsh blockpull has the same issue to blockjob. 

Expected results:
raise correct error information and write these error into libvirtd.log. 

Additional info:

# qemu-img create /tmp/backing1.img 100M
Formatting '/tmp/backing1.img', fmt=raw size=104857600

# qemu-img create -f qcow2 -o backing_file=/tmp/backing1.img /tmp/disk1.qcow2
Formatting '/tmp/disk1.qcow2', fmt=qcow2 size=104857600 backing_file='/tmp/backing1.img' encryption=off cluster_size=65536

# qemu-img info /tmp/disk1.qcow2
image: /tmp/disk1.qcow2
file format: qcow2
virtual size: 100M (104857600 bytes)
disk size: 140K
cluster_size: 65536
backing file: /tmp/backing1.img (actual path: /tmp/backing1.img)

# virsh dumpxml demo
<domain type='kvm' id='40'>
  <name>demo</name>
  <uuid>a2ebcaf2-be21-035b-5a0d-f76ad2f9c6c1</uuid>
  <memory>131072</memory>
  <currentMemory>131072</currentMemory>
  <vcpu>1</vcpu>
  <os>
    <type arch='x86_64' machine='rhel6.2.0'>hvm</type>
    <boot dev='hd'/>
  </os>
  <features>
    <acpi/>
    <apic/>
    <pae/>
  </features>
  <clock offset='utc'/>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>restart</on_reboot>
  <on_crash>restart</on_crash>
  <devices>
    <emulator>/usr/libexec/qemu-kvm</emulator>
    <disk type='file' device='disk'>
      <driver name='qemu' type='qcow2'/>
      <source file='/tmp/disk1.qcow2'/>
      <target dev='vda' bus='virtio'/>
      <alias name='virtio-disk0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
    </disk>
    <input type='mouse' bus='ps2'/>
    <graphics type='vnc' port='5900' autoport='yes'/>
    <video>
      <model type='cirrus' vram='9216' heads='1'/>
      <alias name='video0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>
    </video>
    <memballoon model='virtio'>
      <alias name='balloon0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x06' function='0x0'/>
    </memballoon>
  </devices>
  <seclabel type='dynamic' model='selinux' relabel='yes'>
    <label>system_u:system_r:svirt_t:s0:c287,c513</label>
    <imagelabel>system_u:object_r:svirt_image_t:s0:c287,c513</imagelabel>
  </seclabel>
</domain>

Comment 1 Nan Zhang 2011-08-12 09:19:24 UTC
Reproduced with libvirt-0.9.4-2.el6.x86_64, qemu-kvm-0.12.1.2-2.180.el6.x86_64.
qemu seems no named 'block-jobs' in commands.


21:33:11.252: 13707: debug : qemuMonitorBlockJob:2503 : mon=0x7f48e414e000, device=0x7f48dc000e80, bandwidth=0, info=0x7f48ed9c7b70, mode=1
21:33:11.253: 13707: debug : qemuMonitorJSONCommandWithFd:227 : Send command '{"execute":"query-block-jobs","id":"libvirt-6"}' for write with FD -1
21:33:11.253: 13705: debug : qemuMonitorJSONIOProcessLine:118 : Line [{"id": "libvirt-6", "error": {"class": "CommandNotFound", "desc": "The command block-jobs has not been found", "data": {"name": "block-jobs"}}}]
21:33:11.253: 13705: debug : qemuMonitorJSONIOProcess:185 : Total used 145 bytes out of 145 available in buffer
21:33:11.253: 13707: debug : qemuMonitorJSONCommandWithFd:232 : Receive command reply ret=0 rxObject=0x26da740
21:33:11.253: 13707: error : qemuMonitorJSONBlockJob:3050 : internal error Unexpected error
21:33:11.255: 13705: debug : qemuProcessAutoDestroyRun:3540 : conn=0x7f48d4000c10


{"execute":"query-commands"}
{"return": [{"name": "quit"}, {"name": "eject"}, {"name": "__com.redhat_drive_del"}, {"name": "change"}, {"name": "stop"}, {"name": "cont"}, {"name": "system_reset"}, {"name": "system_powerdown"}, {"name": "device_add"}, {"name": "device_del"}, {"name": "cpu"}, {"name": "memsave"}, {"name": "pmemsave"}, {"name": "inject-nmi"}, {"name": "migrate"}, {"name": "migrate_cancel"}, {"name": "migrate_set_speed"},{"name": "client_migrate_info"}, {"name": "migrate_set_downtime"}, {"name": "block_resize"}, {"name": "netdev_add"}, {"name": "netdev_del"}, {"name": "blockdev-snapshot-sync"}, {"name": "balloon"}, {"name": "set_link"}, {"name": "getfd"}, {"name": "closefd"}, {"name": "block_passwd"}, {"name": "set_password"}, {"name": "expire_password"}, {"name":"__com.redhat_set_password"}, {"name": "__com.redhat_spice_migrate_info"}, {"name": "qmp_capabilities"}, {"name": "human-monitor-command"}, {"name": "__com.redhat_drive_add"}, {"name": "query-version"}, {"name": "query-commands"}, {"name": "query-chardev"}, {"name": "query-block"}, {"name": "query-blockstats"}, {"name": "query-cpus"}, {"name": "query-kvm"}, {"name": "query-status"}, {"name": "query-mice"}, {"name": "query-vnc"}, {"name": "query-spice"}, {"name": "query-name"}, {"name": "query-uuid"}, {"name": "query-migrate"}, {"name": "query-balloon"}]}

Comment 2 Osier Yang 2011-08-17 13:59:21 UTC
This is quite strange, even there is no debug log for the command execution with my testing, but I see there is a problem of the error handling in the codes. It doesn't handle the error "CommandNotFound".

Comment 3 Osier Yang 2011-08-24 06:47:49 UTC
commit 10b100240f997139fb44186e2d2b41f933ae8a5e
Author: Osier Yang <jyang>
Date:   Wed Aug 24 14:39:42 2011 +0800

    qemu: Report error if qemu monitor command not found for BlockJob
    
    * src/qemu/qemu_monitor_json.c: Handle error "CommandNotFound" and
      report the error.
    
    * src/qemu/qemu_monitor_text.c: If a sub info command is not found,
      it prints the output of "help info", for other commands,
      "unknown command" is printed.
    
    Without this patch, libvirt always report:
    
      An error occurred, but the cause is unknown
    
    This patch was adapted from a patch by Osier Yang <jyang> to
    break out detection of unrecognized text monitor commands into a separate
    function.
    
    Signed-off-by: Adam Litke <agl.com>


commit dba7086fc3e1f6dcc6c636c251a6ce7362fcc0b6
Author: Osier Yang <jyang>
Date:   Tue Aug 23 14:55:23 2011 +0800

    virsh: Print error if specified bandwidth is invalid for blockjob
    
    It's strange that the command fails but without any error if one
    specifies as not a number.

Patches committed into upstream.

Comment 4 Osier Yang 2011-08-24 07:04:14 UTC
http://post-office.corp.redhat.com/archives/rhvirt-patches/2011-August/msg00578.html

Patch posted internally, move to POST.

Comment 7 Nan Zhang 2011-08-29 03:26:20 UTC
Verified with libvirt-0.9.4-6.el6.x86_64, we can get the correct error info.

# qemu-img info /var/lib/libvirt/images/foo-new.img 
image: /var/lib/libvirt/images/foo-new.img
file format: qcow2
virtual size: 4.0G (4294967296 bytes)
disk size: 136K
cluster_size: 65536
backing file: /var/lib/libvirt/images/foo.img (actual path: /var/lib/libvirt/images/foo.img)

# virsh blockjob foo-new /var/lib/libvirt/images/foo-new.img --info
error: Requested operation is not valid: Command 'query-block-jobs' is not found

# virsh blockjob foo-new /var/lib/libvirt/images/foo-new.img --info --bandwidth 10M
error: bandwidth must be a number

# virsh blockjob foo-new /var/lib/libvirt/images/foo-new.img --info --bandwidth 10
error: Requested operation is not valid: Command 'query-block-jobs' is not found

# virsh blockjob foo-new /var/lib/libvirt/images/foo-new.img --abort
error: Requested operation is not valid: Command 'block_job_cancel' is not found

# virsh blockpull foo-new /var/lib/libvirt/images/foo-new.img 10
error: Requested operation is not valid: Command 'block_stream' is not found

Comment 8 Adam Litke 2011-08-29 13:25:29 UTC
You must also be using a version of qemu that has the image streaming backport.  This is why libvirt is reporting a command not found error.

Comment 9 Nan Zhang 2011-08-30 03:34:13 UTC
Thanks, Adam. I guess you mean qemu upstream has the image streaming. For now, I'm sure qemu-kvm don't support this feature on RHEL.

Comment 10 Nan Zhang 2011-08-30 03:44:02 UTC
Test version:
libvirt-0.9.4-6.el6.x86_64
qemu-kvm-0.12.1.2-2.184.el6.x86_64

Comment 11 dyuan 2011-08-30 09:29:55 UTC
(In reply to comment #8)
> You must also be using a version of qemu that has the image streaming backport.
>  This is why libvirt is reporting a command not found error.

Is there any qemu-kvm bug to track the unsupported commands in comment 7 for RHEL6.2 ? or a new bug should be filed against qemu-kvm ?

Comment 12 Daniel Veillard 2011-09-16 09:33:57 UTC
I would suggest to retry the testing with qemu-kvm-0.12.1.2-2.190.el6
which is now available with many streaming patches, c.f. bug 633370

Daniel

Comment 13 dyuan 2011-09-16 09:56:01 UTC
Tested with qemu-kvm-0.12.1.2-2.190.el6 and libvirt-0.9.4-11.el6, get the same result as comment 7.

Comment 14 Adam Litke 2011-09-16 13:39:24 UTC
(In reply to comment #12)
> I would suggest to retry the testing with qemu-kvm-0.12.1.2-2.190.el6
> which is now available with many streaming patches, c.f. bug 633370
> 
> Daniel

Is this package available to partners yet?  Right now we have:
  RHEL6.2-20110907.1-Server-x86_64-DVD1.iso which only ships qemu-kvm-0.12.1.2-2.183.el6.x86_64.rpm.

Comment 15 Nan Zhang 2011-09-19 03:17:51 UTC
(In reply to comment #13)
> Tested with qemu-kvm-0.12.1.2-2.190.el6 and libvirt-0.9.4-11.el6, get the same
> result as comment 7.

I just tested with the same version, but got an error on blockpull command.

[root@localhost ~]# qemu-img info /var/lib/libvirt/images/foo-new.img 
image: /var/lib/libvirt/images/foo-new.img
file format: qcow2
virtual size: 4.0G (4294967296 bytes)
disk size: 136K
cluster_size: 65536
backing file: /var/lib/libvirt/images/foo.img (actual path: /var/lib/libvirt/images/foo.img)

[root@localhost ~]# virsh blockjob foo-new /var/lib/libvirt/images/foo-new.img --info

[root@localhost ~]# virsh blockpull foo-new /var/lib/libvirt/images/foo-new.img
error: Requested operation is not valid: Operation is not supported for device: drive-virtio-disk0

Comment 16 Nan Zhang 2011-09-19 08:12:29 UTC
Ahh, please ignore comment 15, I took the wrong image format to do the test.

Below is the correct results:

# qemu-img info /var/lib/libvirt/images/demo-new.qed
image: /var/lib/libvirt/images/demo-new.qed
file format: qed
virtual size: 2.0G (2147483648 bytes)
disk size: 964K
cluster_size: 65536
backing file: /var/lib/libvirt/images/demo.qed (actual path: /var/lib/libvirt/images/demo.qed)

# virsh blockpull demo-new /var/lib/libvirt/images/demo-new.qed 1

# virsh blockjob demo-new /var/lib/libvirt/images/demo-new.qed --info
Block Pull: [  6 %]    Bandwidth limit: 1 MB/s

# virsh blockjob demo-new /var/lib/libvirt/images/demo-new.qed --info
Block Pull: [  9 %]    Bandwidth limit: 1 MB/s

# qemu-img info /var/lib/libvirt/images/demo-new.qed
image: /var/lib/libvirt/images/demo-new.qed
file format: qed
virtual size: 2.0G (2147483648 bytes)
disk size: 21M
cluster_size: 65536
backing file: /var/lib/libvirt/images/demo.qed (actual path: /var/lib/libvirt/images/demo.qed)

# virsh blockjob demo-new /var/lib/libvirt/images/demo-new.qed --abort

# virsh blockjob demo-new /var/lib/libvirt/images/demo-new.qed --info

Comment 17 errata-xmlrpc 2011-12-06 11:20:41 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-2011-1513.html


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