[Freeipa-users] Troubleshooting SSO

Tue Mar 31 07:30:47 UTC 2015

On Tue, Mar 31, 2015 at 07:56:53AM +0200, Jan Cholasta wrote:
> Hi,
> 
> Dne 30.3.2015 v 19:42 Gould, Joshua napsal(a):
> >
> >On 3/30/15, 11:56 AM, "Dmitri Pal" <dpal at redhat.com> wrote:
> >
> >>>#  auth_to_local =
> >>>RULE:[1:$1@$0](^.*@TEST.OSUWMC$)s/@TEST.OSUWMC/@test.osuwmc/
> >>>    auth_to_local = RULE:[1:$1 $0](^ *
> >>>TEST.OSUWMC$)s/@TEST.OSUWMC/@test.osuwmc/
> >>If you use the plugin then this RULE should not be needed.
> >>Have you tried commenting it out and restarting SSSD?
> >
> >I commented out those lines and restarted SSSD. I still was not able to
> >get in with SSO.
> >
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[12789]: debug3: fd 5 is not O_NONBLOCK
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[12789]: debug1: Forked child 13750.
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[12789]: debug3: send_rexec_state:
> >entering fd = 8 config len 899
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[12789]: debug3: ssh_msg_send: type 0
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[12789]: debug3: send_rexec_state: done
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: oom_adjust_restore
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: Set /proc/self/oom_score_adj to 0
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: rexec start in 5 out 5
> >newsock 5 pipe 7 sock 8
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: inetd sockets after
> >dupping: 3, 3
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: Connection from 10.80.5.239 port
> >65333 on 10.127.26.73 port 22
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: Client protocol version
> >2.0; client software version PuTTY_Release_0.64
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: no match:
> >PuTTY_Release_0.64
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: Enabling compatibility
> >mode for protocol 2.0
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: Local version string
> >SSH-2.0-OpenSSH_6.6.1
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: fd 3 setting O_NONBLOCK
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: ssh_sandbox_init:
> >preparing rlimit sandbox
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: Network child is on pid
> >13751
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: preauth child monitor
> >started
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: SELinux support enabled
> >[preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3:
> >ssh_selinux_change_context: setting context from
> >'system_u:system_r:sshd_t:s0-s0:c0.c1023' to 'system_u:
> >system_r:sshd_net_t:s0-s0:c0.c1023' [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: privsep user:group 74:74
> >[preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: permanently_set_uid:
> >74/74 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: list_hostkey_types:
> >ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: SSH2_MSG_KEXINIT sent
> >[preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: SSH2_MSG_KEXINIT
> >received [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >curve25519-sha256 at libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha
> >2-nistp521
> >,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,di
> >ffie-hellman-group14-sha1,diffie-hellman-group1-sha1 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-gcm at openssh.c
> >om,aes256-
> >gcm at openssh.com,chacha20-poly1305 at openssh.com,aes128-cbc,3des-cbc,blowfish-
> >cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc at lysator.liu.se
> >[prea
> >uth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-gcm at openssh.c
> >om,aes256-
> >gcm at openssh.com,chacha20-poly1305 at openssh.com,aes128-cbc,3des-cbc,blowfish-
> >cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc at lysator.liu.se
> >[prea
> >uth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >hmac-md5-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64-etm at openssh.com,
> >umac-128-e
> >tm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com,
> >hmac-ripemd160-etm at openssh.com,hmac-sha1-96-etm at openssh.com,hmac-md5-96-etm
> >@ope
> >nssh.com,hmac-md5,hmac-sha1,umac-64 at openssh.com,umac-128 at openssh.com,hmac-s
> >ha2-256,hmac-sha2-512,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-9
> >6,hm
> >ac-md5-96 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >hmac-md5-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64-etm at openssh.com,
> >umac-128-e
> >tm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com,
> >hmac-ripemd160-etm at openssh.com,hmac-sha1-96-etm at openssh.com,hmac-md5-96-etm
> >@ope
> >nssh.com,hmac-md5,hmac-sha1,umac-64 at openssh.com,umac-128 at openssh.com,hmac-s
> >ha2-256,hmac-sha2-512,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-9
> >6,hm
> >ac-md5-96 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >none,zlib at openssh.com [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >none,zlib at openssh.com [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >[preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >[preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >first_kex_follows 0  [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >reserved 0  [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,dif
> >fie-hellman-group14-sha1,diffie-hellman-group1-sha1,rsa2048-sha256,rsa1024-
> >sha1 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >ssh-rsa,ssh-dss [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >aes256-ctr,aes256-cbc,rijndael-cbc at lysator.liu.se,aes192-ctr,aes192-cbc,aes
> >128-ctr,aes128-cbc,blowfish-ctr,blowfish-cbc,3des-ctr,3des-cbc,arcfour256,a
> >rcfour128 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >aes256-ctr,aes256-cbc,rijndael-cbc at lysator.liu.se,aes192-ctr,aes192-cbc,aes
> >128-ctr,aes128-cbc,blowfish-ctr,blowfish-cbc,3des-ctr,3des-cbc,arcfour256,a
> >rcfour128 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >hmac-sha2-256,hmac-sha1,hmac-sha1-96,hmac-md5 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >hmac-sha2-256,hmac-sha1,hmac-sha1-96,hmac-md5 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >none,zlib [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >none,zlib [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >[preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >[preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >first_kex_follows 0  [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_parse_kexinit:
> >reserved 0  [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: mac_setup: setup
> >hmac-sha2-256 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: kex: client->server
> >aes256-ctr hmac-sha2-256 none [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: mac_setup: setup
> >hmac-sha2-256 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: kex: server->client
> >aes256-ctr hmac-sha2-256 none [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: kex:
> >diffie-hellman-group-exchange-sha256 need=32 dh_need=32 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 120 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3:
> >mm_request_receive_expect entering: type 121 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: monitor_read: checking
> >request 120
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 121
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: kex:
> >diffie-hellman-group-exchange-sha256 need=32 dh_need=32 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 120 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3:
> >mm_request_receive_expect entering: type 121 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: monitor_read: checking
> >request 120
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 121
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1:
> >SSH2_MSG_KEX_DH_GEX_REQUEST_OLD received [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 0 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_choose_dh: waiting
> >for MONITOR_ANS_MODULI [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3:
> >mm_request_receive_expect entering: type 1 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: monitor_read: checking
> >request 0
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_answer_moduli: got
> >parameters: 1024 4096 8192
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 1
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: monitor_read: 0 used
> >once, disabling now
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_choose_dh: remaining
> >0 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1:
> >SSH2_MSG_KEX_DH_GEX_GROUP sent [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: bits set: 2013/4096
> >[preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: expecting
> >SSH2_MSG_KEX_DH_GEX_INIT [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: bits set: 2017/4096
> >[preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_key_sign entering
> >[preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 6 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_key_sign: waiting for
> >MONITOR_ANS_SIGN [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3:
> >mm_request_receive_expect entering: type 7 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: monitor_read: checking
> >request 6
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_answer_sign
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_answer_sign:
> >signature 0x7f60fd611d20(271)
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 7
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: monitor_read: 6 used
> >once, disabling now
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1:
> >SSH2_MSG_KEX_DH_GEX_REPLY sent [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: kex_derive_keys [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: set_newkeys: mode 1
> >[preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: SSH2_MSG_NEWKEYS sent
> >[preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: expecting
> >SSH2_MSG_NEWKEYS [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: set_newkeys: mode 0
> >[preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: SSH2_MSG_NEWKEYS
> >received [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: KEX done [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: userauth-request for
> >user adm-faru03 at test.osuwmc service ssh-connection method none [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug1: attempt 0 failures 0
> >[preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_getpwnamallow
> >entering [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 8 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_getpwnamallow:
> >waiting for MONITOR_ANS_PWNAM [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3:
> >mm_request_receive_expect entering: type 9 [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering [preauth]
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: monitor_read: checking
> >request 8
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: mm_answer_pwnamallow
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug3: Trying to reverse map
> >address 10.80.5.239.
> >Mar 30 13:33:35 mid-ipa-vp01 sshd[13750]: debug2: parse_server_config:
> >config reprocess config len 899
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: mm_answer_pwnamallow:
> >sending MONITOR_ANS_PWNAM: 1
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 9
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug2: monitor_read: 8 used
> >once, disabling now
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug2: input_userauth_request:
> >setting up authctxt for adm-faru03 at test.osuwmc [preauth]
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: mm_start_pam entering
> >[preauth]
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 100 [preauth]
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: mm_inform_authserv
> >entering [preauth]
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 4 [preauth]
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: mm_inform_authrole
> >entering [preauth]
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 80 [preauth]
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug2: input_userauth_request:
> >try method none [preauth]
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: userauth_finish: failure
> >partial=0 next methods="publickey,gssapi-keyex,gssapi-with-mic,password"
> >[preauth]
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: monitor_read: checking
> >request 100
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug1: PAM: initializing for
> >"adm-faru03 at test.osuwmc"
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug1: PAM: setting PAM_RHOST
> >to "svr-addc-vt01.test.osuwmc"
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug1: PAM: setting PAM_TTY to
> >"ssh"
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug2: monitor_read: 100 used
> >once, disabling now
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug1: userauth-request for
> >user adm-faru03 at test.osuwmc service ssh-connection method gssapi-with-mic
> >[preauth]
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug1: attempt 1 failures 0
> >[preauth]
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug2: input_userauth_request:
> >try method gssapi-with-mic [preauth]
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 42 [preauth]
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3:
> >mm_request_receive_expect entering: type 43 [preauth]
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering [preauth]
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: monitor_read: checking
> >request 4
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: mm_answer_authserv:
> >service=ssh-connection, style=
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug2: monitor_read: 4 used
> >once, disabling now
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: monitor_read: checking
> >request 80
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: mm_answer_authrole: role=
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug2: monitor_read: 80 used
> >once, disabling now
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: monitor_read: checking
> >request 42
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 43
> >Mar 30 13:33:36 mid-ipa-vp01 sshd[13750]: Postponed gssapi-with-mic for
> >adm-faru03 at test.osuwmc from 10.80.5.239 port 65333 ssh2 [preauth]
> >Mar 30 13:33:39 mid-ipa-vp01 sshd[13750]: debug1: userauth-request for
> >user adm-faru03 at test.osuwmc service ssh-connection method password
> >[preauth]
> >Mar 30 13:33:39 mid-ipa-vp01 sshd[13750]: debug1: attempt 2 failures 0
> >[preauth]
> >Mar 30 13:33:39 mid-ipa-vp01 sshd[13750]: debug2: input_userauth_request:
> >try method password [preauth]
> >Mar 30 13:33:39 mid-ipa-vp01 sshd[13750]: debug3: mm_auth_password
> >entering [preauth]
> >Mar 30 13:33:39 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 12 [preauth]
> >Mar 30 13:33:39 mid-ipa-vp01 sshd[13750]: debug3: mm_auth_password:
> >waiting for MONITOR_ANS_AUTHPASSWORD [preauth]
> >Mar 30 13:33:39 mid-ipa-vp01 sshd[13750]: debug3:
> >mm_request_receive_expect entering: type 13 [preauth]
> >Mar 30 13:33:39 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering [preauth]
> >Mar 30 13:33:39 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering
> >Mar 30 13:33:39 mid-ipa-vp01 sshd[13750]: debug3: monitor_read: checking
> >request 12
> >Mar 30 13:33:39 mid-ipa-vp01 sshd[13750]: debug3: PAM: sshpam_passwd_conv
> >called with 1 messages
> >Mar 30 13:33:39 mid-ipa-vp01 sshd[13750]: pam_unix(sshd:auth):
> >authentication failure; logname= uid=0 euid=0 tty=ssh ruser=
> >rhost=svr-addc-vt01.test.osuwmc  user=adm-faru03 at test.osuwmc
> >Mar 30 13:33:40 mid-ipa-vp01 sshd[13750]: pam_sss(sshd:auth):
> >authentication success; logname= uid=0 euid=0 tty=ssh ruser=
> >rhost=svr-addc-vt01.test.osuwmc user=adm-faru03 at test.osuwmc
> >Mar 30 13:33:40 mid-ipa-vp01 sshd[13750]: debug1: PAM: password
> >authentication accepted for adm-faru03 at test.osuwmc
> >Mar 30 13:33:40 mid-ipa-vp01 sshd[13750]: debug3: mm_answer_authpassword:
> >sending result 1
> >Mar 30 13:33:40 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 13
> >Mar 30 13:33:40 mid-ipa-vp01 sshd[13750]: debug3:
> >mm_request_receive_expect entering: type 102
> >Mar 30 13:33:40 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering
> >Mar 30 13:33:40 mid-ipa-vp01 sshd[13750]: debug1: do_pam_account: called
> >Mar 30 13:33:42 mid-ipa-vp01 sshd[13719]: debug1:
> >server_input_global_request: rtype keepalive at openssh.com want_reply 1
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: PAM: do_pam_account
> >pam_acct_mgmt = 0 (Success)
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 103
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: Accepted password for
> >adm-faru03 at test.osuwmc from 10.80.5.239 port 65333 ssh2
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug1: monitor_child_preauth:
> >adm-faru03 at test.osuwmc has been authenticated by privileged process
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_get_keystate: Waiting
> >for new keys
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3:
> >mm_request_receive_expect entering: type 26
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_newkeys_from_blob:
> >0x7f60fd62ff00(159)
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug2: mac_setup: setup
> >hmac-sha2-256
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_get_keystate: Waiting
> >for second key
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_newkeys_from_blob:
> >0x7f60fd62ff00(159)
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug2: mac_setup: setup
> >hmac-sha2-256
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_get_keystate: Getting
> >compression state
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_get_keystate: Getting
> >Network I/O buffers
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3:
> >mm_request_receive_expect entering: type 122
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 123
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_auth_password: user
> >authenticated [preauth]
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_do_pam_account
> >entering [preauth]
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 102 [preauth]
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3:
> >mm_request_receive_expect entering: type 103 [preauth]
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering [preauth]
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_do_pam_account
> >returning 1 [preauth]
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_send_keystate:
> >Sending new keys: 0x7f60fd61fc90 0x7f60fd610a40 [preauth]
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_newkeys_to_blob:
> >converting 0x7f60fd61fc90 [preauth]
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_newkeys_to_blob:
> >converting 0x7f60fd610a40 [preauth]
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_send_keystate: New
> >keys have been sent [preauth]
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_send_keystate:
> >Sending compression state [preauth]
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 26 [preauth]
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_send_keystate:
> >Finished sending state [preauth]
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 122 [preauth]
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3:
> >mm_request_receive_expect entering: type 123 [preauth]
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering [preauth]
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug1: monitor_read_log: child
> >log fd closed
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_share_sync: Share sync
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3: mm_share_sync: Share
> >sync end
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3:
> >ssh_sandbox_parent_finish: finished
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug1: temporarily_use_uid:
> >1398410/1398410 (e=0/0)
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug1: ssh_gssapi_storecreds:
> >Not a GSSAPI mechanism
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug1: restore_uid: 0/0
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug1: SELinux support enabled
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug3:
> >sshd_selinux_setup_variables: setting execution context
> >Mar 30 13:33:43 mid-ipa-vp01 sshd[13750]: debug1: PAM: establishing
> >credentials
> >Mar 30 13:33:44 mid-ipa-vp01 sshd[13750]: debug3: PAM: opening session
> >Mar 30 13:33:45 mid-ipa-vp01 sshd[13750]: pam_unix(sshd:session): session
> >opened for user adm-faru03 at test.osuwmc by (uid=0)
> >Mar 30 13:33:46 mid-ipa-vp01 sshd[13750]: User child is on pid 13761
> >Mar 30 13:33:46 mid-ipa-vp01 sshd[13761]: debug1: PAM: establishing
> >credentials
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug3:
> >sshd_selinux_setup_variables: setting execution context
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug1: permanently_set_uid:
> >1398410/1398410
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug2: set_newkeys: mode 0
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug2: set_newkeys: mode 1
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug1: Entering interactive
> >session for SSH2.
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug2: fd 10 setting O_NONBLOCK
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug2: fd 11 setting O_NONBLOCK
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug1: server_init_dispatch_20
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug3: Received SSH2_MSG_IGNORE
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug1:
> >server_input_channel_open: ctype session rchan 256 win 16384 max 16384
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug1: input_session_request
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug1: channel 0: new
> >[server-session]
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug2: session_new: allocate
> >(allocated 0 max 10)
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug3: session_unused: session
> >id 0 unused
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug1: session_new: session 0
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug1: session_open: channel 0
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug1: session_open: session 0:
> >link with channel 0
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug1:
> >server_input_channel_open: confirm session
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug1:
> >server_input_channel_req: channel 0 request pty-req reply 1
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug1: session_by_channel:
> >session 0 channel 0
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug1:
> >session_input_channel_req: session 0 req pty-req
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug1: Allocating pty.
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug3: mm_request_send
> >entering: type 28
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug3: mm_pty_allocate: waiting
> >for MONITOR_ANS_PTY
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13750]: debug3: monitor_read: checking
> >request 28
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13750]: debug3: mm_answer_pty entering
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13750]: debug2: session_new: allocate
> >(allocated 0 max 10)
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13750]: debug3: session_unused: session
> >id 0 unused
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13750]: debug1: session_new: session 0
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug3:
> >mm_request_receive_expect entering: type 29
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug3: mm_request_receive
> >entering
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13750]: debug1: SELinux support enabled
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13750]: debug3: ssh_selinux_setup_pty:
> >setting TTY context on /dev/pts/2
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13750]: debug3: ssh_selinux_setup_pty:
> >done
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 29
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13750]: debug3: mm_answer_pty: tty
> >/dev/pts/2 ptyfd 5
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug1: session_pty_req: session
> >0 alloc /dev/pts/2
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug1:
> >server_input_channel_req: channel 0 request shell reply 1
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug1: session_by_channel:
> >session 0 channel 0
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug1:
> >session_input_channel_req: session 0 req shell
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: Starting session: shell on pts/2
> >for adm-faru03 at test.osuwmc from 10.80.5.239 port 65333
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug2: fd 3 setting TCP_NODELAY
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug3: packet_set_tos: set
> >IP_TOS 0x10
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug2: channel 0: rfd 14 isatty
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug2: fd 14 setting O_NONBLOCK
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13761]: debug3: fd 12 is O_NONBLOCK
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13762]: debug1: Setting controlling tty
> >using TIOCSCTTY.
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13762]: debug3: mm_request_send
> >entering: type 124
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13762]: debug3:
> >mm_request_receive_expect entering: type 125
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13750]: debug3: mm_request_receive
> >entering
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13762]: debug3: mm_request_receive
> >entering
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13750]: debug3: monitor_read: checking
> >request 124
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13750]: debug3: mm_request_send
> >entering: type 125
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13762]: debug3: Copy environment:
> >KRB5CCNAME=FILE:/tmp/krb5cc_1398410_B30vDK
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13762]: debug3: Copy environment:
> >SELINUX_ROLE_REQUESTED=
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13762]: debug3: Copy environment:
> >SELINUX_LEVEL_REQUESTED=
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13762]: debug3: Copy environment:
> >SELINUX_USE_CURRENT_RANGE=
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13762]: debug3: Copy environment:
> >XDG_SESSION_ID=10
> >Mar 30 13:33:47 mid-ipa-vp01 sshd[13762]: debug3: Copy environment:
> >XDG_RUNTIME_DIR=/run/user/1398410
> >
> >Just in case, here is my krb5.conf
> >
> >includedir /var/lib/sss/pubconf/krb5.include.d/
> >
> >[logging]
> >  default = FILE:/var/log/krb5libs.log
> >  kdc = FILE:/var/log/krb5kdc.log
> >  admin_server = FILE:/var/log/kadmind.log
> >
> >[libdefaults]
> >  default_realm = UNIX.TEST.OSUWMC
> >  dns_lookup_realm = true
> >  dns_lookup_kdc = true
> >  rdns = false
> >  ticket_lifetime = 24h
> >  forwardable = yes
> >  udp_preference_limit = 0
> ># default_ccache_name = KEYRING:persistent:%{uid}
> >
> >[realms]
> >  UNIX.TEST.OSUWMC = {
> >   kdc = mid-ipa-vp01.unix.test.osuwmc:88
> >   master_kdc = mid-ipa-vp01.unix.test.osuwmc:88
> >   admin_server = mid-ipa-vp01.unix.test.osuwmc:749
> >   default_domain = unix.test.osuwmc
> >   pkinit_anchors = FILE:/etc/ipa/ca.crt
> >#  auth_to_local =
> >RULE:[1:$1@$0](^.*@TEST.OSUWMC$)s/@TEST.OSUWMC/@test.osuwmc/
> >#  auth_to_local = RULE:[1:$1 $0](^ *
> >TEST.OSUWMC$)s/@TEST.OSUWMC/@test.osuwmc/
> >   auth_to_local = DEFAULT
> >}
> >
> >[domain_realm]
> >  .unix.test.osuwmc = UNIX.TEST.OSUWMC
> >  unix.test.osuwmc = UNIX.TEST.OSUWMC
> >
> >[dbmodules]
> >   UNIX.TEST.OSUWMC = {
> >     db_library = ipadb.so
> >   }
> 
> I'm not sure if this would be of any help to you, but in case you have
> GSSAPI credential delegation enabled in PuTTY, you also need to allow them
> to be delegated to the IPA server using:
> 
>     $ ipa host-mod <ipa server fqdn> --ok-as-delegate=1

This is only needed if you want that your Kerberos credentials (the TGT) are
forwarded from the Windows client to the IPA client so that you can use
them to access kerberized services from the IPA client as well without
the need to call kinit.

This is not needed for authentication because here only the service
ticket is send to the IPA client and not the TGT.

Can you do the follwoing checks:

Can you check by calling klist in a Windows Command window if you got                                                                                                                         
a proper host/... ticket for the IPA host?                                                                                                                                                    

What version of IPA and SSSD are you using.                                                                                                                                                   

Can you check if the following works on a IPA host:                                                                                                                                           

kinit adm-faru03 at TEST.OSUWMC                                                                                                                                                                  
kvno host/name.of.the.ipa-client.to.login at IPA.REALM                                                                                                                                           
ssh -v -l adm-faru03 at test.osuwmc name.of.the.ipa-client.to.login                                                                                                                              

The error messages return by the ssh -v output might help to see why                                                                                                                          
GSSAPI auth failed.                                                                                                                                                                           

bye,
Sumit

> 
> Honza
> 
> -- 
> Jan Cholasta
> 
> -- 
> Manage your subscription for the Freeipa-users mailing list:
> https://www.redhat.com/mailman/listinfo/freeipa-users
> Go to http://freeipa.org for more info on the project