[Freeipa-users] Troubleshooting SSO
Gould, Joshua
Joshua.Gould at osumc.edu
Mon Mar 30 17:42:10 UTC 2015
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
}
More information about the Freeipa-users
mailing list