Solved Why does ssh session in FreeBSD 14.0 generate enormous amount of packets?

I

Igor2022

I have two FreeBSD boxes running 13.0 and 14.0 respectively, and I'm comparing the behavior of those boxes in similar scenarios.
One scenario exhibit significant discrepancy, and I'd like to ask the community if anyone else has seen (or can reproduce) such discrepancy, and how can it be explained.

The scenario is:
1. Run sshd server with default config (unmodified /etc/ssh/sshd_config that was installed with the system).
2. Start ssh session to localhost.
3. Once connected, logged in, and got to the shell prompt, start capturing the session packets with tcpdump.
4. Press a single character key in ssh client terminal.
5. See how much captured traffic that single key press has generated.

When performed on FreeBSD 13.0 box running its default OpenSSH_7.9p1, OpenSSL 1.1.1k-freebsd 24 Aug 2021, this test gives 3 packets per keypress, which is perfectly reasonable:
Code: 
07:29:36.793499 IP 127.0.0.1.41646 > 127.0.0.1.22: Flags [P.], seq 1420536330:1420536366, ack 3304629505, win 1277, options [nop,nop,TS val 228470794 ecr 3231882770], length 36
07:29:36.793747 IP 127.0.0.1.22 > 127.0.0.1.41646: Flags [P.], seq 1:37, ack 36, win 1277, options [nop,nop,TS val 3231890982 ecr 228470794], length 36
07:29:36.834272 IP 127.0.0.1.41646 > 127.0.0.1.22: Flags [.], ack 37, win 1277, options [nop,nop,TS val 228470835 ecr 3231890982], length 0

