Patchwork Remove debugging messages.

login
register
mail settings
Submitter Richard W.M. Jones
Date July 19, 2011, 7:23 p.m.
Message ID <1311103418-29380-2-git-send-email-rjones@redhat.com>
Download mbox | patch
Permalink /patch/105509/
State New
Headers show

Comments

Richard W.M. Jones - July 19, 2011, 7:23 p.m.
From: "Richard W.M. Jones" <rjones@redhat.com>

When using qemu -machine accel=kvm:tcg, if KVM is not available you
get a load of debugging output:

  Could not access KVM kernel module: No such file or directory
  failed to initialize KVM: No such file or directory
  Back to tcg accelerator.

Signed-off-by: Richard W.M. Jones <rjones@redhat.com>
---
 kvm-all.c |    1 -
 vl.c      |   14 --------------
 2 files changed, 0 insertions(+), 15 deletions(-)
Jan Kiszka - July 19, 2011, 7:47 p.m.
On 2011-07-19 21:23, Richard W.M. Jones wrote:
> From: "Richard W.M. Jones" <rjones@redhat.com>
> 
> When using qemu -machine accel=kvm:tcg, if KVM is not available you
> get a load of debugging output:
> 
>   Could not access KVM kernel module: No such file or directory
>   failed to initialize KVM: No such file or directory
>   Back to tcg accelerator.
> 
> Signed-off-by: Richard W.M. Jones <rjones@redhat.com>
> ---
>  kvm-all.c |    1 -
>  vl.c      |   14 --------------
>  2 files changed, 0 insertions(+), 15 deletions(-)
> 
> diff --git a/kvm-all.c b/kvm-all.c
> index cbc2532..35d698b 100644
> --- a/kvm-all.c
> +++ b/kvm-all.c
> @@ -713,7 +713,6 @@ int kvm_init(void)
>      s->vmfd = -1;
>      s->fd = qemu_open("/dev/kvm", O_RDWR);
>      if (s->fd == -1) {
> -        fprintf(stderr, "Could not access KVM kernel module: %m\n");
>          ret = -errno;
>          goto err;
>      }
> diff --git a/vl.c b/vl.c
> index fcd7395..83a08b6 100644
> --- a/vl.c
> +++ b/vl.c
> @@ -1922,7 +1922,6 @@ static int configure_accelerator(void)
>      char buf[10];
>      int i, ret;
>      bool accel_initalised = 0;
> -    bool init_failed = 0;
>  
>      QemuOptsList *list = qemu_find_opts("machine");
>      if (!QTAILQ_EMPTY(&list->head)) {
> @@ -1944,15 +1943,6 @@ static int configure_accelerator(void)
>                  *(accel_list[i].allowed) = 1;
>                  ret = accel_list[i].init();
>                  if (ret < 0) {
> -                    init_failed = 1;
> -                    if (!accel_list[i].available()) {
> -                        printf("%s not supported for this target\n",
> -                               accel_list[i].name);
> -                    } else {
> -                        fprintf(stderr, "failed to initialize %s: %s\n",
> -                                accel_list[i].name,
> -                                strerror(-ret));
> -                    }
>                      *(accel_list[i].allowed) = 0;
>                  } else {
>                      accel_initalised = 1;
> @@ -1970,10 +1960,6 @@ static int configure_accelerator(void)
>          exit(1);
>      }
>  
> -    if (init_failed) {
> -        fprintf(stderr, "Back to %s accelerator.\n", accel_list[i].name);
> -    }
> -
>      return !accel_initalised;
>  }
>  

I agree the current situation is unfortunate.

However, I think dumping some error information is useful when either no
alternatives were specified or some verbose mode was selected. Maybe add
an option "verbose=on|off" to -machine?

