issue with putty and openssh-server running in a libvirt based centos virtual machine

[adrian2...@gmail.com]

I have a very strange ssh issue, and I do not know how to solve it.

I am using Putty release 0.70, and the latest OpenSSH server from CentOS 7.4 (debug1: sshd version OpenSSH_7.4, OpenSSL 1.0.2k-fips 26 Jan 2017)

I have two centos hosts: first one is a physical server called server1, that acts as a host for the second one, called centos1. The centos1 is a virtual machine (VM) running in server1. A linux bridge in forwarding mode is used to connect the centos1 VM network interface to the server1 network interface and to the external network. The centos1 VM and the linux bridge are managed with libvirt.

Both server1 and centos1 have IP addresses in the same subnet, and both are reachable with ping from every other host in my network. In both server1 and centos1, the openssh-server configuration in /etc/ssh/sshd_config is the default one, and has not been changed.

When I ssh with Putty to the physical server server1 IP address, everything works as expected: I get a login prompt, I enter my password and I log in.

However, when I use Putty to connect to the centos1 VM, I do not get a login prompt whatsoever. I used openssh-server in debug mode, so see where the ssh connection hangs, and here is what I get:

[root@centos1 ~]# /sbin/sshd -p 22 -D -d -e
debug1: sshd version OpenSSH_7.4, OpenSSL 1.0.2k-fips 26 Jan 2017
debug1: private host key #0: ssh-rsa SHA256:pEuFQsodwK+0PoRzbVRba1ahHLEpwp8DG2KGQmxOGJk
debug1: private host key #1: ecdsa-sha2-nistp256 SHA256:F6HrSNWZhYaU7LMweI+RBviqTCHcTYyMBGPDz5OjT4c
debug1: private host key #2: ssh-ed25519 SHA256:aG3V6jjPHXUnNeavbxT/xozqrb5q3yWDkkAmXBCdnGk
debug1: rexec_argv[0]='/sbin/sshd'
debug1: rexec_argv[1]='-p'
debug1: rexec_argv[2]='22'
debug1: rexec_argv[3]='-D'
debug1: rexec_argv[4]='-d'
debug1: rexec_argv[5]='-e'
debug1: Set /proc/self/oom_score_adj from 0 to -1000
debug1: Bind to port 22 on 0.0.0.0.
Server listening on 0.0.0.0 port 22.
debug1: Bind to port 22 on ::.
Server listening on :: port 22.

Here the debug log stops and the openssh server waits for an inbound ssh client connection. At this stage I am using Putty with all default settings to connect to this openssh sever, that runs in the centos1 VM, and below is the debug log after Putty starts the ssh connection:

debug1: Server will not fork when running in debugging mode.
debug1: rexec start in 5 out 5 newsock 5 pipe -1 sock 8
debug1: sshd version OpenSSH_7.4, OpenSSL 1.0.2k-fips 26 Jan 2017
debug1: private host key #0: ssh-rsa SHA256:pEuFQsodwK+0PoRzbVRba1ahHLEpwp8DG2KGQmxOGJk
debug1: private host key #1: ecdsa-sha2-nistp256 SHA256:F6HrSNWZhYaU7LMweI+RBviqTCHcTYyMBGPDz5OjT4c
debug1: private host key #2: ssh-ed25519 SHA256:aG3V6jjPHXUnNeavbxT/xozqrb5q3yWDkkAmXBCdnGk
debug1: inetd sockets after dupping: 3, 3
Connection from x.x.x.181 port 49436 on x.x.x.115 port 22
debug1: Client protocol version 2.0; client software version PuTTY_Release_0.70
debug1: no match: PuTTY_Release_0.70
debug1: Local version string SSH-2.0-OpenSSH_7.4
debug1: Enabling compatibility mode for protocol 2.0
debug1: SELinux support enabled [preauth]
debug1: permanently_set_uid: 74/74 [preauth]
debug1: list_hostkey_types: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
debug1: SSH2_MSG_KEXINIT sent [preauth]

Here the debug mode stops, and there is no login prompt shown on the Putty windows. Actually nothing happens on the Putty window, even if I wait for couple of minutes. Finally when I give up and I close the Putty window, this is what is shown in the openssh server debug log:

Connection closed by x.x.x.181 port 49436 [preauth]
debug1: do_cleanup [preauth]
debug1: monitor_read_log: child log fd closed
debug1: do_cleanup
debug1: Killing privsep child 1274

So I do not understand why this is not working. I used the log in Putty side to see whats happening, and this is all what I get:

=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2018.01.22 18:51:38 =~=~=~=~=~=~=~=~=~=~=~=
Event Log: Writing new session log (SSH packets mode) to file: C:\Users\adrian\Desktop\putty.log
Event Log: Connecting to x.x.x.115 port 22
Event Log: We claim version: SSH-2.0-PuTTY_Release_0.70