However, on FreeBSD 14.0 box running its default OpenSSH_9.5p1, OpenSSL 3.0.12 24 Oct 2023, this test gives random number of packets per keypress, varying wildly. I've seen from 100 to 226 packets. Exact tcpdump log is attached. Here's a short snippet:
Code: 
06:44:15.052966 IP 127.0.0.1.20330 > 127.0.0.1.22: Flags [P.], seq 2908534396:2908534432, ack 1900938993, win 1277, options [nop,nop,TS val 2096734498 ecr 2538083088], length 36
06:44:15.053198 IP 127.0.0.1.22 > 127.0.0.1.20330: Flags [P.], seq 1:37, ack 36, win 1277, options [nop,nop,TS val 2538094118 ecr 2096734498], length 36
06:44:15.075464 IP 127.0.0.1.20330 > 127.0.0.1.22: Flags [P.], seq 36:72, ack 37, win 1277, options [nop,nop,TS val 2096734521 ecr 2538094118], length 36
06:44:15.075550 IP 127.0.0.1.22 > 127.0.0.1.20330: Flags [P.], seq 37:73, ack 72, win 1277, options [nop,nop,TS val 2538094141 ecr 2096734521], length 36
06:44:15.096729 IP 127.0.0.1.20330 > 127.0.0.1.22: Flags [P.], seq 72:108, ack 73, win 1277, options [nop,nop,TS val 2096734542 ecr 2538094141], length 36
06:44:15.096785 IP 127.0.0.1.22 > 127.0.0.1.20330: Flags [P.], seq 73:109, ack 108, win 1277, options [nop,nop,TS val 2538094162 ecr 2096734542], length 36
06:44:15.117779 IP 127.0.0.1.20330 > 127.0.0.1.22: Flags [P.], seq 108:144, ack 109, win 1277, options [nop,nop,TS val 2096734563 ecr 2538094162], length 36
06:44:15.117827 IP 127.0.0.1.22 > 127.0.0.1.20330: Flags [P.], seq 109:145, ack 144, win 1277, options [nop,nop,TS val 2538094183 ecr 2096734563], length 36
06:44:15.139248 IP 127.0.0.1.20330 > 127.0.0.1.22: Flags [P.], seq 144:180, ack 145, win 1277, options [nop,nop,TS val 2096734584 ecr 2538094183], length 36
06:44:15.139292 IP 127.0.0.1.22 > 127.0.0.1.20330: Flags [P.], seq 145:181, ack 180, win 1277, options [nop,nop,TS val 2538094204 ecr 2096734584], length 36
06:44:15.161560 IP 127.0.0.1.20330 > 127.0.0.1.22: Flags [P.], seq 180:216, ack 181, win 1277, options [nop,nop,TS val 2096734607 ecr 2538094204], length 36
06:44:15.161603 IP 127.0.0.1.22 > 127.0.0.1.20330: Flags [P.], seq 181:217, ack 216, win 1277, options [nop,nop,TS val 2538094227 ecr 2096734607], length 36
06:44:15.183483 IP 127.0.0.1.20330 > 127.0.0.1.22: Flags [P.], seq 216:252, ack 217, win 1277, options [nop,nop,TS val 2096734629 ecr 2538094227], length 36
06:44:15.183528 IP 127.0.0.1.22 > 127.0.0.1.20330: Flags [P.], seq 217:253, ack 252, win 1277, options [nop,nop,TS val 2538094249 ecr 2096734629], length 36
06:44:15.203777 IP 127.0.0.1.20330 > 127.0.0.1.22: Flags [P.], seq 252:288, ack 253, win 1277, options [nop,nop,TS val 2096734649 ecr 2538094249], length 36
06:44:15.203821 IP 127.0.0.1.22 > 127.0.0.1.20330: Flags [P.], seq 253:289, ack 288, win 1277, options [nop,nop,TS val 2538094269 ecr 2096734649], length 36
06:44:15.226392 IP 127.0.0.1.20330 > 127.0.0.1.22: Flags [P.], seq 288:324, ack 289, win 1277, options [nop,nop,TS val 2096734672 ecr 2538094269], length 36
06:44:15.226435 IP 127.0.0.1.22 > 127.0.0.1.20330: Flags [P.], seq 289:325, ack 324, win 1277, options [nop,nop,TS val 2538094292 ecr 2096734672], length 36
06:44:15.247924 IP 127.0.0.1.20330 > 127.0.0.1.22: Flags [P.], seq 324:360, ack 325, win 1277, options [nop,nop,TS val 2096734693 ecr 2538094292], length 36
06:44:15.247967 IP 127.0.0.1.22 > 127.0.0.1.20330: Flags [P.], seq 325:361, ack 360, win 1277, options [nop,nop,TS val 2538094313 ecr 2096734693], length 36
06:44:15.269352 IP 127.0.0.1.20330 > 127.0.0.1.22: Flags [P.], seq 360:396, ack 361, win 1277, options [nop,nop,TS val 2096734715 ecr 2538094313], length 36
06:44:15.269396 IP 127.0.0.1.22 > 127.0.0.1.20330: Flags [P.], seq 361:397, ack 396, win 1277, options [nop,nop,TS val 2538094335 ecr 2096734715], length 36
[...]
06:44:17.154728 IP 127.0.0.1.20330 > 127.0.0.1.22: Flags [P.], seq 3456:3492, ack 3457, win 1277, options [nop,nop,TS val 2096736600 ecr 2538096198], length 36
06:44:17.154776 IP 127.0.0.1.22 > 127.0.0.1.20330: Flags [P.], seq 3457:3493, ack 3492, win 1277, options [nop,nop,TS val 2538096220 ecr 2096736600], length 36
06:44:17.175741 IP 127.0.0.1.20330 > 127.0.0.1.22: Flags [P.], seq 3492:3528, ack 3493, win 1277, options [nop,nop,TS val 2096736621 ecr 2538096220], length 36
06:44:17.175794 IP 127.0.0.1.22 > 127.0.0.1.20330: Flags [P.], seq 3493:3529, ack 3528, win 1277, options [nop,nop,TS val 2538096241 ecr 2096736621], length 36
06:44:17.196725 IP 127.0.0.1.20330 > 127.0.0.1.22: Flags [P.], seq 3528:3564, ack 3529, win 1277, options [nop,nop,TS val 2096736642 ecr 2538096241], length 36
06:44:17.196773 IP 127.0.0.1.22 > 127.0.0.1.20330: Flags [P.], seq 3529:3565, ack 3564, win 1277, options [nop,nop,TS val 2538096262 ecr 2096736642], length 36
06:44:17.219358 IP 127.0.0.1.20330 > 127.0.0.1.22: Flags [P.], seq 3564:3600, ack 3565, win 1277, options [nop,nop,TS val 2096736665 ecr 2538096262], length 36
06:44:17.219404 IP 127.0.0.1.22 > 127.0.0.1.20330: Flags [P.], seq 3565:3601, ack 3600, win 1277, options [nop,nop,TS val 2538096285 ecr 2096736665], length 36
06:44:17.242040 IP 127.0.0.1.20330 > 127.0.0.1.22: Flags [P.], seq 3600:3636, ack 3601, win 1277, options [nop,nop,TS val 2096736687 ecr 2538096285], length 36
06:44:17.242083 IP 127.0.0.1.22 > 127.0.0.1.20330: Flags [P.], seq 3601:3637, ack 3636, win 1277, options [nop,nop,TS val 2538096307 ecr 2096736687], length 36
06:44:17.297656 IP 127.0.0.1.20330 > 127.0.0.1.22: Flags [.], ack 3637, win 1277, options [nop,nop,TS val 2096736743 ecr 2538096307], length 0
The log above is generated by a single key press. It spans 2 seconds!

