Clarification on libssh behaviour

[Adam Ball <adam.ball88@xxxxxxxxx>]

Hello,

I am integrating libssh with boost::asio and I am observing some behaviour
I can't explain.
boost::asio is creating the tcp socket and then that socket is provided
into libssh.
The tcp socket will then call handlers when data is present for a read, and
also when data can be written.

I am having an issue specifically when performing a read via
ssh_channel_read_nonblocking.
If there are X bytes available, and I only read Y bytes where Y < X, I
schedule another read until X == 0.

In the beginning ( first message being received ) everything seems to be
working fine as indicated by the following libssh logs:
[2020/12/11 21:58:17.678608, 3] ssh_channel_read_timeout:  Read (256)
buffered : 2793 bytes. Window: 1278157
[2020/12/11 21:58:17.678926, 3] ssh_channel_read_timeout:  Read (256)
buffered : 2537 bytes. Window: 1278157
[2020/12/11 21:58:17.679162, 3] ssh_channel_read_timeout:  Read (256)
buffered : 2281 bytes. Window: 1278157
etc

until nothing more is available to be read and the following logs are
produced
[2020/12/11 21:58:17.681919, 4] ssh_socket_pollcallback:  Poll callback on
socket 6 (POLLIN POLLOUT ), out buffer 0
[2020/12/11 21:58:17.682002, 3] ssh_packet_socket_callback:  packet: read
type 93 [len=28,padding=18,comp=9,payload=9]
[2020/12/11 21:58:17.682036, 3] ssh_packet_process:  Dispatching handler
for packet type 93
[2020/12/11 21:58:17.682067, 2] channel_rcv_change_window:  Adding 1248155
bytes to channel (43:43) (from 31845 bytes)
[2020/12/11 21:58:17.682097, 4] ssh_socket_pollcallback:  sending control
flow event
[2020/12/11 21:58:17.682125, 4] ssh_packet_socket_controlflow_callback:
 sending channel_write_wontblock callback

This puts boost::asio basically into a quiet period until something can be
read.

The issue I see is the next message that comes, again reading Y where Y is
less than X, the total amount available to read
[2020/12/11 21:58:18.738078, 4] ssh_socket_pollcallback:  Poll callback on
socket 6 (POLLIN POLLOUT ), out buffer 0
[2020/12/11 21:58:18.738194, 3] ssh_packet_socket_callback:  packet: read
type 94 [len=588,padding=6,comp=581,payload=581]
[2020/12/11 21:58:18.738227, 3] ssh_packet_process:  Dispatching handler
for packet type 94
[2020/12/11 21:58:18.738282, 3] channel_rcv_data:  Channel receiving 572
bytes data in 0 (local win=1278157 remote win=1279738)
[2020/12/11 21:58:18.738311, 3] channel_default_bufferize:  placing 572
bytes into channel buffer (stderr=0)
[2020/12/11 21:58:18.738345, 3] channel_rcv_data:  Channel windows are now
(local win=1277585 remote win=1279738)
[2020/12/11 21:58:18.738379, 3] ssh_packet_socket_callback:  Processing 64
bytes left in socket buffer
[2020/12/11 21:58:18.738426, 3] ssh_packet_socket_callback:  packet: read
type 94 [len=28,padding=12,comp=15,payload=15]
[2020/12/11 21:58:18.738456, 3] ssh_packet_process:  Dispatching handler
for packet type 94
[2020/12/11 21:58:18.738492, 3] channel_rcv_data:  Channel receiving 6
bytes data in 0 (local win=1277585 remote win=1279738)
[2020/12/11 21:58:18.738522, 3] channel_default_bufferize:  placing 6 bytes
into channel buffer (stderr=0)
[2020/12/11 21:58:18.738553, 3] channel_rcv_data:  Channel windows are now
(local win=1277579 remote win=1279738)
[2020/12/11 21:58:18.738585, 4] ssh_socket_pollcallback:  sending control
flow event
[2020/12/11 21:58:18.738614, 4] ssh_packet_socket_controlflow_callback:
 sending channel_write_wontblock callback
[2020/12/11 21:58:18.738647, 3] ssh_channel_read_timeout:  Read (256)
buffered : 578 bytes. Window: 1277579

The 256 bytes are read, however there will not be any follow on reads to
continue pulling from libssh.

These logs are different then the logs for the first message so I'm trying
to figure out if libssh is doing something differently.

Thanks for any help :)