Bug 603266 - qemu should mention reason for chardev open failure
qemu should mention reason for chardev open failure
Status: CLOSED CURRENTRELEASE
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: qemu-kvm (Show other bugs)
7.0
All Linux
low Severity medium
: pre-dev-freeze
: 7.0
Assigned To: Laszlo Ersek
Virtualization Bugs
:
Depends On:
Blocks: 580953
  Show dependency treegraph
 
Reported: 2010-06-12 02:01 EDT by Nan Zhang
Modified: 2016-04-26 10:56 EDT (History)
13 users (show)

See Also:
Fixed In Version: qemu-kvm-1.5.3-11.el7
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2014-09-10 09:23:35 EDT
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Nan Zhang 2010-06-12 02:01:57 EDT
Description of problem:
As subject.

Version-Release number of selected component (if applicable):
libvirt-0.8.1-8.el6.x86_64

How reproducible:
Always

Steps to Reproduce:
# touch /tmp/demo.log

# virsh start demo
error: Failed to start domain demo
error: internal error Process exited while reading console log output: chardev: opening backend "file" failed

# virsh dumpxml demo
------ snip ------
    <serial type='file'>
      <source path='/tmp/demo.log'/>
      <target port='0'/>
    </serial>
    <console type='file'>
      <source path='/tmp/demo.log'/>
      <target port='0'/>
    </console>

Actual results:
Fail to boot up.

Expected results:
Guest can be boot up.

Additional info:
Comment 2 RHEL Product and Program Management 2010-06-12 02:32:55 EDT
This request was evaluated by Red Hat Product Management for inclusion in a Red
Hat Enterprise Linux major release.  Product Management has requested further
review of this request by Red Hat Engineering, for potential inclusion in a Red
Hat Enterprise Linux Major release.  This request is not yet committed for
inclusion.
Comment 3 Jiri Denemark 2010-06-16 14:22:11 EDT
The error message from qemu is quite cryptic since it doesn't give us the reason for this failure. However, the behavior is expected since qemu is run under qemu user while you created that file as root. Since qemu is not allowed to write to such file, it fails to start.

If you don't express any disagreement, I'll close this as not a bug soon. Or perhaps we could move this bug to qemu to improve the error message.
Comment 4 Nan Zhang 2010-06-16 22:16:46 EDT
I think if there is a specified file exists, the contents of log file should be replaced with new console output. If you think it's qemu issue, could move it to qemu. Thanks
Comment 5 Dave Allan 2010-06-17 18:35:47 EDT
Moving to qemu; we should get a reason for the failure, but otherwise I agree that this is expected behavior.
Comment 6 Nan Zhang 2010-06-17 22:31:37 EDT
# rpm -q qemu-kvm
qemu-kvm-0.12.1.2-2.77.el6.x86_64

# ls -l /tmp/demo.log
-rw-r--r--. 1 qemu qemu 0 Jun 17 22:20 /tmp/demo.log

# LIBVIRT_DEBUG=1 virsh start demo
------ snip ------
22:24:59.416: debug : virDomainLookupByName:2127 : conn=0xe98f40, name=demo
22:24:59.416: debug : remoteIO:9748 : Do proc=23 serial=3 length=36 wait=(nil)
22:24:59.416: debug : remoteIO:9823 : We have the buck 23 0xe9c570 0xe9c570
22:24:59.416: debug : remoteIODecodeMessageLength:9179 : Got length, now need 84 total (80 more)
22:24:59.416: debug : remoteIOEventLoop:9674 : Giving up the buck 23 0xe9c570 (nil)
22:24:59.416: debug : remoteIO:9854 : All done with our call 23 (nil) 0xe9c570
22:24:59.416: debug : virGetDomain:383 : New hash entry 0xe98580
22:24:59.416: debug : virDomainGetID:2775 : domain=0xe98580
22:24:59.416: debug : virDomainCreate:4863 : domain=0xe98580
22:24:59.416: debug : remoteIO:9748 : Do proc=9 serial=4 length=56 wait=(nil)
22:24:59.416: debug : remoteIO:9823 : We have the buck 9 0xe9c800 0xe9c800
22:24:59.746: debug : remoteIODecodeMessageLength:9179 : Got length, now need 296 total (292 more)
22:24:59.747: debug : remoteIOEventLoop:9674 : Giving up the buck 9 0xe9c800 (nil)
22:24:59.747: debug : remoteIO:9854 : All done with our call 9 (nil) 0xe9c800
22:24:59.747: debug : virDomainGetName:2681 : domain=0xe98580
error: Failed to start domain demo
22:24:59.747: debug : virDomainFree:2215 : domain=0xe98580
22:24:59.747: debug : virUnrefDomain:462 : unref domain 0xe98580 demo 1
22:24:59.747: debug : virReleaseDomain:414 : release domain 0xe98580 demo
22:24:59.747: debug : virReleaseDomain:432 : unref connection 0xe98f40 2
error: internal error Process exited while reading console log output: chardev: opening backend "file" failed


