diff mbox

log: Redirect stderr to logfile if deamonized

Message ID 1455795518-19205-1-git-send-email-dimara@arrikto.com (mailing list archive)
State New, archived
Headers show

Commit Message

Dimitris Aragiorgis Feb. 18, 2016, 11:38 a.m. UTC
In case of daemonize, use the logfile passed with the -D option in
order to redirect stderr to it instead of /dev/null.

Also remove some unused code in log.h.

Signed-off-by: Dimitris Aragiorgis <dimara@arrikto.com>
---
 include/qemu/log.h |    6 ------
 os-posix.c         |    6 +++++-
 util/log.c         |   11 +++++++++--
 3 files changed, 14 insertions(+), 9 deletions(-)

Comments

Paolo Bonzini Feb. 18, 2016, 3:22 p.m. UTC | #1
On 18/02/2016 12:38, Dimitris Aragiorgis wrote:
> In case of daemonize, use the logfile passed with the -D option in
> order to redirect stderr to it instead of /dev/null.
> 
> Also remove some unused code in log.h.
> 
> Signed-off-by: Dimitris Aragiorgis <dimara@arrikto.com>
> ---
>  include/qemu/log.h |    6 ------
>  os-posix.c         |    6 +++++-
>  util/log.c         |   11 +++++++++--
>  3 files changed, 14 insertions(+), 9 deletions(-)
> 
> diff --git a/include/qemu/log.h b/include/qemu/log.h
> index 30817f7..dda65fd 100644
> --- a/include/qemu/log.h
> +++ b/include/qemu/log.h
> @@ -94,12 +94,6 @@ static inline void qemu_log_close(void)
>      }
>  }
>  
> -/* Set up a new log file */
> -static inline void qemu_log_set_file(FILE *f)
> -{
> -    qemu_logfile = f;
> -}
> -
>  /* define log items */
>  typedef struct QEMULogItem {
>      int mask;
> diff --git a/os-posix.c b/os-posix.c
> index cce62ed..92fa3ba 100644
> --- a/os-posix.c
> +++ b/os-posix.c
> @@ -37,6 +37,7 @@
>  #include "qemu-options.h"
>  #include "qemu/rcu.h"
>  #include "qemu/error-report.h"
> +#include "qemu/log.h"
>  
>  #ifdef CONFIG_LINUX
>  #include <sys/prctl.h>
> @@ -275,7 +276,10 @@ void os_setup_post(void)
>  
>          dup2(fd, 0);
>          dup2(fd, 1);
> -        dup2(fd, 2);
> +        /* In case -D is given do not redirect stderr to /dev/null */
> +        if (!qemu_logfile) {
> +            dup2(fd, 2);
> +        }
>  
>          close(fd);
>  
> diff --git a/util/log.c b/util/log.c
> index 2709e98..a7ddc7e 100644
> --- a/util/log.c
> +++ b/util/log.c
> @@ -56,13 +56,20 @@ void do_qemu_set_log(int log_flags, bool use_own_buffers)
>  #ifdef CONFIG_TRACE_LOG
>      qemu_loglevel |= LOG_TRACE;
>  #endif
> -    if (qemu_loglevel && !qemu_logfile) {
> +    if ((qemu_loglevel || is_daemonized()) && !qemu_logfile) {
>          if (logfilename) {
>              qemu_logfile = fopen(logfilename, log_append ? "a" : "w");
>              if (!qemu_logfile) {
>                  perror(logfilename);
>                  _exit(1);
>              }
> +            /* In case we are a daemon redirect stderr to logfile */
> +            if (is_daemonized()) {
> +                dup2(fileno(qemu_logfile), STDERR_FILENO);
> +                fclose(qemu_logfile);
> +                /* This will skip closing logfile in qemu_log_close() */
> +                qemu_logfile = stderr;
> +            }
>          } else {
>              /* Default to stderr if no log file specified */
>              qemu_logfile = stderr;
> @@ -82,7 +89,7 @@ void do_qemu_set_log(int log_flags, bool use_own_buffers)
>              log_append = 1;
>          }
>      }
> -    if (!qemu_loglevel && qemu_logfile) {
> +    if (!qemu_loglevel && !is_daemonized() && qemu_logfile) {
>          qemu_log_close();
>      }

Why is this necessary?  Perhaps qemu_log_close should dup(1,2) if QEMU
is daemonized.  The rest looks great.

Paolo
Dimitris Aragiorgis Feb. 18, 2016, 5:12 p.m. UTC | #2
* Paolo Bonzini <pbonzini@redhat.com> [2016-02-18 16:22:13 +0100]:

> 
> 
> On 18/02/2016 12:38, Dimitris Aragiorgis wrote:
> > In case of daemonize, use the logfile passed with the -D option in
> > order to redirect stderr to it instead of /dev/null.
> > 
> > Also remove some unused code in log.h.
> > 
> > Signed-off-by: Dimitris Aragiorgis <dimara@arrikto.com>
> > ---
> >  include/qemu/log.h |    6 ------
> >  os-posix.c         |    6 +++++-
> >  util/log.c         |   11 +++++++++--
> >  3 files changed, 14 insertions(+), 9 deletions(-)
> > 
> > diff --git a/include/qemu/log.h b/include/qemu/log.h
> > index 30817f7..dda65fd 100644
> > --- a/include/qemu/log.h
> > +++ b/include/qemu/log.h
> > @@ -94,12 +94,6 @@ static inline void qemu_log_close(void)
> >      }
> >  }
> >  
> > -/* Set up a new log file */
> > -static inline void qemu_log_set_file(FILE *f)
> > -{
> > -    qemu_logfile = f;
> > -}
> > -
> >  /* define log items */
> >  typedef struct QEMULogItem {
> >      int mask;
> > diff --git a/os-posix.c b/os-posix.c
> > index cce62ed..92fa3ba 100644
> > --- a/os-posix.c
> > +++ b/os-posix.c
> > @@ -37,6 +37,7 @@
> >  #include "qemu-options.h"
> >  #include "qemu/rcu.h"
> >  #include "qemu/error-report.h"
> > +#include "qemu/log.h"
> >  
> >  #ifdef CONFIG_LINUX
> >  #include <sys/prctl.h>
> > @@ -275,7 +276,10 @@ void os_setup_post(void)
> >  
> >          dup2(fd, 0);
> >          dup2(fd, 1);
> > -        dup2(fd, 2);
> > +        /* In case -D is given do not redirect stderr to /dev/null */
> > +        if (!qemu_logfile) {
> > +            dup2(fd, 2);
> > +        }
> >  
> >          close(fd);
> >  
> > diff --git a/util/log.c b/util/log.c
> > index 2709e98..a7ddc7e 100644
> > --- a/util/log.c
> > +++ b/util/log.c
> > @@ -56,13 +56,20 @@ void do_qemu_set_log(int log_flags, bool use_own_buffers)
> >  #ifdef CONFIG_TRACE_LOG
> >      qemu_loglevel |= LOG_TRACE;
> >  #endif
> > -    if (qemu_loglevel && !qemu_logfile) {
> > +    if ((qemu_loglevel || is_daemonized()) && !qemu_logfile) {
> >          if (logfilename) {
> >              qemu_logfile = fopen(logfilename, log_append ? "a" : "w");
> >              if (!qemu_logfile) {
> >                  perror(logfilename);
> >                  _exit(1);
> >              }
> > +            /* In case we are a daemon redirect stderr to logfile */
> > +            if (is_daemonized()) {
> > +                dup2(fileno(qemu_logfile), STDERR_FILENO);
> > +                fclose(qemu_logfile);
> > +                /* This will skip closing logfile in qemu_log_close() */
> > +                qemu_logfile = stderr;
> > +            }
> >          } else {
> >              /* Default to stderr if no log file specified */
> >              qemu_logfile = stderr;
> > @@ -82,7 +89,7 @@ void do_qemu_set_log(int log_flags, bool use_own_buffers)
> >              log_append = 1;
> >          }
> >      }
> > -    if (!qemu_loglevel && qemu_logfile) {
> > +    if (!qemu_loglevel && !is_daemonized() && qemu_logfile) {
> >          qemu_log_close();
> >      }
> 
> Why is this necessary?  Perhaps qemu_log_close should dup(1,2) if QEMU
> is daemonized.  The rest looks great.
> 

Without !is_daemonized(), if we use -daemon with -D without -d,
qemu_log_close() will eventually set qemu_logfile to NULL. This
will make os_setup_post() redirect stderr to /dev/null, which
is unwanted.

To be honest, I don't understand your suggestion. How would calling
dup2(1, 2) help in our case? Isn't fd 1 the standard output?

Thanks,
dimara

> Paolo
Paolo Bonzini Feb. 19, 2016, 5:25 p.m. UTC | #3
On 18/02/2016 18:12, Dimitris Aragiorgis wrote:
> * Paolo Bonzini <pbonzini@redhat.com> [2016-02-18 16:22:13 +0100]:
> 
>>
>>
>> On 18/02/2016 12:38, Dimitris Aragiorgis wrote:
>>> In case of daemonize, use the logfile passed with the -D option in
>>> order to redirect stderr to it instead of /dev/null.
>>>
>>> Also remove some unused code in log.h.
>>>
>>> Signed-off-by: Dimitris Aragiorgis <dimara@arrikto.com>
>>> ---
>>>  include/qemu/log.h |    6 ------
>>>  os-posix.c         |    6 +++++-
>>>  util/log.c         |   11 +++++++++--
>>>  3 files changed, 14 insertions(+), 9 deletions(-)
>>>
>>> diff --git a/include/qemu/log.h b/include/qemu/log.h
>>> index 30817f7..dda65fd 100644
>>> --- a/include/qemu/log.h
>>> +++ b/include/qemu/log.h
>>> @@ -94,12 +94,6 @@ static inline void qemu_log_close(void)
>>>      }
>>>  }
>>>  
>>> -/* Set up a new log file */
>>> -static inline void qemu_log_set_file(FILE *f)
>>> -{
>>> -    qemu_logfile = f;
>>> -}
>>> -
>>>  /* define log items */
>>>  typedef struct QEMULogItem {
>>>      int mask;
>>> diff --git a/os-posix.c b/os-posix.c
>>> index cce62ed..92fa3ba 100644
>>> --- a/os-posix.c
>>> +++ b/os-posix.c
>>> @@ -37,6 +37,7 @@
>>>  #include "qemu-options.h"
>>>  #include "qemu/rcu.h"
>>>  #include "qemu/error-report.h"
>>> +#include "qemu/log.h"
>>>  
>>>  #ifdef CONFIG_LINUX
>>>  #include <sys/prctl.h>
>>> @@ -275,7 +276,10 @@ void os_setup_post(void)
>>>  
>>>          dup2(fd, 0);
>>>          dup2(fd, 1);
>>> -        dup2(fd, 2);
>>> +        /* In case -D is given do not redirect stderr to /dev/null */
>>> +        if (!qemu_logfile) {
>>> +            dup2(fd, 2);
>>> +        }
>>>  
>>>          close(fd);
>>>  
>>> diff --git a/util/log.c b/util/log.c
>>> index 2709e98..a7ddc7e 100644
>>> --- a/util/log.c
>>> +++ b/util/log.c
>>> @@ -56,13 +56,20 @@ void do_qemu_set_log(int log_flags, bool use_own_buffers)
>>>  #ifdef CONFIG_TRACE_LOG
>>>      qemu_loglevel |= LOG_TRACE;
>>>  #endif
>>> -    if (qemu_loglevel && !qemu_logfile) {
>>> +    if ((qemu_loglevel || is_daemonized()) && !qemu_logfile) {
>>>          if (logfilename) {
>>>              qemu_logfile = fopen(logfilename, log_append ? "a" : "w");
>>>              if (!qemu_logfile) {
>>>                  perror(logfilename);
>>>                  _exit(1);
>>>              }
>>> +            /* In case we are a daemon redirect stderr to logfile */
>>> +            if (is_daemonized()) {
>>> +                dup2(fileno(qemu_logfile), STDERR_FILENO);
>>> +                fclose(qemu_logfile);
>>> +                /* This will skip closing logfile in qemu_log_close() */
>>> +                qemu_logfile = stderr;
>>> +            }
>>>          } else {
>>>              /* Default to stderr if no log file specified */
>>>              qemu_logfile = stderr;
>>> @@ -82,7 +89,7 @@ void do_qemu_set_log(int log_flags, bool use_own_buffers)
>>>              log_append = 1;
>>>          }
>>>      }
>>> -    if (!qemu_loglevel && qemu_logfile) {
>>> +    if (!qemu_loglevel && !is_daemonized() && qemu_logfile) {
>>>          qemu_log_close();
>>>      }
>>
>> Why is this necessary?  Perhaps qemu_log_close should dup(1,2) if QEMU
>> is daemonized.  The rest looks great.
>>
> 
> Without !is_daemonized(), if we use -daemon with -D without -d,
> qemu_log_close() will eventually set qemu_logfile to NULL. This
> will make os_setup_post() redirect stderr to /dev/null, which
> is unwanted.

Sorry, I missed the context of this hunk.  The patch is okay, thanks for
putting up with me!

Paolo
Gerd Hoffmann March 1, 2016, 11:15 a.m. UTC | #4
On Do, 2016-02-18 at 13:38 +0200, Dimitris Aragiorgis wrote:
> In case of daemonize, use the logfile passed with the -D option in
> order to redirect stderr to it instead of /dev/null.
> 
> Also remove some unused code in log.h.

Patch breaks interaction with libvirt.  libvirt hangs on startup, while
probing qemu capabilities.  qemu runs in probing mode (command line is
"/home/kraxel/projects/qemu/build-default/x86_64-softmmu/qemu-system-x86_64 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities.pidfile -daemonize" according to "systemctl status libvirtd -l"), apparently both qemu and libvirt wait for each other.

cheers,
  Gerd
Daniel P. Berrangé March 1, 2016, 11:47 a.m. UTC | #5
On Tue, Mar 01, 2016 at 12:15:21PM +0100, Gerd Hoffmann wrote:
> On Do, 2016-02-18 at 13:38 +0200, Dimitris Aragiorgis wrote:
> > In case of daemonize, use the logfile passed with the -D option in
> > order to redirect stderr to it instead of /dev/null.
> > 
> > Also remove some unused code in log.h.
> 
> Patch breaks interaction with libvirt.  libvirt hangs on startup, while
> probing qemu capabilities.  qemu runs in probing mode (command line is
> "/home/kraxel/projects/qemu/build-default/x86_64-softmmu/qemu-system-x86_64 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities.pidfile -daemonize" according to "systemctl status libvirtd -l"), apparently both qemu and libvirt wait for each other.

When libvirt is probing capabilities it passes a pipe file descriptor
for stderr. It reads from this pipe to detect any errors printed by
QEMU before daemonizing. When QEMU daemonizes, it closes this FD and
sets stderr to /dev/null. Libvirt knows qemu has successfully started
up at this point.

With this patch though, this code:

@@ -275,7 +276,10 @@ void os_setup_post(void)
 
         dup2(fd, 0);
         dup2(fd, 1);
-        dup2(fd, 2);
+        /* In case -D is given do not redirect stderr to /dev/null */
+        if (!qemu_logfile) {
+            dup2(fd, 2);
+        }
 
         close(fd);
 

means that QEMU will never close stderr anymore, so libvirt things
QEMU is still starting up....forever.

Given current libvirt behaviour / expectations, I think the only
option is to revert this change.

IMHO if applications want qemu logs to go to stderr, they should
explicitly ask for that to happen via a CLI arg.

Regards,
Daniel
Paolo Bonzini March 1, 2016, 11:50 a.m. UTC | #6
On 01/03/2016 12:15, Gerd Hoffmann wrote:
> On Do, 2016-02-18 at 13:38 +0200, Dimitris Aragiorgis wrote:
>> In case of daemonize, use the logfile passed with the -D option in
>> order to redirect stderr to it instead of /dev/null.
>>
>> Also remove some unused code in log.h.
> 
> Patch breaks interaction with libvirt.  libvirt hangs on startup, while
> probing qemu capabilities.  qemu runs in probing mode (command line is
> "/home/kraxel/projects/qemu/build-default/x86_64-softmmu/qemu-system-x86_64 -S -no-user-config -nodefaults -nographic -M none -qmp unix:/var/lib/libvirt/qemu/capabilities.monitor.sock,server,nowait -pidfile /var/lib/libvirt/qemu/capabilities.pidfile -daemonize" according to "systemctl status libvirtd -l"), apparently both qemu and libvirt wait for each other.

Patch sent, as a workaround use "./configure --enable-trace-backend=nop".

Paolo
Paolo Bonzini March 1, 2016, 11:51 a.m. UTC | #7
On 01/03/2016 12:47, Daniel P. Berrange wrote:
> means that QEMU will never close stderr anymore, so libvirt things
> QEMU is still starting up....forever.
> 
> Given current libvirt behaviour / expectations, I think the only
> option is to revert this change.

Why not fix it instead? :)

Paolo
Daniel P. Berrangé March 1, 2016, 11:58 a.m. UTC | #8
On Tue, Mar 01, 2016 at 12:51:03PM +0100, Paolo Bonzini wrote:
> 
> 
> On 01/03/2016 12:47, Daniel P. Berrange wrote:
> > means that QEMU will never close stderr anymore, so libvirt things
> > QEMU is still starting up....forever.
> > 
> > Given current libvirt behaviour / expectations, I think the only
> > option is to revert this change.
> 
> Why not fix it instead? :)

Because if the user upgrades QEMU it'll cause all existing deployed
version of libvirt to hang. I think that's pretty undesirable
behaviour.

Regards,
Daniel
Paolo Bonzini March 1, 2016, 12:03 p.m. UTC | #9
On 01/03/2016 12:58, Daniel P. Berrange wrote:
> > > means that QEMU will never close stderr anymore, so libvirt things
> > > QEMU is still starting up....forever.
> > > 
> > > Given current libvirt behaviour / expectations, I think the only
> > > option is to revert this change.
> > 
> > Why not fix it instead? :)
> 
> Because if the user upgrades QEMU it'll cause all existing deployed
> version of libvirt to hang. I think that's pretty undesirable
> behaviour.

Let me rephrase, why not fix it in QEMU?  Jan Tomko helped me debugging
it, and I've sent a patch just before seeing your message.

Paolo
Daniel P. Berrangé March 1, 2016, 1:54 p.m. UTC | #10
On Tue, Mar 01, 2016 at 01:03:56PM +0100, Paolo Bonzini wrote:
> 
> 
> On 01/03/2016 12:58, Daniel P. Berrange wrote:
> > > > means that QEMU will never close stderr anymore, so libvirt things
> > > > QEMU is still starting up....forever.
> > > > 
> > > > Given current libvirt behaviour / expectations, I think the only
> > > > option is to revert this change.
> > > 
> > > Why not fix it instead? :)
> > 
> > Because if the user upgrades QEMU it'll cause all existing deployed
> > version of libvirt to hang. I think that's pretty undesirable
> > behaviour.
> 
> Let me rephrase, why not fix it in QEMU?  Jan Tomko helped me debugging
> it, and I've sent a patch just before seeing your message.

Oh, we were talking with crossed wires. Yes, fixing the problem rather
than fully reverting the patch is of course a reasonable solution.

Regards,
Daniel
diff mbox

Patch

diff --git a/include/qemu/log.h b/include/qemu/log.h
index 30817f7..dda65fd 100644
--- a/include/qemu/log.h
+++ b/include/qemu/log.h
@@ -94,12 +94,6 @@  static inline void qemu_log_close(void)
     }
 }
 
