[PATCH 1/4] libxl: event handling: Add an assert to egc_run_callbacks

[PATCH 1/4] libxl: event handling: Add an assert to egc_run_callbacks

[Ian Jackson]

Check that the ao is still live when we are about to running some of
its callbacks.

This reveals an existing bug in libxl which is exercised by libvirt,
converting
   libvirtd: libxl_event.c:1792: libxl__ao_complete_check_progress_reports: Assertion `ao->in_initiator' failed.
into
   libvirtd: libxl_event.c:1338: egc_run_callbacks: Assertion `aop->ao->magic == 0xA0FACE00ul' failed.

Signed-off-by: Ian Jackson <Ian.Jackson@eu.citrix.com>
CC: Ian Campbell <ian.campbell@citrix.com>
CC: Wei Liu <wei.liu2@citrix.com>
CC: Jim Fehlig <jfehlig@suse.com>
---
 tools/libxl/libxl_event.c |    1 +
 1 file changed, 1 insertion(+)

diff --git a/tools/libxl/libxl_event.c b/tools/libxl/libxl_event.c
index 0d874d9..ae73728 100644
--- a/tools/libxl/libxl_event.c
+++ b/tools/libxl/libxl_event.c
@@ -1335,6 +1335,7 @@ static void egc_run_callbacks(libxl__egc *egc)
         aop->how->callback(CTX, aop->ev, aop->how->for_callback);
 
         CTX_LOCK;
+        assert(aop->ao->magic == LIBXL__AO_MAGIC);
         aop->ao->progress_reports_outstanding--;
         libxl__ao_complete_check_progress_reports(egc, aop->ao);
         CTX_UNLOCK;
-- 
1.7.10.4

[PATCH 2/4] libxl: event handling: Break out ao_work_outstanding

[Ian Jackson]

Break out the test in libxl__ao_complete_check_progress_reports, into
ao_work_outstanding, which reports false if either (i) the ao is still
ongoing or (ii) there is a progress report (perhaps on a different
thread's callback queue) which has yet to be reported to the
application.

No functional change.

Signed-off-by: Ian Jackson <Ian.Jackson@eu.citrix.com>
CC: Ian Campbell <ian.campbell@citrix.com>
CC: Wei Liu <wei.liu2@citrix.com>
CC: Jim Fehlig <jfehlig@suse.com>
---
 tools/libxl/libxl_event.c |   12 +++++++++---
 1 file changed, 9 insertions(+), 3 deletions(-)

diff --git a/tools/libxl/libxl_event.c b/tools/libxl/libxl_event.c
index ae73728..89ca6d2 100644
--- a/tools/libxl/libxl_event.c
+++ b/tools/libxl/libxl_event.c
@@ -1773,19 +1773,25 @@ void libxl__ao_complete(libxl__egc *egc, libxl__ao *ao, int rc)
     libxl__ao_complete_check_progress_reports(egc, ao);
 }
 
