Bug 995887 - gnome-boxes is not reporting the qemu error message
gnome-boxes is not reporting the qemu error message
Status: CLOSED EOL
Product: Fedora
Classification: Fedora
Component: gnome-boxes (Show other bugs)
20
Unspecified Unspecified
unspecified Severity unspecified
: ---
: ---
Assigned To: Christophe Fergeau
Fedora Extras Quality Assurance
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2013-08-11 16:23 EDT by František Zatloukal
Modified: 2015-06-29 08:16 EDT (History)
6 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2015-06-29 08:16:14 EDT
Type: Bug
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 František Zatloukal 2013-08-11 16:23:17 EDT
Description of problem:
gnome-boxes is not reporting the qemu error message

Version-Release number of selected component (if applicable):
gnome-boxes-3.9.3-4.fc20.x86_64

How reproducible:
Always

Steps to Reproduce:
1.Run Gnome Boxes
2.Simulate some error[1]

Actual results:
Gnome Boxes simply outputs "Box creation failed", so it is very difficult to do the debugging.

Expected results:
Full report of qemu error(at least when opened in terminal).

Additional info:
[1] https://bugzilla.redhat.com/show_bug.cgi?id=993423
Comment 1 Christophe Fergeau 2013-08-12 06:19:15 EDT
For what it's worth, gnome-boxes is not directly interacting with qemu, it's libvirt which takes care of invoking qemu-img, qemu-system-x86_64, ... for us, so if this output does not appear in libvirt log, then such changes probably belong to libvirt.
Comment 2 Steve Tyler 2013-08-12 06:36:30 EDT
Thanks for pointing that out. When gnome-boxes is run from the command-line, any qemu error message should be displayed in the terminal session and be written to a log file. How does gnome-boxes handle libvirt exceptions? Can gnome-boxes get error messages from libvirt?
Comment 3 Christophe Fergeau 2013-08-12 09:40:14 EDT
Boxes did show the error from libvirt:
"Terminal output: (gnome-boxes:17395): Boxes-WARNING **: wizard.vala:382: Failed to create volume: internal error: unable to parse qemu-img output ''"
Dunno if libvirt shows the qemu output in its log.
Comment 4 Steve Tyler 2013-08-12 11:04:45 EDT
OK, thanks. Then the annotation is misleading, because the string says:

"gnome-boxes:17395"
"Boxes-WARNING"

And "wizard.vala:382" is gnome-boxes code:[1]

