Description of problem: I have a container with up-to-date rawhide, glibc-2.26.9000-28.fc28.x86_64 openssh-server-7.6p1-2.fc28.x86_64 When I'm trying to log in with a key, I get the failure in $subject. After setting log level to DEBUG: Dec 11 13:22:41 rawhide systemd[1]: Reloading OpenSSH server daemon. Dec 11 13:22:41 rawhide sshd[493]: Received SIGHUP; restarting. Dec 11 13:22:41 rawhide systemd[1]: Reloaded OpenSSH server daemon. Dec 11 13:22:41 rawhide sshd[493]: debug1: Set /proc/self/oom_score_adj from 0 to -1000 Dec 11 13:22:41 rawhide sshd[493]: debug1: Bind to port 22 on 0.0.0.0. Dec 11 13:22:41 rawhide sshd[493]: Server listening on 0.0.0.0 port 22. Dec 11 13:22:41 rawhide sshd[493]: debug1: Bind to port 22 on ::. Dec 11 13:22:41 rawhide sshd[493]: Server listening on :: port 22. Dec 11 13:22:46 rawhide sshd[493]: debug1: Forked child 1130. Dec 11 13:22:46 rawhide sshd[1130]: debug1: Set /proc/self/oom_score_adj to 0 Dec 11 13:22:46 rawhide sshd[1130]: debug1: rexec start in 5 out 5 newsock 5 pipe 7 sock 8 Dec 11 13:22:46 rawhide sshd[1130]: debug1: inetd sockets after dupping: 3, 3 Dec 11 13:22:46 rawhide sshd[1130]: Connection from 10.0.0.1 port 44746 on 10.0.0.12 port 22 Dec 11 13:22:46 rawhide sshd[1130]: debug1: Client protocol version 2.0; client software version OpenSSH_7.5 Dec 11 13:22:46 rawhide sshd[1130]: debug1: match: OpenSSH_7.5 pat OpenSSH* compat 0x04000000 Dec 11 13:22:46 rawhide sshd[1130]: debug1: Local version string SSH-2.0-OpenSSH_7.6 Dec 11 13:22:46 rawhide sshd[1130]: debug1: SELinux support disabled [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: permanently_set_uid: 74/74 [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: list_hostkey_types: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: SSH2_MSG_KEXINIT sent [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: SSH2_MSG_KEXINIT received [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: kex: algorithm: curve25519-sha256 [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: kex: host key algorithm: ecdsa-sha2-nistp256 [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: kex: client->server cipher: aes256-gcm MAC: <implicit> compression: none [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: kex: server->client cipher: aes256-gcm MAC: <implicit> compression: none [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: kex: curve25519-sha256 need=32 dh_need=32 [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: kex: curve25519-sha256 need=32 dh_need=32 [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: rekey after 4294967296 blocks [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: SSH2_MSG_NEWKEYS sent [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: expecting SSH2_MSG_NEWKEYS [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: SSH2_MSG_NEWKEYS received [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: rekey after 4294967296 blocks [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: KEX done [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: userauth-request for user zbyszek service ssh-connection method none [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: attempt 0 failures 0 [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: PAM: initializing for "zbyszek" Dec 11 13:22:46 rawhide sshd[1130]: debug1: PAM: setting PAM_RHOST to "10.0.0.1" Dec 11 13:22:46 rawhide sshd[1130]: debug1: PAM: setting PAM_TTY to "ssh" Dec 11 13:22:46 rawhide sshd[1130]: debug1: userauth-request for user zbyszek service ssh-connection method publickey [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: attempt 1 failures 0 [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: userauth_pubkey: test whether pkalg/pkblob are acceptable for RSA SHA256:Rah0vZSh2dd181FCDSviqIU0oTlGFCPLCh9YUjgo1Go [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: temporarily_use_uid: 1000/1000 (e=0/0) Dec 11 13:22:46 rawhide sshd[1130]: debug1: trying public key file /home/zbyszek/.ssh/authorized_keys Dec 11 13:22:46 rawhide sshd[1130]: debug1: fd 4 clearing O_NONBLOCK Dec 11 13:22:46 rawhide sshd[1130]: debug1: matching key found: file /home/zbyszek/.ssh/authorized_keys, line 1 RSA SHA256:Rah0vZSh2dd181FCDSviqIU0oTlGFCPLCh9YUjgo1Go Dec 11 13:22:46 rawhide sshd[1130]: debug1: restore_uid: 0/0 Dec 11 13:22:46 rawhide sshd[1130]: Postponed publickey for zbyszek from 10.0.0.1 port 44746 ssh2 [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: userauth-request for user zbyszek service ssh-connection method publickey [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: attempt 2 failures 0 [preauth] Dec 11 13:22:46 rawhide sshd[1130]: debug1: temporarily_use_uid: 1000/1000 (e=0/0) Dec 11 13:22:46 rawhide sshd[1130]: debug1: trying public key file /home/zbyszek/.ssh/authorized_keys Dec 11 13:22:46 rawhide sshd[1130]: debug1: fd 4 clearing O_NONBLOCK Dec 11 13:22:46 rawhide sshd[1130]: debug1: matching key found: file /home/zbyszek/.ssh/authorized_keys, line 1 RSA SHA256:Rah0vZSh2dd181FCDSviqIU0oTlGFCPLCh9YUjgo1Go Dec 11 13:22:46 rawhide sshd[1130]: debug1: restore_uid: 0/0 Dec 11 13:22:46 rawhide sshd[1130]: debug1: do_pam_account: called Dec 11 13:22:46 rawhide sshd[1130]: Accepted publickey for zbyszek from 10.0.0.1 port 44746 ssh2: RSA SHA256:Rah0vZSh2dd181FCDSviqIU0oTlGFCPLCh9YUjgo1Go Dec 11 13:22:46 rawhide sshd[1130]: debug1: monitor_child_preauth: zbyszek has been authenticated by privileged process Dec 11 13:22:46 rawhide sshd[1130]: debug1: monitor_read_log: child log fd closed Dec 11 13:22:46 rawhide sshd[1130]: fatal: privsep_preauth: preauth child terminated by signal 31 Dec 11 13:22:46 rawhide sshd[1130]: debug1: do_cleanup
SELinux is in permissive mode.
Created attachment 1365964 [details] strace of sshd 1245 getpid() = 1245 1245 gettid() = ? 1245 +++ killed by SIGSYS +++ Hmmm.
SIGSYS is violation of seccomp filter, but gettid syscall is not whitelisted for privsep child. It is not called from OpenSSH code. What is calling gettid()? Can you get gdb/backtrace from where does it come?
Workaround is obviously to allow gettid() syscall. It should not pose any significant threat, but before doing so, I would be curious what is issuing this syscall, since it is not OpenSSH itself. This also works fine with Fedora 27 and before, isn't it? Without any additional information, when was the last time it worked for you, how does your Dockerfile look like it is hard to guess where the problem is. I just tested with simple dockerfile with openssh on rawhide and I do not see this issue: https://github.com/Jakuje/stuff/blob/master/Dockerfile
I think OpenSSL-1.1 can call it (indirectly through pthread_self() call).
Although it is quite unclear why you cannot reproduce it.
I'm not sure if I hit the same problem on my F27 system. After upgrade to Openssh 7.6p1-2.fc27.x86_64 The sshd crashes. I saw this on 2 different machines. I downgraded one of them to solve the problem. With the other I can perform some tests, if you want. Jouk
(In reply to J.Jansen from comment #7) > I'm not sure if I hit the same problem on my F27 system. After upgrade to > Openssh > 7.6p1-2.fc27.x86_64 The sshd crashes. I saw this on 2 different machines. I > downgraded one of them to solve the problem. With the other I can perform > some tests, if you want. > > Jouk You probably hit different issue, which should be resolved by the following update: https://bodhi.fedoraproject.org/updates/FEDORA-2017-be30d29a15
my problem did not solve by installing 7.6p1-3. The sshd crashes directly at startup ( systemctl start sshd.service fails) Jouk
So lets provide some DEBUG3 logs. The "crash" should be visible also in the audit log. Having a coredump and or gdb backtrace from the problematic place would be very useful to see what is going on there. It might be the same issue, but I have no idea why I can not reproduce it. So configuration or information about other related software installed would help too.
Created attachment 1366621 [details] part of the audit.log Seems that every time sshd is "started" you get 3 entries START,STOP,START The first 2 succeed, but the third fails.
Please coach me a little to get the other things you like to have, because I do not know (by heart) how to to this. Jouk
I have a modified configuration file in order to support "old" ciphers, KEX and MACS and switched off the systemwide crypto policy for ssh (as we deiscussed last month). Jouk
Created attachment 1366626 [details] sshd configuration file configuration of sshd as used on my system
This seems to be in systemd code (the pam module, I suppose). (gdb) bt #0 gettid () at ../src/basic/missing_syscall.h:126 #1 0x00007f41e8e9f050 in is_main_thread () at ../src/basic/process-util.c:845 #2 0x00007f41e8e8898d in cleanup_pools () at ../src/basic/hashmap.c:294 #3 0x00007f41e996b973 in _dl_fini () at dl-fini.c:233 #4 0x00007f41e6f9df21 in __run_exit_handlers (status=0, listp=0x7f41e7319718 <__exit_funcs>, run_list_atexit=run_list_atexit@entry=true, run_dtors=run_dtors@entry=true) at exit.c:108 #5 0x00007f41e6f9e01a in __GI_exit (status=<optimized out>) at exit.c:139 #6 0x00005612486359a3 in main (ac=<optimized out>, av=<optimized out>) at sshd.c:2190
Yes, that is systemd. PAM module should certainly not be opened from denoted privilege-separated child. I suppose it is the libsystemd we are linking against in recent versions to make systemd able to track the status of running sshd. Sigh ... Wondering what has changed right now, preventing it from working. Anyway, I will whitelist this syscall and update the OpenSSH package. Jouk, this error happens when you are connecting to that machine, not when you restart the sshd service. I don't see this issue in your audit log either. If your sshd "crashes" directly after systemctl start, please have a look into journalctl, to /var/log/secure or just systemctl status sshd to find out more. But your problem is that you manually list all the ciphers, while blowfish-cbc was removed from OpenSSH 7.6: http://www.openssh.com/txt/release-7.6
The following patch should resolve the problem. diff -up openssh-7.6p1/sandbox-seccomp-filter.c.sandbox openssh-7.6p1/sandbox-seccomp-filter.c --- openssh-7.6p1/sandbox-seccomp-filter.c.sandbox 2017-12-12 13:59:30.563874059 +0100 +++ openssh-7.6p1/sandbox-seccomp-filter.c 2017-12-12 13:59:14.842784083 +0100 @@ -190,6 +190,9 @@ static const struct sock_filter preauth_ #ifdef __NR_geteuid32 SC_ALLOW(__NR_geteuid32), #endif +#ifdef __NR_gettid + SC_ALLOW(__NR_gettid), +#endif #ifdef __NR_getrandom SC_ALLOW(__NR_getrandom), #endif Can you try with the following scratch build, it if resolves your problem, before I will push the change to rawhide? I would be really interested to see what has changed here. https://koji.fedoraproject.org/koji/taskinfo?taskID=23655711
(In reply to Jakub Jelen from comment #16) > > Jouk, this error happens when you are connecting to that machine, not when > you restart the sshd service. I don't see this issue in your audit log > either. > > If your sshd "crashes" directly after systemctl start, please have a look > into journalctl, to /var/log/secure or just systemctl status sshd to find > out more. But your problem is that you manually list all the ciphers, while > blowfish-cbc was removed from OpenSSH 7.6: > > http://www.openssh.com/txt/release-7.6 Ok, putting Cipher +aes128-cbc get the sshd running. (seems that my OpenVMS uses the aes128-cbc) But now I have a problem connectiong from my OpenVMS system: with 7.5 it works OK: debug(12-DEC-2017 16:33:54.42): Remote version: SSH-2.0-OpenSSH_7.5 debug(12-DEC-2017 16:33:54.42): OpenSSH: Major: 7 Minor: 5 Revision: 0 debug(12-DEC-2017 16:33:54.42): Ssh2Transport/TRCOMMON.C:1857: All versions of O penSSH handle kex guesses incorrectly. debug(12-DEC-2017 16:33:54.43): Ssh2Transport/TRCOMMON.C:1935: Using Client orde r for common key exchange algorithms. debug(12-DEC-2017 16:33:54.43): Ssh2Transport/TRCOMMON.C:1139: Sending packet wi th type 2 to connection debug(12-DEC-2017 16:33:54.43): Ssh2Transport/TRCOMMON.C:1139: Sending packet wi th type 20 to connection debug(12-DEC-2017 16:33:54.43): Ssh2Transport/TRCOMMON.C:2832: >TR packet_type=2 0 debug(12-DEC-2017 16:33:54.43): Ssh2Transport/TRCOMMON.C:2394: lang s to c: `', lang c to s: `' debug(12-DEC-2017 16:33:54.43): Ssh2Transport/TRCOMMON.C:2459: c_to_s: cipher ae s128-cbc, mac hmac-sha1, compression none debug(12-DEC-2017 16:33:54.43): Ssh2Transport/TRCOMMON.C:2462: s_to_c: cipher ae s128-cbc, mac hmac-sha1, compression none debug(12-DEC-2017 16:33:54.44): Ssh2Transport/TRCOMMON.C:1139: Sending packet wi th type 2 to connection with 7.6 I get an error: debug(12-DEC-2017 16:32:10.12): Remote version: SSH-2.0-OpenSSH_7.6 debug(12-DEC-2017 16:32:10.12): OpenSSH: Major: 7 Minor: 6 Revision: 0 debug(12-DEC-2017 16:32:10.12): Ssh2Transport/TRCOMMON.C:1857: All versions of O penSSH handle kex guesses incorrectly. debug(12-DEC-2017 16:32:10.12): Ssh2Transport/TRCOMMON.C:1935: Using Client orde r for common key exchange algorithms. debug(12-DEC-2017 16:32:10.12): Ssh2Transport/TRCOMMON.C:1139: Sending packet wi th type 2 to connection debug(12-DEC-2017 16:32:10.12): Ssh2Transport/TRCOMMON.C:1139: Sending packet wi th type 20 to connection debug(12-DEC-2017 16:32:10.12): Ssh2Transport/TRCOMMON.C:1139: Sending packet wi th type 2 to connection debug(12-DEC-2017 16:32:10.12): Ssh2Transport/TRCOMMON.C:1139: Sending packet wi th type 1 to connection debug(12-DEC-2017 16:32:10.12): Ssh2Common/SSHCOMMON.C:180: DISCONNECT received: Protocol error: packet too long: 1349676920. debug(12-DEC-2017 16:32:10.12): SshReadLine/SSHREADLINE.C:3728: Uninitializing R eadLine... warning: Authentication failed. debug(12-DEC-2017 16:32:10.12): Ssh2/SSH2.C:327: locally_generated = TRUE Disconnected; protocol error (Protocol error: packet too long: 1349676920.). debug(12-DEC-2017 16:32:10.12): Ssh2Client/SSHCLIENT.C:1731: Destroying client.
What are the debug logs in the server? Put LogLevel DEBUG3 into sshd_config, restart the sshd server and try to connect once more. The /var/log/secure should contain then the logs from server what is it sending/receiving. This part is not yet encrypted so you can even run wireshark/tcpdump, to capture the packets and see what is sent by the server to your client.
I switched on DEBUG3, but on my system there is no /var/log/secure. So where is the info written in that case?
So then it is left only in journal. You should be able to list recent entries for example using journalctl -b -e
Created attachment 1367190 [details] relevant output of journalctl-xe Listing from where I detect the IP address of the connevting machine (131.180.121.86)
The important message is Dec 13 10:03:23 csardas.nano.tudelft.nl sshd[6432]: Protocol major versions differ for 131.180.121.86 port 54495: SSH-2.0-OpenSSH_7.6 vs. SSH-1.99-3.2.0 SSH OpenVMS V5.5 VMS_sftp_version 3 This is related to the removal of SSH-1 protocol from server [1]. The current OpenSSH supports only SSH-2 and therefore treats the 1.99 version as non-compatible. According to the specification [2], I see that version 1.99 was intended only for servers so if your client sends it, it is a bug in the client. It should always send 2.0 version. [1] https://fedoraproject.org/wiki/Changes/Remove_SSH-1_from_OpenSSH [2] https://tools.ietf.org/html/rfc4253#section-5.1
I'm pretty sure that is actually a SSH-2 client. I'm going to ask some questtions in the OpenVMS discussion group. I'll come back on it later. Jouk
(In reply to Jakub Jelen from comment #23) > The important message is > > [1] https://fedoraproject.org/wiki/Changes/Remove_SSH-1_from_OpenSSH This text is on removing SSH-1 from the clients not the server. > [2] https://tools.ietf.org/html/rfc4253#section-5.1 Should 1.99 not regarded anyway as 2.0? Jouk
(In reply to J.Jansen from comment #25) > (In reply to Jakub Jelen from comment #23) > > The important message is > > > > > [1] https://fedoraproject.org/wiki/Changes/Remove_SSH-1_from_OpenSSH > This text is on removing SSH-1 from the clients not the server. Sorry, from server it was removed some time before this. Namely with OpenSSH-6.9p1 release. But the recent update removed these compatibility bits as well as complete support for SSH-1 from both parts. > > [2] https://tools.ietf.org/html/rfc4253#section-5.1 > Should 1.99 not regarded anyway as 2.0? The client should not send this identification string in the first place. From the RFC I read that it is supposed to be send by server, announcing to client "hey, I have protocol 2, but you can connect also using protocol 1". But you are right, there was a change in upstream [1], which I suspect is wrong and which you are hitting: - if (remote_major == 2 || - (remote_major == 1 && remote_minor == 99)) { - enable_compat20(); - } else { + if (remote_major != 2 || + (remote_major == 1 && remote_minor != 99)) { I believe it should say + if (remote_major != 2 && + !(remote_major == 1 && remote_minor == 99)) { I will fill a bug upstream. [1] https://github.com/openssh/openssh-portable/commit/97f4d3083b036ce3e68d6346a6140a22123d5864#diff-4035368a40ab0fedd413faefcbf832d7
(In reply to Jakub Jelen from comment #26) > (In reply to J.Jansen from comment #25) > > (In reply to Jakub Jelen from comment #23) > > > The important message is > > > > > > > > [1] https://fedoraproject.org/wiki/Changes/Remove_SSH-1_from_OpenSSH > > This text is on removing SSH-1 from the clients not the server. > > Sorry, from server it was removed some time before this. Namely with > OpenSSH-6.9p1 release. But the recent update removed these compatibility > bits as well as complete support for SSH-1 from both parts. > > > > [2] https://tools.ietf.org/html/rfc4253#section-5.1 > > Should 1.99 not regarded anyway as 2.0? > > The client should not send this identification string in the first place. I asked the question in the newsgroup comp.os.vms no answers yet > > From the RFC I read that it is supposed to be send by server, announcing to > client "hey, I have protocol 2, but you can connect also using protocol 1". > > But you are right, there was a change in upstream [1], which I suspect is > wrong and which you are hitting: > > - if (remote_major == 2 || > - (remote_major == 1 && remote_minor == 99)) { > - enable_compat20(); > - } else { > + if (remote_major != 2 || > + (remote_major == 1 && remote_minor != 99)) { > > I believe it should say > > + if (remote_major != 2 && > + !(remote_major == 1 && remote_minor == 99)) { > > I will fill a bug upstream. thanks. Looks reasonable because the second line in the current if-statement does not do anything. I'll wait for the outcome > > [1] > https://github.com/openssh/openssh-portable/commit/ > 97f4d3083b036ce3e68d6346a6140a22123d5864#diff- > 4035368a40ab0fedd413faefcbf832d7
My problem is solved. There was a way to set the version of the ssh-client to 2.0 [1] Note that this was already possible more than 7 years ago, but HP did not change it in newer versions of their TCP/IP-services (why??) Thanks for analyzing my problem. [1] https://community.hpe.com/t5/Operating-System-OpenVMS/Reconfigure-SSH-client-to-be-SSH-2-0/td-p/5245572
https://koji.fedoraproject.org/koji/taskinfo?taskID=23655711 works.
Jouk, good to see it resolved for you. Thank you for testing. I am building OpenSSH with the new seccomp filter in rawhide.
openssh-7.6p1-4.fc27 has been submitted as an update to Fedora 27. https://bodhi.fedoraproject.org/updates/FEDORA-2018-061197def5
I just downloaded this koji and the server is failing to restart due to timeout. Various tries of systemctl restart sshd.service failed. After downgrading to previous version everything worked fine. FYI
Thank you for the comment. It should be fixed with the next build.
openssh-7.6p1-5.fc27 has been submitted as an update to Fedora 27. https://bodhi.fedoraproject.org/updates/FEDORA-2018-621b9a9095
openssh-7.6p1-4.fc27 has been pushed to the Fedora 27 testing repository. If problems still persist, please make note of it in this bug report. See https://fedoraproject.org/wiki/QA:Updates_Testing for instructions on how to install test updates. You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2018-061197def5
openssh-7.6p1-5.fc27 has been pushed to the Fedora 27 testing repository. If problems still persist, please make note of it in this bug report. See https://fedoraproject.org/wiki/QA:Updates_Testing for instructions on how to install test updates. You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2018-621b9a9095
openssh-7.6p1-5.fc27 has been pushed to the Fedora 27 stable repository. If problems still persist, please make note of it in this bug report.