Bug#115767: I see this too on x86-xen running etch
On Sat, Apr 29, 2006 at 03:11:55PM +0000, Andy Smith wrote:
> On Mon, Apr 24, 2006 at 08:04:27PM +0000, Andy Smith wrote:
> > I'll look into running another sshd on a higher port for my own
> > needs and strace one on port 22. The dictionary attacks should
> > still trigger this eventually.
>
> Okay, I did this, and ~5 days later a massive dictionary attack
> triggered the problem:
>
> # grep -c 'sshd.*Invalid user.*from 62.193.245.215' /var/log/auth.log
> 1902
> # grep -B 4 6372 /var/log/auth.log
> Apr 29 13:57:06 ruminant sshd[443]: Invalid user qmailr from 62.193.245.215
> Apr 29 13:57:06 ruminant sshd[445]: Invalid user qmails from 62.193.245.215
> Apr 29 13:57:07 ruminant sshd[447]: Invalid user r00t from 62.193.245.215
> Apr 29 13:57:07 ruminant sshd[449]: Invalid user r00t from 62.193.245.215
> Apr 29 13:57:07 ruminant sshd[6372]: fatal: Couldn't obtain random bytes (error 604389476)
> # ls -lh /var/log/ssh-strace/ssh-strace.log.6372
> -rw-r--r-- 1 root root 23M Apr 29 13:57 /var/log/ssh-strace/ssh-strace.log.6372
> # tail -40 /var/log/ssh-strace/ssh-strace.log.6372
> 13:57:07 write(7, "\0\0\2Y\n\n\n\nPort 22\n\n\n\nProtocol 2\n\nH"..., 609) = 609
> 13:57:07 close(7) = 0
> 13:57:07 close(8) = 0
> 13:57:07 getpid() = 6372
> 13:57:07 getpid() = 6372
> 13:57:07 close(4) = 0
> 13:57:07 select(8, [3 5], NULL, NULL, NULL) = 1 (in [5])
> 13:57:07 --- SIGCHLD (Child exited) @ 0 (0) ---
> 13:57:07 waitpid(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 255}], WNOHANG) = 449
> 13:57:07 waitpid(-1, 0xbfffeb5c, WNOHANG) = -1 ECHILD (No child processes)
> 13:57:07 rt_sigaction(SIGCHLD, NULL, {0x804d470, [], 0}, 8) = 0
> 13:57:07 sigreturn() = ? (mask now [])
> 13:57:07 close(5) = 0
> 13:57:07 select(8, [3], NULL, NULL, NULL) = 1 (in [3])
> 13:57:07 accept(3, {sa_family=AF_INET6, sin6_port=htons(40492), inet_pton(AF_INET6, "::ffff:62.193.245.215", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 4
> 13:57:07 fcntl64(4, F_GETFL) = 0x2 (flags O_RDWR)
> 13:57:07 pipe([5, 6]) = 0
> 13:57:07 socketpair(PF_FILE, SOCK_STREAM, 0, [7, 8]) = 0
> 13:57:07 fork() = 451
> 13:57:07 close(6) = 0
> 13:57:07 write(7, "\0\0\2b\0", 5) = 5
> 13:57:07 write(7, "\0\0\2Y\n\n\n\nPort 22\n\n\n\nProtocol 2\n\nH"..., 609) = 609
> 13:57:07 close(7) = 0
> 13:57:07 close(8) = 0
> 13:57:07 getpid() = 6372
> 13:57:07 getpid() = 6372
> 13:57:07 getpid() = 6372
> 13:57:07 getpid() = 6372
> 13:57:07 getpid() = 6372
> 13:57:07 time([1146319027]) = 1146319027
> 13:57:07 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=56, ...}) = 0
> 13:57:07 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=56, ...}) = 0
> 13:57:07 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=56, ...}) = 0
> 13:57:07 getpid() = 6372
> 13:57:07 socket(PF_FILE, SOCK_DGRAM, 0) = 6
> 13:57:07 fcntl64(6, F_SETFD, FD_CLOEXEC) = 0
> 13:57:07 connect(6, {sa_family=AF_FILE, path="/dev/log"}, 16) = 0
> 13:57:07 send(6, "<34>Apr 29 13:57:07 sshd[6372]: "..., 85, MSG_NOSIGNAL) = 85
> 13:57:07 close(6) = 0
> 13:57:07 exit_group(255) = ?
>
> I can't see anything that jumps out as being wrong in any of the
> strace logs for the forked children 451, 449, 447, 445 etc.. Any
> ideas?
Nothing that I can see.. You might change your strace to use -s200 to
get longer strings. Could you send more complete strace logs from
sshd and the relevant client? I guess it was another process (451?)
which experienced the actual problem, and communicated that to the
master daemon process.
Justin
Reply to: