sshd keeps dying

JustinHoMi · 01-03-2006, 05:52 AM

Ah... I remember now the problems I was having with the init scripts. For some reason, when I use "-d -d -d" webmin tries to capture the output of the script. Webmin ends up wrapped around the ssh process, and nothing goes to syslog.

unSpawn · 01-03-2006, 06:10 AM

Then try adding a Xinetd entry instead of the initscript stuff.

JustinHoMi · 01-06-2006, 03:28 PM

Happened again. I had level 1 debugging enabled. This time was a little different that the previous. When I tried to connect, it just disconnected me immediately. After rebooting the server, I still can't login. It goes back to the previous behaviour where it asks for my password, then sits forever.

Here are the logs from before I restarted the server. The last line is me trying to kill the process.

Code:

Jan  4 17:08:17 server sshd[5768]: debug1: session_by_channel: session 0 channel 0
Jan  4 17:08:17 server sshd[5768]: debug1: session_input_channel_req: session 0 req window-change
Jan  4 17:19:14 server sshd[5913]: Connection from 62.75.231.48 port 51812
Jan  4 17:19:14 server sshd[5913]: Did not receive identification string from 62.75.231.48
Jan  4 17:19:14 server sshd[5913]: debug1: Calling cleanup 0x806f1d0(0x0)
Jan  4 17:19:14 server sshd[8151]: debug1: Forked child 5913.
Jan  4 17:19:14 server sshd[5914]: Connection from 62.75.231.48 port 51813
Jan  4 17:19:14 server sshd[5914]: Did not receive identification string from 62.75.231.48
Jan  4 17:19:14 server sshd[5914]: debug1: Calling cleanup 0x806f1d0(0x0)
Jan  4 17:19:14 server sshd[8151]: debug1: Forked child 5914.
Jan  4 17:19:14 server sshd[5915]: Connection from 62.75.231.48 port 51815
Jan  4 17:19:14 server sshd[5915]: Did not receive identification string from 62.75.231.48
Jan  4 17:19:14 server sshd[5915]: debug1: Calling cleanup 0x806f1d0(0x0)
Jan  4 17:19:14 server sshd[8151]: debug1: Forked child 5915.
Jan  4 17:19:14 server sshd[5916]: Connection from 62.75.231.48 port 51814
Jan  4 17:19:14 server sshd[8151]: debug1: Forked child 5916.
Jan  4 17:19:14 server sshd[5916]: Did not receive identification string from 62.75.231.48
Jan  4 17:19:14 server sshd[5917]: Connection from 62.75.231.48 port 51816
Jan  4 17:19:14 server sshd[8151]: debug1: Forked child 5917.
Jan  4 17:19:14 server sshd[5916]: debug1: Calling cleanup 0x806f1d0(0x0)
Jan  4 17:19:14 server sshd[5917]: Did not receive identification string from 62.75.231.48
Jan  4 17:19:14 server sshd[5917]: debug1: Calling cleanup 0x806f1d0(0x0)
Jan  4 17:20:24 server sshd[5768]: debug1: server_input_channel_req: channel 0 request window-change reply 0
Jan  4 17:20:24 server sshd[5768]: debug1: session_by_channel: session 0 channel 0
Jan  4 17:20:24 server sshd[5768]: debug1: session_input_channel_req: session 0 req window-change
Jan  4 17:38:13 server sshd[5768]: debug1: server_input_channel_req: channel 0 request window-change reply 0
Jan  4 17:38:13 server sshd[5768]: debug1: session_by_channel: session 0 channel 0
Jan  4 17:38:13 server sshd[5768]: debug1: session_input_channel_req: session 0 req window-change
Jan  4 17:48:51 server sshd[8151]: Generating new 768 bit RSA key.
Jan  4 17:48:51 server sshd[8151]: RSA key generation complete.
Jan  4 18:14:03 server sshd[5768]: debug1: server_input_channel_req: channel 0 request window-change reply 0
Jan  4 18:14:03 server sshd[5768]: debug1: session_by_channel: session 0 channel 0
Jan  4 18:14:03 server sshd[5768]: debug1: session_input_channel_req: session 0 req window-change
Jan  4 18:14:06 server sshd[5768]: debug1: server_input_channel_req: channel 0 request window-change reply 0
Jan  4 18:14:06 server sshd[5768]: debug1: session_by_channel: session 0 channel 0
Jan  4 18:14:06 server sshd[5768]: debug1: session_input_channel_req: session 0 req window-change
Jan  4 18:14:13 server sshd[5768]: debug1: server_input_channel_req: channel 0 request window-change reply 0
Jan  4 18:14:13 server sshd[5768]: debug1: session_by_channel: session 0 channel 0
Jan  4 18:14:13 server sshd[5768]: debug1: session_input_channel_req: session 0 req window-change
Jan  4 18:18:58 server sshd[5768]: debug1: server_input_channel_req: channel 0 request window-change reply 0
Jan  4 18:18:58 server sshd[5768]: debug1: session_by_channel: session 0 channel 0
Jan  4 18:18:58 server sshd[5768]: debug1: session_input_channel_req: session 0 req window-change
Jan  4 18:58:46 server sshd[17912]: Connection from 62.75.231.48 port 44771
Jan  4 18:58:46 server sshd[8151]: debug1: Forked child 17912.
Jan  4 18:58:46 server sshd[17912]: debug1: Client protocol version 2.0; client software version libssh-0.1
Jan  4 18:58:46 server sshd[17912]: debug1: no match: libssh-0.1
Jan  4 18:58:46 server sshd[17912]: debug1: Enabling compatibility mode for protocol 2.0
Jan  4 18:58:46 server sshd[17912]: debug1: Local version string SSH-1.99-OpenSSH_3.6.1p2
Jan  4 18:58:48 server sshd[17912]: User root not allowed because not listed in AllowUsers
Jan  4 18:58:48 server sshd[17912]: debug1: Starting up PAM with username "root"
Jan  4 18:58:48 server sshd[17912]: debug1: PAM setting rhost to "host01294.perfectserver.de"
Jan  4 18:58:50 server sshd[17914]: Connection from 62.75.231.48 port 44891
Jan  4 18:58:50 server sshd[8151]: debug1: Forked child 17914.
Jan  4 18:58:50 server sshd[17914]: debug1: Client protocol version 2.0; client software version libssh-0.1
Jan  4 18:58:50 server sshd[17914]: debug1: no match: libssh-0.1
Jan  4 18:58:50 server sshd[17914]: debug1: Enabling compatibility mode for protocol 2.0
Jan  4 18:58:50 server sshd[17914]: debug1: Local version string SSH-1.99-OpenSSH_3.6.1p2
Jan  4 18:58:51 server sshd[17914]: User root not allowed because not listed in AllowUsers
Jan  4 18:58:51 server sshd[17914]: debug1: Starting up PAM with username "root"
Jan  4 18:58:51 server sshd[17914]: debug1: PAM setting rhost to "host01294.perfectserver.de"
Jan  4 18:58:56 server sshd[17916]: Connection from 62.75.231.48 port 45127
Jan  4 18:58:56 server sshd[8151]: debug1: Forked child 17916.
Jan  4 18:58:56 server sshd[17916]: debug1: Client protocol version 2.0; client software version libssh-0.1
Jan  4 18:58:56 server sshd[17916]: debug1: no match: libssh-0.1
Jan  4 18:58:56 server sshd[17916]: debug1: Enabling compatibility mode for protocol 2.0
Jan  4 18:58:56 server sshd[17916]: debug1: Local version string SSH-1.99-OpenSSH_3.6.1p2
Jan  4 18:58:57 server sshd[17918]: Connection from 62.75.231.48 port 45180
Jan  4 18:58:57 server sshd[8151]: debug1: Forked child 17918.
Jan  4 18:58:57 server sshd[17916]: User root not allowed because not listed in AllowUsers
Jan  4 18:58:57 server sshd[17916]: debug1: Starting up PAM with username "root"
Jan  4 18:58:57 server sshd[17916]: debug1: PAM setting rhost to "host01294.perfectserver.de"
Jan  4 18:58:57 server sshd[17918]: debug1: Client protocol version 2.0; client software version libssh-0.1
Jan  4 18:58:57 server sshd[17918]: debug1: no match: libssh-0.1
Jan  4 18:58:57 server sshd[17918]: debug1: Enabling compatibility mode for protocol 2.0
Jan  4 18:58:57 server sshd[17918]: debug1: Local version string SSH-1.99-OpenSSH_3.6.1p2
Jan  4 18:58:58 server sshd[17918]: User root not allowed because not listed in AllowUsers
Jan  4 18:58:58 server sshd[17918]: debug1: Starting up PAM with username "root"
Jan  4 18:58:58 server sshd[17918]: debug1: PAM setting rhost to "host01294.perfectserver.de"
Jan  4 18:59:00 server sshd[17920]: Connection from 62.75.231.48 port 45249
Jan  4 18:59:00 server sshd[8151]: debug1: Forked child 17920.
Jan  4 18:59:00 server sshd[17920]: debug1: Client protocol version 2.0; client software version libssh-0.1
Jan  4 18:59:00 server sshd[17920]: debug1: no match: libssh-0.1
Jan  4 18:59:00 server sshd[17920]: debug1: Enabling compatibility mode for protocol 2.0
Jan  4 18:59:00 server sshd[17920]: debug1: Local version string SSH-1.99-OpenSSH_3.6.1p2
Jan  4 18:59:01 server sshd[17920]: User root not allowed because not listed in AllowUsers
Jan  4 18:59:01 server sshd[17920]: debug1: Starting up PAM with username "root"
Jan  4 18:59:01 server sshd[17920]: debug1: PAM setting rhost to "host01294.perfectserver.de"
Jan  4 19:19:01 server sshd[5768]: Read error from remote host 66.26.51.32: Connection reset by peer
Jan  4 19:19:01 server sshd[5768]: debug1: Calling cleanup 0x80599e0(0x808db80)
Jan  4 19:19:01 server sshd[5768]: debug1: Calling cleanup 0x8067250(0x0)
Jan  4 19:19:01 server sshd[5768]: debug1: channel_free: channel 0: server-session, nchannels 1
Jan  4 19:19:01 server sshd[5768]: debug1: Calling cleanup 0x806f1d0(0x0)
Jan  4 19:19:01 server sshd[5768]: debug1: Calling cleanup 0x8063b20(0x0)
Jan  4 19:19:01 server sshd[5766]: debug1: session_by_tty: session 0 tty /dev/pts/0
Jan  4 19:19:01 server sshd[5766]: debug1: session_pty_cleanup: session 0 release /dev/pts/0
Jan  4 19:19:01 server sshd[5768]: debug1: Received SIGCHLD.
Jan  4 19:19:01 server sshd[5766]: debug1: Calling cleanup 0x8063b20(0x0)
Jan  4 19:58:46 server sshd[8151]: Generating new 768 bit RSA key.
Jan  4 19:58:46 server sshd[8151]: RSA key generation complete.
Jan  5 11:11:14 server sshd[18993]: Connection from 62.75.231.48 port 37145
Jan  5 11:11:14 server sshd[8151]: debug1: Forked child 18993.
Jan  5 11:11:14 server sshd[18994]: Connection from 62.75.231.48 port 37149
Jan  5 11:11:14 server sshd[8151]: debug1: Forked child 18994.
Jan  5 11:11:14 server sshd[18995]: Connection from 62.75.231.48 port 37151
Jan  5 11:11:14 server sshd[8151]: debug1: Forked child 18995.
Jan  5 11:11:14 server sshd[18993]: debug1: Client protocol version 2.0; client software version libssh-0.1
Jan  5 11:11:14 server sshd[18993]: debug1: no match: libssh-0.1
Jan  5 11:11:14 server sshd[18993]: debug1: Enabling compatibility mode for protocol 2.0
Jan  5 11:11:14 server sshd[18993]: debug1: Local version string SSH-1.99-OpenSSH_3.6.1p2
Jan  5 11:11:14 server sshd[18994]: debug1: Client protocol version 2.0; client software version libssh-0.1
Jan  5 11:11:14 server sshd[18994]: debug1: no match: libssh-0.1
Jan  5 11:11:14 server sshd[18994]: debug1: Enabling compatibility mode for protocol 2.0
Jan  5 11:11:14 server sshd[18994]: debug1: Local version string SSH-1.99-OpenSSH_3.6.1p2
Jan  5 11:11:14 server sshd[18995]: debug1: Client protocol version 2.0; client software version libssh-0.1
Jan  5 11:11:14 server sshd[18995]: debug1: no match: libssh-0.1
Jan  5 11:11:14 server sshd[18995]: debug1: Enabling compatibility mode for protocol 2.0
Jan  5 11:11:14 server sshd[18995]: debug1: Local version string SSH-1.99-OpenSSH_3.6.1p2
Jan  5 11:11:14 server sshd[18999]: Connection from 62.75.231.48 port 37188
Jan  5 11:11:14 server sshd[8151]: debug1: Forked child 18999.
Jan  5 11:11:15 server sshd[18999]: debug1: Client protocol version 2.0; client software version libssh-0.1
Jan  5 11:11:15 server sshd[18999]: debug1: no match: libssh-0.1
Jan  5 11:11:15 server sshd[18999]: debug1: Enabling compatibility mode for protocol 2.0
Jan  5 11:11:15 server sshd[18999]: debug1: Local version string SSH-1.99-OpenSSH_3.6.1p2
Jan  5 11:11:16 server sshd[18993]: Illegal user anonymous from 62.75.231.48
Jan  5 11:11:16 server sshd[18993]: debug1: Starting up PAM with username "anonymous"
Jan  5 11:11:16 server sshd[18993]: debug1: PAM setting rhost to "host01294.perfectserver.de"
Jan  5 11:11:16 server sshd[18994]: Illegal user anonymous from 62.75.231.48
Jan  5 11:11:16 server sshd[18994]: debug1: Starting up PAM with username "anonymous"
Jan  5 11:11:16 server sshd[18994]: debug1: PAM setting rhost to "host01294.perfectserver.de"
Jan  5 11:11:16 server sshd[18995]: Illegal user anonymous from 62.75.231.48
Jan  5 11:11:16 server sshd[18995]: debug1: Starting up PAM with username "anonymous"
Jan  5 11:11:16 server sshd[18995]: debug1: PAM setting rhost to "host01294.perfectserver.de"
Jan  5 11:11:16 server sshd[18999]: Illegal user anonymous from 62.75.231.48
Jan  5 11:11:16 server sshd[18999]: debug1: Starting up PAM with username "anonymous"
Jan  5 11:11:16 server sshd[18999]: debug1: PAM setting rhost to "host01294.perfectserver.de"
Jan  5 11:11:24 server sshd[19001]: Connection from 62.75.231.48 port 37793
Jan  5 11:11:24 server sshd[8151]: debug1: Forked child 19001.
Jan  5 11:11:24 server sshd[19001]: debug1: Client protocol version 2.0; client software version libssh-0.1
Jan  5 11:11:24 server sshd[19001]: debug1: no match: libssh-0.1
Jan  5 11:11:24 server sshd[19001]: debug1: Enabling compatibility mode for protocol 2.0
Jan  5 11:11:24 server sshd[19001]: debug1: Local version string SSH-1.99-OpenSSH_3.6.1p2
Jan  5 11:11:25 server sshd[19001]: Illegal user anonymous from 62.75.231.48
Jan  5 11:11:25 server sshd[19001]: debug1: Starting up PAM with username "anonymous"
Jan  5 11:11:25 server sshd[19001]: debug1: PAM setting rhost to "host01294.perfectserver.de"
Jan  5 12:11:14 server sshd[8151]: Generating new 768 bit RSA key.
Jan  5 12:11:14 server sshd[8151]: RSA key generation complete.
Jan  5 13:01:01 server sshd[8151]: debug1: drop connection #10
Jan  5 13:06:06 server last message repeated 5 times
Jan  5 13:25:49 server last message repeated 5 times
Jan  5 13:28:34 server last message repeated 2 times
Jan  6 06:59:45 server last message repeated 2 times
Jan  6 07:15:10 server last message repeated 5 times
Jan  6 08:24:22 server last message repeated 5 times
Jan  6 14:52:51 server last message repeated 5 times
Jan  6 14:52:55 server sshd[8151]: debug1: drop connection #10
Jan  6 14:54:01 server sshd[8151]: Received signal 15; terminating.

