-
Notifications
You must be signed in to change notification settings - Fork 95
Description
Hi,
I am having difficulties piping data from a openssh client to a wolfsshd host.
For example, the following command never finishes.
cat test | ssh 192.168.0.1 -p 1234 'cat > xxxxxxxx'
ctrl-c aborts the connection. The test file is 48894 bytes, but 8188 bytes only makes it to the xxxxxxx
file. The same happens using mbuffer -i file ...
It seems to always be 8188
bytes, even if I cat a large ISO or some text files. However when doing cat /dev/random
or /dev/urandom
, the command finishes but no remote file is created at all.
I built wolfssh from a git checkout today using ./configure --prefix=/opt/wolfssh --enable-all --with-wolfssl=/opt/wolfssl
I use the following sshd_config
Port 1234
PermitRootLogin yes
PasswordAuthentication yes
LoginGraceTime 30
HostKey /opt/wolfssh/etc/host_key_ed25519.pem
HostKey /opt/wolfssh/etc/host_key_ecdsa.pem
HostKey /opt/wolfssh/etc/host_key_rsa.pem
I start wolfsshd using /opt/wolfssh/bin/wolfsshd -d -E /tmp/wolfsshd.log -f /opt/wolfssh/etc/sshd_config
Logfile contains
...
[PID 67002]: [SSHD] Incoming TCP data found
[PID 81519]: [SSHD] Checking user name root
[PID 81519]: [SSHD] Unix check user
[PID 81519]: [SSHD] User ok.
[PID 81519]: [SSHD] Attempting to raise permissions level
[PID 81519]: [SSHD] Public key ok.
[PID 81519]: [SSHD] Lowering permissions level
[PID 81519]: [SSHD] Checking user name root
[PID 81519]: [SSHD] Unix check user
[PID 81519]: [SSHD] User ok.
[PID 81519]: [SSHD] Attempting to raise permissions level
[PID 81519]: [SSHD] Public key ok.
[PID 81519]: [SSHD] Lowering permissions level
[PID 81519]: [SSHD] grace time = 30 timeout = 0
[PID 81519]: [SSHD] Entering exec session [cat > /xxxxxxxx]
[PID 81519]: [SSHD] Attempting to raise permissions level
[PID 81519]: [SSHD] Attempting to close down connection
[PID 81519]: [SSHD] Return from closing connection = 0
The source test file was created using the following, so I can determine how much was processed.
for i in {1..10000} ; do echo $i ; done >> test
An strace of wolfsshd reveals it receives and sends 1859 rows and then stops with <unfinished ...>
reading from /dev/pts/9<char 136:9
83782<cat> 01:15:52.827126 read(0</dev/pts/9<char 136:9>>, "1857\n", 262144) = 5
83782<cat> 01:15:52.827148 write(1</xxxxxxxx>, "1857\n", 5) = 5
83782<cat> 01:15:52.827172 read(0</dev/pts/9<char 136:9>>, "1858\n", 262144) = 5
83782<cat> 01:15:52.827194 write(1</xxxxxxxx>, "1858\n", 5) = 5
83782<cat> 01:15:52.827218 read(0</dev/pts/9<char 136:9>>, "1859\n", 262144) = 5
83782<cat> 01:15:52.827240 write(1</xxxxxxxx>, "1859\n", 5) = 5
83782<cat> 01:15:52.827264 read(0</dev/pts/9<char 136:9>>, <unfinished ...>
83405<wolfsshd> 01:15:53.642975 <... pselect6 resumed>) = 0 (Timeout)
83405<wolfsshd> 01:15:53.643025 pselect6(5, [4<TCP:[0.0.0.0:1234]>], [], [], {tv_sec=1, tv_nsec=0}, NULL) = 0 (Timeout)
83405<wolfsshd> 01:15:54.643890 pselect6(5, [4<TCP:[0.0.0.0:1234]>], [], [], {tv_sec=1, tv_nsec=0}, NULL) = 0 (Timeout)
83405<wolfsshd> 01:15:55.645052 pselect6(5, [4<TCP:[0.0.0.0:1234]>], [], [], {tv_sec=1, tv_nsec=0}, NULL) = 0 (Timeout)
Using a 1024 byte file, all rows transfer, but worlfsshd still end in unfinished state.
✦ ❯ less strace-wolfsshd
86739<strace> 01:35:04.941395 execve("/opt/wolfssh/bin/wolfsshd", ["/opt/wolfssh/bin/wolfsshd", "-d", "-E", "/tmp/wolfsshd.log", "-f", "/opt/wolfssh/etc/sshd_config"], ["SHELL=/bin/bash", "MAGICK_THREAD_LIMIT=12", "LESS=-R -M --shift 5", "HISTCONTROL=ignoreboth:erasedups", "JDK_HOME=/etc/java-config-2/curr"..., "CONFIG_PROTECT_MASK=/etc/sandbox"..., "PKG_CONFIG_PATH=/usr/share/guile"..., "HISTSIZE=", "TERMCAP=SC|screen.xterm-256color"..., "JAVA_HOME=/etc/java-config-2/cur"..., "OMP_THREAD_LIMIT=12", "HISTTIMEFORMAT=[%F %T] ", "WINDOW=3", "LC_MONETARY=sv_SE.utf8", "EDITOR=nano", "PWD=/tmp", "CONFIG_PROTECT=/usr/share/gnupg/"..., "LOGNAME=root", "MANPATH=/etc/java-config-2/curre"..., "_=/usr/bin/strace", "OPENCL_PROFILE=ocl-icd", "TZ=:/etc/localtime", "HOME=/root", "LANG=en_GB.utf8", "HISTFILE=/root/.bash_eternal_his"..., "LS_COLORS=rs=0:di=01;34:ln=01;36"..., "FLTK_DOCDIR=/usr/share/doc/fltk-"..., "STARSHIP_SHELL=bash", "OPENGL_PROFILE=xorg-x11", "SSH_CONNECTION=192.168.0.114 473"..., "XZ_OPT=-T0", "STARSHIP_SESSION_KEY=58881359626"..., "INFOPATH=/usr/share/gcc-data/x86"..., "JAVAC=/etc/java-config-2/current"..., "TERM=screen.xterm-256color", "LESSOPEN=|lesspipe %s", "USER=root", "MANPAGER=manpager", "SHLVL=2", "PAGER=less", "LEX=flex", "XSESSION=openbox", "GCC_SPECS=", "GSETTINGS_BACKEND=dconf", "SSH_CLIENT=192.168.0.114 47358 3"..., "OMP_NUM_THREADS=12", "PATH=/usr/local/sbin:/usr/local/"..., "STY=9459.pts-1.e350", "HISTFILESIZE=", "LV2_PATH=/usr/lib64/lv2", "MAIL=/var/mail/root", "SSH_TTY=/dev/pts/1", "SHELL_SETS_TITLE=0", "LC_NUMERIC=sv_SE.utf8", "OLDPWD=/root", "LADSPA_PATH=/usr/lib64/ladspa", "BASH_FUNC_compact_ram%%=()
{ ec"..., "BASH_FUNC_emerge_world%%=() { e"..., "BASH_FUNC_emerge_depclean%%=() {"..., "BASH_FUNC_wp%%=() { sudo -u wor"..., "BASH_FUNC_occ%%=() { cgexec -g "...]) = 0
86739<wolfsshd> 01:35:04.941684 brk(NULL) = 0x5576d148f000
86739<wolfsshd> 01:35:04.941732 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f65da95d000
86739<wolfsshd> 01:35:04.941768 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
86739<wolfsshd> 01:35:04.941839 openat(AT_FDCWD</tmp>, "/opt/wolfssh/lib/glibc-hwcaps/x86-64-v3/libwolfssh.so.7", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
86739<wolfsshd> 01:35:04.941887 newfstatat(AT_FDCWD</tmp>, "/opt/wolfssh/lib/glibc-hwcaps/x86-64-v3/", 0x7ffda91132e0, 0) = -1 ENOENT (No such file or directory)
86739<wolfsshd> 01:35:04.941920 openat(AT_FDCWD</tmp>, "/opt/wolfssh/lib/glibc-hwcaps/x86-64-v2/libwolfssh.so.7", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
86739<wolfsshd> 01:35:04.941952 newfstatat(AT_FDCWD</tmp>, "/opt/wolfssh/lib/glibc-hwcaps/x86-64-v2/", 0x7ffda91132e0, 0) = -1 ENOENT (No such file or directory)
86739<wolfsshd> 01:35:04.941990 openat(AT_FDCWD</tmp>, "/opt/wolfssh/lib/libwolfssh.so.7", O_RDONLY|O_CLOEXEC) = 3</opt/wolfssh/lib/libwolfssh.so.7.10.1>
86739<wolfsshd> 01:35:04.942030 read(3</opt/wolfssh/lib/libwolfssh.so.7.10.1>, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\0\0\0\0\0\0\0"..., 832) = 832
86739<wolfsshd> 01:35:04.942060 fstat(3</opt/wolfssh/lib/libwolfssh.so.7.10.1>, {st_dev=makedev(0, 0x1d), st_ino=23233759, st_mode=S_IFREG|0755, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=672, st_size=342760, st_atime=1739141413 /* 2025-02-09T23:50:13.896709447+0100 */, st_atime_nsec=896709447, st_mtime=1739141413 /* 2025-02-09T23:50:13.896709447+0100 */, st_mtime_nsec=896709447, st_ctime=1739141413 /* 2025-02-09T23...skipping...
87232<cat> 01:36:33.627184 brk(NULL) = 0x559ea523d000
87232<cat> 01:36:33.627201 brk(0x559ea525e000) = 0x559ea525e000
87232<cat> 01:36:33.627225 openat(AT_FDCWD</root>, "/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 4</usr/lib/locale/locale-archive>
87232<cat> 01:36:33.627253 fstat(4</usr/lib/locale/locale-archive>, {st_dev=makedev(0,
0x1d), st_ino=18192717, st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=13544, st_size=6990080, st_atime=1706910198 /* 2024-02-02T22:43:18.377880014+0100 */, st_atime_nsec=377880014, st_mtime=1706910198 /* 2024-02-02T22:43:18.417880807+0100 */, st_mtime_nsec=417880807, st_ctime=1706910198 /* 2024-02-02T22:43:18.417880807+0100 */, st_ctime_nsec=417880807}) = 0
87232<cat> 01:36:33.627279 mmap(NULL, 6990080, PROT_READ, MAP_PRIVATE, 4</usr/lib/locale/locale-archive>, 0) = 0x7f2d65400000
87232<cat> 01:36:33.627304 close(4</usr/lib/locale/locale-archive>) = 0
87232<cat> 01:36:33.627356 fstat(1</xxxxxxxx>, {st_dev=makedev(0, 0x1d), st_ino=23234129, st_mode=S_IFREG|0666, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=0,
st_size=0, st_atime=1739147793 /* 2025-02-10T01:36:33.620917714+0100 */, st_atime_nsec=620917714, st_mtime=1739147793 /* 2025-02-10T01:36:33.620917714+0100 */, st_mtime_nsec=620917714, st_ctime=1739147793 /* 2025-02-10T01:36:33.620917714+0100 */, st_ctime_nsec=620917714}) = 0
87232<cat> 01:36:33.627383 fstat(0</dev/pts/9<char 136:9>>, {st_dev=makedev(0, 0x17), st_ino=12, st_mode=S_IFCHR|0620, st_nlink=1, st_uid=0, st_gid=5, st_blksize=1024, st_blocks=0, st_rdev=makedev(0x88, 0x9), st_atime=1739147792 /* 2025-02-10T01:36:32.808908319+0100 */, st_atime_nsec=808908319, st_mtime=1739147792 /* 2025-02-10T01:36:32.808908319+0100 */, st_mtime_nsec=808908319, st_ctime=1739147792 /* 2025-02-10T01:36:32.808908319+0100 */, st_ctime_nsec=808908319}) = 0
87232<cat> 01:36:33.627410 fadvise64(0</dev/pts/9<char 136:9>>, 0, 0, POSIX_FADV_SEQUENTIAL) = 0
87232<cat> 01:36:33.627432 mmap(NULL, 270336, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f2d65c59000
87232<cat> 01:36:33.627453 read(0</dev/pts/9<char 136:9>>, "1\n", 262144) = 2
87232<cat> 01:36:33.627479 write(1</xxxxxxxx>, "1\n", 2) = 2
87232<cat> 01:36:33.627508 read(0</dev/pts/9<char 136:9>>, "2\n", 262144) = 2
87232<cat> 01:36:33.627531 write(1</xxxxxxxx>, "2\n", 2) = 2
87232<cat> 01:36:33.627559 read(0</dev/pts/9<char 136:9>>, "3\n", 262144) = 2
87232<cat> 01:36:33.627582 write(1</xxxxxxxx>, "3\n", 2) = 2
87232<cat> 01:36:33.627606 read(0</dev/pts/9<char 136:9>>, "4\n", 262144) = 2
87232<cat> 01:36:33.627629 write(1</xxxxxxxx>, "4\n", 2) = 2
87232<cat> 01:36:33.627653 read(0</dev/pts/9<char 136:9>>, "5\n", 262144) = 2
87232<cat> 01:36:33.627675 write(1</xxxxxxxx>, "5\n", 2) = 2
87232<cat> 01:36:33.627699 read(0</dev/pts/9<char 136:9>>, "6\n", 262144) = 2
87232<cat> 01:36:33.627721 write(1</xxxxxxxx>, "6\n", 2) = 2
87232<cat> 01:36:33.627745 read(0</dev/pts/9<char 136:9>>, "7\n", 262144) = 2
87232<cat> 01:36:33.627768 write(1</xxxxxxxx>, "7\n", 2) = 2
87232<cat> 01:36:33.627818 read(0</dev/pts/9<char 136:9>>, "8\n", 262144) = 2
87232<cat> 01:36:33.627843 write(1</xxxxxxxx>, "8\n", 2) = 2
87232<cat> 01:36:33.627868 read(0</dev/pts/9<char 136:9>>, "9\n", 262144) = 2
87232<cat> 01:36:33.627890 write(1</xxxxxxxx>, "9\n", 2) = 2
87232<cat> 01:36:33.627915 read(0</dev/pts/9<char 136:9>>, "10\n", 262144) = 3
87232<cat> 01:36:33.627937 write(1</xxxxxxxx>, "10\n", 3) = 3
87232<cat> 01:36:33.627961 read(0</dev/pts/9<char 136:9>>, "11\n", 262144) = 3
87232<cat> 01:36:33.627984 write(1</xxxxxxxx>, "11\n", 3) = 3
87232<cat> 01:36:33.628008 read(0</dev/pts/9<char 136:9>>, "12\n", 262144) = 3
87232<cat> 01:36:33.628031 write(1</xxxxxxxx>, "12\n", 3) = 3
87232<cat> 01:36:33.628055 read(0</dev/pts/9<char 136:9>>, "13\n", 262144) = 3
87232<cat> 01:36:33.628077 write(1</xxxxxxxx>, "13\n", 3) = 3
... snip
87232<cat> 01:36:33.639488 read(0</dev/pts/9<char 136:9>>, "256\n", 262144) = 4
87232<cat> 01:36:33.639517 write(1</xxxxxxxx>, "256\n", 4) = 4
87232<cat> 01:36:33.639547 read(0</dev/pts/9<char 136:9>>, "257\n", 262144) = 4
87232<cat> 01:36:33.639576 write(1</xxxxxxxx>, "257\n", 4) = 4
87232<cat> 01:36:33.639607 read(0</dev/pts/9<char 136:9>>, "258\n", 262144) = 4
87232<cat> 01:36:33.639636 write(1</xxxxxxxx>, "258\n", 4) = 4
87232<cat> 01:36:33.639671 read(0</dev/pts/9<char 136:9>>, "259\n", 262144) = 4
87232<cat> 01:36:33.639703 write(1</xxxxxxxx>, "259\n", 4) = 4
87232<cat> 01:36:33.640770 write(1</xxxxxxxx>, "278\n", 4) = 4
87232<cat> 01:36:33.640797 read(0</dev/pts/9<char 136:9>>, "279\n", 262144) = 4
87232<cat> 01:36:33.640823 write(1</xxxxxxxx>, "279\n", 4) = 4
87232<cat> 01:36:33.640850 read(0</dev/pts/9<char 136:9>>, "280\n", 262144) = 4
87232<cat> 01:36:33.640876 write(1</xxxxxxxx>, "280\n", 4) = 4
87232<cat> 01:36:33.640903 read(0</dev/pts/9<char 136:9>>, "281\n", 262144) = 4
87232<cat> 01:36:33.640928 write(1</xxxxxxxx>, "281\n", 4) = 4
87232<cat> 01:36:33.640955 read(0</dev/pts/9<char 136:9>>, "282\n", 262144) = 4
87232<cat> 01:36:33.640979 write(1</xxxxxxxx>, "282\n", 4) = 4
87232<cat> 01:36:33.641005 read(0</dev/pts/9<char 136:9>>, "283\n", 262144) = 4
87232<cat> 01:36:33.641028 write(1</xxxxxxxx>, "283\n", 4) = 4
87232<cat> 01:36:33.641052 read(0</dev/pts/9<char 136:9>>, <unfinished ...>
86758<wolfsshd> 01:36:33.719328 <... pselect6 resumed>) = 0 (Timeout)
86758<wolfsshd> 01:36:33.719410 pselect6(5, [4<TCP:[0.0.0.0:1234]>], [], [], {tv_sec=1, tv_nsec=0}, NULL) = 0 (Timeout)
86758<wolfsshd> 01:36:34.719832 pselect6(5, [4<TCP:[0.0.0.0:1234]>], [], [], {tv_sec=1, tv_nsec=0}, NULL) = 0 (Timeout)
86758<wolfsshd> 01:36:35.720935 pselect6(5, [4<TCP:[0.0.0.0:1234]>], [], [], {tv_sec=1, tv_nsec=0}, NULL) = 0 (Timeout)
86758<wolfsshd> 01:36:36.722026 pselect6(5, [4<TCP:[0.0.0.0:1234]>], [], [], {tv_sec=1, tv_nsec=0}, NULL) = 0 (Timeout)
86758<wolfsshd> 01:36:37.723281 pselect6(5, [4<TCP:[0.0.0.0:1234]>], [], [], {tv_sec=1, tv_nsec=0}, NULL) = 0 (Timeout)
86758<wolfsshd> 01:36:38.724250 pselect6(5, [4<TCP:[0.0.0.0:1234]>], [], [], {tv_sec=1, tv_nsec=0}, NULL) = 0 (Timeout)
86758<wolfsshd> 01:36:39.725364 pselect6(5, [4<TCP:[0.0.0.0:1234]>], [], [], {tv_sec=1, tv_nsec=0}, NULL) = 0 (Timeout)
86758<wolfsshd> 01:36:40.726448 pselect6(5, [4<TCP:[0.0.0.0:1234]>], [], [], {tv_sec=1, tv_nsec=0}, NULL) = 0 (Timeout)
86758<wolfsshd> 01:36:41.727556 pselect6(5, [4<TCP:[0.0.0.0:1234]>], [], [], {tv_sec=1, tv_nsec=0}, NULL) = 0 (Timeout)
86758<wolfsshd> 01:36:42.728104 pselect6(5, [4<TCP:[0.0.0.0:1234]>], [], [], {tv_sec=1, tv_nsec=0}, NULL) = 0 (Timeout)
86758<wolfsshd> 01:36:43.729116 pselect6(5, [4<TCP:[0.0.0.0:1234]>], [], [], {tv_sec=1, tv_nsec=0}, NULL) = 0 (Timeout)
86758<wolfsshd> 01:36:44.730267 pselect6(5, [4<TCP:[0.0.0.0:1234]>], [], [], {tv_sec=1, tv_nsec=0}, NULL) = 0 (Timeout)
87232<cat> 01:36:33.640770 write(1</xxxxxxxx>, "278\n", 4) = 4
87232<cat> 01:36:33.640797 read(0</dev/pts/9<char 136:9>>, "279\n", 262144) = 4
87232<cat> 01:36:33.640823 write(1</xxxxxxxx>, "279\n", 4) = 4
87232<cat> 01:36:33.640850 read(0</dev/pts/9<char 136:9>>, "280\n", 262144) = 4
87232<cat> 01:36:33.640876 write(1</xxxxxxxx>, "280\n", 4) = 4
87232<cat> 01:36:33.640903 read(0</dev/pts/9<char 136:9>>, "281\n", 262144) = 4
87232<cat> 01:36:33.640928 write(1</xxxxxxxx>, "281\n", 4) = 4
87232<cat> 01:36:33.640955 read(0</dev/pts/9<char 136:9>>, "282\n", 262144) = 4
87232<cat> 01:36:33.640979 write(1</xxxxxxxx>, "282\n", 4) = 4
87232<cat> 01:36:33.641005 read(0</dev/pts/9<char 136:9>>, "283\n", 262144) = 4
87232<cat> 01:36:33.641028 write(1</xxxxxxxx>, "283\n", 4) = 4
87232<cat> 01:36:33.641052 read(0</dev/pts/9<char 136:9>>, <unfinished ...>
86758<wolfsshd> 01:36:33.719328 <... pselect6 resumed>) = 0 (Timeout)
86758<wolfsshd> 01:36:33.719410 pselect6(5, [4<TCP:[0.0.0.0:1234]>], [], [], {tv_sec=1, tv_nsec=0}, NULL) = 0 (Timeout)
86758<wolfsshd> 01:36:34.719832 pselect6(5, [4<TCP:[0.0.0.0:1234]>], [], [], {tv_sec=1, tv_nsec=0}, NULL) = 0 (Timeout)
86758<wolfsshd> 01:36:35.720935 pselect6(5, [4<TCP:[0.0.0.0:1234]>], [], [], {tv_sec=1, tv_nsec=0}, NULL) = 0 (Timeout)
86758<wolfsshd> 01:36:36.722026 pselect6(5, [4<TCP:[0.0.0.0:1234]>], [], [], {tv_sec=1, tv_nsec=0}, NULL) = 0 (Timeout)
86758<wolfsshd> 01:36:37.723281 pselect6(5, [4<TCP:[0.0.0.0:1234]>], [], [], {tv_sec=1, tv_nsec=0}, NULL) = 0 (Timeout)
I ran the sending cat
and ssh
through strace too and see that both do finish sending data and close the pipe, but somehow wolfsshd does not recognize this.
It seems as there are two problems;
- wolfsshd stalls on transfers more than than a few KiB.
- wolfsshd does not recognize that the caller has closed the pipe, and keeps the connection open.
I'm running in Gentoo Linux, x86_64, gcc-14.2.1. I did try this in September last year, with the same issue.