Bug 2229738

Summary: Cannot upload files bigger than 64K to "SSH-2.0-9.99 sshlib" server, transfer hangs
Product: Red Hat Enterprise Linux 8 Reporter: Renaud Métrich <rmetrich>
Component: libsshAssignee: Sahana Prasad <shebburn>
Status: NEW --- QA Contact: BaseOS QE Security Team <qe-baseos-security>
Severity: high Docs Contact:
Priority: high    
Version: 8.8CC: ansasaki, jjelen, jsantos, shebburn
Target Milestone: rcKeywords: Triaged
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Renaud Métrich 2023-08-07 13:40:38 UTC 
Description of problem:

We have a customer uploading files to a SFTP server advertising as "SSH-2.0-9.99 sshlib" (no idea for now which product it is). The customer uses a curl command for that, which makes internally use of libssh implementation.

When uploading 64K files or bigger (it works up to 63K included), the transfer hangs forever.
curl backtrace shows libssh is waiting indefinitely for 4 bytes from the server, which are never sent by the server (frame 8):
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
[2023/08/07 15:00:09.206865, 3] sftp_write:  Could not write as much data as expected
[2023/08/07 15:00:09.206878, 3] ssh_channel_read_timeout:  Read (4) buffered : 0 bytes. Window: 1279932
[2023/08/07 15:00:09.206894, 4] ssh_socket_pollcallback:  Poll callback on socket 4 (POLLOUT ), out buffer 0
[2023/08/07 15:00:09.206904, 4] ssh_socket_pollcallback:  sending control flow event
[2023/08/07 15:00:09.206914, 4] ssh_packet_socket_controlflow_callback:  sending channel_write_wontblock callback
^C
Program received signal SIGINT, Interrupt.
0x00007ffff6ce7f08 in __GI___poll (fds=0x5555557d5190, nfds=1, timeout=-1) at ../sysdeps/unix/sysv/linux/poll.c:29
29	  return SYSCALL_CANCEL (poll, fds, nfds, timeout);
(gdb) bt
#0  0x00007ffff6ce7f08 in __GI___poll (fds=0x5555557d5190, nfds=1, timeout=-1) at ../sysdeps/unix/sysv/linux/poll.c:29
#1  0x00007ffff6543f69 in poll (__timeout=<optimized out>, __nfds=<optimized out>, __fds=<optimized out>) at /usr/include/bits/poll2.h:38
#2  ssh_poll (fds=<optimized out>, nfds=<optimized out>, timeout=<optimized out>) at /usr/src/debug/libssh-0.9.6-10.el8_8.x86_64/src/poll.c:96
#3  0x00007ffff6544358 in ssh_poll_ctx_dopoll (ctx=ctx@entry=0x5555557d3fa0, timeout=timeout@entry=-1) at /usr/src/debug/libssh-0.9.6-10.el8_8.x86_64/src/poll.c:679
#4  0x00007ffff6545430 in ssh_handle_packets (session=session@entry=0x5555557b0a10, timeout=timeout@entry=-1) at /usr/src/debug/libssh-0.9.6-10.el8_8.x86_64/src/session.c:664
#5  0x00007ffff65454fd in ssh_handle_packets_termination (session=session@entry=0x5555557b0a10, timeout=timeout@entry=-3,  fct=fct@entry=0x7ffff6525650 <ssh_channel_read_termination>, user=user@entry=0x7fffffff9860) at /usr/src/debug/libssh-0.9.6-10.el8_8.x86_64/src/session.c:733
#6  0x00007ffff6528d04 in ssh_channel_read_timeout (channel=0x5555557dcdf0, dest=dest@entry=0x7fffffff98c0,  count=count@entry=4, is_stderr=is_stderr@entry=0, timeout_ms=<optimized out>, timeout_ms@entry=-3) at /usr/src/debug/libssh-0.9.6-10.el8_8.x86_64/src/channels.c:2943
#7  0x00007ffff6528e4f in ssh_channel_read (channel=<optimized out>, dest=dest@entry=0x7fffffff98c0, count=count@entry=4,  is_stderr=is_stderr@entry=0) at /usr/src/debug/libssh-0.9.6-10.el8_8.x86_64/src/channels.c:2855
#8  0x00007ffff6552f44 in sftp_packet_read (sftp=sftp@entry=0x5555557dc600) at /usr/src/debug/libssh-0.9.6-10.el8_8.x86_64/src/sftp.c:462
#9  0x00007ffff6553370 in sftp_read_and_dispatch (sftp=0x5555557dc600) at /usr/src/debug/libssh-0.9.6-10.el8_8.x86_64/src/sftp.c:635
#10 0x00007ffff6555750 in sftp_write (file=0x5555557dcfb0, buf=<optimized out>, count=65536) at /usr/src/debug/libssh-0.9.6-10.el8_8.x86_64/src/sftp.c:2198
#11 0x00007ffff7b83982 in sftp_send () from /lib64/libcurl.so.4
#12 0x00007ffff7b5aca8 in Curl_write () from /lib64/libcurl.so.4
#13 0x00007ffff7b6e977 in Curl_readwrite () from /lib64/libcurl.so.4
#14 0x00007ffff7b78804 in multi_runsingle () from /lib64/libcurl.so.4
#15 0x00007ffff7b79a51 in curl_multi_perform () from /lib64/libcurl.so.4
#16 0x00007ffff7b7033b in curl_easy_perform () from /lib64/libcurl.so.4
#17 0x0000555555569da0 in operate_do (global=global@entry=0x7fffffffe100, config=0x55555578db40) at ../../src/tool_operate.c:1574
#18 0x000055555556b2ea in operate (config=0x7fffffffe100, argc=<optimized out>, argv=<optimized out>) at ../../src/tool_operate.c:2077
#19 0x000055555555d9dc in main (argc=8, argv=0x7fffffffe278) at ../../src/tool_main.c:262
(gdb)
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

It seems like there is an issue with flow control.
Diffing a 63K upload and 64K one, I see not much diff except for 63K upload, the server sends back some data which causes normal termination to occur.
On the 64K upload, nothing happens after last "ssh_packet_socket_controlflow_callback:  sending channel_write_wontblock callback" is seen.
See curl.63K and curl.64K debug outputs.

It's unclear to me who is culprit here, it may be the backend, but just FYI a transfer using openssh's sftp command just works fine.

The issue happens with latest Fedora's libssh as well (libssh-0.10.5-1.fc38.x86_64).
The issue doesn't happen when building curl with libssh2 instead of libssh.

Version-Release number of selected component (if applicable):

libssh-0.9.6-10.el8_8.x86_64 (RHEL 8.8)
libssh-0.10.5-1.fc38.x86_64 (Fedora 38)

How reproducible:

Always when uploading to end customer's system
Comment 4 Renaud Métrich 2023-08-07 14:03:07 UTC 
Compiling curl with libssh (as RH does):

./configure --disable-shared --with-openssl --with-libssh

Compiling with libssh2:

./configure --disable-shared --with-openssl --with-libssh2