Here are additional logs from after I restarted (still can't login).

Code:

Jan  6 15:00:50 server sshd[2364]: socket: Address family not supported by protocol
Jan  6 15:00:50 server sshd[2364]: debug1: Bind to port 22 on 0.0.0.0.
Jan  6 15:00:50 server sshd[2364]: Server listening on 0.0.0.0 port 22.
Jan  6 15:00:50 server sshd[2364]: Generating 768 bit RSA key.
Jan  6 15:00:50 server sshd[2364]: RSA key generation complete.
Jan  6 15:00:45 server sshd[2364]: debug1: Forked child 2494.
Jan  6 15:00:45 server sshd[2494]: Connection from 1.2.3.4 port 16366
Jan  6 15:00:45 server sshd[2494]: debug1: Client protocol version 1.99; client software version 3.2.9 SSH Secure Shell for Windows
Jan  6 15:00:45 server sshd[2494]: debug1: no match: 3.2.9 SSH Secure Shell for Windows
Jan  6 15:00:45 server sshd[2494]: debug1: Enabling compatibility mode for protocol 2.0
Jan  6 15:00:45 server sshd[2494]: debug1: Local version string SSH-1.99-OpenSSH_3.6.1p2
Jan  6 15:00:46 server sshd[2494]: debug1: Starting up PAM with username "justin"
Jan  6 15:00:46 server sshd[2494]: debug1: PAM setting rhost to "my-host-name-dot-com"
Jan  6 15:01:59 server sshd[2544]: Connection from 1.2.3.4 port 16406
Jan  6 15:01:59 server sshd[2364]: debug1: Forked child 2544.
Jan  6 15:01:59 server sshd[2544]: debug1: Client protocol version 1.99; client software version 3.2.9 SSH Secure Shell for Windows
Jan  6 15:01:59 server sshd[2544]: debug1: no match: 3.2.9 SSH Secure Shell for Windows
Jan  6 15:01:59 server sshd[2544]: debug1: Enabling compatibility mode for protocol 2.0
Jan  6 15:01:59 server sshd[2544]: debug1: Local version string SSH-1.99-OpenSSH_3.6.1p2
Jan  6 15:02:00 server sshd[2544]: debug1: Starting up PAM with username "justin"
Jan  6 15:02:00 server sshd[2544]: debug1: PAM setting rhost to "my-host-name-dot-com"

I'm in a bad spot now, since I can't login via ssh at all.

JustinHoMi · 01-06-2006, 05:38 PM

Well, I'm running into more trouble. I wasn't able to get ssh working again, so I uninstalled the rpms via webmin. I was able to reinstall openssh and openssh-clients via webmin, but it won't install openssh-servers. The browser just sits and waits, and nothing happens... so I don't know what the problem is. The up2date and yum logs don't show anything.

So, I enabled krb5-telnet on the server and setup a firewall rule so only I can access it. I'm able to login via my username, but I can't su to root, or even use sudo. When I try, the session just seems to freeze.

Any ideas?

unSpawn · 01-06-2006, 07:06 PM

Can you drop files or modify /etc/sudoers contents to just read "justin ALL=NOPASSWD: ALL"? Tried rebooting? No clues at all in the system logs?

JustinHoMi · 01-06-2006, 11:05 PM

I tried modifying sudoers like you mentioned, but it did the same thing. It didn't ask for a password... the terminal just stopped responding.

proftpd is doing the same thing with logins. In addition, the proftpd connections are also staying alive... just like with sshd. PAM?

I've never messed w/ PAM before. I'm quite scared to touch it

JustinHoMi · 01-06-2006, 11:11 PM

Logs don't have anything useful. It mentions that I ran sudo, but no errors reported.

And yeah, I'm rebooting quite frequently through this.

JustinHoMi · 01-06-2006, 11:19 PM

This might be useful... when I try to connect via the linux ftp cli client, I get this:

Code:

ftp myserver.com
Connect to myserver.com.
220 ProFTPD 1.2.10 Server (FTP Server) [1.2.3.4]
500 AUTH not understood
500 AUTH not understood
KERBEROS_V4 rejected as an authentication type
Name (myserver.com:root): justin
331 Password required for justin.
Password:

It just sits there after entering in the password.

/var/log/messages:

Code:

Jan  6 23:17:43 server proftpd[2541]: myserver.com (4.3.2.1[4.3.2.1]) - FTP session opened. 
Jan  6 23:17:50 server PAM_pwdb[2541]: authentication failure; (uid=0) -> justin for ftp service

JustinHoMi · 01-06-2006, 11:26 PM

Oh, and when I login via telnet I get this error... I have no idea what it means... googling it now... kerberos related.

Code:

login: Cannot resolve network address for KDC in requested realm while getting initial credentials

JustinHoMi · 01-07-2006, 12:38 AM

So, I'm trying to enable debugging within PAM. I'm not really getting any output for ftp or telnet logins, but I did get some output when using sudo and su. Can anybody make sense of this?

sudo top

Code:

Jan  7 00:35:49 server sudo:   justin : TTY=pts/0 ; PWD=/home/justin ; USER=root ; COMMAND=/usr/bin/top
Jan  7 00:35:49 server pam_stack[2995]: called for "PAM_SETCRED"
Jan  7 00:35:49 server pam_stack[2995]: called from "sudo"
Jan  7 00:35:49 server pam_stack[2995]: initializing
Jan  7 00:35:49 server pam_stack[2995]: creating child stack `system-auth'
Jan  7 00:35:49 server pam_stack[2995]: creating environment
Jan  7 00:35:49 server pam_stack[2995]: NOT passing PAM_AUTHTOK to child: source is NULL
Jan  7 00:35:49 server pam_stack[2995]: passing PAM_CONV to child
Jan  7 00:35:49 server pam_stack[2995]: NOT passing PAM_FAIL_DELAY to child: source not set
Jan  7 00:35:49 server pam_stack[2995]: NOT passing PAM_OLDAUTHTOK to child: source is NULL
Jan  7 00:35:49 server pam_stack[2995]: NOT passing PAM_RHOST to child: source is NULL
Jan  7 00:35:49 server pam_stack[2995]: passing PAM_RUSER to child
Jan  7 00:35:49 server pam_stack[2995]: passing PAM_SERVICE to child
Jan  7 00:35:49 server pam_stack[2995]: passing PAM_TTY to child
Jan  7 00:35:49 server pam_stack[2995]: passing PAM_USER to child
Jan  7 00:35:49 server pam_stack[2995]: NOT passing PAM_USER_PROMPT to child: source is NULL
Jan  7 00:35:49 server pam_stack[2995]: passing data to child
Jan  7 00:35:49 server pam_stack[2995]: calling substack
Jan  7 00:35:49 server pam_stack[2995]: substack returned 0 (Success)
Jan  7 00:35:49 server pam_stack[2995]: NOT passing PAM_AUTHTOK to parent: source is NULL
Jan  7 00:35:49 server pam_stack[2995]: NOT passing PAM_CONV to parent: destination already set
Jan  7 00:35:49 server pam_stack[2995]: NOT passing PAM_FAIL_DELAY to parent: source not set
Jan  7 00:35:49 server pam_stack[2995]: NOT passing PAM_OLDAUTHTOK to parent: source is NULL
Jan  7 00:35:49 server pam_stack[2995]: NOT passing PAM_RHOST to parent: source is NULL
Jan  7 00:35:49 server pam_stack[2995]: passing PAM_RUSER to parent
Jan  7 00:35:49 server pam_stack[2995]: passing PAM_SERVICE to parent
Jan  7 00:35:49 server pam_stack[2995]: passing PAM_TTY to parent
Jan  7 00:35:49 server pam_stack[2995]: passing PAM_USER to parent
Jan  7 00:35:49 server pam_stack[2995]: NOT passing PAM_USER_PROMPT to parent: source is NULL
Jan  7 00:35:49 server pam_stack[2995]: passing data back
Jan  7 00:35:49 server pam_stack[2995]: passing former back
Jan  7 00:35:49 server pam_stack[2995]: returning 0 (Success)
Jan  7 00:35:49 server pam_limits[2995]: reading settings from '/etc/security/limits.conf'
Jan  7 00:35:49 server pam_limits[2995]: process_limit: processing hard core 0 for ALL 
Jan  7 00:35:49 server pam_limits[2995]: process_limit: processing soft nproc 100 for ALL 
Jan  7 00:35:49 server pam_limits[2995]: process_limit: processing hard nproc 150 for ALL 
Jan  7 00:35:49 server pam_limits[2995]: user 'root' has UID 0 - no limits imposed

/etc/pam.d/sudo

Code:

#%PAM-1.0
auth       required	pam_stack.so service=system-auth debug
account    required	pam_stack.so service=system-auth debug
password   required	pam_stack.so service=system-auth debug
session    required     pam_limits.so debug

su - root

Code:

Jan  7 00:40:56 server PAM-rootok[3133]: authentication failed
Jan  7 00:40:56 server pam_stack[3133]: called for "PAM_AUTHENTICATE"
Jan  7 00:40:56 server pam_stack[3133]: called from "su"
Jan  7 00:40:56 server pam_stack[3133]: initializing
Jan  7 00:40:56 server pam_stack[3133]: creating child stack `system-auth'
Jan  7 00:40:56 server pam_stack[3133]: creating environment
Jan  7 00:40:56 server pam_stack[3133]: NOT passing PAM_AUTHTOK to child: source is NULL
Jan  7 00:40:56 server pam_stack[3133]: passing PAM_CONV to child
Jan  7 00:40:56 server pam_stack[3133]: NOT passing PAM_FAIL_DELAY to child: source not set
Jan  7 00:40:56 server pam_stack[3133]: NOT passing PAM_OLDAUTHTOK to child: source is NULL
Jan  7 00:40:56 server pam_stack[3133]: NOT passing PAM_RHOST to child: source is NULL
Jan  7 00:40:56 server pam_stack[3133]: passing PAM_RUSER to child
Jan  7 00:40:56 server pam_stack[3133]: passing PAM_SERVICE to child
Jan  7 00:40:56 server pam_stack[3133]: NOT passing PAM_TTY to child: source is NULL
Jan  7 00:40:56 server pam_stack[3133]: passing PAM_USER to child
Jan  7 00:40:56 server pam_stack[3133]: NOT passing PAM_USER_PROMPT to child: source is NULL
Jan  7 00:40:56 server pam_stack[3133]: passing data to child
Jan  7 00:40:56 server pam_stack[3133]: calling substack
Jan  7 00:41:00 server pam_stack[3133]: substack returned 0 (Success)
Jan  7 00:41:00 server pam_stack[3133]: passing PAM_AUTHTOK to parent
Jan  7 00:41:00 server pam_stack[3133]: NOT passing PAM_CONV to parent: destination already set
Jan  7 00:41:00 server pam_stack[3133]: passing PAM_FAIL_DELAY to parent
Jan  7 00:41:00 server pam_stack[3133]: NOT passing PAM_OLDAUTHTOK to parent: source is NULL
Jan  7 00:41:00 server pam_stack[3133]: NOT passing PAM_RHOST to parent: source is NULL
Jan  7 00:41:00 server pam_stack[3133]: passing PAM_RUSER to parent
Jan  7 00:41:00 server pam_stack[3133]: passing PAM_SERVICE to parent
Jan  7 00:41:00 server pam_stack[3133]: NOT passing PAM_TTY to parent: source is NULL
Jan  7 00:41:00 server pam_stack[3133]: passing PAM_USER to parent
Jan  7 00:41:00 server pam_stack[3133]: NOT passing PAM_USER_PROMPT to parent: source is NULL
Jan  7 00:41:00 server pam_stack[3133]: passing data back
Jan  7 00:41:00 server pam_stack[3133]: passing former back
Jan  7 00:41:00 server pam_stack[3133]: returning 0 (Success)

/etc/pam.d/su

Code:

#%PAM-1.0
auth       sufficient   /lib/security/$ISA/pam_rootok.so debug
# Uncomment the following line to implicitly trust users in the "wheel" group.
#auth       sufficient   /lib/security/$ISA/pam_wheel.so trust use_uid
# Uncomment the following line to require a user to be in the "wheel" group.
#auth       required     /lib/security/$ISA/pam_wheel.so use_uid
auth       required	/lib/security/$ISA/pam_stack.so service=system-auth debug
account    required	/lib/security/$ISA/pam_stack.so service=system-auth debug
password   required	/lib/security/$ISA/pam_stack.so service=system-auth debug
session    required	/lib/security/$ISA/pam_stack.so service=system-auth debug
session    optional	/lib/security/$ISA/pam_xauth.so debug

JustinHoMi · 01-07-2006, 12:53 AM

Another thing... I'm getting ridiculously high load averages. This isn't a very busy server....

CPU load averages: 13.34 (1 mins) , 11.30 (5 mins) , 7.91 (15 mins)

I checked the running processes, and no process is using more than 0.3% of the cpu.

JustinHoMi · 01-07-2006, 01:10 AM

I think I figured out why I can't get openssh-server reinstalled... it's hanging up on this process:

/usr/sbin/useradd -c Privilege-seperated SSH -u 74 -s /sbin/nologin -r -d /var/empty/sshd sshd

I tried running useradd test from webmin, and it locks up just like everything else.

I'm putting my money on PAM, but unfortunately I know nothing about it....

I ran rpmverify on PAM again... everything was normal.

live_dont_exist · 01-07-2006, 01:33 AM

Hey Justin,
This is some problem man...Im gonna sit n read up on PAM rite now n see if me can help out...the thing is...why r u not able to install openssh-server...??and y shud adding a user hang...??...PAM is avery likely culprit...but its a bit dangerous to touch it... theres just so much depending on it...

The thing is...its not just ssh its telnet and other stuff whioch deals with Linux authentication...so lets try and find out how exactly Linux authentication works....n work our way backwards...Im as much in the dark as you abt PAM...need to read up..but do this...

log on to the console....

vi /etc/passwd
duplicate root's line...change username of root to test
vi /etc/shadow...
duplicate root's line...change username of root to test
vi /etc/group
add test everywhere...

Try and login with test and root's password...see what happens..keep us posted...if it isnt working....maybe a PAM problem after all...but how and why???...lets c..

Do something here...just run vmstat 1 300 and see if theres any swapping going on (look at the intr and context switch columns)or stuff..and if its a multiprocessor mpstat -P ALL 1 300 will give you processor load..

iostat will give you disk I/o so u cud try dat as well...2 see if sum process is writing too much 2 disk...for the high load thing..but all dat is later...lets first find out wats happening with PAM...

Keep going...

Arvind

JustinHoMi · 01-07-2006, 01:44 PM

Cool, thanks Arvind

Can I have two users with the same UID? I'm sorta scared about locking myself out of this box. I have webmin, and right now I have telnet... but if I completely hose the user authentication stuff I'm in hot water! I cross my fingers every time I reboot this thing or make a change to the firewall.

I did run vmstat... it's not swapping at all. The load sat steady at 4.0 all night, I believe.

I'm going to be painting my bedroom all day (bad timing huh?). So, I probably won't be back on here until late tonight or tomorrow. Although, I may try to get on someone else's computer in the meantime.

Code:

procs                      memory      swap          io     system         cpu
 r  b   swpd   free   buff  cache   si   so    bi    bo   in    cs us sy id wa
 0  0      0 158776  66288 100792    0    0     2    13  104    20  1  0 99  0

unSpawn · 01-07-2006, 02:09 PM

You enabled service kerb5_telnet. Maybe it enabled Kerberos as auth method.
From your logs there's no host defined as Kerberos Domain Controller.
Maybe first disable Kerberos before testing other stuff.

Of course this isn't good advice nor practice, but if all fails you might as well inject a custom OpenSSH package + config that bypasses PAM, doesn't do privilege separating, allows root logins etc, etc. Building the package from source isn't hard, and you can mitigate risk somewhat by firewalling that separate port.