- Package:
- openssh-server
- Source:
- openssh
- Description:
- secure shell (SSH) server, for secure access from remote machines
- Submitter:
- Peter Schwindt
- Date:
- 2025-08-17 17:47:16 UTC
- Severity:
- important
- Tags:
After upgrading to ssh 4.1p1-3 (including openssh-server and -client) I'm not able to login via ssh anymore. Log follows:
Could you do /etc/init.d/rmnologin then retry ? I had a user which found it it was not run and broke its ssh login for non root users. Also could you confirm there where no other upgrade at the same time that could break the user session : the user shell and the like I cannot reproduce the bug :( Regards Alban
Alban, I reinstalled ssh 4.1p1-4 and did etc/init.d/rmnologin
I second this bug, I've debugged it further to additionally permissions on /var/log/btmp were wrong. Had to change that in logrotate.conf and manually, but even with sshd -d desolation:~# /usr/sbin/sshd -d debug1: sshd version OpenSSH_4.1p1 Debian-4 debug1: read PEM private key done: type RSA debug1: private host key: #0 type 1 RSA debug1: read PEM private key done: type DSA debug1: private host key: #1 type 2 DSA debug1: rexec_argv[0]='/usr/sbin/sshd' debug1: rexec_argv[1]='-d' debug1: Bind to port 22 on 127.0.0.1. Server listening on 127.0.0.1 port 22. debug1: Server will not fork when running in debugging mode. debug1: rexec start in 4 out 4 newsock 4 pipe -1 sock 7 debug1: inetd sockets after dupping: 3, 3 Connection from 127.0.0.1 port 58459 debug1: Client protocol version 2.0; client software version OpenSSH_4.1p1 Debian-4 debug1: match: OpenSSH_4.1p1 Debian-4 pat OpenSSH* debug1: Enabling compatibility mode for protocol 2.0 debug1: Local version string SSH-2.0-OpenSSH_4.1p1 Debian-4 debug1: list_hostkey_types: ssh-rsa,ssh-dss debug1: SSH2_MSG_KEXINIT sent debug1: SSH2_MSG_KEXINIT received debug1: kex: client->server aes128-cbc hmac-md5 none debug1: kex: server->client aes128-cbc hmac-md5 none debug1: SSH2_MSG_KEX_DH_GEX_REQUEST received debug1: SSH2_MSG_KEX_DH_GEX_GROUP sent debug1: expecting SSH2_MSG_KEX_DH_GEX_INIT debug1: SSH2_MSG_KEX_DH_GEX_REPLY sent debug1: SSH2_MSG_NEWKEYS sent debug1: expecting SSH2_MSG_NEWKEYS debug1: SSH2_MSG_NEWKEYS received debug1: KEX done debug1: userauth-request for user damm service ssh-connection method nonedebug1: attempt 0 failures 0 Failed none for damm from 127.0.0.1 port 58459 ssh2 debug1: userauth-request for user damm service ssh-connection method publickey debug1: attempt 1 failures 1 Failed publickey for damm from 127.0.0.1 port 58459 ssh2 debug1: userauth-request for user damm service ssh-connection method keyboard-interactive debug1: attempt 2 failures 2 Failed keyboard-interactive for damm from 127.0.0.1 port 58459 ssh2 debug1: userauth-request for user damm service ssh-connection method password debug1: attempt 3 failures 3 Failed password for damm from 127.0.0.1 port 58459 ssh2--- sshd_config attached
I'm experiencing the same issue with this package. Here's an strace -f of
the sshd process, starting after I typed my password (password removed).
Process 5023 attached - interrupt to quit
read(6, "\0\0\0\21", 4) = 4
read(6, "4\0\0\0\1\0\0\0\10", 17) = 17
write(7, "\0\0\0\r\6", 5) = 5
write(7, "\0\0\0\10", 12) = 12
--- SIGCHLD (Child exited) @ 0 (0) ---
rt_sigaction(SIGCHLD, NULL, {0x8064a10, [], 0}, 8) = 0
rt_sigaction(SIGCHLD, {SIG_DFL}, NULL, 8) = 0
waitpid(5027, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], WNOHANG) = 5027
sigreturn() = ? (mask now [])
write(6, "\0\0\0\0055", 5) = 5
write(6, "\0\0\0\1", 4) = 4
read(6, "\0\0\0\1", 4) = 4
read(6, "2", 1) = 1
read(7, "\0\0\0\27", 4) = 4
read(7, "\0\0\0\0\2OK\0\0\0\1\0\0\0\0\0\0\0\0\0\0\0\0", 23) = 23
write(6, "\0\0\0\0213", 5) = 5
write(6, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", 16) = 16
read(6, "\0\0\0\5", 4) = 4
read(6, "4\0\0\0\0", 5) = 5
write(6, "\0\0\0\0055", 5) = 5
write(6, "\0\0\0\0", 4) = 4
read(6, "\0\0\0\1", 4) = 4
read(6, "6", 1) = 1
rt_sigaction(SIGCHLD, NULL, {SIG_DFL}, 8) = 0
kill(5027, SIGTERM) = -1 ESRCH (No such process)
close(7) = 0
close(8) = 0
write(6, "\0\0\0\0017", 5) = 5
read(6, "\0\0\0\1", 4) = 4
read(6, ".", 1) = 1
write(6, "\0\0\0\t/", 5) = 5
write(6, "\0\0\0\1\0\0\0\0", 8) = 8
--- SIGCHLD (Child exited) @ 0 (0) ---
time([1120254395]) = 1120254395
getpid() = 5023
rt_sigaction(SIGPIPE, {0xb7de4a70, [], 0}, {SIG_IGN}, 8) = 0
send(4, "<38>Jul 1 14:46:35 sshd[5023]: "..., 111, 0) = 111
rt_sigaction(SIGPIPE, {SIG_IGN}, NULL, 8) = 0
close(4) = 0
read(6, "\0\0\4\207", 4) = 4
read(6, "\30\0\0\0\24_\231\34X#8@\200s6\26>\267\274\362M.|RX\0\0"..., 1159) = 1159
close(6) = 0
mmap2(NULL, 1310720, PROT_READ|PROT_WRITE, MAP_SHARED|MAP_ANONYMOUS, -1, 0) = 0xb7a34000
munmap(0xb7fd9000, 65536) = 0
waitpid(5024, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0) = 5024
alarm(0) = 570
close(5) = 0
socketpair(PF_FILE, SOCK_STREAM, 0, [4, 5]) = 0
fcntl64(4, F_SETFD, FD_CLOEXEC) = 0
fcntl64(5, F_SETFD, FD_CLOEXEC) = 0
clone(Process 5029 attached
child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xb7d0f648) = 5029
[pid 5023] close(4) = 0
[pid 5023] rt_sigaction(SIGHUP, NULL, {SIG_DFL}, 8) = 0
[pid 5023] rt_sigaction(SIGHUP, {0x805e2c0, [], 0}, NULL, 8) = 0
[pid 5023] rt_sigaction(SIGTERM, NULL, {SIG_DFL}, 8) = 0
[pid 5023] rt_sigaction(SIGTERM, {0x805e2c0, [], 0}, NULL, 8) = 0
[pid 5023] read(5, <unfinished ...>
[pid 5029] close(5) = 0
[pid 5029] getuid32() = 0
[pid 5029] setgid32(1000) = 0
[pid 5029] open("/etc/group", O_RDONLY) = 5
[pid 5029] fcntl64(5, F_GETFD) = 0
[pid 5029] fcntl64(5, F_SETFD, FD_CLOEXEC) = 0
[pid 5029] _llseek(5, 0, [0], SEEK_CUR) = 0
[pid 5029] fstat64(5, {st_mode=S_IFREG|0644, st_size=777, ...}) = 0
[pid 5029] mmap2(NULL, 777, PROT_READ, MAP_SHARED, 5, 0) = 0xb7fe8000
[pid 5029] _llseek(5, 777, [777], SEEK_SET) = 0
[pid 5029] fstat64(5, {st_mode=S_IFREG|0644, st_size=777, ...}) = 0
[pid 5029] munmap(0xb7fe8000, 777) = 0
[pid 5029] close(5) = 0
[pid 5029] setgroups32(9, [1000, 4, 6, 20, 24, 25, 29, 40, 44]) = 0
[pid 5029] getuid32() = 0
[pid 5029] getuid32() = 0
[pid 5029] ioctl(0, SNDCTL_TMR_TIMEBASE or TCGETS, 0xbfffe954) = -1 ENOTTY (Inappropriate ioctl for device)
[pid 5029] time([1120254395]) = 1120254395
[pid 5029] getpid() = 5029
[pid 5029] rt_sigaction(SIGPIPE, {0xb7de4a70, [], 0}, {SIG_IGN}, 8) = 0
[pid 5029] socket(PF_FILE, SOCK_DGRAM, 0) = 5
[pid 5029] fcntl64(5, F_SETFD, FD_CLOEXEC) = 0
[pid 5029] connect(5, {sa_family=AF_FILE, path="/dev/log"}, 16) = 0
[pid 5029] send(5, "<38>Jul 1 14:46:35 sshd[5029]: "..., 86, 0) = 86
[pid 5029] rt_sigaction(SIGPIPE, {SIG_IGN}, NULL, 8) = 0
[pid 5029] open("/etc/motd", O_RDONLY) = 6
[pid 5029] fstat64(6, {st_mode=S_IFREG|0644, st_size=373, ...}) = 0
[pid 5029] read(6, "Linux maguro.burlingame.ibm.com "..., 373) = 373
[pid 5029] close(6) = 0
[pid 5029] stat64("/var/mail/amckenna", 0xbfffeb8c) = -1 ENOENT (No such file or directory)
[pid 5029] open("/etc/passwd", O_RDONLY) = 6
[pid 5029] fcntl64(6, F_GETFD) = 0
[pid 5029] fcntl64(6, F_SETFD, FD_CLOEXEC) = 0
[pid 5029] _llseek(6, 0, [0], SEEK_CUR) = 0
[pid 5029] fstat64(6, {st_mode=S_IFREG|0644, st_size=2000, ...}) = 0
[pid 5029] mmap2(NULL, 2000, PROT_READ, MAP_SHARED, 6, 0) = 0xb7fe8000
[pid 5029] _llseek(6, 2000, [2000], SEEK_SET) = 0
[pid 5029] munmap(0xb7fe8000, 2000) = 0
[pid 5029] close(6) = 0
[pid 5029] getrlimit(RLIMIT_CPU, {rlim_cur=RLIM_INFINITY, rlim_max=RLIM_INFINITY}) = 0
[pid 5029] getrlimit(RLIMIT_FSIZE, {rlim_cur=RLIM_INFINITY, rlim_max=RLIM_INFINITY}) = 0
[pid 5029] getrlimit(RLIMIT_DATA, {rlim_cur=RLIM_INFINITY, rlim_max=RLIM_INFINITY}) = 0
[pid 5029] getrlimit(RLIMIT_STACK, {rlim_cur=8192*1024, rlim_max=RLIM_INFINITY}) = 0
[pid 5029] getrlimit(RLIMIT_CORE, {rlim_cur=0, rlim_max=RLIM_INFINITY}) = 0
[pid 5029] getrlimit(RLIMIT_RSS, {rlim_cur=RLIM_INFINITY, rlim_max=RLIM_INFINITY}) = 0
[pid 5029] getrlimit(RLIMIT_NPROC, {rlim_cur=RLIM_INFINITY, rlim_max=RLIM_INFINITY}) = 0
[pid 5029] getrlimit(RLIMIT_NOFILE, {rlim_cur=1024, rlim_max=1024}) = 0
[pid 5029] getrlimit(RLIMIT_MEMLOCK, {rlim_cur=RLIM_INFINITY, rlim_max=RLIM_INFINITY}) = 0
[pid 5029] getrlimit(RLIMIT_AS, {rlim_cur=RLIM_INFINITY, rlim_max=RLIM_INFINITY}) = 0
[pid 5029] getrlimit(RLIMIT_LOCKS, {rlim_cur=RLIM_INFINITY, rlim_max=RLIM_INFINITY}) = 0
[pid 5029] open("/etc/security/limits.conf", O_RDONLY) = 6
[pid 5029] fstat64(6, {st_mode=S_IFREG|0644, st_size=1519, ...}) = 0
[pid 5029] mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fe8000
[pid 5029] read(6, "# /etc/security/limits.conf\n#\n#E"..., 4096) = 1519
[pid 5029] read(6, "", 4096) = 0
[pid 5029] close(6) = 0
[pid 5029] munmap(0xb7fe8000, 4096) = 0
[pid 5029] setrlimit(RLIMIT_CPU, {rlim_cur=RLIM_INFINITY, rlim_max=RLIM_INFINITY}) = 0
[pid 5029] setrlimit(RLIMIT_FSIZE, {rlim_cur=RLIM_INFINITY, rlim_max=RLIM_INFINITY}) = 0
[pid 5029] setrlimit(RLIMIT_DATA, {rlim_cur=RLIM_INFINITY, rlim_max=RLIM_INFINITY}) = 0
[pid 5029] setrlimit(RLIMIT_STACK, {rlim_cur=8192*1024, rlim_max=RLIM_INFINITY}) = 0
[pid 5029] setrlimit(RLIMIT_CORE, {rlim_cur=0, rlim_max=RLIM_INFINITY}) = 0
[pid 5029] setrlimit(RLIMIT_RSS, {rlim_cur=RLIM_INFINITY, rlim_max=RLIM_INFINITY}) = 0
[pid 5029] setrlimit(RLIMIT_NPROC, {rlim_cur=RLIM_INFINITY, rlim_max=RLIM_INFINITY}) = 0
[pid 5029] setrlimit(RLIMIT_NOFILE, {rlim_cur=RLIM_INFINITY, rlim_max=RLIM_INFINITY}) = -1 EPERM (Operation not permitted)
[pid 5029] setrlimit(RLIMIT_MEMLOCK, {rlim_cur=RLIM_INFINITY, rlim_max=RLIM_INFINITY}) = 0
[pid 5029] setrlimit(RLIMIT_AS, {rlim_cur=RLIM_INFINITY, rlim_max=RLIM_INFINITY}) = 0
[pid 5029] setrlimit(RLIMIT_LOCKS, {rlim_cur=RLIM_INFINITY, rlim_max=RLIM_INFINITY}) = 0
[pid 5029] setpriority(PRIO_PROCESS, 0, 0) = 0
[pid 5029] open("/etc/security/pam_env.conf", O_RDONLY) = 6
[pid 5029] fstat64(6, {st_mode=S_IFREG|0644, st_size=3101, ...}) = 0
[pid 5029] mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fe8000
[pid 5029] read(6, "# $Date: 2002/09/21 18:37:34 $\n#"..., 4096) = 3101
[pid 5029] read(6, "", 4096) = 0
[pid 5029] close(6) = 0
[pid 5029] munmap(0xb7fe8000, 4096) = 0
[pid 5029] open("/etc/environment", O_RDONLY) = 6
[pid 5029] fstat64(6, {st_mode=S_IFREG|0644, st_size=12, ...}) = 0
[pid 5029] mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fe8000
[pid 5029] read(6, "\nLANG=en_US\n", 4096) = 12
[pid 5029] read(6, "", 4096) = 0
[pid 5029] close(6) = 0
[pid 5029] munmap(0xb7fe8000, 4096) = 0
[pid 5029] time([1120254395]) = 1120254395
[pid 5029] getpid() = 5029
[pid 5029] rt_sigaction(SIGPIPE, {0xb7de4a70, [], 0}, {SIG_IGN}, 8) = 0
[pid 5029] send(5, "<34>Jul 1 14:46:35 sshd[5029]: "..., 76, 0) = 76
[pid 5029] rt_sigaction(SIGPIPE, {SIG_IGN}, NULL, 8) = 0
[pid 5029] close(5) = 0
[pid 5029] getuid32() = 0
[pid 5029] time([1120254395]) = 1120254395
[pid 5029] getpid() = 5029
[pid 5029] rt_sigaction(SIGPIPE, {0xb7de4a70, [], 0}, {SIG_IGN}, 8) = 0
[pid 5029] socket(PF_FILE, SOCK_DGRAM, 0) = 5
[pid 5029] fcntl64(5, F_SETFD, FD_CLOEXEC) = 0
[pid 5029] connect(5, {sa_family=AF_FILE, path="/dev/log"}, 16) = 0
[pid 5029] send(5, "<38>Jul 1 14:46:35 sshd[5029]: "..., 75, 0) = 75
[pid 5029] rt_sigaction(SIGPIPE, {SIG_IGN}, NULL, 8) = 0
[pid 5029] munmap(0xb7baf000, 14548) = 0
[pid 5029] munmap(0xb7b97000, 93032) = 0
[pid 5029] munmap(0xb7b95000, 7384) = 0
[pid 5029] munmap(0xb7b92000, 12128) = 0
[pid 5029] munmap(0xb7b8e000, 15600) = 0
[pid 5029] munmap(0xb7b78000, 14676) = 0
[pid 5029] exit_group(255) = ?
Process 5029 detached
<... read resumed> "", 4) = 0
munmap(0xb7baf000, 14548) = 0
munmap(0xb7b97000, 93032) = 0
munmap(0xb7b95000, 7384) = 0
munmap(0xb7b92000, 12128) = 0
munmap(0xb7b8e000, 15600) = 0
munmap(0xb7b78000, 14676) = 0
exit_group(255) = ?
Process 5023 detached
Could I have that strace with '-s 1024' or similar, so that I can see what the log messages were? In the trace you sent they're all cut off at a most unhelpful point. Thanks,
There you go. Starts right after reading my password:
22815 <... read resumed> "\6", 14) = 1
22813 <... write resumed> ) = 13
22815 read(7, <unfinished ...>
22813 read(6, <unfinished ...>
22815 <... read resumed> "\0\0\0\tmvemjsu6p", 13) = 13
22815 open("/etc/passwd", O_RDONLY) = 8
22815 fcntl64(8, F_GETFD) = 0
22815 fcntl64(8, F_SETFD, FD_CLOEXEC) = 0
22815 _llseek(8, 0, [0], SEEK_CUR) = 0
22815 fstat64(8, {st_mode=S_IFREG|0644, st_size=2759, ...}) = 0
22815 mmap2(NULL, 2759, PROT_READ, MAP_SHARED, 8, 0) = 0xb7fe8000
22815 _llseek(8, 2759, [2759], SEEK_SET) = 0
22815 munmap(0xb7fe8000, 2759) = 0
22815 close(8) = 0
22815 open("/etc/shadow", O_RDONLY) = 8
22815 fcntl64(8, F_GETFD) = 0
22815 fcntl64(8, F_SETFD, FD_CLOEXEC) = 0
22815 _llseek(8, 0, [0], SEEK_CUR) = 0
22815 fstat64(8, {st_mode=S_IFREG|0640, st_size=2087, ...}) = 0
22815 mmap2(NULL, 2087, PROT_READ, MAP_SHARED, 8, 0) = 0xb7fe8000
22815 _llseek(8, 2087, [2087], SEEK_SET) = 0
22815 munmap(0xb7fe8000, 2087) = 0
22815 close(8) = 0
22815 getuid32() = 0
22815 open("/etc/passwd", O_RDONLY) = 8
22815 fcntl64(8, F_GETFD) = 0
22815 fcntl64(8, F_SETFD, FD_CLOEXEC) = 0
22815 _llseek(8, 0, [0], SEEK_CUR) = 0
22815 fstat64(8, {st_mode=S_IFREG|0644, st_size=2759, ...}) = 0
22815 mmap2(NULL, 2759, PROT_READ, MAP_SHARED, 8, 0) = 0xb7fe8000
22815 _llseek(8, 2759, [2759], SEEK_SET) = 0
22815 munmap(0xb7fe8000, 2759) = 0
22815 close(8) = 0
22815 open("/etc/shadow", O_RDONLY) = 8
22815 fcntl64(8, F_GETFD) = 0
22815 fcntl64(8, F_SETFD, FD_CLOEXEC) = 0
22815 _llseek(8, 0, [0], SEEK_CUR) = 0
22815 fstat64(8, {st_mode=S_IFREG|0640, st_size=2087, ...}) = 0
22815 mmap2(NULL, 2087, PROT_READ, MAP_SHARED, 8, 0) = 0xb7fe8000
22815 _llseek(8, 2087, [2087], SEEK_SET) = 0
22815 munmap(0xb7fe8000, 2087) = 0
22815 close(8) = 0
22815 time(NULL) = 1120636582
22815 write(7, "\0\0\0\27\0", 5 <unfinished ...>
22813 <... read resumed> "\0\0\0\27", 4) = 4
22815 <... write resumed> ) = 5
22813 read(6, <unfinished ...>
22815 write(7, "\0\0\0\2OK\0\0\0\1\0\0\0\0\0\0\0\0\0\0\0\0", 22 <unfinished ...>
22813 <... read resumed> "\0", 23) = 1
22815 <... write resumed> ) = 22
22813 read(6, <unfinished ...>
22815 exit_group(0) = ?
22813 <... read resumed> "\0\0\0\2OK\0\0\0\1\0\0\0\0\0\0\0\0\0\0\0\0", 22) = 22
22813 --- SIGCHLD (Child exited) @ 0 (0) ---
22813 rt_sigaction(SIGCHLD, NULL, {0x8064a10, [], 0}, 8) = 0
22813 rt_sigaction(SIGCHLD, {SIG_DFL}, NULL, 8) = 0
22813 waitpid(22815, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], WNOHANG) = 22815
22813 sigreturn() = ? (mask now [])
22813 write(3, "\366\336T\326Ar\313\n1\253\244Vm\224\245\201t\217\5\233a\325aE\255\203\323\340\221\305P\321\24\271\316\36\311u\347\vxJ\302\312\342\367|op{\25F", 52) = 52
22813 select(4, [3], NULL, NULL, NULL) = 1 (in [3])
22813 read(3, "G\203\377ISkOUNh@\214w$\347\316\275\337\212+#w\264u\300y<\21\322\250\267(ji\260\',8\257+\242F\354\245\212\364\337\300\323\330pR^\260S0\322r\303\251MVCM$\3729\321\"0aJP\37\225\216\335~\336L\335\36\n9w\22\356\2137\367\263?\7Cs\16\365v\366\2\325\301\243\36+Y\"\200\276\325L\304\244\261\330\1T\35O\3668\327\307xS/$\34L\225\211\251:\37\244\361\342\372U4\27\362\276-(\265\277\272>\"C\313\344\351\32e42\35*\223\340$38\f\213eh\210}\7C\272\327\333\315O|\224t\25%&\355a].\216\254)\f\26Z\3242\252\372\347\21\243\302\373\22Q\365!\3#q|\243\272.W\1\230\364[~\375?\1\22\37\202\340\311\20\365\352\265\306`\302\330=\34\364\302e\256\20\'\222\35\241\217\223\373\212q\37\30\331\216\354fa=\272\242W\3448\303Y\366\206\35\0040\267\300\247\341", 8192) = 276
22813 rt_sigaction(SIGCHLD, NULL, {SIG_DFL}, 8) = 0
22813 kill(22815, SIGTERM) = -1 ESRCH (No such process)
22813 close(6) = 0
22813 close(7) = 0
22813 time([1120636582]) = 1120636582
22813 getpid() = 22813
22813 rt_sigaction(SIGPIPE, {0xb7de6a70, [], 0}, {SIG_IGN}, 8) = 0
22813 send(4, "<38>Jul 6 09:56:22 sshd[22813]: Accepted keyboard-interactive/pam for schwindt from 193.196.182.171 port 1246 ssh2", 115, 0) = 115
22813 rt_sigaction(SIGPIPE, {SIG_IGN}, NULL, 8) = 0
22813 close(4) = 0
22813 write(3, "\373}\212\350\225m\251\323@\6\212\276HJ-\317\200\363\253\206\25..\357(\311\232\371V\252W\340]\344z\327", 36) = 36
22813 alarm(0) = 590
22813 close(5) = 0
22810 <... select resumed> ) = 1 (in [5])
22813 rt_sigaction(SIGCHLD, NULL, <unfinished ...>
22810 close(5 <unfinished ...>
22813 <... rt_sigaction resumed> {SIG_DFL}, 8) = 0
22810 <... close resumed> ) = 0
22813 rt_sigaction(SIGCHLD, {0x8053620, [], 0}, <unfinished ...>
22810 select(6, [3], NULL, NULL, NULL <unfinished ...>
22813 <... rt_sigaction resumed> NULL, 8) = 0
22813 pipe([4, 5]) = 0
22813 fcntl64(4, F_SETFD, FD_CLOEXEC) = 0
22813 fcntl64(5, F_SETFD, FD_CLOEXEC) = 0
22813 fcntl64(4, F_GETFL) = 0 (flags O_RDONLY)
22813 fcntl64(4, F_SETFL, O_RDONLY|O_NONBLOCK) = 0
22813 fcntl64(5, F_GETFL) = 0x1 (flags O_WRONLY)
22813 fcntl64(5, F_SETFL, O_WRONLY|O_NONBLOCK) = 0
22813 select(5, [3 4], [], NULL, NULL) = 1 (in [3])
22813 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
22813 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
22813 read(3, "\10v\211\27\331)\211\217f\376\243.\357\21\220qx\252Y\0b\24\231F\33\267\3529Z\257\177\242\5\327\270\270\267\214h\214\336\301cj\37\0059\261\237\256\355\241\16kT\353\344\333\216\177g\341 I\31\245\27\323", 16384) = 68
22813 ioctl(-1, SNDCTL_TMR_TIMEBASE or TCGETS, 0xbfffe3a8) = -1 EBADF (Bad file descriptor)
22813 ioctl(-1, SNDCTL_TMR_TIMEBASE or TCGETS, 0xbfffe3a8) = -1 EBADF (Bad file descriptor)
22813 select(5, [3 4], [3], NULL, NULL) = 1 (out [3])
22813 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
22813 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
22813 write(3, "k\262\274C\366\357D\250\311IZ\34\'\305C\204&\355\225\222\377_\5N\3624\177\220!\356\217\324\262Q\321q\262O\2260\224L\7\10\20\352U\301J\273\35\222", 52) = 52
22813 select(5, [3 4], [], NULL, NULL) = 1 (in [3])
22813 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
22813 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
22813 read(3, "\200\25\331\254\374J\3214\2^\302\350&\221\25\222\205\4ji\342\230\240<\365 \374\25\0377\220r\213\214\235\370\306\34\213W\272\362\307T~\rn8\326;\320\264q\232\2172j\327\227\211\342|\\\37o<*\'\300l\233-t^\201\17\240\374L\33\35\234\2v\337\344V\355\337\3236)\265\332C\371ch\253\262", 16384) = 100
22813 open("/dev/ptmx", O_RDWR) = 6
22813 statfs("/dev/pts", {f_type="DEVPTS_SUPER_MAGIC", f_bsize=4096, f_blocks=0, f_bfree=0, f_bavail=0, f_files=0, f_ffree=0, f_fsid={0, 0}, f_namelen=255, f_frsize=4096}) = 0
22813 ioctl(6, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
22813 ioctl(6, TIOCGPTN, [12]) = 0
22813 stat64("/dev/pts/12", {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 12), ...}) = 0
22813 statfs("/dev/pts/12", {f_type="DEVPTS_SUPER_MAGIC", f_bsize=4096, f_blocks=0, f_bfree=0, f_bavail=0, f_files=0, f_ffree=0, f_fsid={0, 0}, f_namelen=255, f_frsize=4096}) = 0
22813 ioctl(6, TIOCSPTLCK, [0]) = 0
22813 ioctl(6, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
22813 ioctl(6, TIOCGPTN, [12]) = 0
22813 stat64("/dev/pts/12", {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 12), ...}) = 0
22813 open("/dev/pts/12", O_RDWR|O_NOCTTY) = 7
22813 ioctl(7, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
22813 readlink("/proc/self/fd/7", "/dev/pts/12", 4095) = 11
22813 ioctl(7, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
22813 ioctl(7, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
22813 ioctl(7, SNDCTL_TMR_START or TCSETS, {B38400 opost isig icanon echo ...}) = 0
22813 ioctl(7, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
22813 open("/etc/group", O_RDONLY) = 8
22813 fcntl64(8, F_GETFD) = 0
22813 fcntl64(8, F_SETFD, FD_CLOEXEC) = 0
22813 _llseek(8, 0, [0], SEEK_CUR) = 0
22813 fstat64(8, {st_mode=S_IFREG|0644, st_size=1015, ...}) = 0
22813 mmap2(NULL, 1015, PROT_READ, MAP_SHARED, 8, 0) = 0xb7cde000
22813 _llseek(8, 1015, [1015], SEEK_SET) = 0
22813 munmap(0xb7cde000, 1015) = 0
22813 close(8) = 0
22813 stat64("/dev/pts/12", {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 12), ...}) = 0
22813 open("/proc/filesystems", O_RDONLY|O_LARGEFILE) = 8
22813 read(8, "nodev\tsysfs\nnodev\trootfs\nnodev\tbdev\nnodev\tproc\nnodev\tsockfs\nnodev\tpipefs\nnodev\tfutexfs\nnodev\ttmpfs\nnodev\teventpollfs\nnodev\tdevpts\n\text3\n\text2\nnodev\tramfs\nnodev\tautofs\nnodev\tusbfs\nnodev\trpc_pipefs\nnodev\tnfs\n\tvfat\n\tiso9660\n", 4095) = 221
22813 close(8) = 0
22813 chown32("/dev/pts/12", 1000, 5) = 0
22813 ioctl(6, TIOCSWINSZ, {ws_row=24, ws_col=80, ws_xpixel=0, ws_ypixel=0}) = 0
22813 select(5, [3 4], [3], NULL, NULL) = 1 (out [3])
22813 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
22813 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
22813 write(3, "\374B\377\t\25T\'\211\301\1\'d7~\210\7J\360\261@~\353\3\363\371;\345@\3029\206:\270q6\235", 36) = 36
22813 select(5, [3 4], [], NULL, NULL) = 1 (in [3])
22813 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
22813 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
22813 read(3, "!\341\254\317h>\327\216\224\202\350:<\6\0\326\324Igc\344\226\220>\317P]\220j\24D\254\211\22\230G\331P{\354)\302{\215w<\237\211\236\17\263\274", 16384) = 52
22813 open("/etc/security/pam_env.conf", O_RDONLY) = 8
22813 fstat64(8, {st_mode=S_IFREG|0644, st_size=3101, ...}) = 0
22813 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7cde000
22813 read(8, "# $Date: 2002/09/21 18:37:34 $\n# $Author: hartmans $\n# $Id: pam_env.conf-example,v 1.4 2002/09/21 18:37:34 hartmans Exp $\n#\n# This is the configuration file for pam_env, a PAM module to load in \n# a configurable list of environment variables for a \n# \n# The original idea for this came from Andrew G. Morgan ...\n#<quote>\n# Mmm. Perhaps you might like to write a pam_env module that reads a\n# default environment from a file? I can see that as REALLY\n# useful... Note it would be an \"auth\" module that returns PAM_IGNORE\n# for the auth part and sets the environment returning PAM_SUCCESS in\n# the setcred function...\n#</quote>\n#\n# What I wanted was the REMOTEHOST variable set, purely for selfish\n# reasons, and AGM didn\'t want it added to the SimpleApps login\n# program (which is where I added the patch). So, my first concern is\n# that variable, from there there are numerous others that might/would\n# be useful to be set: NNTPSERVER, LESS, PATH, PAGER, MANPAGER .....\n#\n# Of course, these are a different kind of"..., 4096) = 3101
22813 read(8, "", 4096) = 0
22813 close(8) = 0
22813 munmap(0xb7cde000, 4096) = 0
22813 open("/etc/environment", O_RDONLY) = 8
22813 fstat64(8, {st_mode=S_IFREG|0644, st_size=12, ...}) = 0
22813 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7cde000
22813 read(8, "\nLANG=de_DE\n", 4096) = 12
22813 read(8, "", 4096) = 0
22813 close(8) = 0
22813 munmap(0xb7cde000, 4096) = 0
22813 time([1120636582]) = 1120636582
22813 getpid() = 22813
22813 rt_sigaction(SIGPIPE, {0xb7de6a70, [], 0}, {SIG_IGN}, 8) = 0
22813 socket(PF_FILE, SOCK_DGRAM, 0) = 8
22813 fcntl64(8, F_SETFD, FD_CLOEXEC) = 0
22813 connect(8, {sa_family=AF_FILE, path="/dev/log"}, 16) = 0
22813 send(8, "<34>Jul 6 09:56:22 sshd[22813]: fatal: PAM: pam_setcred(): Permission denied", 77, 0) = 77
22813 rt_sigaction(SIGPIPE, {SIG_IGN}, NULL, 8) = 0
22813 close(8) = 0
22813 munmap(0xb7fe4000, 14548) = 0
22813 munmap(0xb7cdf000, 93032) = 0
22813 munmap(0xb7fe2000, 7384) = 0
22813 munmap(0xb7fdf000, 12128) = 0
22813 munmap(0xb7fdb000, 15600) = 0
22813 munmap(0xb7ccb000, 14676) = 0
22813 getuid32() = 0
22813 chown32("/dev/pts/12", 0, 0) = 0
22813 chmod("/dev/pts/12", 0666) = 0
22813 close(0) = 0
22813 exit_group(255) = ?
22810 <... select resumed> ) = ? ERESTARTNOHAND (To be restarted)
22810 --- SIGCHLD (Child exited) @ 0 (0) ---
22810 waitpid(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 255}], WNOHANG) = 22813
22810 waitpid(-1, 0xbfffe450, WNOHANG) = -1 ECHILD (No child processes)
22810 rt_sigaction(SIGCHLD, NULL, {0x804cab0, [], 0}, 8) = 0
22810 sigreturn() = ? (mask now [])
22810 select(6, [3], NULL, NULL, NULL) = ? ERESTARTNOHAND (To be restarted)
22810 --- SIGINT (Interrupt) @ 0 (0) ---
22810 +++ killed by SIGINT +++
While ssh server invokes PAM for service "sshd", the provided PAM config is /etc/pam.d/ssh. So PAM does NOT load it, and depending on level of paranoia of the default setting either authenticates the user or not. Lines like this showed up in my log: Jul 7 17:47:41 vagabond PAM-warn[30881]: function=[pam_sm_acct_mgmt] service=[sshd] terminal=[ssh] user=[root] ruser=[<unknown>] rhost=[localhost] And creating a symlink: ln -s /etc/pam.d/ssh /etc/pam.d/sshd fixed the problem for me. There are three possible fixes for the package: 1) Find the serivce name and replace it with "ssh". 2) Provide the link above (mostly a quick-hack) 3) Provide /etc/pam.d/sshd instead of /etc/pam.d/ssh and provide a pre-inst to copy over the old contents. Note: I am trying to tag this bug with patch, because "other easy procedure for fixing the bug is included".
This is a different bug which only exists in 1:4.1p1-5, not 1:4.1p1-3 against which this bug was reported. It is fixed in 1:4.1p1-6, currently on incoming.debian.org. This isn't a fix for this bug (but fortunately the method above does not work for tagging an existing bug, so I don't need to undo it). Cheers,
Um, ok. The symptoms looked the same, so I thought it is the same. Ok. Thanks.------------------------------------------------------------------------------- Jan 'Bulb' Hudec <bulb@ucw.cz>
I have the same bug. But I have noticed that RSA authentication, public key login does work. Also, here is my very verbose debug trace from the debug client at the point right after I enter the password: ***************** password login **************** debug3: packet_send2: adding 32 (len 20 padlen 12 extra_pad 64) debug2: input_userauth_info_req debug2: input_userauth_info_req: num_prompts 0 debug3: packet_send2: adding 48 (len 10 padlen 6 extra_pad 64) debug1: Authentication succeeded (keyboard-interactive). debug1: channel 0: new [client-session] debug3: ssh_session2_open: channel_new: 0 debug2: channel 0: send open debug1: Entering interactive session. debug1: channel 0: free: client-session, nchannels 1 debug3: channel 0: status: The following connections are open: #0 client-session (t3 r-1 i0/0 o0/0 fd 4/5) debug3: channel 0: close_fds r 4 w 5 e 6 Connection to reactor-core.org closed by remote host. Connection to reactor-core.org closed. debug1: Transferred: stdin 0, stdout 0, stderr 95 bytes in 0.0 seconds debug1: Bytes per second: stdin 0.0, stdout 0.0, stderr 8587.9 debug1: Exit status -1 ************************************************* ***************** public key auth *************** debug1: channel 0: new [client-session] debug3: ssh_session2_open: channel_new: 0 debug1: send channel open 0 debug1: Entering interactive session. debug2: callback start debug1: ssh_session2_setup: id 0 debug1: channel request 0: pty-req ... *************************************************
Downgrade to openssh-4.0p1 and the problem goes away. Somewhere between openssh-4.0p1-1 and openssh-4.1p1-1, the login problem was introduced. Jonathan
Disabling POSIX_THREADS was the problem. Here is a patch that reenables them (which will reopen other, less important bugs). A wiser head than mine will have to find out what differs between the threaded and non-threaded versions which causes this logging in problem. Since the main bug closed by getting rid of threads was a "policy violation", I recommend that "policy" be reconsidered. *********************************************** --- openssh-4.1p1/debian/rules 2005-07-21 20:49:16.000000000 -0700 +++ openssh-fixed/debian/rules 2005-07-21 20:24:10.000000000 -0700 @@ -59,8 +59,11 @@ # SELinux support? ifeq ($(DEB_HOST_ARCH_OS),linux) SELINUX := --with-selinux +LINK_PTHREAD := -pthread +else +LINK_PTHREAD := -lpthread endif # Change the version string to include the Debian version SSH_EXTRAVERSION := Debian-$(shell dpkg-parsechangelog | sed -n -e '/^Version:/s/Version: //p' | sed -e 's/[^-]*-//') @@ -78,10 +81,12 @@ perl -pi -e 's/.*#undef (BROKEN_SETRES[UG]ID).*/#define $$1 1/' build-deb/config.h endif # Debian's /var/log/btmp has inappropriate permissions. perl -pi -e 's,.*#define USE_BTMP .*,/* #undef USE_BTMP */,' build-deb/config.h + # Supply pthread linkage for just those binaries linked to PAM. + perl -pi -e 's/^(LIBPAM=.*)/$$1 $(LINK_PTHREAD)/' build-deb/Makefile - $(MAKE) -C build-deb -j 2 ASKPASS_PROGRAM='/usr/bin/ssh-askpass' CFLAGS='$(OPTFLAGS) -g -Wall -DLOGIN_PROGRAM=\"/bin/login\" -DLOGIN_NO_ENDOPT -DSSHD_PAM_SERVICE=\"ssh\" -DSSH_EXTRAVERSION="\" $(SSH_EXTRAVERSION)\""' + $(MAKE) -C build-deb -j 2 ASKPASS_PROGRAM='/usr/bin/ssh-askpass' CFLAGS='$(OPTFLAGS) -g -Wall -DUNSUPPORTED_POSIX_THREADS_HACK -DLOGIN_PROGRAM=\"/bin/login\" -DLOGIN_NO_ENDOPT -DSSHD_PAM_SERVICE=\"ssh\" -DSSH_EXTRAVERSION="\" $(SSH_EXTRAVERSION)\""' # Support building on Debian 3.0 (with GNOME 1.4) and later. if [ -f /usr/include/libgnomeui-2.0/gnome.h ]; then \ $(MAKE) -C contrib gnome-ssh-askpass2 CC='gcc $(OPTFLAGS) -g -Wall'; \ elif [ -f /usr/include/gnome-1.0/gnome.h ]; then \ **************** END OF PATCH *****************
Sorry, I'm not going to re-enable POSIX threads across the board; upstream are vehemently opposed to it and I do need upstream help from time to time. Doing so would reopen other bugs which are equally severe. It's possible that I may create a separate sshd-pthreads binary if there is no alternative. In the meantime, what's in your PAM configuration? I'd like to narrow this down to particular modules.
Please find my pam.conf and pam.d/ inside the attached tar/gzip file. I hope that helps. I did try telling sshd not to use PAM at all, but that didn't solve the login bug. Jonathan
Please find my pam.conf and pam.d/ inside the attached tar/gzip file. I hope that helps. I did try telling sshd not to use PAM at all, but that didn't solve the login bug. Jonathan
A workaround for this bug (worked for me, anyway) is to disable UsePAM and enable UseLogin in the sshd config file. YMMV,
I found that the problem was a missing /etc/environment file. I did a touch /etc/environment and after that, my problem went away. // Henrik
That's a different bug, namely #330843.
This is what we had installed: ii libpam-modules 0.72-34 Pluggable Authentication Modules for PAM ii libpam-runtime 0.76-15 Runtime support for the PAM library ii libpam0g 0.76-7 Pluggable Authentication Modules library Then we upgraded openssh-server to 4.3p2-8. Afterwards it refused all connections. This is what turned up in auth.log Jan 19 21:46:35 dora sshd[11322]: PAM unable to resolve symbol: pam_sm_acct_mgmt Jan 19 21:46:52 dora sshd[11322]: Failed password for agnes from 192.168.42.44 port 54009 After upgrading all pam packages to recent version the problem was gone.
I updated openssh after the weak keys notices of the past days and I couldn't login anymore using password authentication on one of my servers. I logged in from the console, looked at auth.log, googled for the error message I got and found this bug #314289. The fix in the last post was effective (update libpam-modules, libpam-runtime and libpam0g, thanks!) but I wonder if it would be possible to add some dependencies and use apt-get install openssh to keep all the libraries aligned. Paolo
What versions of those packages did you have before upgrading? (If you don't know offhand, please attach /var/log/dpkg.log to your reply; that will let me find out.) Thanks,
Dear Customer, Your item has arrived at the USPS Post Office at January 22, but the courier was unable to deliver parcel to you. Please check the attachment for complete details! Yours respectfully, Melvin Long, USPS Station Manager.
Dear Customer, Your item has arrived at the UPS Post Office at March 02, but the courier was unable to deliver parcel to you. Please check the attachment for complete details! Kind thoughts, Glen Tipton, UPS Operation Manager.