[Qemu-devel] 100% CPU when sockfd is half-closed and unexpected behavior for qemu_co_send()

[Qemu-devel] 100% CPU when sockfd is half-closed and unexpected behavior for qemu_co_send()

[Liu Yuan]

Hi List,
  This problem can be reproduced by:
  1. start a sheepdog cluster and create a volume 'test'*
  2. attach 'test' to a bootable image like
     $ qemu -hda image -drive if=virtio,file=sheepdog:test
  3. pkill sheep # create a half-closed situation

I have straced it that QEMU is busy doing nonsense read/write() after
select() in os_host_main_loop_wait(). I have no knowledge of
glib_select_xxx, so someone please help fix it.

Another unexpected behavior is that qemu_co_send() will send data
successfully for the half-closed situation, even the other end is
completely down. I think the *expected* behavior is that we get notified
by a HUP and close the affected sockfd, then qemu_co_send() will not
send any data, then the caller of qemu_co_send() can handle error case.

I don't know which one I should Cc, so I only include Stefan in.

* You can easily start up a one node sheepdog cluster as following:
 $ git clone https://github.com/collie/sheepdog.git
 $ cd sheepdog
 $ apt-get install liburcu-dev
 $ ./autogen.sh; ./configure --disable-corosync;make
 #start up a one node sheep cluster
 $ mkdir store;./sheep/sheep store -c local
 $ collie/collie cluster format -c 1
 #create a volume named test
 $ collie/collie vdi create test 1G

Thanks,
Yuan

Re: [Qemu-devel] 100% CPU when sockfd is half-closed and unexpected behavior for qemu_co_send()

[Paolo Bonzini]

Il 14/01/2013 09:16, Liu Yuan ha scritto:
> Hi List,
>   This problem can be reproduced by:
>   1. start a sheepdog cluster and create a volume 'test'*
>   2. attach 'test' to a bootable image like
>      $ qemu -hda image -drive if=virtio,file=sheepdog:test
>   3. pkill sheep # create a half-closed situation
> 
> I have straced it that QEMU is busy doing nonsense read/write() after
> select() in os_host_main_loop_wait(). I have no knowledge of
> glib_select_xxx, so someone please help fix it.

read/write() is not done by os_host_main_loop_wait().

It must be done by qemu_co_send()/qemu_co_recv() after the handler has
reentered the coroutine.

> Another unexpected behavior is that qemu_co_send() will send data
> successfully for the half-closed situation, even the other end is
> completely down. I think the *expected* behavior is that we get notified
> by a HUP and close the affected sockfd, then qemu_co_send() will not
> send any data, then the caller of qemu_co_send() can handle error case.

qemu_co_send() should get an EPIPE or similar error.  The first time it
will report a partial send, the second time it will report the error
directly to the caller.

Please check if this isn't a bug in the Sheepdog driver.

Paolo

> I don't know which one I should Cc, so I only include Stefan in.
> 
> * You can easily start up a one node sheepdog cluster as following:
>  $ git clone https://github.com/collie/sheepdog.git
>  $ cd sheepdog
>  $ apt-get install liburcu-dev
>  $ ./autogen.sh; ./configure --disable-corosync;make
>  #start up a one node sheep cluster
>  $ mkdir store;./sheep/sheep store -c local
>  $ collie/collie cluster format -c 1
>  #create a volume named test
>  $ collie/collie vdi create test 1G
> 
> Thanks,
> Yuan
> 
> 

Re: [Qemu-devel] 100% CPU when sockfd is half-closed and unexpected behavior for qemu_co_send()

[Liu Yuan]

On 01/14/2013 05:09 PM, Paolo Bonzini wrote:
>> Another unexpected behavior is that qemu_co_send() will send data
>> > successfully for the half-closed situation, even the other end is
>> > completely down. I think the *expected* behavior is that we get notified
>> > by a HUP and close the affected sockfd, then qemu_co_send() will not
>> > send any data, then the caller of qemu_co_send() can handle error case.
> qemu_co_send() should get an EPIPE or similar error.  The first time it
> will report a partial send, the second time it will report the error
> directly to the caller.
> 
> Please check if this isn't a bug in the Sheepdog driver.

I don't think so. I use netstat to assure that the connection is in closed_wait state and I added a printf in the qemu_co_send() and it indeed sent successfully, this can be backed by the Linux kernel source code:

static ssize_t do_tcp_sendpages(struct sock *sk, struct page *page, int offset,
                                size_t size, int flags)
{
         ....
        /* Wait for a connection to finish. One exception is TCP Fast Open
         * (passive side) where data is allowed to be sent before a connection
         * is fully established.
         */
        if (((1 << sk->sk_state) & ~(TCPF_ESTABLISHED | TCPF_CLOSE_WAIT)) &&
            !tcp_passive_fastopen(sk)) {
                if ((err = sk_stream_wait_connect(sk, &timeo)) != 0)
                        goto out_err;
        }
        ....
}

