Re: Library blocks in call to poll

[Joao Pedro Almeida Pereira <joao.almeida@xxxxxxxxxxx>]

Hello,
Was this patch ever reviewed? Or added to the master?

BR

On Thu, Jul 31, 2014 at 2:55 PM, Joao Pedro Almeida Pereira <
joao.almeida@xxxxxxxxxxx> wrote:

> Hello,
> I am seeing a behaviour in the library that is strange and due to a return
> value that is not being retrieved.
> The behaviour is the following
> 1 - Create a shell channel
> 2 - write and read a bunch of commands
> 3 - Wait 10 minutes without traffic
> 4 - Try to disconnect the channel
> 4 - Read the output but the output is an EOF and the channel closes
> 5 - After that the poll is called to flush the rest of the packets from
> the socket and will never leave this function because we get a Broken Pipe
> in the connection
>
> I am using linux and the library version 0.6.3
>
> This is the log of the library:
>
> [2014/07/31 11:06:16.326721, 3] ssh_socket_unbuffered_write:  Enabling
> POLLOUT for socket
> [2014/07/31 11:06:16.326741, 3] packet_send2:  packet: wrote
> [len=12,padding=6,comp=5,payload=5]
> [2014/07/31 11:06:16.326750, 3] ssh_channel_send_eof:  Sent a EOF on
> client channel (43:0)
> [2014/07/31 11:06:16.326770, 3] packet_send2:  packet: wrote
> [len=12,padding=6,comp=5,payload=5]
> [2014/07/31 11:06:16.326779, 3] ssh_channel_close:  Sent a close on client
> channel (43:0)
> [2014/07/31 11:06:16.326806, 3] ssh_packet_socket_callback:  packet: read
> type 96 [len=12,padding=6,comp=5,payload=5]
> [2014/07/31 11:06:16.326816, 3] ssh_packet_process:  Dispatching handler
> for packet type 96
> [2014/07/31 11:06:16.326827, 3] channel_rcv_eof:  Received eof on channel
> (44:1)
> [2014/07/31 11:06:16.326835, 3] ssh_packet_socket_callback:  Processing
> 244 bytes left in socket buffer
> [2014/07/31 11:06:16.326850, 3] ssh_packet_socket_callback:  packet: read
> type 98 [len=44,padding=5,comp=38,payload=38]
> [2014/07/31 11:06:16.326858, 3] ssh_packet_process:  Dispatching handler
> for packet type 98
> [2014/07/31 11:06:16.326870, 3] channel_rcv_request:  Remote connection
> closed by signal SIG TERM
> [2014/07/31 11:06:16.326878, 3] ssh_packet_socket_callback:  Processing
> 176 bytes left in socket buffer
> [2014/07/31 11:06:16.326891, 3] ssh_packet_socket_callback:  packet: read
> type 97 [len=12,padding=6,comp=5,payload=5]
> [2014/07/31 11:06:16.326899, 3] ssh_packet_process:  Dispatching handler
> for packet type 97
> [2014/07/31 11:06:16.326907, 3] channel_rcv_close:  Received close on
> channel (44:1)
> [2014/07/31 11:06:16.326914, 3] ssh_packet_socket_callback:  Processing
> 140 bytes left in socket buffer
> [2014/07/31 11:06:16.326927, 3] ssh_packet_socket_callback:  packet: read
> type 96 [len=12,padding=6,comp=5,payload=5]
> [2014/07/31 11:06:16.326935, 3] ssh_packet_process:  Dispatching handler
> for packet type 96
> [2014/07/31 11:06:16.326943, 3] channel_rcv_eof:  Received eof on channel
> (43:0)
> [2014/07/31 11:06:16.326950, 3] ssh_packet_socket_callback:  Processing
> 104 bytes left in socket buffer
> [2014/07/31 11:06:16.326963, 3] ssh_packet_socket_callback:  packet: read
> type 98 [len=44,padding=5,comp=38,payload=38]
> [2014/07/31 11:06:16.326971, 3] ssh_packet_process:  Dispatching handler
> for packet type 98
> [2014/07/31 11:06:16.326980, 3] channel_rcv_request:  Remote connection
> closed by signal SIG TERM
> [2014/07/31 11:06:16.326988, 3] ssh_packet_socket_callback:  Processing 36
> bytes left in socket buffer
> [2014/07/31 11:06:16.327001, 3] ssh_packet_socket_callback:  packet: read
> type 97 [len=12,padding=6,comp=5,payload=5]
> [2014/07/31 11:06:16.327009, 3] ssh_packet_process:  Dispatching handler
> for packet type 97
> [2014/07/31 11:06:16.327016, 3] channel_rcv_close:  Received close on
> channel (43:0)
> [2014/07/31 11:06:16.327044, 3] ssh_socket_unbuffered_write:  Enabling
> POLLOUT for socket
> [2014/07/31 11:06:16.327066, 1] ssh_socket_nonblocking_flush:  Writing
> packet: error on socket (or connection closed): Broken pipe
>
>
> This is the library back trace:
>
> #0  0x00007ff8e99cc4bf in poll () from /lib64/libc.so.6
> #1  0x00007ff8e426fceb in ssh_poll_ctx_dopoll () from
> /usr/lib64/libssh.so.4
> #2  0x00007ff8e4270121 in ssh_handle_packets () from /usr/lib64/libssh.so.4
> #3  0x00007ff8e427038a in ssh_handle_packets_termination () from
> /usr/lib64/libssh.so.4
> #4  0x00007ff8e427051a in ssh_blocking_flush () from /usr/lib64/libssh.so.4
> #5  0x00007ff8e425e476 in ssh_channel_close () from /usr/lib64/libssh.so.4
>
>
> The problem that i found is that the function ssh_socket_nonblocking_flush
> when is called the library do not check if an error happened and follow the
> stream without looking into it an so when the poll is done in the socket it
> gets stuck.
>
> To solve the following issue i created the attached patch that correct
> some points present in the socket.c that had "FIXME" tags on them, and now
> the problem is solved.
>
> If you see any issue please tell me.
>
> BR
> --
> -----
> --------
> João Pereira
>
> Email: joao.almeida@xxxxxxxxxxx
> Web: http://www.bluetc.es
>



-- 
--
-----
--------
João Pereira

Email: joao.almeida@xxxxxxxxxxx
Web: http://www.bluetc.es