Subject: Bug#1460: Windows client crashes if Jumphost runs NetBSD 6 (probably race)

From: Edgar Fuß <[email-masked]>
Date: Sun, 19 Apr 2020 20:23:14 +0200

Package: x2go-client for windows
Version: 4.1.2.2

The Windows X2Go client crashes (in ntdll.dll) if the Jumphost is running NetBSD 6 (it works for NetBSD 8). It crashes so early in the SSH negotiation that no further details (authentication type etc.) are relevant.

Now, NetBSD 6 (and OpenSSH 5.9, which it uses) are pretty obsolete, but interestingly, the client does not crash if run under logger.exe, so this looks like a race.

Installing OpenSSH 8.0 (from pkgsrc) on the NetBSD 6 Jumphost doesn't help. I verified that insatlling OpenSSH 8.0 on a NetBSD 8 host (which natively uses OpenSSH 7.6) works. So it's not just the OpenSSH version that matters.

But, if the Jumphost runs OpenSSH 8.0 on NetBSD 6 (where the client crashes unless run under logger.exe), tcpdump-ing the SSH connection on the Jumphost makes the client work. If I additionally tcpdump on the client side (more precisely, on the macOS system hosting the VirtualBox VM running MS Win), the client crashes again.

It looks like the condition that triggers the crash may be the client receiving the Server Key Exchange Init _after_ it sent the Client Key Exchange Init.

The packet sequence involved is (I/O as seen on the Jumphost, i.e. I client->server and O server->client):
1 I SYN (ECN, CWR)
2 O SYN/ACK
3 I ACK
4 I Client: Protocol
5 O Server: Protocol
6 I ACK

running tcpdump on NetBSD only (works):
7 O Server: Key Exchange Init
8 I ACK
9 I Client: Key Exchange Init
10 I Client: Diffie-Hellman Key Ecxhange Init
11 O ACK
12 O Diffie-Hellman Key Exchange Reply
13 I ACK
14 I Client: New Keys
15 I Client: Encrypted Packet
...

running tcpdump on NetBSD and macOS (client crashes), as seen on the NetBSD side:
7 O Server: Key Exchange Init
8 I Client: Key Exchange Init
9 I ACK
10 I Client: Diffie-Hellman Key Exhange Init
11 O ACK
12 O Diffie-Hellman Key Exchange Reply
13 I ACK
14 I Client: New Keys
15 O ACK
16 I FIN/ACK

same as seen on the macOS side:
7 I Client: Key Exchange Init
8 O Server: Key Exchange Init
[rest looks as on the NetBSD side]

Any hints how to debug this? I know virtually nothing about MS Win.

---

From: Edgar Fuß <[email-masked]>
Date: Tue, 21 Apr 2020 10:20:51 +0200

reassign 1460 x2goclient 4.1.2.2

---

From: Edgar Fuß <[email-masked]>
Date: Mon, 4 May 2020 17:48:19 +0200

I may have been able to obtain a backtrace (using windebug):

 # ChildEBP RetAddr  Args to Child              
00 0607e87c 771d98cb 77114c88 933a9ca3 01b70000 ntdll!RtlpValidateHeapEntry+0x63ad4
01 0607e8dc 7712dd3e 015bfd78 933a9dcf 015bfd70 ntdll!RtlDebugFreeHeap+0xc6 (FPO: [Non-Fpo])
02 0607e9b0 77176ceb 015bfd70 015bfd78 015bfd78 ntdll!RtlpFreeHeap+0xce (FPO: [Non-Fpo])
03 0607ea0c 7712dc16 00000000 00000000 00000000 ntdll!RtlpFreeHeapInternal+0x783 (FPO: [Non-Fpo])
04 0607ea2c 754d7409 01b70000 00000000 015bfd78 ntdll!RtlFreeHeap+0x46 (FPO: [Non-Fpo])
05 0607ea78 61af8e1a 015bfd78 0000008b 0000008b msvcrt!free+0x69 (FPO: [Non-Fpo])
06 0607eac8 61ae8470 03be64f0 03addae8 0000000a libssh!ssh_threads_get_pthread+0x291a
07 0607eb08 61ae3c8c 03befbe0 03be64f0 0607eb3c libssh!ssh_pki_copy_cert_to_privkey+0x250
08 0607eb48 61ae2d84 03b1a620 00000015 03be65b0 libssh!ssh_bind_options_parse_config+0x215c
09 0607eb88 61ae3407 03b1a620 00000015 61b1b180 libssh!ssh_bind_options_parse_config+0x1254
0a 0607ebf8 61ae394f 03bc5070 00000010 03b1a620 libssh!ssh_bind_options_parse_config+0x18d7
0b 0607ec38 61ac55b7 03bc4ec0 0607ecb0 000001c0 libssh!ssh_bind_options_parse_config+0x1e1f
0c 00000000 00000000 00000000 00000000 00000000 libssh!ssh_buffer_add_data+0xe7