which will put data in the sock buf and returns successful in a CLOSED_WAIT state. I don't see means in Sheepdog driver code to get a HUP notification for a actual cut off connection.

Thanks,
Yuan

Re: [Qemu-devel] 100% CPU when sockfd is half-closed and unexpected behavior for qemu_co_send()

[Paolo Bonzini]

Il 14/01/2013 10:29, Liu Yuan ha scritto:
> I don't think so. I use netstat to assure that the connection is in
> closed_wait state and I added a printf in the qemu_co_send() and it
> indeed sent successfully, this can be backed by the Linux kernel
> source code:
> 
> static ssize_t do_tcp_sendpages(struct sock *sk, struct page *page, int offset,
>                                 size_t size, int flags)
> {
>          ....
>         /* Wait for a connection to finish. One exception is TCP Fast Open
>          * (passive side) where data is allowed to be sent before a connection
>          * is fully established.
>          */
>         if (((1 << sk->sk_state) & ~(TCPF_ESTABLISHED | TCPF_CLOSE_WAIT)) &&
>             !tcp_passive_fastopen(sk)) {
>                 if ((err = sk_stream_wait_connect(sk, &timeo)) != 0)
>                         goto out_err;
>         }
>         ....
> }
> 
> which will put data in the sock buf and returns successful in a
> CLOSED_WAIT state. I don't see means in Sheepdog driver code to get a
> HUP notification for a actual cut off connection.

Ok.  I guess the problem is that we use select(), not poll(), so we have
no way to get POLLHUP notifications.  But the write fd_set receives the
file descriptor because indeed writes will not block.

Stefan, Anthony, any ideas?

Paolo

Re: [Qemu-devel] 100% CPU when sockfd is half-closed and unexpected behavior for qemu_co_send()

[Stefan Hajnoczi]

On Mon, Jan 14, 2013 at 04:16:34PM +0800, Liu Yuan wrote:
> Hi List,
>   This problem can be reproduced by:
>   1. start a sheepdog cluster and create a volume 'test'*
>   2. attach 'test' to a bootable image like
>      $ qemu -hda image -drive if=virtio,file=sheepdog:test
>   3. pkill sheep # create a half-closed situation
> 
> I have straced it that QEMU is busy doing nonsense read/write() after
> select() in os_host_main_loop_wait(). I have no knowledge of
> glib_select_xxx, so someone please help fix it.

You mentioned a nonsense read().  What is the return value?

If you get a read with return value 0, this tells you the socket has
been closed.  Can you handle these cases in block/sheepdog.c?

Stefan

Re: [Qemu-devel] 100% CPU when sockfd is half-closed and unexpected behavior for qemu_co_send()

[Liu Yuan]

On 01/14/2013 06:23 PM, Stefan Hajnoczi wrote:
> On Mon, Jan 14, 2013 at 04:16:34PM +0800, Liu Yuan wrote:
>> Hi List,
>>   This problem can be reproduced by:
>>   1. start a sheepdog cluster and create a volume 'test'*
>>   2. attach 'test' to a bootable image like
>>      $ qemu -hda image -drive if=virtio,file=sheepdog:test
>>   3. pkill sheep # create a half-closed situation
>>
>> I have straced it that QEMU is busy doing nonsense read/write() after
>> select() in os_host_main_loop_wait(). I have no knowledge of
>> glib_select_xxx, so someone please help fix it.
> 
> You mentioned a nonsense read().  What is the return value?
> 
> If you get a read with return value 0, this tells you the socket has
> been closed.  Can you handle these cases in block/sheepdog.c?
> 

This is what I saw repeatedly:

select(25, [3 4 5 8 9 10 13 18 19 24], [], [], {1, 0}) = 2 (in [5 13],
left {0, 999994})
read(5, "\6\0\0\0\0\0\0\0", 16)         = 8
write(5, "\1\0\0\0\0\0\0\0", 8)         = 8
write(5, "\1\0\0\0\0\0\0\0", 8)         = 8
write(5, "\1\0\0\0\0\0\0\0", 8)         = 8
write(5, "\1\0\0\0\0\0\0\0", 8)         = 8
write(5, "\1\0\0\0\0\0\0\0", 8)         = 8
write(5, "\1\0\0\0\0\0\0\0", 8)         = 8
....

5 isn't a sockfd that sheepdog uses.

I don't know if I can handle it in sheepdog.c because I noticed that
there isn't any function called when this happens. So I suspect this
should be handle at upper block core.

Thanks,
Yuan

Re: [Qemu-devel] 100% CPU when sockfd is half-closed and unexpected behavior for qemu_co_send()

[Liu Yuan]

On 01/14/2013 06:07 PM, Paolo Bonzini wrote:
> Ok.  I guess the problem is that we use select(), not poll(), so we have
> no way to get POLLHUP notifications.  But the write fd_set receives the
> file descriptor because indeed writes will not block.

Hi Paolo,
  is there any movement switch select() to poll()?

Thanks,
Yuan