Attachment 970 Details for Bug 1095 – sshd -ddde output when failure occurs

sshd -ddde output when failure occurs

ssh-bug1.txt (text/plain), 13.68 KB, created by John Devitofranceschi on 2005-09-29 12:41:05 AEST

(hide)

Description:

Filename:

MIME Type:

Creator: John Devitofranceschi

Created: 2005-09-29 12:41:05 AEST

Size: 13.68 KB

patch

obsolete

>The pam-test-harness works just fine:
>
># /tmp/pam-test-harness -s other
>$Id: pam-test-harness.c,v 1.24 2005/07/18 14:10:35 dtucker Exp $
>
>conversation struct {conv=0x116a0, appdata_ptr=0x237cc}
>
>pam_start(other, (NULL), &conv, &pamh) = 0 (Success)
>
>pam_set_item(pamh, PAM_TTY, "/dev/pts/4") = 0 (Success)
>
>pam_set_item(pamh, PAM_RHOST, "binky") = 0 (Success)
>
>pam_set_item(pamh, PAM_RUSER, "fred") = 0 (Success)
>
>pam_authenticate(pamh, 0)
>    conversation called with 1 messages data 0x237cc
>        PROMPT_ECHO_ON: Please enter user name: nonkrb5u
>
>    conversation called with 1 messages data 0x237cc
>        PROMPT_ECHO_OFF: Password: XXXXXXXX
> = 0 (Success)
>
>pam_acct_mgmt(pamh, 0) = 0 (Success)
>
>pam_open_session(pamh, 0) = 0 (Success)
>
>pam_setcred(pamh, 0) = 0 (Success)
>
>pam_get_item(pamh, PAM_USER, ...) = 0 (Success)
>
>PAM_USER = nonkrb5u (CHANGED)
>
>Standard environment variables
>
>PAM environment variables
>
>uid 0 euid 0 gid 0 egid 0
>
>pam_close_session(pamh, 0) = 0 (Success)
>
>pam_end(pamh, 0) = 0 (Success)
>
>
>
>When the user "nonkrb5u" (a user with no krb5 principal) tries to
>authenticate, sshd pukes:
>
># ./sshd -ddde -p 6666
>debug2: : filename /etc/opt/openssh/sshd_config
>debug2: : done config len = 455
>debug2: : config /etc/opt/openssh/sshd_config len 455
>debug1: sshd version OpenSSH_4.2p1
>debug1: private host key: #0 type 0 RSA1
>debug3: Not a RSA1 key file /etc/opt/openssh/ssh_host_rsa_key.
>debug1: read PEM private key done: type RSA
>debug1: private host key: #1 type 1 RSA
>debug3: Not a RSA1 key file /etc/opt/openssh/ssh_host_dsa_key.
>debug1: read PEM private key done: type DSA
>debug1: private host key: #2 type 2 DSA
>debug1: rexec_argv[0]='/opt/openssh/sbin/sshd'
>debug1: rexec_argv[1]='-ddde'
>debug1: rexec_argv[2]='-p'
>debug1: rexec_argv[3]='6666'
>debug2: fd 4 setting O_NONBLOCK
>debug1: Bind to port 6666 on ::.
>Server listening on :: port 6666.
>debug2: fd 5 setting O_NONBLOCK
>debug1: Bind to port 6666 on 0.0.0.0.
>Server listening on 0.0.0.0 port 6666.
>Generating 768 bit RSA key.
>RSA key generation complete.
>debug1: fd 6 clearing O_NONBLOCK
>debug1: Server will not fork when running in debugging mode.
>debug3: : entering fd = 11 config len 455
>debug3: ssh_msg_send: type 0
>debug3: : done
>debug1: rexec start in 6 out 6 newsock 6 pipe -1 sock 11
>debug3: : entering fd = 5
>debug3: ssh_msg_recv entering
>debug3: : done
>debug2: : config rexec len 455
>debug1: sshd version OpenSSH_4.2p1
>debug1: private host key: #0 type 0 RSA1
>debug3: Not a RSA1 key file /etc/opt/openssh/ssh_host_rsa_key.
>debug1: read PEM private key done: type RSA
>debug1: private host key: #1 type 1 RSA
>debug3: Not a RSA1 key file /etc/opt/openssh/ssh_host_dsa_key.
>debug1: read PEM private key done: type DSA
>debug1: private host key: #2 type 2 DSA
>debug1: inetd sockets after dupping: 4, 4
>Connection from 192.168.119.89 port 48528
>debug1: Client protocol version 2.0; client software version
>OpenSSH_3.8.1p1_gssmic07
>debug1: match: OpenSSH_3.8.1p1_gssmic07 pat OpenSSH_3.*
>debug1: Enabling compatibility mode for protocol 2.0
>debug1: Local version string SSH-1.99-OpenSSH_4.2
>debug2: fd 4 setting O_NONBLOCK
>debug3: privsep user:group 74:74
>debug1: permanently_set_uid: 74/74
>debug1: list_hostkey_types: ssh-rsa,ssh-dss
>debug1: SSH2_MSG_KEXINIT sent
>debug1: SSH2_MSG_KEXINIT received
>debug2: kex_parse_kexinit:
>diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-he
>llman-group1-sha1
>debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
>debug2: kex_parse_kexinit:
>aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfo
>ur,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-ctr,aes192-c
>tr,aes256-ctr
>debug2: kex_parse_kexinit:
>aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfo
>ur,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-ctr,aes192-c
>tr,aes256-ctr
>debug2: kex_parse_kexinit:
>hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-9
>6,hmac-md5-96
>debug2: kex_parse_kexinit:
>hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-9
>6,hmac-md5-96
>debug2: kex_parse_kexinit: none,zlib@openssh.com
>debug2: kex_parse_kexinit: none,zlib@openssh.com
>debug2: kex_parse_kexinit: 
>debug2: kex_parse_kexinit: 
>debug2: kex_parse_kexinit: first_kex_follows 0 
>debug2: kex_parse_kexinit: reserved 0 
>debug2: kex_parse_kexinit:
>diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1
>debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
>debug2: kex_parse_kexinit:
>aes256-cbc,aes192-cbc,aes128-cbc,cast128-cbc,blowfish-cbc,3des-cbc,arcfo
>ur
>debug2: kex_parse_kexinit:
>aes256-cbc,aes192-cbc,aes128-cbc,cast128-cbc,blowfish-cbc,3des-cbc,arcfo
>ur
>debug2: kex_parse_kexinit:
>hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-9
>6,hmac-md5-96
>debug2: kex_parse_kexinit:
>hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-9
>6,hmac-md5-96
>debug2: kex_parse_kexinit: none,zlib
>debug2: kex_parse_kexinit: none,zlib
>debug2: kex_parse_kexinit: 
>debug2: kex_parse_kexinit: 
>debug2: kex_parse_kexinit: first_kex_follows 0 
>debug2: kex_parse_kexinit: reserved 0 
>debug2: mac_init: found hmac-md5
>debug1: kex: client->server aes256-cbc hmac-md5 none
>debug2: mac_init: found hmac-md5
>debug1: kex: server->client aes256-cbc hmac-md5 none
>debug1: SSH2_MSG_KEX_DH_GEX_REQUEST received
>debug3:  entering: type 0
>debug3: : waiting for MONITOR_ANS_MODULI
>debug3:  entering: type 1
>debug3:  entering
>debug2: Network child is on pid 5784
>debug3: preauth child monitor started
>debug3:  entering
>debug3: : checking request 0
>debug3: : got parameters: 1024 4096 8192
>debug3:  entering: type 1
>debug3: : remaining 0
>debug1: SSH2_MSG_KEX_DH_GEX_GROUP sent
>debug2: : 0 used once, disabling now
>debug3:  entering
>debug2: dh_gen_key: priv key bits set: 247/512
>debug2: bits set: 1996/4096
>debug1: expecting SSH2_MSG_KEX_DH_GEX_INIT
>debug2: bits set: 2090/4096
>debug3:  entering
>debug3:  entering: type 4
>debug3: : checking request 4
>debug3: 
>debug3: : signature 42fd38(143)
>debug3:  entering: type 5
>debug2: : 4 used once, disabling now
>debug3:  entering
>debug3: : waiting for MONITOR_ANS_SIGN
>debug3:  entering: type 5
>debug3:  entering
>debug1: SSH2_MSG_KEX_DH_GEX_REPLY sent
>debug2: kex_derive_keys
>debug2: set_newkeys: mode 1
>debug1: SSH2_MSG_NEWKEYS sent
>debug1: expecting SSH2_MSG_NEWKEYS
>debug2: set_newkeys: mode 0
>debug1: SSH2_MSG_NEWKEYS received
>debug1: KEX done
>debug1: userauth-request for user nonkrb5u service ssh-connection method
>none
>debug1: attempt 0 failures 0
>debug3:  entering
>debug3:  entering: type 6
>debug3: : checking request 6
>debug3: 
>debug3: : sending MONITOR_ANS_PWNAM: 1
>debug3:  entering: type 7
>debug2: : 6 used once, disabling now
>debug3:  entering
>debug3: : waiting for MONITOR_ANS_PWNAM
>debug3:  entering: type 7
>debug3:  entering
>debug2: input_userauth_request: setting up authctxt for nonkrb5u
>debug3:  entering
>debug3:  entering: type 45
>debug3: : checking request 45
>debug1: PAM: initializing for "nonkrb5u"
>debug3:  entering
>debug3:  entering: type 3
>debug2: input_userauth_request: try method none
>debug3:  entering
>debug3:  entering: type 10
>debug3: : waiting for MONITOR_ANS_AUTHPASSWORD
>debug3:  entering: type 11
>debug3:  entering
>debug3: Trying to reverse map address 192.168.119.89.
>debug1: PAM: setting PAM_RHOST to "binky.k5realm.com"
>debug1: PAM: setting PAM_TTY to "ssh"
>debug2: : 45 used once, disabling now
>debug3:  entering
>debug3: : checking request 3
>debug3: : service=ssh-connection, style=
>debug2: : 3 used once, disabling now
>debug3:  entering
>debug3: : checking request 10
>debug3: : sending result 0
>debug3:  entering: type 11
>Failed none for nonkrb5u from 192.168.119.89 port 48528 ssh2
>debug3:  entering
>debug3: : user not authenticated
>Failed none for nonkrb5u from 192.168.119.89 port 48528 ssh2
>debug1: userauth-request for user nonkrb5u service ssh-connection method
>gssapi-with-mic
>debug1: attempt 1 failures 1
>debug2: input_userauth_request: try method gssapi-with-mic
>debug3:  entering: type 37
>debug3: : checking request 37
>debug3:  entering: type 38
>debug3:  entering
>debug3:  entering: type 38
>debug3:  entering
>Postponed gssapi-with-mic for nonkrb5u from 192.168.119.89 port 48528
>ssh2
>debug3:  entering: type 39
>debug3: : checking request 39
>debug3:  entering: type 40
>debug3:  entering
>debug1: Got no client credentials
>debug3:  entering: type 40
>debug3:  entering
>debug3:  entering: type 43
>debug3: : checking request 43
>debug3:  entering: type 44
>debug3:  entering
>debug3:  entering: type 44
>debug3:  entering
>debug3:  entering: type 41
>debug3: : checking request 41
>debug3:  entering: type 42
>debug3:  entering
>debug3: : sending result 0
>debug3:  entering: type 42
>Failed gssapi-with-mic for nonkrb5u from 192.168.119.89 port 48528 ssh2
>debug3:  entering
>debug3: : user not authenticated
>Failed gssapi-with-mic for nonkrb5u from 192.168.119.89 port 48528 ssh2
>debug1: userauth-request for user nonkrb5u service ssh-connection method
>gssapi-with-mic
>debug1: attempt 2 failures 2
>debug2: input_userauth_request: try method gssapi-with-mic
>Failed gssapi-with-mic for nonkrb5u from 192.168.119.89 port 48528 ssh2
>debug1: userauth-request for user nonkrb5u service ssh-connection method
>publickey
>debug1: attempt 3 failures 3
>debug2: input_userauth_request: try method publickey
>debug1: test whether pkalg/pkblob are acceptable
>debug3:  entering
>debug3:  entering: type 20
>debug3: : checking request 20
>debug3:  entering
>debug3: : key_from_blob: 4555d8
>debug1: temporarily_use_uid: 15919/13308 (e=0/0)
>debug3: : waiting for MONITOR_ANS_KEYALLOWED
>debug3:  entering: type 21
>debug3:  entering
>debug1: trying public key file /home/nonkrb5u/.ssh/authorized_keys
>debug3: secure_filename: checking '/home/nonkrb5u/.ssh'
>debug3: secure_filename: checking '/home/nonkrb5u'
>debug3: secure_filename: terminating check at '/home/nonkrb5u'
>debug2: key_type_from_name: unknown key type 'ssh-ext-name-pat:krb5'
>debug3: key_read: missing keytype
>debug2: user_key_allowed: check options: 'ssh-ext-name-pat:krb5
>fred@K5REALM.COM
>'
>debug3: key_read: missing whitespace
>debug2: user_key_allowed: advance: 'fred@K5REALM.COM
>'
>debug1: restore_uid: 0/0
>debug2: key not found
>debug1: temporarily_use_uid: 15919/13308 (e=0/0)
>debug1: trying public key file /home/nonkrb5u/.ssh/authorized_keys2
>debug1: restore_uid: 0/0
>debug3: : key 4555d8 is disallowed
>debug3:  entering: type 21
>debug3:  entering
>debug2: userauth_pubkey: authenticated 0 pkalg ssh-rsa
>Failed publickey for nonkrb5u from 192.168.119.89 port 48528 ssh2
>debug1: userauth-request for user nonkrb5u service ssh-connection method
>publickey
>debug1: attempt 4 failures 4
>debug2: input_userauth_request: try method publickey
>debug1: test whether pkalg/pkblob are acceptable
>debug3:  entering
>debug3:  entering: type 20
>debug3: : waiting for MONITOR_ANS_KEYALLOWED
>debug3:  entering: type 21
>debug3:  entering
>debug3: : checking request 20
>debug3:  entering
>debug3: : key_from_blob: 4555d8
>debug1: temporarily_use_uid: 15919/13308 (e=0/0)
>debug1: trying public key file /home/nonkrb5u/.ssh/authorized_keys
>debug3: secure_filename: checking '/home/nonkrb5u/.ssh'
>debug3: secure_filename: checking '/home/nonkrb5u'
>debug3: secure_filename: terminating check at '/home/nonkrb5u'
>debug2: key_type_from_name: unknown key type 'ssh-ext-name-pat:krb5'
>debug3: key_read: missing keytype
>debug2: user_key_allowed: check options: 'ssh-ext-name-pat:krb5
>fred@K5REALM.COM
>'
>debug3: key_read: missing whitespace
>debug2: user_key_allowed: advance: 'fred@K5REALM.COM
>'
>debug1: restore_uid: 0/0
>debug2: key not found
>debug1: temporarily_use_uid: 15919/13308 (e=0/0)
>debug1: trying public key file /home/nonkrb5u/.ssh/authorized_keys2
>debug1: restore_uid: 0/0
>debug3: : key 4555d8 is disallowed
>debug3:  entering: type 21
>debug2: userauth_pubkey: authenticated 0 pkalg ssh-rsa
>Failed publickey for nonkrb5u from 192.168.119.89 port 48528 ssh2
>debug3:  entering
>debug1: userauth-request for user nonkrb5u service ssh-connection method
>keyboard-interactive
>debug1: attempt 5 failures 5
>debug2: input_userauth_request: try method keyboard-interactive
>debug1: keyboard-interactive devs 
>debug1: auth2_challenge: user=nonkrb5u devs=
>debug1: kbdint_alloc: devices 'pam'
>debug2: auth2_challenge_start: devices pam
>debug2: kbdint_next_device: devices <empty>
>debug1: auth2_challenge_start: trying authentication method 'pam'
>debug3: 
>debug3:  entering: type 48
>debug3: : waiting for MONITOR_ANS_PAM_INIT_CTX
>debug3:  entering: type 49
>debug3:  entering
>debug3: : checking request 48
>debug3: 
>debug3: PAM:  entering
>debug3:  entering: type 49
>debug3: 
>debug3:  entering: type 50
>debug3: : waiting for MONITOR_ANS_PAM_QUERY
>debug3:  entering: type 51
>debug3:  entering
>debug3:  entering
>debug3: : checking request 50
>debug3: 
>debug3: PAM:  entering
>debug3: ssh_msg_recv entering
>debug3: PAM:  entering, 1 messages
>debug3: ssh_msg_send: type 1
>debug3: ssh_msg_recv entering
>debug3:  entering: type 51
>debug3: : pam_query returned 0
>Postponed keyboard-interactive for nonkrb5u from 192.168.119.89 port
>48528 ssh2
>debug3:  entering
>debug3: 
>debug3:  entering: type 52
>debug3: : waiting for MONITOR_ANS_PAM_RESPOND
>debug3:  entering: type 53
>debug3:  entering
>debug3: : checking request 52
>debug3: 
>debug2: PAM:  entering, 1 responses
>debug3: ssh_msg_send: type 6
>debug3:  entering: type 53
>debug3:  entering
>debug3: : pam_respond returned 1
>debug3: 
>debug3:  entering: type 50
>debug3: : waiting for MONITOR_ANS_PAM_QUERY
>debug3:  entering: type 51
>debug3:  entering
>PAM: authentication thread exited unexpectedly
>debug1: do_cleanup
>debug1: PAM: cleanup
>debug3: PAM:  entering
>debug1: do_cleanup
>debug1: PAM: cleanup
>debug3: PAM:  entering

Actions: View

Attachments on bug 1095: 970 | 974 | 975 | 976 | 978