Unfortunately, this looks like a double free in libssh to me.

---

From: Edgar Fuß <[email-masked]>
Date: Mon, 25 May 2020 19:07:57 +0200

By chance, I learned of the --libssh-debug and --libssh-packetlog options.
So here's the output of a session that crashes. Any hints as how to pursue this further?

C:\Program Files (x86)\x2goclient>x2goclient.debug.exe --debug --libssh-debug --libssh-packetlog
x2go-INFO-1> "Starting X2Go Client 4.1.2.2..."
x2go-INFO-4> "Translator: :/i18n/x2goclient_de_de found."
x2go-INFO-4> "Übersetzung: :/i18n/qt_de_de gefunden."
x2go-DEBUG-../src/onmainwindow.cpp:10779> Getting X.Org Server settings.
x2go-INFO-3> "X2GoClient wurde gestartet."
x2go-DEBUG-../src/onmainwindow.cpp:575> "$HOME=C:/Users/ef"
x2go-DEBUG-../src/onmainwindow.cpp:2266> Reading 1 sessions from config file.
x2go-DEBUG-../src/sessionbutton.cpp:361> Creating QPixmap with session icon: ":/img/icons/128x128/x2gosession.png".
x2go-DEBUG-../src/onmainwindow.cpp:13290> libssh not initialized yet. Initializing.
x2go-DEBUG-../src/pulsemanager.cpp:369> pulseaudio --version returned:"pulseaudio 13.0
"

