Library blocks in call to poll

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

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

Attachment: 0001-Sending-EOF-on-Socket-that-received-a-Broken-Pipe-ma.patch
Description: Binary data