$ less -N gnome-boxes-3.9.3/src/wizard.vala
...
    364     private async bool do_review_cancellable () {
    365         return_if_fail (review_cancellable != null);
    366 
    367         nokvm_label.hide ();
    368         summary.clear ();
    369 
    370         if (source != null) {
    371             try {
    372                 machine = new RemoteMachine (source);
    373             } catch (Boxes.Error error) {
    374                 warning (error.message);
    375             }
    376         } else if (vm_creator != null && libvirt_machine == null) {
    377             try {
    378                 machine = yield vm_creator.create_vm (review_cancellable);
    379             } catch (IOError.CANCELLED cancel_error) { // We did this, so ignore!
    380             } catch (GLib.Error error) {
    381                 App.app.notificationbar.display_error (_("Box setup failed"));
    382                 warning (error.message);
    383             }
    384 
    385             if (libvirt_machine == null) {
    386                 // notify the VM creation failed
    387                 notify_property ("machine");
    388                 return false;
    389             }
    390         }
...

[1] gnome-boxes source downloaded from here:
http://ftp.gnome.org/pub/GNOME/sources/gnome-boxes/3.9/
Comment 5 Steve Tyler 2013-08-12 11:48:23 EDT
... unable to parse qemu-img output ''" ...
                                    ^^
The message appears to be reporting a string in quotes that is empty ...
Comment 6 Christophe Fergeau 2013-08-12 11:52:11 EDT
(In reply to Steve Tyler from comment #5)
> ... unable to parse qemu-img output ''" ...
>                                     ^^
> The message appears to be reporting a string in quotes that is empty ...

qemu-img stdout was probably empty given it couldn't be started at all.
Comment 7 Steve Tyler 2013-08-12 11:59:19 EDT
Right: Bug 993423, Comment 16(In reply to Christophe Fergeau from comment #6)
> (In reply to Steve Tyler from comment #5)
> > ... unable to parse qemu-img output ''" ...
> >                                     ^^
> > The message appears to be reporting a string in quotes that is empty ...
> 
> qemu-img stdout was probably empty given it couldn't be started at all.

Confirmed in Bug 993423, Comment 19.
Comment 8 Steve Tyler 2013-08-12 12:29:36 EDT
Line 610 of storage_backend.c in the libvirt source appears to be the origin of the error message.[1]

The code is validating the qemu-img command with "qemu-img -h".

$ less -N ./libvirt-1.1.1/src/storage/storage_backend.c
...
    586 static int
    587 virStorageBackendQEMUImgBackingFormat(const char *qemuimg)
    588 {
...
    595     virCommandPtr cmd = virCommandNewArgList(qemuimg, "-h", NULL);
...
    607     if ((start = strstr(help, " create ")) == NULL ||
    608         (end = strstr(start, "\n")) == NULL) {
    609         virReportError(VIR_ERR_INTERNAL_ERROR,
    610                        _("unable to parse qemu-img output '%s'"),
    611                        help);
    612         goto cleanup;
    613     }
...
    626 }

[1] Source URL is from:
$ sudo repoquery --arch=src libvirt --repoid=fedora-source --releasever=rawhide --location
Extract with:
$ cat libvirt-1.1.1-1.fc20.src.rpm | rpm2cpio | cpio -i
Comment 9 Christophe Fergeau 2013-08-12 12:37:59 EDT
Seems like the virCommandRun call should report failure in this case, and that this is not happening .
Comment 10 Steve Tyler 2013-08-12 12:51:16 EDT
This attempts to reproduce what libvirt does to validate the gemu-img command. The results are the same -- qemu-img writes an error message to stderr:

$ qemu-img -h
qemu-img: symbol lookup error: qemu-img: undefined symbol: rbd_aio_flush
$ qemu-img -h 2>/dev/null
$ rpm -q qemu-img ceph-libs
qemu-img-1.5.2-4.fc20.x86_64
ceph-libs-0.56.4-1.fc20.x86_64
Comment 11 Steve Tyler 2013-08-12 13:10:38 EDT
ISTM, there is enough information to justify changing the bug component to "libvirt" with a modified bug summary:

"libvirt is not reporting the qemu error message on stderr to gnome-boxes"
Comment 12 Steve Tyler 2013-08-12 13:57:31 EDT
(In reply to Christophe Fergeau from comment #9)
> Seems like the virCommandRun call should report failure in this case, and
> that this is not happening .

Thanks for referring to virCommandRun. The comments suggest that virCommandRun is designed to capture stderr and possibly log it:

$ cat -n libvirt-1.1.1/src/util/vircommand.c | gedit -
...
  2017	virCommandRun(virCommandPtr cmd, int *exitstatus)
  2018	{
...
  2066	
  2067	    /* If caller requested the same string for stdout and stderr, then
  2068	     * merge those into one string.  */
  2069	    if (cmd->outbuf && cmd->outbuf == cmd->errbuf) {
  2070	        cmd->errfdptr = &cmd->outfd;
  2071	        cmd->errbuf = NULL;
  2072	    }
  2073	
  2074	    /* If caller hasn't requested capture of stdout/err, then capture
  2075	     * it ourselves so we can log it.  But the intermediate child for
  2076	     * a daemon has no expected output, and we don't want our
  2077	     * capturing pipes passed on to the daemon grandchild.
  2078	     */
...
  2135	    return ret;
  2136	}
...
Comment 13 Steve Tyler 2013-08-12 14:22:59 EDT
(In reply to Steve Tyler from comment #4)
...
> $ less -N gnome-boxes-3.9.3/src/wizard.vala
...

BTW, I hadn't heard of Vala before.
Vala looks like very nice language to work in:
"Exception Handling: try, catch, finally, throw"
https://wiki.gnome.org/Vala/Syntax
Comment 14 Steve Tyler 2013-08-12 16:47:21 EDT
(In reply to Steve Tyler from comment #4)
> OK, thanks. Then the annotation is misleading, because the string says:
> 
> "gnome-boxes:17395"
> "Boxes-WARNING"
> 
> And "wizard.vala:382" is gnome-boxes code:[1]
...

In fact, the "wizard.vala:382" string is constructed by the vala compiler:

$ less -N wizard.c
...
   3369 g_warning ("wizard.vala:382: %s", _data_->_tmp26_);
...
Comment 15 Steve Tyler 2013-08-12 22:11:54 EDT
Fault injection can be used to reproduce the problem by replacing qemu-img with a shell script that writes a message to stderr and exits with code 1.

$ ll /usr/bin/qemu-img*
-rwxr-xr-x. 1 root root     50 Aug 12 18:45 /usr/bin/qemu-img*
-rwxr-xr-x. 1 root root 657432 Jul 30 07:11 /usr/bin/qemu-img.ORIG*

$ cat /usr/bin/qemu-img
#!/bin/bash
echo "$0: failed" >/dev/stderr
exit 1

$ /usr/bin/qemu-img
/usr/bin/qemu-img: failed

$ gnome-boxes

(gnome-boxes:3404): Boxes-WARNING **: wizard.vala:382: Failed to create volume: internal error unable to parse qemu-img output ''

The gnome-boxes GUI displays: "Box setup failed".

There is no error message from the fake qemu-img in the libvirt log file:
$ grep failed ~/.cache/libvirt/qemu/log/*
$

Tested with:
$ rpm -q gnome-boxes libvirt
gnome-boxes-3.8.3-1.fc19.x86_64
libvirt-1.0.5.5-1.fc19.x86_64
Comment 16 Steve Tyler 2013-08-12 22:35:03 EDT
(In reply to Steve Tyler from comment #15)
...
> There is no error message from the fake qemu-img in the libvirt log file:
> $ grep failed ~/.cache/libvirt/qemu/log/*
> $
...

Actually, no log file is written at all. The only log files in
~/.cache/libvirt/qemu/log/
are from previous test runs of gnome-boxes.
Comment 17 Fedora End Of Life 2013-09-16 12:30:14 EDT
This bug appears to have been reported against 'rawhide' during the Fedora 20 development cycle.
Changing version to '20'.

More information and reason for this action is here:
https://fedoraproject.org/wiki/BugZappers/HouseKeeping/Fedora20
Comment 18 Fedora End Of Life 2015-05-29 05:18:55 EDT
This message is a reminder that Fedora 20 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 20. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as EOL if it remains open with a Fedora  'version'
of '20'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 20 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.
Comment 19 Fedora End Of Life 2015-06-29 08:16:14 EDT
Fedora 20 changed to end-of-life (EOL) status on 2015-06-23. Fedora 20 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.

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