Now, I have tried with other ssh clients, like the openssh client that comes in centos (this is from another physical server, lets call it server2), and it works without any issue. I have checked the exactly same debug log, and here is what I get:

[...]
debug1: SELinux support enabled [preauth]
debug1: permanently_set_uid: 74/74 [preauth]
debug1: list_hostkey_types: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
debug1: SSH2_MSG_KEXINIT sent [preauth]

Here it hangs with Putty, but with the openssh client it works, and the debug log continues like below:

debug1: SSH2_MSG_KEXINIT received [preauth]
debug1: kex: algorithm: curve25519-sha256 [preauth]
debug1: kex: host key algorithm: ecdsa-sha2-nistp256 [preauth]
debug1: kex: client->server cipher: chacha20...@openssh.com MAC: <implicit> compression: none [preauth]
debug1: kex: server->client cipher: chacha20...@openssh.com MAC: <implicit> compression: none [preauth]
debug1: kex: curve25519-sha256 need=64 dh_need=64 [preauth]
debug1: kex: curve25519-sha256 need=64 dh_need=64 [preauth]
[...]

So, I would suspect is an issue with the Putty, however I have no clue how I can troubleshoot this further.

Any help is greatly appreciated.

Thanks,
Adrian

[red floyd]

On 1/22/2018 12:56 PM, adrian2...@gmail.com wrote:
> I have a very strange ssh issue, and I do not know how to solve it.
>
> I am using Putty release 0.70, and the latest OpenSSH server from CentOS 7.4 (debug1: sshd version OpenSSH_7.4, OpenSSL 1.0.2k-fips 26 Jan 2017)
>
> I have two centos hosts: first one is a physical server called server1, that acts as a host for the second one, called centos1. The centos1 is a virtual machine (VM) running in server1. A linux bridge in forwarding mode is used to connect the centos1 VM network interface to the server1 network interface and to the external network. The centos1 VM and the linux bridge are managed with libvirt.
>
> Both server1 and centos1 have IP addresses in the same subnet, and both are reachable with ping from every other host in my network. In both server1 and centos1, the openssh-server configuration in /etc/ssh/sshd_config is the default one, and has not been changed.
>
> When I ssh with Putty to the physical server server1 IP address, everything works as expected: I get a login prompt, I enter my password and I log in.
>
> However, when I use Putty to connect to the centos1 VM, I do not get a login prompt whatsoever. I used openssh-server in debug mode, so see where the ssh connection hangs, and here is what I get:

> [server-side log redacted]
>

Have you turned on client side SSH Packet logging in PuTTY? What does
that show?

[adrian2...@gmail.com]

On Tuesday, January 23, 2018 at 7:57:22 PM UTC+2, red floyd wrote:

> Have you turned on client side SSH Packet logging in PuTTY? What does
> that show?

In Putty side, this is all it is showing:

=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2018.01.22 18:51:38 =~=~=~=~=~=~=~=~=~=~=~=
Event Log: Writing new session log (SSH packets mode) to file: C:\Users\adrian\Desktop\putty.log
Event Log: Connecting to x.x.x.115 port 22
Event Log: We claim version: SSH-2.0-PuTTY_Release_0.70

However, I have used other ssh clients as well, like the MobaXterm, and this one shows a bit more information, see below:

[2018-01-25 19:41.04] ~
[adrian.decebal2] ➤ ssh -vvv x.x.x.115
OpenSSH_7.1p2, OpenSSL 1.0.1g 7 Apr 2014
debug1: Reading configuration data /etc/ssh_config
debug2: ssh_connect: needpriv 0
debug1: Connecting to x.x.x.115 [x.x.x.115] port 22.
debug1: Connection established.
debug1: key_load_public: No such file or directory
debug1: identity file /home/mobaxterm/.ssh/id_rsa type -1
debug1: key_load_public: No such file or directory
debug1: identity file /home/mobaxterm/.ssh/id_rsa-cert type -1
debug1: key_load_public: No such file or directory
debug1: identity file /home/mobaxterm/.ssh/id_dsa type -1
debug1: key_load_public: No such file or directory
debug1: identity file /home/mobaxterm/.ssh/id_dsa-cert type -1
debug1: key_load_public: No such file or directory
debug1: identity file /home/mobaxterm/.ssh/id_ecdsa type -1
debug1: key_load_public: No such file or directory
debug1: identity file /home/mobaxterm/.ssh/id_ecdsa-cert type -1
debug1: key_load_public: No such file or directory
debug1: identity file /home/mobaxterm/.ssh/id_ed25519 type -1
debug1: key_load_public: No such file or directory
debug1: identity file /home/mobaxterm/.ssh/id_ed25519-cert type -1

debug1: Enabling compatibility mode for protocol 2.0