-void libxl__ao_complete_check_progress_reports(libxl__egc *egc, libxl__ao *ao)
+static bool ao_work_outstanding(libxl__ao *ao)
 {
     /*
      * We don't consider an ao complete if it has any outstanding
      * callbacks.  These callbacks might be outstanding on other
      * threads, queued up in the other threads' egc's.  Those threads
      * will, after making the callback, take out the lock again,
-     * decrement progress_reports_outstanding, and call us again.
+     * decrement progress_reports_outstanding, and call
+     * libxl__ao_complete_check_progress_reports.
      */
+    return !ao->complete || ao->progress_reports_outstanding;
+}
+
+void libxl__ao_complete_check_progress_reports(libxl__egc *egc, libxl__ao *ao)
+{
     libxl_ctx *ctx = libxl__gc_owner(&egc->gc);
     assert(ao->progress_reports_outstanding >= 0);
 
-    if (!ao->complete || ao->progress_reports_outstanding)
+    if (ao_work_outstanding(ao))
         return;
 
     if (ao->poller) {
-- 
1.7.10.4

[PATCH 3/4] libxl: event handling: ao_inprogress does waits while reports outstanding

[Ian Jackson]

libxl__ao_inprogress needs to check (like
libxl__ao_complete_check_progress_reports) that there are no
oustanding progress callbacks.

Otherwise it might happen that we would destroy the ao while another
thread has an outstanding callback its egc report queue.  The other
thread would then, in its egc_run_callbacks, touch the destroyed ao.

Instead, when this happens in libxl__ao_inprogress, simply run round
the event loop again.  The thread which eventually makes the callback
will spot our poller in the ao, and notify the poller, waking us up.

This fixes an assertion failure race seen with libvirt:
  libvirtd: libxl_event.c:1792: libxl__ao_complete_check_progress_reports: Assertion `ao->in_initiator' failed.
or (after "Add an assert to egc_run_callbacks")
  libvirtd: libxl_event.c:1338: egc_run_callbacks: Assertion `aop->ao->magic == 0xA0FACE00ul' failed.

Signed-off-by: Ian Jackson <Ian.Jackson@eu.citrix.com>
CC: Ian Campbell <ian.campbell@citrix.com>
CC: Wei Liu <wei.liu2@citrix.com>
CC: Jim Fehlig <jfehlig@suse.com>
---
 tools/libxl/libxl_event.c |    2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/tools/libxl/libxl_event.c b/tools/libxl/libxl_event.c
index 89ca6d2..595da2b 100644
--- a/tools/libxl/libxl_event.c
+++ b/tools/libxl/libxl_event.c
@@ -1878,7 +1878,7 @@ int libxl__ao_inprogress(libxl__ao *ao,
         for (;;) {
             assert(ao->magic == LIBXL__AO_MAGIC);
 
-            if (ao->complete) {
+            if (!ao_work_outstanding(ao)) {
                 rc = ao->rc;
                 ao->notified = 1;
                 break;
-- 
1.7.10.4

[PATCH 4/4] libxl: More probably detect reentry of destroyed ctx

[Ian Jackson]

In libxl_ctx_free:

1. Move the GC_INIT earlier, so that we can:

2. Take the lock around most of the work.  This is technically
   unnecessary since calling any other libxl entrypoint on a ctx being
   passed to libxl_ctx_free risks undefined behaviour.  But, taking
   the lock allows us to much more usually spot this.

3. Increment osevent_in_hook by 1000.  If we are reentered after
   destroy, this will trip some of our entrypoints' asserts.  It also
   means that if we crash for some other reason relating to reentering
   a destroyed ctx, the cause will be more obviously visible by
   examining ctx->osevent_in_hook (assuming that the memory previously
   used for the ctx hasn't been reused and overwritten).

4. Free the lock again.  (pthread_mutex_destroy requires that the
   mutex be unlocked.)

With this patch, I find that an occasional race previously reported
as:
  libvirtd: libxl_internal.h:3265: libxl__ctx_unlock: Assertion `!r' failed.
is now reported as:
  libvirtd: libxl_event.c:1236: libxl_osevent_occurred_fd: Assertion `!libxl__gc_owner(gc)->osevent_in_hook' failed.

Examining the call trace with gdb shows this:
  (gdb) bt
  #0  0xb773f424 in __kernel_vsyscall ()
  #1  0xb7022871 in raise () from /lib/i386-linux-gnu/i686/nosegneg/libc.so.6
  #2  0xb7025d62 in abort () from /lib/i386-linux-gnu/i686/nosegneg/libc.so.6
  #3  0xb701b958 in __assert_fail () from /lib/i386-linux-gnu/i686/nosegneg/libc.so.6
  #4  0xb6f00390 in libxl_osevent_occurred_fd (ctx=0xb84813a8, for_libxl=0xb84d6848, fd=31, events_ign=0, revents_ign=1) at libxl_event.c:1236
  #5  0xb1b70464 in libxlDomainObjFDEventCallback () from /usr/local/lib/libvirt/connection-driver/libvirt_driver_libxl.so
  #6  0xb72163b1 in virEventPollDispatchHandles () from /usr/local/lib/libvirt.so.0
  #7  0xb7216be5 in virEventPollRunOnce () from /usr/local/lib/libvirt.so.0
  #8  0xb7214a7e in virEventRunDefaultImpl () from /usr/local/lib/libvirt.so.0
  #9  0xb77c7b98 in virNetServerRun ()
  #10 0xb7771c63 in main ()
  (gdb) print ctx->osevent_in_hook
  $2 = 1000
  (gdb)
which IMO demonstrates that libxl_osevent_occurred_fd is being called
on a destroyed ctx.

This is probably a symptom of the bug in libvirt fixed by these
patches:
   https://www.redhat.com/archives/libvir-list/2015-February/msg00024.html

Signed-off-by: Ian Jackson <Ian.Jackson@eu.citrix.com>
CC: Ian Campbell <ian.campbell@citrix.com>
CC: Wei Liu <wei.liu2@citrix.com>
CC: Jim Fehlig <jfehlig@suse.com>
---
 tools/libxl/libxl.c |    7 +++++--
 1 file changed, 5 insertions(+), 2 deletions(-)

diff --git a/tools/libxl/libxl.c b/tools/libxl/libxl.c
index cd6f42c..de75ac4 100644
--- a/tools/libxl/libxl.c
+++ b/tools/libxl/libxl.c
@@ -146,11 +146,13 @@ int libxl_ctx_free(libxl_ctx *ctx)
 {
     if (!ctx) return 0;
 
-    assert(!ctx->osevent_in_hook);
-
     int i;
     GC_INIT(ctx);
 
+    CTX_LOCK;
+    assert(!ctx->osevent_in_hook);
+    CTX->osevent_in_hook += 1000;
+
     /* Deregister all libxl__ev_KINDs: */
 
     free_disable_deaths(gc, &CTX->death_list);
@@ -196,6 +198,7 @@ int libxl_ctx_free(libxl_ctx *ctx)
     libxl__sigchld_notneeded(gc);
     libxl__pipe_close(ctx->sigchld_selfpipe);
 
+    CTX_UNLOCK;
     pthread_mutex_destroy(&ctx->lock);
 
     GC_FREE;
-- 
1.7.10.4

Re: [PATCH 1/4] libxl: event handling: Add an assert to egc_run_callbacks

[Wei Liu]

On Mon, Feb 09, 2015 at 03:51:09PM +0000, Ian Jackson wrote:
> Check that the ao is still live when we are about to running some of
> its callbacks.
> 
> This reveals an existing bug in libxl which is exercised by libvirt,
> converting
>    libvirtd: libxl_event.c:1792: libxl__ao_complete_check_progress_reports: Assertion `ao->in_initiator' failed.
> into
>    libvirtd: libxl_event.c:1338: egc_run_callbacks: Assertion `aop->ao->magic == 0xA0FACE00ul' failed.
> 
> Signed-off-by: Ian Jackson <Ian.Jackson@eu.citrix.com>
> CC: Ian Campbell <ian.campbell@citrix.com>
> CC: Wei Liu <wei.liu2@citrix.com>
> CC: Jim Fehlig <jfehlig@suse.com>

Acked-by: Wei Liu <wei.liu2@citrix.com>

> ---
>  tools/libxl/libxl_event.c |    1 +
>  1 file changed, 1 insertion(+)
> 
> diff --git a/tools/libxl/libxl_event.c b/tools/libxl/libxl_event.c
> index 0d874d9..ae73728 100644
> --- a/tools/libxl/libxl_event.c
> +++ b/tools/libxl/libxl_event.c
> @@ -1335,6 +1335,7 @@ static void egc_run_callbacks(libxl__egc *egc)
>          aop->how->callback(CTX, aop->ev, aop->how->for_callback);
>  
>          CTX_LOCK;
> +        assert(aop->ao->magic == LIBXL__AO_MAGIC);
>          aop->ao->progress_reports_outstanding--;
>          libxl__ao_complete_check_progress_reports(egc, aop->ao);
>          CTX_UNLOCK;
> -- 
> 1.7.10.4

Re: [PATCH 2/4] libxl: event handling: Break out ao_work_outstanding

[Wei Liu]

On Mon, Feb 09, 2015 at 03:51:10PM +0000, Ian Jackson wrote:
> Break out the test in libxl__ao_complete_check_progress_reports, into
> ao_work_outstanding, which reports false if either (i) the ao is still
> ongoing or (ii) there is a progress report (perhaps on a different
> thread's callback queue) which has yet to be reported to the
> application.
> 
> No functional change.
> 
> Signed-off-by: Ian Jackson <Ian.Jackson@eu.citrix.com>
> CC: Ian Campbell <ian.campbell@citrix.com>
> CC: Wei Liu <wei.liu2@citrix.com>
> CC: Jim Fehlig <jfehlig@suse.com>

Acked-by: Wei Liu <wei.liu2@citrix.com>

Re: [PATCH 3/4] libxl: event handling: ao_inprogress does waits while reports outstanding

[Wei Liu]

On Mon, Feb 09, 2015 at 03:51:11PM +0000, Ian Jackson wrote:
> libxl__ao_inprogress needs to check (like
> libxl__ao_complete_check_progress_reports) that there are no
> oustanding progress callbacks.
> 
> Otherwise it might happen that we would destroy the ao while another
> thread has an outstanding callback its egc report queue.  The other
> thread would then, in its egc_run_callbacks, touch the destroyed ao.
> 
> Instead, when this happens in libxl__ao_inprogress, simply run round
> the event loop again.  The thread which eventually makes the callback
> will spot our poller in the ao, and notify the poller, waking us up.
> 
> This fixes an assertion failure race seen with libvirt:
>   libvirtd: libxl_event.c:1792: libxl__ao_complete_check_progress_reports: Assertion `ao->in_initiator' failed.
> or (after "Add an assert to egc_run_callbacks")
>   libvirtd: libxl_event.c:1338: egc_run_callbacks: Assertion `aop->ao->magic == 0xA0FACE00ul' failed.
> 
> Signed-off-by: Ian Jackson <Ian.Jackson@eu.citrix.com>
> CC: Ian Campbell <ian.campbell@citrix.com>
> CC: Wei Liu <wei.liu2@citrix.com>
> CC: Jim Fehlig <jfehlig@suse.com>

Acked-by: Wei Liu <wei.liu2@citrix.com>

> ---
>  tools/libxl/libxl_event.c |    2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/tools/libxl/libxl_event.c b/tools/libxl/libxl_event.c
> index 89ca6d2..595da2b 100644
> --- a/tools/libxl/libxl_event.c
> +++ b/tools/libxl/libxl_event.c
> @@ -1878,7 +1878,7 @@ int libxl__ao_inprogress(libxl__ao *ao,
>          for (;;) {
>              assert(ao->magic == LIBXL__AO_MAGIC);
>  
> -            if (ao->complete) {
> +            if (!ao_work_outstanding(ao)) {
>                  rc = ao->rc;
>                  ao->notified = 1;
>                  break;
> -- 
> 1.7.10.4

Re: [PATCH 4/4] libxl: More probably detect reentry of destroyed ctx

[Wei Liu]

On Mon, Feb 09, 2015 at 03:51:12PM +0000, Ian Jackson wrote:
> In libxl_ctx_free:
> 
> 1. Move the GC_INIT earlier, so that we can:
> 
> 2. Take the lock around most of the work.  This is technically
>    unnecessary since calling any other libxl entrypoint on a ctx being
>    passed to libxl_ctx_free risks undefined behaviour.  But, taking
>    the lock allows us to much more usually spot this.
> 
> 3. Increment osevent_in_hook by 1000.  If we are reentered after
>    destroy, this will trip some of our entrypoints' asserts.  It also
>    means that if we crash for some other reason relating to reentering
>    a destroyed ctx, the cause will be more obviously visible by
>    examining ctx->osevent_in_hook (assuming that the memory previously
>    used for the ctx hasn't been reused and overwritten).
> 
> 4. Free the lock again.  (pthread_mutex_destroy requires that the
>    mutex be unlocked.)
> 
> With this patch, I find that an occasional race previously reported
> as:
>   libvirtd: libxl_internal.h:3265: libxl__ctx_unlock: Assertion `!r' failed.
> is now reported as:
>   libvirtd: libxl_event.c:1236: libxl_osevent_occurred_fd: Assertion `!libxl__gc_owner(gc)->osevent_in_hook' failed.
> 
> Examining the call trace with gdb shows this:
>   (gdb) bt
>   #0  0xb773f424 in __kernel_vsyscall ()
>   #1  0xb7022871 in raise () from /lib/i386-linux-gnu/i686/nosegneg/libc.so.6
>   #2  0xb7025d62 in abort () from /lib/i386-linux-gnu/i686/nosegneg/libc.so.6
>   #3  0xb701b958 in __assert_fail () from /lib/i386-linux-gnu/i686/nosegneg/libc.so.6
>   #4  0xb6f00390 in libxl_osevent_occurred_fd (ctx=0xb84813a8, for_libxl=0xb84d6848, fd=31, events_ign=0, revents_ign=1) at libxl_event.c:1236
>   #5  0xb1b70464 in libxlDomainObjFDEventCallback () from /usr/local/lib/libvirt/connection-driver/libvirt_driver_libxl.so
>   #6  0xb72163b1 in virEventPollDispatchHandles () from /usr/local/lib/libvirt.so.0
>   #7  0xb7216be5 in virEventPollRunOnce () from /usr/local/lib/libvirt.so.0
>   #8  0xb7214a7e in virEventRunDefaultImpl () from /usr/local/lib/libvirt.so.0
>   #9  0xb77c7b98 in virNetServerRun ()
>   #10 0xb7771c63 in main ()
>   (gdb) print ctx->osevent_in_hook
>   $2 = 1000
>   (gdb)
> which IMO demonstrates that libxl_osevent_occurred_fd is being called
> on a destroyed ctx.
> 
> This is probably a symptom of the bug in libvirt fixed by these
> patches:
>    https://www.redhat.com/archives/libvir-list/2015-February/msg00024.html
> 
> Signed-off-by: Ian Jackson <Ian.Jackson@eu.citrix.com>
> CC: Ian Campbell <ian.campbell@citrix.com>
> CC: Wei Liu <wei.liu2@citrix.com>
> CC: Jim Fehlig <jfehlig@suse.com>

Acked-by: Wei Liu <wei.liu2@citrix.com>

> ---
>  tools/libxl/libxl.c |    7 +++++--
>  1 file changed, 5 insertions(+), 2 deletions(-)
> 
> diff --git a/tools/libxl/libxl.c b/tools/libxl/libxl.c
> index cd6f42c..de75ac4 100644
> --- a/tools/libxl/libxl.c
> +++ b/tools/libxl/libxl.c
> @@ -146,11 +146,13 @@ int libxl_ctx_free(libxl_ctx *ctx)
>  {
>      if (!ctx) return 0;
>  
> -    assert(!ctx->osevent_in_hook);
> -
>      int i;
>      GC_INIT(ctx);
>  
> +    CTX_LOCK;
> +    assert(!ctx->osevent_in_hook);
> +    CTX->osevent_in_hook += 1000;
> +

It would be good if you add comment here to say this is used to help
debugging.

Wei.

Re: [PATCH 4/4] libxl: More probably detect reentry of destroyed ctx

[Ian Jackson]

Wei Liu writes ("Re: [PATCH 4/4] libxl: More probably detect reentry of destroyed ctx"):
> On Mon, Feb 09, 2015 at 03:51:12PM +0000, Ian Jackson wrote:
> > In libxl_ctx_free:
> > 
> > 1. Move the GC_INIT earlier, so that we can:
> 
> Acked-by: Wei Liu <wei.liu2@citrix.com>

Thanks.

> > +    assert(!ctx->osevent_in_hook);
> > +    CTX->osevent_in_hook += 1000;
> 
> It would be good if you add comment here to say this is used to help
> debugging.

Good idea.  I have done this:

    CTX->osevent_in_hook += 1000; /* make violations easier to debug */

Thanks for your acks.  I will push this to staging now.  I think at
least 1-3 of these, and probably all of them, should be backported.

Ian.