[libvirt] [PATCH] fix bug libvirt daemon deadlock when another force console break down an existed console client when this deadlock hanppened, libvirtd backtrace as follow, a typical ABBA deadlock circumstance:

LanceLiu posted 1 patch 4 years, 5 months ago
Failed in applying to current master (apply log)
src/remote/remote_daemon_stream.c | 4 +++-
1 file changed, 3 insertions(+), 1 deletion(-)
[libvirt] [PATCH] fix bug libvirt daemon deadlock when another force console break down an existed console client when this deadlock hanppened, libvirtd backtrace as follow, a typical ABBA deadlock circumstance:
Posted by LanceLiu 4 years, 5 months ago
(gdb) thread 23
[Switching to thread 23 (Thread 0x7fbb54810700 (LWP 296966))]
(gdb) bt
    at rpc/virnetserverclient.c:1503
    client=client@entry=0x5641d20e20a0, msg=0x7fbb08003ab0, rerr=rerr@entry=0x7fbb5480f7b0, procedure=201,
    type=type@entry=3, serial=9) at rpc/virnetserverprogram.c:173
    msg=<optimized out>, rerr=rerr@entry=0x7fbb5480f7b0, procedure=<optimized out>, serial=<optimized out>)
    at rpc/virnetserverprogram.c:222
    opaque=opaque@entry=0x5641d20e20a0) at stream.c:246
    force=force@entry=true) at conf/virchrdev.c:386
    at qemu/qemu_driver.c:16188
    st=st@entry=0x7fbb08008fc0, flags=1) at libvirt-domain.c:9363
    rerr=0x7fbb5480fc10, msg=<optimized out>, client=0x5641d20e4e80) at remote_dispatch.h:8540
    rerr=0x7fbb5480fc10, args=0x7fbb08005eb0, ret=<optimized out>) at remote_dispatch.h:8505
    server=0x5641d20be420, prog=0x5641d20da580) at rpc/virnetserverprogram.c:437
    msg=0x5641d20e9a20) at rpc/virnetserverprogram.c:307
    srv=0x5641d20be420) at rpc/virnetserver.c:148
---Type <return> to continue, or q <return> to quit---

(gdb) thread 26
[Switching to thread 26 (Thread 0x7fbb87a378c0 (LWP 295636))]
(gdb) bt
    at stream.c:286
    at rpc/virnetserverclient.c:1247
    at rpc/virnetserverclient.c:1457
    at util/vireventpoll.c:508

Signed-off-by: LanceLiu <liu.lance.89@gmail.com>
---
 src/remote/remote_daemon_stream.c | 4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

diff --git a/src/remote/remote_daemon_stream.c b/src/remote/remote_daemon_stream.c
index 1f6e783..b27348f 100644
--- a/src/remote/remote_daemon_stream.c
+++ b/src/remote/remote_daemon_stream.c
@@ -284,14 +284,16 @@ daemonStreamEvent(virStreamPtr st, int events, void *opaque)
  * -1 on fatal client error
  */
 static int
