[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

Bug#1117574: openssh-client: output pauses in interactive session over ControlMaster

Package: openssh-client
Version: 1:10.1p1-1
Severity: normal

After upgrading to 10.1p1-1, interactive sessions are very slow and
halting while producing output from the server, as if the client is
missing some poll()/select() triggers. It's a bit hard to show the
timing in an email, but if I ssh to a local machine that is running
trixie's 10.0p1-7, like this:

  $ ssh -o ControlMaster=yes segfault.intra.peff.net

then no output is produced immediately. If I start typing (say, "echo
foo") then output does start appearing, but always behind, as if ssh is
not correctly calling read() until my local typing kicks it into a
polling loop.

If I run the command above under "strace -tt", it sits (with no output)
on this call:

  963687 01:34:16.851998 read(6 <unfinished ...>

And if I then type "echo foo", I finally get some output, with strace
showing:

  963687 01:35:08.915571 <... read resumed>, "e", 16384) = 1
  963687 01:35:08.915862 write(3, "9=\227\2137\346}\236\222A.82\253\253A\222\211Y\323>\251\243\362\t\314 \364\206B\37\223"..., 640) = 640
  963687 01:35:08.916391 rt_sigprocmask(SIG_BLOCK, [HUP INT QUIT TERM], [], 8) = 0
  963687 01:35:08.916844 ppoll([{fd=3, events=POLLIN}, {fd=3, events=0}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}], 4, NULL, [], 8) = 1 ([{fd=3, revents=POLLIN}])
  963687 01:35:09.925713 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
  963687 01:35:09.926143 read(6, "cho ", 16384) = 4
  963687 01:35:09.926461 read(3, "X\343E\253\376\361\24\351\342\217\236J\266\3\322d\taw\246\34A:\212/#\353\227\v\301B\361"..., 262144) = 300
  963687 01:35:09.926758 getrandom("\x53\x8c\x43\xe3\x6c\x36\x51\xe1\xb9\x80\xe9\x6b\xd3\x66\x19\xdd\x14\x91\x6f\x8f\xf3\xe7\xaf\x8f\x2f\x72\x5f\x11\xfc\x82\x79\xf6", 32, 0) = 32
  963687 01:35:09.926946 rt_sigprocmask(SIG_BLOCK, [HUP INT QUIT TERM], [], 8) = 0
  963687 01:35:09.927062 ppoll([{fd=3, events=POLLIN}, {fd=3, events=POLLOUT}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6, events=POLLIN}, {fd=7, events=POLLOUT}], 6, {tv_sec=0, tv_nsec=19346284}, [], 8) = 2 ([{fd=3, revents=POLLOUT}, {fd=7, revents=POLLOUT}], left {tv_sec=0, tv_nsec=19335352})
  963687 01:35:09.927200 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
  963687 01:35:09.927302 read(6, "f", 16384) = 1
  963687 01:35:10.099933 write(7, "Last login: Wed Oct  8 01:34:00 "..., 117) = 117

So you can see it sat for half a minute before I typed anything, and
then after I did, it eventually polled the other side and got the "Last
login" line from the server. It's curious that it's waiting in read()
and not poll(). If we go back a few lines in the strace output, I see:

  963687 01:34:16.851910 ppoll([{fd=3, events=POLLIN}, {fd=3, events=POLLOUT}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN|POLLOUT}], 4, NULL, [], 8) = 2 ([{fd=3, revents=POLLOUT}, {fd=5, revents=POLLOUT}])
  963687 01:34:16.851941 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
  963687 01:34:16.851967 write(5, "\0\0\0\f\200\0\0\6\0\0\0\1\0\0\0\2", 16) = 16
  963687 01:34:16.851998 read(6 <unfinished ...>

So we did poll(), and it told us there were interesting things to see,
but descriptor 6 was not one of them. So presumably the bug is there.

The problem reproduces against multiple trixie machines, as well as
against public ssh servers like github.com. Downgrading back to 10.0p1-8
makes it go away. Running without "-o ControlMaster=no" likewise runs
fine and quickly. And running a non-interactive session, even with a
ControlMaster (e.g., "ssh $host echo foo") likewise is fine.

-- System Information:
Debian Release: forky/sid
  APT prefers unstable
  APT policy: (500, 'unstable'), (500, 'testing'), (1, 'experimental')
Architecture: amd64 (x86_64)
Foreign Architectures: i386

Kernel: Linux 6.16.8+deb14-amd64 (SMP w/16 CPU threads; PREEMPT)
Kernel taint flags: TAINT_PROPRIETARY_MODULE, TAINT_OOT_MODULE, TAINT_UNSIGNED_MODULE
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8), LANGUAGE not set
Shell: /bin/sh linked to /usr/bin/dash
Init: systemd (via /run/systemd/system)

Versions of packages openssh-client depends on:
ii  adduser              3.153
ii  init-system-helpers  1.69
ii  libc6                2.41-12
ii  libedit2             3.1-20250104-1
ii  libfido2-1           1.16.0-2
ii  libgssapi-krb5-2     1.21.3-5
ii  libselinux1          3.8.1-1
ii  libssl3t64           3.5.4-1
ii  passwd               1:4.18.0-1
ii  zlib1g               1:1.3.dfsg+really1.3.1-1+b1

Versions of packages openssh-client recommends:
ii  xauth  1:1.1.2-1.1

Versions of packages openssh-client suggests:
pn  keychain      <none>
pn  libpam-ssh    <none>
pn  monkeysphere  <none>
ii  ssh-askpass   1:1.2.4.1-16+b1

-- no debconf information
Reply to: