[libvirt] [PATCH] util: Remove logging handlers in virExec

[Daniel P. Berrange]

On Tue, Feb 02, 2010 at 12:15:01PM -0500, Cole Robinson wrote:
> On 02/02/2010 11:54 AM, Daniel P. Berrange wrote:
> > On Tue, Jan 12, 2010 at 03:26:26PM -0500, Cole Robinson wrote:
> >> This allows debug statements and raised errors in hook functions to
> >> actually be logged somewhere (stderr). Users can enable debugging in the
> >> daemon and now see more info in /var/log/libvirt/...
> >>
> >> Signed-off-by: Cole Robinson <crobinso at redhat.com>
> >> ---
> >>  src/util/util.c |    6 ++++++
> >>  1 files changed, 6 insertions(+), 0 deletions(-)
> >>
> >> diff --git a/src/util/util.c b/src/util/util.c
> >> index 44a4b2f..23d781d 100644
> >> --- a/src/util/util.c
> >> +++ b/src/util/util.c
> >> @@ -334,6 +334,7 @@ __virExec(virConnectPtr conn,
> >>      int pipeerr[2] = {-1,-1};
> >>      int childout = -1;
> >>      int childerr = -1;
> >> +    int logprio;
> >>      sigset_t oldmask, newmask;
> >>      struct sigaction sig_action;
> >>  
> >> @@ -452,6 +453,11 @@ __virExec(virConnectPtr conn,
> >>         of being seen / logged */
> >>      virSetErrorFunc(NULL, NULL);
> >>  
> >> +    /* Make sure any hook logging is sent to stderr */
> >> +    logprio = virLogGetDefaultPriority();
> >> +    virLogReset();
> >> +    virLogSetDefaultPriority(logprio);
> >> +
> > 
> > This patch turns out to cause a deadlock in libvirtd. The problem is
> > that fork() preserves the state of any mutexes which are locked. 
> > 
> > So if some thread in libvirtd is currently executing a logging call, 
> > while another thread calls virExec(), that other thread no longer
> > exists in the child, but its lock is never released. So when the
> > child then does virLogReset() it deadlocks.
> > 
> > I'm actuall surprised we've not hit this problem before, since any call
> > to virRaiseError in the child will also eventually run a logging function
> > which will in turn acquire a lock.
> > 
> > The only way I see to address this, is for the parent process to call
> > virLogLock(), immediately before fork(), and then virLogUnlock()
> > afterwards in both parent & child. This will ensure that no other thread
> > can be holding the lock across fork().
> > 
> > https://bugzilla.redhat.com/show_bug.cgi?id=561066
> > 
> 
> Does this look okay? I haven't tested that it fixes the issue (though I
> haven't reproduced the error either).
> 
> - Cole

> diff --git a/src/libvirt_private.syms b/src/libvirt_private.syms
> index e5e8860..7573af3 100644
> --- a/src/libvirt_private.syms
> +++ b/src/libvirt_private.syms
> @@ -366,6 +366,8 @@ virLogParseOutputs;
>  virLogStartup;
>  virLogShutdown;
>  virLogReset;
> +virLogLock;
> +virLogUnlock;
>  
>  
>  # memory.h
> diff --git a/src/util/logging.c b/src/util/logging.c
> index 3b3c309..11a4b06 100644
> --- a/src/util/logging.c
> +++ b/src/util/logging.c
> @@ -133,11 +133,11 @@ static int virLogResetOutputs(void);
>   */
>  virMutex virLogMutex;
>  
> -static void virLogLock(void)
> +void virLogLock(void)
>  {
>      virMutexLock(&virLogMutex);
>  }
> -static void virLogUnlock(void)
> +void virLogUnlock(void)
>  {
>      virMutexUnlock(&virLogMutex);
>  }
> diff --git a/src/util/logging.h b/src/util/logging.h
> index 49e2f6d..5f61f59 100644
> --- a/src/util/logging.h
> +++ b/src/util/logging.h
> @@ -128,6 +128,8 @@ extern int virLogDefineOutput(virLogOutputFunc f, virLogCloseFunc c, void *data,
>   * Internal logging API
>   */
>  
> +extern void virLogLock(void);
> +extern void virLogUnlock(void);
>  extern int virLogStartup(void);
>  extern int virLogReset(void);
>  extern void virLogShutdown(void);
> diff --git a/src/util/util.c b/src/util/util.c
> index cf1290d..901c0d2 100644
> --- a/src/util/util.c
> +++ b/src/util/util.c
> @@ -415,12 +415,19 @@ __virExec(virConnectPtr conn,
>          childerr = null;
>      }
>  
> +    /* Ensure we hold the logging lock, to protect child processes
> +     * from deadlocking on another threads inheirited mutex state */
> +    virLogLock();
> +
>      if ((pid = fork()) < 0) {
>          virReportSystemError(conn, errno,
>                               "%s", _("cannot fork child process"));
>          goto cleanup;
>      }
>  
> +    /* Unlock for both parent and child process */
> +    virLogUnlock();
> +
>      if (pid) { /* parent */
>          close(null);
>          if (outfd && *outfd == -1) {


Yeah, i reckon that this should be sufficient. I'll get the BZ reporter
to try this patch

Daniel
-- 
|: Red Hat, Engineering, London   -o-   http://people.redhat.com/berrange/ :|
|: http://libvirt.org  -o-  http://virt-manager.org  -o-  http://ovirt.org :|
|: http://autobuild.org       -o-         http://search.cpan.org/~danberr/ :|
|: GnuPG: 7D3B9505  -o-  F3C9 553F A1DA 4AC2 5648 23C1 B3DF F742 7D3B 9505 :|