-daemonStreamFilter(virNetServerClientPtr client ATTRIBUTE_UNUSED,
+daemonStreamFilter(virNetServerClientPtr client,
                    virNetMessagePtr msg,
                    void *opaque)
 {
     daemonClientStream *stream = opaque;
     int ret = 0;
 
+    virObjectUnlock(client);
     virMutexLock(&stream->priv->lock);
+    virObjectLock(client);
 
     if (msg->header.type != VIR_NET_STREAM &&
         msg->header.type != VIR_NET_STREAM_HOLE)
-- 
1.8.3.1


--
libvir-list mailing list
libvir-list@redhat.com
https://www.redhat.com/mailman/listinfo/libvir-list

Re: [libvirt] [PATCH] fix bug libvirt daemon deadlock when another force console break down an existed console client when this deadlock hanppened, libvirtd backtrace as follow, a typical ABBA deadlock circumstance:
Posted by Michal Privoznik 4 years, 5 months ago
On 11/19/19 12:39 PM, LanceLiu wrote:
> (gdb) thread 23
> [Switching to thread 23 (Thread 0x7fbb54810700 (LWP 296966))]
> (gdb) bt
>      at rpc/virnetserverclient.c:1503
>      client=client@entry=0x5641d20e20a0, msg=0x7fbb08003ab0, rerr=rerr@entry=0x7fbb5480f7b0, procedure=201,
>      type=type@entry=3, serial=9) at rpc/virnetserverprogram.c:173
>      msg=<optimized out>, rerr=rerr@entry=0x7fbb5480f7b0, procedure=<optimized out>, serial=<optimized out>)
>      at rpc/virnetserverprogram.c:222
>      opaque=opaque@entry=0x5641d20e20a0) at stream.c:246
>      force=force@entry=true) at conf/virchrdev.c:386
>      at qemu/qemu_driver.c:16188
>      st=st@entry=0x7fbb08008fc0, flags=1) at libvirt-domain.c:9363
>      rerr=0x7fbb5480fc10, msg=<optimized out>, client=0x5641d20e4e80) at remote_dispatch.h:8540
>      rerr=0x7fbb5480fc10, args=0x7fbb08005eb0, ret=<optimized out>) at remote_dispatch.h:8505
>      server=0x5641d20be420, prog=0x5641d20da580) at rpc/virnetserverprogram.c:437
>      msg=0x5641d20e9a20) at rpc/virnetserverprogram.c:307
>      srv=0x5641d20be420) at rpc/virnetserver.c:148
> ---Type <return> to continue, or q <return> to quit---
> 
> (gdb) thread 26
> [Switching to thread 26 (Thread 0x7fbb87a378c0 (LWP 295636))]
> (gdb) bt
>      at stream.c:286
>      at rpc/virnetserverclient.c:1247
>      at rpc/virnetserverclient.c:1457
>      at util/vireventpoll.c:508
> 
> Signed-off-by: LanceLiu <liu.lance.89@gmail.com>
> ---
>   src/remote/remote_daemon_stream.c | 4 +++-
>   1 file changed, 3 insertions(+), 1 deletion(-)
> 
> diff --git a/src/remote/remote_daemon_stream.c b/src/remote/remote_daemon_stream.c
> index 1f6e783..b27348f 100644
> --- a/src/remote/remote_daemon_stream.c
> +++ b/src/remote/remote_daemon_stream.c
> @@ -284,14 +284,16 @@ daemonStreamEvent(virStreamPtr st, int events, void *opaque)
>    * -1 on fatal client error
>    */
>   static int
> -daemonStreamFilter(virNetServerClientPtr client ATTRIBUTE_UNUSED,
> +daemonStreamFilter(virNetServerClientPtr client,

This does not look rebased onto current git HEAD ;-) "Luckily", the 
problem you're fixing is still there.

>                      virNetMessagePtr msg,
>                      void *opaque)
>   {
>       daemonClientStream *stream = opaque;
>       int ret = 0;
>   
> +    virObjectUnlock(client);
>       virMutexLock(&stream->priv->lock);
> +    virObjectLock(client);
>   
>       if (msg->header.type != VIR_NET_STREAM &&
>           msg->header.type != VIR_NET_STREAM_HOLE)
> 

I've reworded the commit message, put a comment to 
virNetServerClientFilterFunc() typedef, ACKed and pushed.

Congratulations on your first libvirt contribution!

Michal

--
libvir-list mailing list
libvir-list@redhat.com
https://www.redhat.com/mailman/listinfo/libvir-list

Re: [libvirt] [PATCH] fix bug libvirt daemon deadlock when another force console break down an existed console client when this deadlock hanppened, libvirtd backtrace as follow, a typical ABBA deadlock circumstance:
Posted by Lance Liu 4 years, 5 months ago
Thank you!
But it looks like libvirtd daemon stream module still has bug lead to
process segfault if applied this patch(if not, it will lead libvirtd
deadlock).I have got the cause, but it seems difficult to fix it with
present codes。
Bug reproduce:
1. add sleep(3) in daemonStreamFilter() so it is easily to get the point,
as follows
  static int
daemonStreamFilter(virNetServerClientPtr client,
                   virNetMessagePtr msg,
                   void *opaque)
{
    daemonClientStream *stream = opaque;
    int ret = 0;
    static int first = 1;

//    if (first) {
//        notify_force_console();
//        VIR_ERROR("notify force console to break this client down!client:
%p", client);
//        sleep(30);
//        VIR_ERROR("sleep 10 finished");
//    }
    VIR_ERROR("stream: %p, filter_id: %d", stream, stream->filterID);
    virObjectUnlock(client);
    sleep(3);
    virMutexLock(&stream->priv->lock);
    virObjectLock(client);
2. build the libvirtd with new code, then replace the libvirtd
3. use virsh console to open a vm's console tty, then just input many chars
in the console
4. open new terminal, then use virsh console --force to break the previous
client, then you'll got libvirtd segfault

it looks because when daemonStreamEvent() with para events
as VIR_STREAM_EVENT_ERROR  is called, it will remove stream and free stream,
but daemonStreamFilter still waiting stream->priv->lock mutex, thus cause
invalid memory access

To fix this, I think the most effective and clean way is to drop
client->priv->lock elements, just use client object lock。But for current
code, it's not easy to do that。
also, a workaroud scheme is  to add a big lock, but is ugly and low
efficient。

Any good ideas?




Michal Privoznik <mprivozn@redhat.com> 于2019年11月19日周二 下午11:41写道:

> On 11/19/19 12:39 PM, LanceLiu wrote:
> > (gdb) thread 23
> > [Switching to thread 23 (Thread 0x7fbb54810700 (LWP 296966))]
> > (gdb) bt
> >      at rpc/virnetserverclient.c:1503
> >      client=client@entry=0x5641d20e20a0, msg=0x7fbb08003ab0,
> rerr=rerr@entry=0x7fbb5480f7b0, procedure=201,
> >      type=type@entry=3, serial=9) at rpc/virnetserverprogram.c:173
> >      msg=<optimized out>, rerr=rerr@entry=0x7fbb5480f7b0,
> procedure=<optimized out>, serial=<optimized out>)
> >      at rpc/virnetserverprogram.c:222
> >      opaque=opaque@entry=0x5641d20e20a0) at stream.c:246
> >      force=force@entry=true) at conf/virchrdev.c:386
> >      at qemu/qemu_driver.c:16188
> >      st=st@entry=0x7fbb08008fc0, flags=1) at libvirt-domain.c:9363
> >      rerr=0x7fbb5480fc10, msg=<optimized out>, client=0x5641d20e4e80) at
> remote_dispatch.h:8540
> >      rerr=0x7fbb5480fc10, args=0x7fbb08005eb0, ret=<optimized out>) at
> remote_dispatch.h:8505
> >      server=0x5641d20be420, prog=0x5641d20da580) at
> rpc/virnetserverprogram.c:437
> >      msg=0x5641d20e9a20) at rpc/virnetserverprogram.c:307
> >      srv=0x5641d20be420) at rpc/virnetserver.c:148
> > ---Type <return> to continue, or q <return> to quit---
> >
> > (gdb) thread 26
> > [Switching to thread 26 (Thread 0x7fbb87a378c0 (LWP 295636))]
> > (gdb) bt
> >      at stream.c:286
> >      at rpc/virnetserverclient.c:1247
> >      at rpc/virnetserverclient.c:1457
> >      at util/vireventpoll.c:508
> >
> > Signed-off-by: LanceLiu <liu.lance.89@gmail.com>
> > ---
> >   src/remote/remote_daemon_stream.c | 4 +++-
> >   1 file changed, 3 insertions(+), 1 deletion(-)
> >
> > diff --git a/src/remote/remote_daemon_stream.c
> b/src/remote/remote_daemon_stream.c
> > index 1f6e783..b27348f 100644
> > --- a/src/remote/remote_daemon_stream.c
> > +++ b/src/remote/remote_daemon_stream.c
> > @@ -284,14 +284,16 @@ daemonStreamEvent(virStreamPtr st, int events,
> void *opaque)
> >    * -1 on fatal client error
> >    */
> >   static int
> > -daemonStreamFilter(virNetServerClientPtr client ATTRIBUTE_UNUSED,
> > +daemonStreamFilter(virNetServerClientPtr client,
>
> This does not look rebased onto current git HEAD ;-) "Luckily", the
> problem you're fixing is still there.
>
> >                      virNetMessagePtr msg,
> >                      void *opaque)
> >   {
> >       daemonClientStream *stream = opaque;
> >       int ret = 0;
> >
> > +    virObjectUnlock(client);
> >       virMutexLock(&stream->priv->lock);
> > +    virObjectLock(client);
> >
> >       if (msg->header.type != VIR_NET_STREAM &&
> >           msg->header.type != VIR_NET_STREAM_HOLE)
> >
>
> I've reworded the commit message, put a comment to
> virNetServerClientFilterFunc() typedef, ACKed and pushed.
>
> Congratulations on your first libvirt contribution!
>
> Michal
>
>
--
libvir-list mailing list
libvir-list@redhat.com
https://www.redhat.com/mailman/listinfo/libvir-list
Re: [libvirt] [PATCH] fix bug libvirt daemon deadlock when another force console break down an existed console client when this deadlock hanppened, libvirtd backtrace as follow, a typical ABBA deadlock circumstance:
Posted by Michal Privoznik 4 years, 5 months ago
On 11/22/19 8:00 AM, Lance Liu wrote:
> Thank you!
> But it looks like libvirtd daemon stream module still has bug lead to 
> process segfault if applied this patch(if not, it will lead libvirtd 
> deadlock).I have got the cause, but it seems difficult to fix it with 
> present codes。
> Bug reproduce:
> 1. add sleep(3) in daemonStreamFilter() so it is easily to get the 
> point, as follows
>    static int
> daemonStreamFilter(virNetServerClientPtr client,
>                     virNetMessagePtr msg,
>                     void *opaque)
> {
>      daemonClientStream *stream = opaque;
>      int ret = 0;
>      static int first = 1;
> 
> //    if (first) {
> //        notify_force_console();
> //        VIR_ERROR("notify force console to break this client 
> down!client: %p", client);
> //        sleep(30);
> //        VIR_ERROR("sleep 10 finished");
> //    }
>      VIR_ERROR("stream: %p, filter_id: %d", stream, stream->filterID);
>      virObjectUnlock(client);
>      sleep(3);
>      virMutexLock(&stream->priv->lock);
>      virObjectLock(client);
> 2. build the libvirtd with new code, then replace the libvirtd
> 3. use virsh console to open a vm's console tty, then just input many 
> chars in the console
> 4. open new terminal, then use virsh console --force to break the 
> previous client, then you'll got libvirtd segfault
> 
> it looks because when daemonStreamEvent() with para events 
> as VIR_STREAM_EVENT_ERROR  is called, it will remove stream and free stream,
> but daemonStreamFilter still waiting stream->priv->lock mutex, thus 
> cause invalid memory access

Yes, this is exactly what is happening.

> 
> To fix this, I think the most effective and clean way is to drop 
> client->priv->lock elements, just use client object lock。But for 
> current code, it's not easy to do that。
> also, a workaroud scheme is  to add a big lock, but is ugly and low 
> efficient。
> 
> Any good ideas?

I think we need to get back to drawing board. In the original problem 
you observed ABBA, but also was patching older libvirt. I convinced 
myself that the problem still occurs even with (at that point) current 
master:

1) virNetServerClientDispatchEvent() locks @client,
    virNetServerClientDispatchRead()
    daemonStreamFilter() which locks stream->priv->lock;

on the other hand:

2) daemonStreamEvent() locks stream->priv->lock,
    virNetServerClientClose() which locks @client; /* there are other 
functions called over @client which also lock @client, I've just picked 
one */


So there is ABBA pattern. However, there might be another lock that is 
breaking the pattern (although I don't see it now): CAB and another 
thread then does CBA.

Do you have a reproducer for your original problem? Does it reproduce on 
the current master (after you revert the patch I've merged of course).

Michal

--
libvir-list mailing list
libvir-list@redhat.com
https://www.redhat.com/mailman/listinfo/libvir-list