debug1: Local version string SSH-2.0-OpenSSH_7.1
debug1: ssh_exchange_identification:
debug1: ssh_exchange_identification:
debug1: ssh_exchange_identification: \024\324C9\0047\311'\316h\340.\365\213J\243d
debug1: ssh_exchange_identification: 1,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug1: ssh_exchange_identification: @openssh.com,aes128-cbc,aes192-cbc,aes256-cbc,blowfish-cbc,cast128-cbc,3des-cbc
debug1: ssh_exchange_identification: cbc
debug1: ssh_exchange_identification: 8-...@openssh.com,hmac-sha...@openssh.com,hmac-sha...@openssh.com,hmac-s...@openssh.com,uma...@openssh.com,umac...@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1


On the sshd server side, the log is exactly like in the Putty cases, and it stops at "SSH2_MSG_KEXINIT sent"

[...]
debug1: Client protocol version 2.0; client software version OpenSSH_7.1
debug1: match: OpenSSH_7.1 pat OpenSSH* compat 0x04000000

[Simon Tatham]

<adrian2...@gmail.com> wrote:
> In Putty side, this is all it is showing:
>
> =~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2018.01.22 18:51:38 =~=~=~=~=~=~=~=~=~=~=~=
> Event Log: Writing new session log (SSH packets mode) to file:
> C:\Users\adrian\Desktop\putty.log
> Event Log: Connecting to x.x.x.115 port 22
> Event Log: We claim version: SSH-2.0-PuTTY_Release_0.70

Normally the next thing that would appear in a PuTTY log is a line
showing the version string sent from the server. If PuTTY hasn't
logged that, then that suggests it might not have received it.

That could be due to some sort of network oddity between that
particular pair of machines. You've tried other ssh clients, but have
you tried other ssh clients running on the same _machine_? What do you
see in a network packet trace of a failing connection?

Another possibility in principle, I suppose, is that the could be some
minor divergence in the startup part of the SSH protocol, such as the
greeting not being terminated with the right line-end character, and
that another SSH client tolerates that while PuTTY doesn't. But that
would be more plausible if the server was an obscure niche one; if
it's OpenSSH, that's not very likely.
--
for k in [pow(x,37,0x1a1298d262b49c895d47f) for x in [0x50deb914257022de7fff,
0x213558f2215127d5a2d1, 0x90c99e86d08b91218630, 0x109f3d0cfbf640c0beee7,
0xc83e01379a5fbec5fdd1, 0x19d3d70a8d567e388600e, 0x534e2f6e8a4a33155123]]:
print("".join([chr(32+3*((k>>x)&1))for x in range(79)])) # <ana...@pobox.com>

[adrian2...@gmail.com]

On Friday, January 26, 2018 at 11:06:32 AM UTC+2, Simon Tatham wrote:
> Normally the next thing that would appear in a PuTTY log is a line
> showing the version string sent from the server. If PuTTY hasn't
> logged that, then that suggests it might not have received it.
>
> That could be due to some sort of network oddity between that
> particular pair of machines. You've tried other ssh clients, but have
> you tried other ssh clients running on the same _machine_? What do you
> see in a network packet trace of a failing connection?
>
> Another possibility in principle, I suppose, is that the could be some
> minor divergence in the startup part of the SSH protocol, such as the
> greeting not being terminated with the right line-end character, and
> that another SSH client tolerates that while PuTTY doesn't. But that
> would be more plausible if the server was an obscure niche one; if
> it's OpenSSH, that's not very likely.

I think I just found out this is an network issue again. I took several tcpdump traces, and compared the working ssh sessions with the non working ones, and this is what I have found: when an Ethernet frame that is less then 60 bytes in size goes through the network, it is padded with 0x00 bytes until it has 60 bytes in length (64 with the frame check sequence). In my network I have a linux bridge that connects the centos VM to he external network. When this kind of padded frames goes through the linux bridge, somehow the IP and TCP headers in those frames wrongly consider the 0x00 padded bytes as part of the user data, therefore the upstream protocol (SSH in this case) tries to interpret them, and this is why Putty hangs. Those 0x00 padded bytes are at the layer2 Ethernet frame level, and should not be considered in the user data of the higher level protocols. I think I should take this to the linux bridge mailing lists.

[adrian2...@gmail.com]

Ok, so I found a workaround for this, even if I do not know who caused this issue.

Basically I noticed that I have this ssh connection issue only when the ssh client runs on a windows host. If the ssh client runs on a linux host, the ssh connection works without any problem. So I have compared the tcpdump for ssh connections initiated from both windows and linux, and what I have noticed is that on centos linux, by default the TCP stack uses timestamps in the TCP Options, and because of this, the Ethernet frames are never below 60 bytes, while in my windows the TCP Options timestamps are not used, and therefore some Ethernet frames are less than 60 bytes.

So I enabled the TCP Options timestamps in windows as well, by running the command 'netsh int tcp set global timestamps=enabled', and just like that, the ssh started to work. Still, I do not know who is causing this issue, and who to blame for this behavior...

Any suggestion how to identify which network element wrongly assigns the Ethernet padding to the TCP payload is more than welcome.