Jan
Michael Tokarev - July 19, 2011, 7:49 p.m.
19.07.2011 23:23, Richard W.M. Jones wrote:
> From: "Richard W.M. Jones" <rjones@redhat.com>
> 
> When using qemu -machine accel=kvm:tcg, if KVM is not available you
> get a load of debugging output:
> 
>   Could not access KVM kernel module: No such file or directory
>   failed to initialize KVM: No such file or directory
>   Back to tcg accelerator.
> 
> Signed-off-by: Richard W.M. Jones <rjones@redhat.com>
> ---
>  kvm-all.c |    1 -
>  vl.c      |   14 --------------
>  2 files changed, 0 insertions(+), 15 deletions(-)
> 
> diff --git a/kvm-all.c b/kvm-all.c
> index cbc2532..35d698b 100644
> --- a/kvm-all.c
> +++ b/kvm-all.c
> @@ -713,7 +713,6 @@ int kvm_init(void)
>      s->vmfd = -1;
>      s->fd = qemu_open("/dev/kvm", O_RDWR);
>      if (s->fd == -1) {
> -        fprintf(stderr, "Could not access KVM kernel module: %m\n");

Don't do this.  qemu error reporting sucks badly already,
and this very error message gives us at least some details
(the %m part) about what's missing.  There's no other place
where this information is printed in case this open fails.
We already have to resort to strace in way too many places... :(

Thanks,

/mjt
Anthony Liguori - July 19, 2011, 8:04 p.m.
On 07/19/2011 02:23 PM, Richard W.M. Jones wrote:
> From: "Richard W.M. Jones"<rjones@redhat.com>
>
> When using qemu -machine accel=kvm:tcg, if KVM is not available you
> get a load of debugging output:
>
>    Could not access KVM kernel module: No such file or directory
>    failed to initialize KVM: No such file or directory
>    Back to tcg accelerator.

If you ask for kvm, and it can't be initialized, then shouldn't we alert 
the user about this?

Regards,

Anthony Liguori

>
> Signed-off-by: Richard W.M. Jones<rjones@redhat.com>
> ---
>   kvm-all.c |    1 -
>   vl.c      |   14 --------------
>   2 files changed, 0 insertions(+), 15 deletions(-)
>
> diff --git a/kvm-all.c b/kvm-all.c
> index cbc2532..35d698b 100644
> --- a/kvm-all.c
> +++ b/kvm-all.c
> @@ -713,7 +713,6 @@ int kvm_init(void)
>       s->vmfd = -1;
>       s->fd = qemu_open("/dev/kvm", O_RDWR);
>       if (s->fd == -1) {
> -        fprintf(stderr, "Could not access KVM kernel module: %m\n");
>           ret = -errno;
>           goto err;
>       }
> diff --git a/vl.c b/vl.c
> index fcd7395..83a08b6 100644
> --- a/vl.c
> +++ b/vl.c
> @@ -1922,7 +1922,6 @@ static int configure_accelerator(void)
>       char buf[10];
>       int i, ret;
>       bool accel_initalised = 0;
> -    bool init_failed = 0;
>
>       QemuOptsList *list = qemu_find_opts("machine");
>       if (!QTAILQ_EMPTY(&list->head)) {
> @@ -1944,15 +1943,6 @@ static int configure_accelerator(void)
>                   *(accel_list[i].allowed) = 1;
>                   ret = accel_list[i].init();
>                   if (ret<  0) {
> -                    init_failed = 1;
> -                    if (!accel_list[i].available()) {
> -                        printf("%s not supported for this target\n",
> -                               accel_list[i].name);
> -                    } else {
> -                        fprintf(stderr, "failed to initialize %s: %s\n",
> -                                accel_list[i].name,
> -                                strerror(-ret));
> -                    }
>                       *(accel_list[i].allowed) = 0;
>                   } else {
>                       accel_initalised = 1;
> @@ -1970,10 +1960,6 @@ static int configure_accelerator(void)
>           exit(1);
>       }
>
> -    if (init_failed) {
> -        fprintf(stderr, "Back to %s accelerator.\n", accel_list[i].name);
> -    }
> -
>       return !accel_initalised;
>   }
>
Richard W.M. Jones - July 19, 2011, 8:50 p.m.
On Tue, Jul 19, 2011 at 11:49:22PM +0400, Michael Tokarev wrote:
> 19.07.2011 23:23, Richard W.M. Jones wrote:
> > From: "Richard W.M. Jones" <rjones@redhat.com>
> > 
> > When using qemu -machine accel=kvm:tcg, if KVM is not available you
> > get a load of debugging output:
> > 
> >   Could not access KVM kernel module: No such file or directory
> >   failed to initialize KVM: No such file or directory
> >   Back to tcg accelerator.
> > 
> > Signed-off-by: Richard W.M. Jones <rjones@redhat.com>
> > ---
> >  kvm-all.c |    1 -
> >  vl.c      |   14 --------------
> >  2 files changed, 0 insertions(+), 15 deletions(-)
> > 
> > diff --git a/kvm-all.c b/kvm-all.c
> > index cbc2532..35d698b 100644
> > --- a/kvm-all.c
> > +++ b/kvm-all.c
> > @@ -713,7 +713,6 @@ int kvm_init(void)
> >      s->vmfd = -1;
> >      s->fd = qemu_open("/dev/kvm", O_RDWR);
> >      if (s->fd == -1) {
> > -        fprintf(stderr, "Could not access KVM kernel module: %m\n");
> 
> Don't do this.  qemu error reporting sucks badly already,
> and this very error message gives us at least some details
> (the %m part) about what's missing.  There's no other place
> where this information is printed in case this open fails.
> We already have to resort to strace in way too many places... :(

This is an argument for having some sort of global --debug option.
Silent by default, but debug messages are a mere runtime flag away.

Rich.
Richard W.M. Jones - July 19, 2011, 8:59 p.m.
On Tue, Jul 19, 2011 at 03:04:22PM -0500, Anthony Liguori wrote:
> On 07/19/2011 02:23 PM, Richard W.M. Jones wrote:
> >From: "Richard W.M. Jones"<rjones@redhat.com>
> >
> >When using qemu -machine accel=kvm:tcg, if KVM is not available you
> >get a load of debugging output:
> >
> >   Could not access KVM kernel module: No such file or directory
> >   failed to initialize KVM: No such file or directory
> >   Back to tcg accelerator.
> 
> If you ask for kvm, and it can't be initialized, then shouldn't we
> alert the user about this?

That's one way to look at it.

Another is that libguestfs has specified that we want a "best effort".
Give me KVM, if available - great!  If not, I don't really care, give
me TCG.

The -machine option isn't expressive enough to say all these things of
course.

BTW, it seems in 0.15 that the -machine option is now required?  eg in
this case where it seems totally pointless:

$ qemu -nographic -device \?
KVM not supported for this target
No accelerator found!

This resulted in another bug and fix in libguestfs.

http://git.annexia.org/?p=libguestfs.git;a=commitdiff;h=d82438431c1551610eb7d9945fa76d6387534582

Rich.
Anthony Liguori - July 19, 2011, 9:56 p.m.
On 07/19/2011 03:59 PM, Richard W.M. Jones wrote:
> On Tue, Jul 19, 2011 at 03:04:22PM -0500, Anthony Liguori wrote:
>> On 07/19/2011 02:23 PM, Richard W.M. Jones wrote:
>>> From: "Richard W.M. Jones"<rjones@redhat.com>
>>>
>>> When using qemu -machine accel=kvm:tcg, if KVM is not available you
>>> get a load of debugging output:
>>>
>>>    Could not access KVM kernel module: No such file or directory
>>>    failed to initialize KVM: No such file or directory
>>>    Back to tcg accelerator.
>>
>> If you ask for kvm, and it can't be initialized, then shouldn't we
>> alert the user about this?
>
> That's one way to look at it.
>
> Another is that libguestfs has specified that we want a "best effort".
> Give me KVM, if available - great!  If not, I don't really care, give
> me TCG.

Can't libguestfs just ignore the messages?

>
> The -machine option isn't expressive enough to say all these things of
> course.
>
> BTW, it seems in 0.15 that the -machine option is now required?  eg in
> this case where it seems totally pointless:
>
> $ qemu -nographic -device \?
> KVM not supported for this target
> No accelerator found!

Hrm, what's your HEAD because mine doesn't exhibit this behavior.

Regards,

Anthony Liguori

>
> This resulted in another bug and fix in libguestfs.
>
> http://git.annexia.org/?p=libguestfs.git;a=commitdiff;h=d82438431c1551610eb7d9945fa76d6387534582
>
> Rich.
>
Richard W.M. Jones - July 20, 2011, 8:50 a.m.
On Tue, Jul 19, 2011 at 04:56:24PM -0500, Anthony Liguori wrote:
> Can't libguestfs just ignore the messages?

It does, but they get printed to stderr which confuses users and has
caused several bug reports in the past.  We'll probably have to
redirect them somewhere.

> >$ qemu -nographic -device \?
> >KVM not supported for this target
> >No accelerator found!
> 
> Hrm, what's your HEAD because mine doesn't exhibit this behavior.

Right.  This seems to be a problem specific to Fedora's package.  I
also can't reproduce it with upstream.

Rich.
Anthony Liguori - July 20, 2011, 12:51 p.m.
On 07/20/2011 03:50 AM, Richard W.M. Jones wrote:
> On Tue, Jul 19, 2011 at 04:56:24PM -0500, Anthony Liguori wrote:
>> Can't libguestfs just ignore the messages?
>
> It does, but they get printed to stderr which confuses users and has
> caused several bug reports in the past.  We'll probably have to
> redirect them somewhere.

Given the large number of reports we've gotten in the past where poor 
performance was caused by the expectation that a user had KVM enabled 
and really didn't, I think it's more important to overcommunicate to the 
user here.

If in the case of libguestfs, you think this isn't something a user 
should worry about, you can just filter out the message before it hits 
stderr.

Regards,

Anthony Liguori

>
>>> $ qemu -nographic -device \?
>>> KVM not supported for this target
>>> No accelerator found!
>>
>> Hrm, what's your HEAD because mine doesn't exhibit this behavior.
>
> Right.  This seems to be a problem specific to Fedora's package.  I
> also can't reproduce it with upstream.
>
> Rich.
>
Richard W.M. Jones - July 20, 2011, 5:38 p.m.
On Wed, Jul 20, 2011 at 07:51:29AM -0500, Anthony Liguori wrote:
> Given the large number of reports we've gotten in the past where
> poor performance was caused by the expectation that a user had KVM
> enabled and really didn't, I think it's more important to
> overcommunicate to the user here.
> 
> If in the case of libguestfs, you think this isn't something a user
> should worry about, you can just filter out the message before it
> hits stderr.

That's what we're now doing.

But what's the rationale here?  For instance, qemu 0.15 is also
printing:

  qemu: terminating on signal 15 from pid 9617

which I guess is interesting, but unlikely to be useful for users.

Is qemu now noisy by default?  Is any old debug message that a user
might find interesting fair game?

Rich.

Patch

diff --git a/kvm-all.c b/kvm-all.c
index cbc2532..35d698b 100644
--- a/kvm-all.c
+++ b/kvm-all.c
@@ -713,7 +713,6 @@  int kvm_init(void)
     s->vmfd = -1;
     s->fd = qemu_open("/dev/kvm", O_RDWR);
     if (s->fd == -1) {
-        fprintf(stderr, "Could not access KVM kernel module: %m\n");
         ret = -errno;
         goto err;
     }
diff --git a/vl.c b/vl.c
index fcd7395..83a08b6 100644
--- a/vl.c
+++ b/vl.c
@@ -1922,7 +1922,6 @@  static int configure_accelerator(void)
     char buf[10];
     int i, ret;
     bool accel_initalised = 0;
-    bool init_failed = 0;
 
     QemuOptsList *list = qemu_find_opts("machine");
     if (!QTAILQ_EMPTY(&list->head)) {
@@ -1944,15 +1943,6 @@  static int configure_accelerator(void)
                 *(accel_list[i].allowed) = 1;
                 ret = accel_list[i].init();
                 if (ret < 0) {
-                    init_failed = 1;
-                    if (!accel_list[i].available()) {
-                        printf("%s not supported for this target\n",
-                               accel_list[i].name);
-                    } else {
-                        fprintf(stderr, "failed to initialize %s: %s\n",
-                                accel_list[i].name,
-                                strerror(-ret));
-                    }
                     *(accel_list[i].allowed) = 0;
                 } else {
                     accel_initalised = 1;
@@ -1970,10 +1960,6 @@  static int configure_accelerator(void)
         exit(1);
     }
 
-    if (init_failed) {
-        fprintf(stderr, "Back to %s accelerator.\n", accel_list[i].name);
-    }
-
     return !accel_initalised;
 }