22:24:59.747: debug : virConnectClose:1497 : conn=0xe98f40
22:24:59.747: debug : virUnrefConnect:294 : unref connection 0xe98f40 1
22:24:59.747: debug : remoteIO:9748 : Do proc=2 serial=5 length=28 wait=(nil)
22:24:59.747: debug : remoteIO:9823 : We have the buck 2 0xe9c870 0xe9c870
22:24:59.748: debug : remoteIODecodeMessageLength:9179 : Got length, now need 56 total (52 more)
22:24:59.748: debug : remoteIOEventLoop:9674 : Giving up the buck 2 0xe9c870 (nil)
22:24:59.748: debug : remoteIO:9854 : All done with our call 2 (nil) 0xe9c870
22:24:59.748: debug : virReleaseConnect:249 : release connection 0xe98f40
Comment 7 Jiri Denemark 2010-06-18 12:15:19 EDT
As Daniel pointed, ideally libvirt would be pre-creating those files with appropriate ownership and selinux label, which gets complicated with stuff like root-squashed nfs so it seems more like a longer term goal... I'll file a separate bug to track it.
Comment 8 Daniel Berrange 2010-06-23 08:13:57 EDT
FYI getting libvirt to pre-create and set selinux labels on serial log files is being tracked in https://bugzilla.redhat.com/show_bug.cgi?id=585249
Comment 9 Jiri Denemark 2010-06-23 08:40:36 EDT
Ah, I didn't notice it existed... I closed the BZ I created as a duplicate of the older one.
Comment 10 RHEL Product and Program Management 2010-07-15 10:33:36 EDT
This issue has been proposed when we are only considering blocker
issues in the current Red Hat Enterprise Linux release. It has
been denied for the current Red Hat Enterprise Linux release.

** If you would still like this issue considered for the current
release, ask your support representative to file as a blocker on
your behalf. Otherwise ask that it be considered for the next
Red Hat Enterprise Linux release. **
Comment 17 Markus Armbruster 2012-02-10 07:55:39 EST
Upstream fix posted http://lists.nongnu.org/archive/html/qemu-devel/2012-02/msg00714.html

Let's hope it gets accepted.
Comment 22 Luiz Capitulino 2012-07-17 10:17:26 EDT
I took a look at Markus's series and here are my thoughts.

For upstream, making chardev open use error_set() shouldn't be difficult, as most errors are open() failures. It might get a little more difficult to report the sockets errors correctly, but it's all doable and I can work on that.

Now, I'm not sure how difficult it would be to backport this to 6.4. That series is going to touch a lot of code and it might depend on errors infra bits that haven't been backported yet. This can double the effort to fix this downstream.

My advice to this bz is to move it to 7.0.
Comment 28 Laszlo Ersek 2014-09-10 06:45:46 EDT
This bug has been mostly addressed in upstream, meanwhile. There are now two ways to create chardevs in qemu, the QAPI way and the legacy way.

typedef struct CharDriver {
    const char *name;
    /* old, pre qapi */
    CharDriverState *(*open)(QemuOpts *opts);
    /* new, qapi-based */
    ChardevBackendKind kind;
    void (*parse)(QemuOpts *opts, ChardevBackend *backend, Error **errp);
} CharDriver;


The QAPI way has builtin error propagation support. Such chardev drivers are registered with register_char_driver_qapi(), and the parse() member function that is set up with the register_char_driver_qapi()() call has an "Error **errp" parameter.

The function qemu_chr_new_from_opts() -- which looks like the main entry point for creating chardev *instances* -- uses the chardev type's parse() member (ie. the new API) when open() (ie. the old API) is absent. When using parse(), errors are propagated nicely. For example:

  touch testfile
  chmod a-w testfile
  /usr/libexec/qemu-kvm -chardev file,id=f0,path=testfile

qemu-kvm: -chardev file,id=f0,path=testfile: Could not open 'testfile': Permission denied

(Tested with qemu-kvm-1.5.3-69.el7.x86_64.)

So, we need to look for chardev types that still use the old API -- those aren't registered with register_char_driver_qapi() but with register_char_driver().

I can find two callers:

qemu-char.c:    register_char_driver("socket", qemu_chr_open_socket);
qemu-char.c:    register_char_driver("udp", qemu_chr_open_udp);

Both qemu_chr_open_socket() and qemu_chr_open_udp() already handle Errors internally. They correctly collect errors propagated up to them, and then deal with them locally, because the open() interface cannot propagate the error further.
Comment 29 Laszlo Ersek 2014-09-10 09:23:35 EDT
In addition, the "local way" that both qemu_chr_open_socket() and qemu_chr_open_udp() deal with the errors that have been propagated to them, is a call to qerror_report_err(). Which means that the error will be reported through the monitor.

commit 87d5f24f3f5edc4b69d071d5966cea0aec7b571d
Author: Paolo Bonzini <pbonzini@redhat.com>
Date:   Tue Oct 2 09:16:49 2012 +0200

    qemu-char: ask and print error information from qemu-sockets

commit 58a3714c529b1b97ee078ea25b58f731aabcbfff
Author: Gerd Hoffmann <kraxel@redhat.com>
Date:   Mon Jun 24 08:39:55 2013 +0200

    qemu-char: report udp backend errors

RHEL-7.0 contains both patches. The first fix is part of upstream v1.3.0. The second fix has been released in upstream v1.6.0, but it also has been cherry-picked to RHEL, as RHEL-7 commit ecf98a56 (for bug 922010).

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