x2go-DEBUG-../src/onmainwindow.cpp:10682> Starting helper servers for Windows ...
x2go-DEBUG-../src/onmainwindow.cpp:10849> "/cygdrive/C/Users/ef/.x2go/var" cygwin var path
x2go-DEBUG-../src/onmainwindow.cpp:10937> "C:/Users/ef/.x2go/etc/sshd_config created."
x2go-DEBUG-../src/onmainwindow.cpp:10344> Resolved localhost.
x2go-DEBUG-../src/onmainwindow.cpp:10366> Port is free: 7022
x2go-DEBUG-../src/onmainwindow.cpp:11288> Logging cygwin sshd to: "C:/Users/ef/.x2go/sshLogs/Hp2320.log"
x2go-DEBUG-../src/onmainwindow.cpp:11302> Creating desktop: x2go_ef
x2go-DEBUG-../src/pulsemanager.cpp:227> pulse started with arguments ("--exit-idle-time=-1", "-n", "-F", "C:\Users\ef\.x2go\pulse\config.pa", "-p", "C:\Program Files (x86)\x2goclient\pulse\lib\pulse-13.0\modules", "--log-level=debug", "--verbose", "--log-target=file:C:\Users\ef\.x2go\pulse\pulse.log") - waiting for it to finx2go-DEBUG-../src/onmainwindow.cpp:10344> Resolved localhost.
ish...
x2go-DEBUG-../src/onmainwindow.cpp:10372> Port already in use: 7022
x2go-DEBUG-../src/onmainwindow.cpp:10344> Resolved localhost.
x2go-DEBUG-../src/onmainwindow.cpp:10372> Port already in use: 7022
x2go-DEBUG-../src/onmainwindow.cpp:11399> User mode OpenSSH server started successfully.
x2go-DEBUG-../src/onmainwindow.cpp:2752> Creating QPixmap with session icon: '":/img/icons/128x128/x2gosession.png"'.
x2go-INFO-8> "Verbindung mit Server wird gestartet: aegidienberg:22"
x2go-DEBUG-../src/onmainwindow.cpp:2853> Starting new ssh connection to server:"aegidienberg":"22" krbLogin: false
x2go-DEBUG-../src/sshmasterconnection.cpp:168> SshMasterConnection, host "aegidienberg"; port 22; user "mtuser"; useproxy true; proxyserver "login.math.uni-bonn.de"; proxyport 22
x2go-DEBUG-../src/sshmasterconnection.cpp:248> Starting SSH connection without Kerberos authentication.
x2go-DEBUG-../src/sshmasterconnection.cpp:250> SshMasterConnection, instance SshMasterConnection(0x3a10da8)  created.
x2go-DEBUG-../src/sshmasterconnection.cpp:495> SshMasterConnection, instance SshMasterConnection(0x3a10da8)  entering thread.
x2go-DEBUG-../src/sshmasterconnection.cpp:498> proxyserver: "login.math.uni-bonn.de"; proxyport: 22; proxylogin: ""
x2go-DEBUG-../src/sshmasterconnection.cpp:168> SshMasterConnection, host "login.math.uni-bonn.de"; port 22; user ""; useproxy false; proxyserver ""; proxyport 0
x2go-DEBUG-../src/sshmasterconnection.cpp:224> Temporary session user name after config file parse:
x2go-DEBUG-../src/sshmasterconnection.cpp:248> Starting SSH connection without Kerberos authentication.
x2go-DEBUG-../src/sshmasterconnection.cpp:250> SshMasterConnection, instance SshMasterConnection(0x3a112e8)  created.
x2go-DEBUG-../src/sshmasterconnection.cpp:495> SshMasterConnection, instance SshMasterConnection(0x3a112e8)  entering thread.
x2go-DEBUG-../src/sshmasterconnection.cpp:575> Setting SSH directory to C:/Users/ef/ssh
x2go-DEBUG-../src/sshmasterconnection.cpp:797> Session port before config file parse: 22
x2go-DEBUG-../src/sshmasterconnection.cpp:807> Session port after config file parse: 22
[2020/05/25 18:47:02.347704, 2] ssh_connect:  libssh 0.9.3 (c) 2003-2019 Aris Adamantiadis, Andreas Schneider and libssh contributors. Distributed under the LGPL, please refer to COPYING file for information about your rights, using threading threads_pthread
[2020/05/25 18:47:02.401163, 2] ssh_socket_connect:  Nonblocking connection socket: 2228
[2020/05/25 18:47:02.401163, 2] ssh_connect:  Socket connecting, now waiting for the callbacks to work
[2020/05/25 18:47:02.401163, 3] ssh_connect:  Actual timeout : 60000
[2020/05/25 18:47:02.438119, 3] ssh_socket_pollcallback:  Received POLLOUT in connecting state
[2020/05/25 18:47:02.438119, 1] socket_callback_connected:  Socket connection callback: 1 (0)
[2020/05/25 18:47:02.438119, 3] ssh_socket_unbuffered_write:  Enabling POLLOUT for socket
[2020/05/25 18:47:02.491386, 3] callback_receive_banner:  Received banner: SSH-2.0-OpenSSH_5.9 NetBSD_Secure_Shell-20110907-hpn13v11-lpk
[2020/05/25 18:47:02.491386, 2] ssh_client_connection_callback:  SSH server banner: SSH-2.0-OpenSSH_5.9 NetBSD_Secure_Shell-20110907-hpn13v11-lpk
[2020/05/25 18:47:02.491386, 2] ssh_analyze_banner:  Analyzing banner: SSH-2.0-OpenSSH_5.9 NetBSD_Secure_Shell-20110907-hpn13v11-lpk
[2020/05/25 18:47:02.491386, 2] ssh_analyze_banner:  We are talking to an OpenSSH client version: 5.9 (50900)
[2020/05/25 18:47:03.714230, 3] ssh_client_select_hostkeys:  Order of wanted host keys: "ssh-ed25519,ecdsa-sha2-nistp521,ecdsa-sha2-nistp384,ecdsa-sha2-nistp256,rsa-sha2-512,rsa-sha2-256,ssh-rsa,ssh-dss"
[2020/05/25 18:47:03.803831, 1] ssh_known_hosts_read_entries:  Failed to open the known_hosts file '/etc/ssh/ssh_known_hosts': No such file or directory
[2020/05/25 18:47:03.803831, 3] ssh_client_select_hostkeys:  Algorithms found in known_hosts files: "ecdsa-sha2-nistp521"
[2020/05/25 18:47:03.803831, 3] ssh_client_select_hostkeys:  Changing host key method to "ecdsa-sha2-nistp521,ssh-ed25519,ecdsa-sha2-nistp384,ecdsa-sha2-nistp256,rsa-sha2-512,rsa-sha2-256,ssh-rsa,ssh-dss"
[2020/05/25 18:47:03.803831, 3] ssh_socket_unbuffered_write:  Enabling POLLOUT for socket
[2020/05/25 18:47:03.803831, 3] packet_send2:  packet: wrote [type=20, len=940, padding_size=4, comp=935, payload=935]
[2020/05/25 18:47:03.803831, 3] ssh_send_kex:  SSH_MSG_KEXINIT sent
[2020/05/25 18:47:03.803831, 3] ssh_packet_socket_callback:  packet: read type 20 [len=812,padding=5,comp=806,payload=806]
[2020/05/25 18:47:03.803831, 3] ssh_packet_process:  Dispatching handler for packet type 20
[2020/05/25 18:47:03.822580, 2] ssh_kex_select_methods:  Negotiated ecdh-sha2-nistp256,ecdsa-sha2-nistp521,aes256-ctr,aes256-ctr,hmac-sha1,hmac-sha1,none,none,,
[2020/05/25 18:47:03.822580, 3] packet_send2:  packet: wrote [type=30, len=76, padding_size=5, comp=70, payload=70]
[2020/05/25 18:47:03.822580, 3] ssh_socket_unbuffered_write:  Enabling POLLOUT for socket
[2020/05/25 18:47:03.875547, 3] ssh_packet_socket_callback:  packet: read type 31 [len=428,padding=11,comp=416,payload=416]
[2020/05/25 18:47:03.875547, 3] ssh_packet_process:  Dispatching handler for packet type 31
[2020/05/25 18:47:03.875547, 3] ssh_socket_unbuffered_write:  Enabling POLLOUT for socket
[2020/05/25 18:47:03.875547, 3] packet_send2:  packet: wrote [type=21, len=12, padding_size=10, comp=1, payload=1]
[2020/05/25 18:47:03.875547, 3] crypt_set_algorithms2:  Set output algorithm to aes256-ctr
[2020/05/25 18:47:03.875547, 3] crypt_set_algorithms2:  Set HMAC output algorithm to hmac-sha1
[2020/05/25 18:47:03.875547, 3] crypt_set_algorithms2:  Set input algorithm to aes256-ctr
[2020/05/25 18:47:03.875547, 3] crypt_set_algorithms2:  Set HMAC input algorithm to hmac-sha1
[2020/05/25 18:47:03.875547, 2] ssh_init_rekey_state:  Set rekey after 4294967296 blocks
[2020/05/25 18:47:03.875547, 2] ssh_init_rekey_state:  Set rekey after 4294967296 blocks
[2020/05/25 18:47:03.875547, 2] ssh_packet_client_ecdh_reply:  SSH_MSG_NEWKEYS sent
[2020/05/25 18:47:03.875547, 3] ssh_packet_socket_callback:  Processing 16 bytes left in socket buffer
[2020/05/25 18:47:03.875547, 3] ssh_packet_socket_callback:  packet: read type 21 [len=12,padding=10,comp=1,payload=1]
[2020/05/25 18:47:03.875547, 3] ssh_packet_process:  Dispatching handler for packet type 21
[2020/05/25 18:47:03.875547, 2] ssh_packet_newkeys:  Received SSH_MSG_NEWKEY