-/* Set up a new log file */
-static inline void qemu_log_set_file(FILE *f)
-{
-    qemu_logfile = f;
-}
-
 /* define log items */
 typedef struct QEMULogItem {
     int mask;
diff --git a/os-posix.c b/os-posix.c
index cce62ed..92fa3ba 100644
--- a/os-posix.c
+++ b/os-posix.c
@@ -37,6 +37,7 @@ 
 #include "qemu-options.h"
 #include "qemu/rcu.h"
 #include "qemu/error-report.h"
+#include "qemu/log.h"
 
 #ifdef CONFIG_LINUX
 #include <sys/prctl.h>
@@ -275,7 +276,10 @@  void os_setup_post(void)
 
         dup2(fd, 0);
         dup2(fd, 1);
-        dup2(fd, 2);
+        /* In case -D is given do not redirect stderr to /dev/null */
+        if (!qemu_logfile) {
+            dup2(fd, 2);
+        }
 
         close(fd);
 
diff --git a/util/log.c b/util/log.c
index 2709e98..a7ddc7e 100644
--- a/util/log.c
+++ b/util/log.c
@@ -56,13 +56,20 @@  void do_qemu_set_log(int log_flags, bool use_own_buffers)
 #ifdef CONFIG_TRACE_LOG
     qemu_loglevel |= LOG_TRACE;
 #endif
-    if (qemu_loglevel && !qemu_logfile) {
+    if ((qemu_loglevel || is_daemonized()) && !qemu_logfile) {
         if (logfilename) {
             qemu_logfile = fopen(logfilename, log_append ? "a" : "w");
             if (!qemu_logfile) {
                 perror(logfilename);
                 _exit(1);
             }
+            /* In case we are a daemon redirect stderr to logfile */
+            if (is_daemonized()) {
+                dup2(fileno(qemu_logfile), STDERR_FILENO);
+                fclose(qemu_logfile);
+                /* This will skip closing logfile in qemu_log_close() */
+                qemu_logfile = stderr;
+            }
         } else {
             /* Default to stderr if no log file specified */
             qemu_logfile = stderr;
@@ -82,7 +89,7 @@  void do_qemu_set_log(int log_flags, bool use_own_buffers)
             log_append = 1;
         }
     }
-    if (!qemu_loglevel && qemu_logfile) {
+    if (!qemu_loglevel && !is_daemonized() && qemu_logfile) {
         qemu_log_close();
     }
 }