All packets in that log have the same size, consistent with transmitting a single character (hence they aren't key renegotiation). However, they look like genuine stream with monotonically increasing seq numbers (hence they aren't failed retransmits).
What are they? Why so many?
 

Attachments

* ssh(1): add keystroke timing obfuscation to the client. This attempts
to hide inter-keystroke timings by sending interactive traffic at
fixed intervals (default: every 20ms) when there is only a small
amount of data being sent. It also sends fake "chaff" keystrokes for
a random interval after the last real keystroke. These are
controlled by a new ssh_config ObscureKeystrokeTiming keyword.

From

OpenSSH: Release Notes

OpenSSH release notes
www.openssh.com
 
looks like ssh -V on my 14.0-RELEASE-p5 is returning:
OpenSSH_9.5p1, OpenSSL 3.0.12 24 Oct 2023

that keyword looks to be in 9.6
 
I'm seeing the same behavior with 9.5p1 as the client; are you doing X11 Forwarding with your command? I am, I see the same lots of packets, even from keystrokes in the original term window.
grep in /etc/ssh for that keyword does not show anything.
 
The keyword isn't in my config files but it's described in the man pages:

root@box:~ # freebsd-version -u 14.0-RELEASE-p5 root@box:~ # man ssh_config | grep -B1 -A11 inter-keystroke ObscureKeystrokeTiming Specifies whether ssh(1) should try to obscure inter-keystroke timings from passive observers of network traffic. If enabled, then for interactive sessions, ssh(1) will send keystrokes at fixed intervals of a few tens of milliseconds and will send fake keystroke packets for some time after typing ceases. The argument to this keyword must be yes, no or an interval specifier of the form interval:milliseconds (e.g. interval:80 for 80 milliseconds). The default is to obscure keystrokes using a 20ms packet interval. Note that smaller intervals will result in higher fake keystroke packet rates. PasswordAuthentication root@box:~ #
 
Yep. The impact to me showed up as slow X programs to systems on my local network. Work box is linux, my desktop FreeBSD, I'm doing X11forwarding. Starting up X programs took longer, emacs was noticeable.
Since the systems are located physically in the same room, I just added the keyword to my local config with "no" and back to normal.
 
You must log in or register to reply here.
Back
Top