---

From: Ulrich Sibiller <[email-masked]>
Date: Mon, 25 May 2020 21:10:15 +0200

I have seen a very similar problem with the latest windows client. I
believe the libssh 0.9.3 being the culprit. However, as I do not have
a development environment on that windows system I cannot verify by
swapping libssh for 0.9.4 or some older version. Interestingly no
downloadable binary versions of libssh.dll seem to exist.

I also cannot test with an older version because only the newest
version contains the ! patch (prepend ! to a hostname to skip the
internal test for interactivity on the remote host) and I need that
for that special setup...

So from my POV it would help if you could try using an older version
of x2goclient (with an older libssh) to see if it works with that.

Uli

PS: I suspect this happens when the other side has a quite old openssh
running, in my case it's OpenSSH 5.8, for you it's 5.9... So If you
can upgrade the ssh server this might also solve the problem (and is
also not an option for me, unfortunately. Corporate environments tend
to suck...)

On Mon, May 25, 2020 at 7:10 PM Edgar Fuß <[email-masked]> wrote:
> _______________________________________________
> x2go-dev mailing list
> [email-masked]
> https://lists.x2go.org/listinfo/x2go-dev

---

From: Edgar Fuß <[email-masked]>
Date: Tue, 26 May 2020 11:32:57 +0200

> I believe the libssh 0.9.3 being the culprit.
[...]
> of x2goclient (with an older libssh) to see if it works with that.
OK, I tried this. X2Go switched (at least for the MS-Win build) from 0.7.4(!) to 0.9.3 on 2020-02-06, and indeed, the build from 2020-01-29 (the last one before the switch) works for me!

Could someone build x2goclient with libssh 0.9.4 so I could test that?

> can upgrade the ssh server this might also solve the problem
As stated in the original bug report: No, unfortunately, it's not the OpenSSH version that matters (I went into some lengths updating that, but it didn't help), but the base system version. I cannot easily update the login servers to NetBSD 8.