[Freeipa-users] Problem with Free IPA Client Ubuntu Precise (12.04) authenticating with AD account
James Harrison
jamesaharrisonuk at yahoo.co.uk
Wed Dec 7 18:19:06 UTC 2016
Hi all,
I am trying to authenticate an ubuntu Precise (12.06) fully patched system. Its enrolled into a FreeIPA server. The following trace is the output of syslog auth sssd/*.log and full debug (-ddd) from the sshd service.
I am getting a PAM error at the end of the procedure. Also I cant seem to authenticate against the public ssh key from the id override user.
I appreciate any help you can send my way.
Best regards,
James Harrison
Below is more information
root at jamesprecise:~# kinit x_james.harrison at AD.DOMAIN.LOCAL
Password for x_james.harrison at AD.DOMAIN.LOCAL:
root at jamesprecise:~# klist
Ticket cache: FILE:/tmp/krb5cc_0
Default principal: x_james.harrison at AD.DOMAIN.LOCAL
Valid starting Expires Service principal
07/12/16 17:56:30 08/12/16 03:56:30 krbtgt/AD.DOMAIN.LOCAL at AD.DOMAIN.LOCAL
renew until 08/12/16 17:56:23
root at jamesprecise:~# id x_james.harrison at AD.DOMAIN.LOCAL
uid=1039812876(x_james.harrison at ad.domain.local) gid=1039812876(x_james.harrison at ad.domain.local) groups=1039812876(x_james.harrison at ad.domain.local)
root at pul-lv-ipa-02 ~]# ipa idoverrideuser-show External_AD_views x_james.harrison at ad.domain.local
Anchor to override: x_james.harrison at ad.domain.local
User login: x_james.harrison
Login shell: /bin/bash
SSH public key: ssh-rsa
AAAAB3NzaC1yc2EAAAADAQABAAABAQDK1pj2U7H9olLs1xKmcmZVEBMWpaHjxF2LttsdfqfQxm810qMru/WsvzHqu0m5Ugu0FYsPxRLQrAEB8WPsPoh5Y0q5qYPgm5aDOZZEXfCPyuRwdQ+XLfQJ3gnGjW4r/XLEiNVpO9eKsFs0ifspNAJ1ndddddddddddddddd7h40rlHlOIqV/z8Omg6XnFBh9dIfiXtpYDOxe+512RpjtHE98s+NfIpUTT7MGNLHB5o/DqFXEJPH7Pp1bKwxWNvfCb5a71vcE695dQ31QYVYwpSwFmFogewgpV/OCb+S4SUdUq1xg0fmkhYr3d4UXFr91MDimyOBWk9Aai7NkOHPszmHJp
JamesHarrison
Here are the software versions:
root at jamesprecise:# dpkg -l | grep -i freeipa
ii freeipa-client 3.3.4-0ubuntu3.1~precise0.1 FreeIPA centralized identity framework -- client
ii libipa-hbac0 1.11.5-1ubuntu3~precise1 FreeIPA HBAC Evaluator library
ii python-freeipa 3.3.4-0ubuntu3.1~precise0.1 FreeIPA centralized identity framework -- python modules
ii python-libipa-hbac 1.11.5-1ubuntu3~precise1 Python bindings for the FreeIPA HBAC Evaluator library
root at jamesprecise:# dpkg -l | grep -i openssh-server
ii openssh-server 1:5.9p1-5ubuntu1.10 secure shell (SSH) server, for secure access from remote machines
root at jamesprecise:/var/log# dpkg -l | grep -i sssd
ii libsss-idmap0 1.11.5-1ubuntu3~precise1 ID mapping library for SSSD
ii sssd 1.11.5-1ubuntu3~precise1 System Security Services Daemon -- metapackage
ii sssd-ad 1.11.5-1ubuntu3~precise1 System Security Services Daemon -- Active Directory back end
ii sssd-ad-common 1.11.5-1ubuntu3~precise1 System Security Services Daemon -- PAC responder
ii sssd-common 1.11.5-1ubuntu3~precise1 System Security Services Daemon -- common files
ii sssd-ipa 1.11.5-1ubuntu3~precise1 System Security Services Daemon -- IPA back end
ii sssd-krb5 1.11.5-1ubuntu3~precise1 System Security Services Daemon -- Kerberos back end
ii sssd-krb5-common 1.11.5-1ubuntu3~precise1 System Security Services Daemon -- Kerberos helpers
ii sssd-ldap 1.11.5-1ubuntu3~precise1 System Security Services Daemon -- LDAP back end
ii sssd-proxy 1.11.5-1ubuntu3~precise1 System Security Services Daemon -- proxy back end
ii sudo 1.8.9p5-1ubuntu1.1~sssd1 Provide limited super user privileges to specific users
Ubuntu PPAs:
root at jamesprecise:~# ls -l /etc/apt/sources.list.d/
total 16
-rw-r--r-- 1 root root 65 Dec 7 08:48 freeipa-ppa-precise.list
-rw-r--r-- 1 root root 61 Dec 7 08:48 ppa_freeipa_ppa_precise.list
-rw-r--r-- 1 root root 62 Dec 7 08:48 ppa_sssd_updates_precise.list
-rw-r--r-- 1 root root 66 Dec 7 08:48 sssd-updates-precise.list
cat /etc/pam.d/common-session
session [default=1] pam_permit.so
session requisite pam_deny.so
session required pam_permit.so
session optional pam_umask.so
session required pam_mkhomedir.so umask=0022 skel=/etc/skel
session required pam_unix.so
session optional pam_sss.so
session [success=ok default=ignore] pam_ldap.so minimum_uid=1000
root at jamesprecise:~#
root at jamesprecise:~# cat /etc/pam.d/common-auth
auth [success=3 default=ignore] pam_unix.so nullok_secure
auth [success=2 default=ignore] pam_sss.so use_first_pass
auth [success=1 default=ignore] pam_ldap.so minimum_uid=1000 use_first_pass
auth requisite pam_deny.so
auth required pam_permit.so
root at jamesprecise:~# cat /etc/pam.d/common-account
account [success=1 new_authtok_reqd=done default=ignore] pam_unix.so
account requisite pam_deny.so
account required pam_permit.so
account sufficient pam_localuser.so
account [default=bad success=ok user_unknown=ignore] pam_sss.so
account [success=ok new_authtok_reqd=done ignore=ignore user_unknown=ignore authinfo_unavail=ignore default=bad] pam_ldap.so minimum_uid=1000
root at jamesprecise:~# cat /etc/krb5.conf
#File modified by ipa-client-install
includedir /var/lib/sss/pubconf/krb5.include.d/
[libdefaults]
default_realm = FREEIPA-REALM
dns_lookup_realm = true
dns_lookup_kdc = true
rdns = false
ticket_lifetime = 24h
forwardable = yes
# ignore_acceptor_hostname = true
[realms]
FREEIPA-REALM = {
pkinit_anchors = FILE:/etc/ipa/ca.crt
}
[domain_realm]
.freeipa.domain.com = FREEIPA-REALM
freeipa.domain.com = FREEIPA-REALM
root at jamesprecise:~# cat /etc/sssd/sssd.conf
[domain/freeipa.domain.com]
cache_credentials = True
krb5_store_password_if_offline = True
ipa_domain = freeipa.domain.com
id_provider = ipa
auth_provider = ipa
access_provider = ipa
ipa_hostname = jamesprecise.freeipa.domain.com
chpass_provider = ipa
ipa_server = tx-lv-ipa-02.freeipa.domain.com
ldap_tls_cacert = /etc/ipa/ca.crt
debug_level = 5
[sssd]
services = nss, pam, ssh, sudo
config_file_version = 2
domains = freeipa.domain.com
[nss]
[pam]
[sudo]
[autofs]
[ssh]
[pac]
Below if the trace output as appeared on my screen:
root at jamesprecise:/var/log# /usr/sbin/sshd -ddd
debug2: load_server_config: filename /etc/ssh/sshd_config
debug2: load_server_config: done config len = 773
debug2: parse_server_config: config /etc/ssh/sshd_config len 773
debug3: /etc/ssh/sshd_config:5 setting Port 2230
debug3: /etc/ssh/sshd_config:9 setting Protocol 2
debug3: /etc/ssh/sshd_config:11 setting HostKey /etc/ssh/ssh_host_rsa_key
debug3: /etc/ssh/sshd_config:12 setting HostKey /etc/ssh/ssh_host_dsa_key
debug3: /etc/ssh/sshd_config:13 setting HostKey /etc/ssh/ssh_host_ecdsa_key
debug3: /etc/ssh/sshd_config:16 setting UsePrivilegeSeparation yes
debug3: /etc/ssh/sshd_config:19 setting KeyRegenerationInterval 3600
debug3: /etc/ssh/sshd_config:20 setting ServerKeyBits 1024
debug3: /etc/ssh/sshd_config:23 setting SyslogFacility AUTH
debug3: /etc/ssh/sshd_config:24 setting LogLevel VERBOSE
debug3: /etc/ssh/sshd_config:27 setting LoginGraceTime 120
debug3: /etc/ssh/sshd_config:28 setting PermitRootLogin without-password
debug3: /etc/ssh/sshd_config:29 setting StrictModes yes
debug3: /etc/ssh/sshd_config:31 setting RSAAuthentication yes
debug3: /etc/ssh/sshd_config:32 setting AuthorizedKeysFile %h/.ssh/authorized_keys
debug3: /etc/ssh/sshd_config:35 setting IgnoreRhosts yes
debug3: /etc/ssh/sshd_config:37 setting RhostsRSAAuthentication no
debug3: /etc/ssh/sshd_config:39 setting HostbasedAuthentication no
debug3: /etc/ssh/sshd_config:44 setting PermitEmptyPasswords no
debug3: /etc/ssh/sshd_config:48 setting ChallengeResponseAuthentication no
debug3: /etc/ssh/sshd_config:51 setting PasswordAuthentication no
debug3: /etc/ssh/sshd_config:63 setting X11Forwarding no
debug3: /etc/ssh/sshd_config:64 setting X11DisplayOffset 10
debug3: /etc/ssh/sshd_config:65 setting PrintMotd no
debug3: /etc/ssh/sshd_config:66 setting PrintLastLog yes
debug3: /etc/ssh/sshd_config:67 setting TCPKeepAlive yes
debug3: /etc/ssh/sshd_config:74 setting AcceptEnv LANG LC_*
debug3: /etc/ssh/sshd_config:76 setting Subsystem sftp /usr/lib/openssh/sftp-server
debug3: /etc/ssh/sshd_config:87 setting PubkeyAuthentication yes
debug3: /etc/ssh/sshd_config:88 setting UsePAM yes
debug1: sshd version OpenSSH_5.9p1 Debian-5ubuntu1.10
debug3: Incorrect RSA1 identifier
debug1: read PEM private key done: type RSA
debug1: Checking blacklist file /usr/share/ssh/blacklist.RSA-2048
debug1: Checking blacklist file /etc/ssh/blacklist.RSA-2048
debug1: private host key: #0 type 1 RSA
debug3: Incorrect RSA1 identifier
debug1: read PEM private key done: type DSA
debug1: Checking blacklist file /usr/share/ssh/blacklist.DSA-1024
debug1: Checking blacklist file /etc/ssh/blacklist.DSA-1024
debug1: private host key: #1 type 2 DSA
debug3: Incorrect RSA1 identifier
debug1: read PEM private key done: type ECDSA
debug1: Checking blacklist file /usr/share/ssh/blacklist.ECDSA-256
debug1: Checking blacklist file /etc/ssh/blacklist.ECDSA-256
debug1: private host key: #2 type 3 ECDSA
debug1: rexec_argv[0]='/usr/sbin/sshd'
debug1: rexec_argv[1]='-ddd'
debug3: oom_adjust_setup
Set /proc/self/oom_score_adj from 0 to -1000
debug2: fd 3 setting O_NONBLOCK
debug1: Bind to port 2230 on 0.0.0.0.
Server listening on 0.0.0.0 port 2230.
debug2: fd 4 setting O_NONBLOCK
debug3: sock_set_v6only: set socket 4 IPV6_V6ONLY
debug1: Bind to port 2230 on ::.
Server listening on :: port 2230.
debug3: fd 5 is not O_NONBLOCK
debug1: Server will not fork when running in debugging mode.
debug3: send_rexec_state: entering fd = 8 config len 773
debug3: ssh_msg_send: type 0
debug3: send_rexec_state: done
debug1: rexec start in 5 out 5 newsock 5 pipe -1 sock 8
==> auth.log <==
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: recv_rexec_state: entering fd = 5
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: ssh_msg_recv entering
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: recv_rexec_state: done
Dec 7 17:31:47 jamesprecise sshd[1839]: debug2: parse_server_config: config rexec len 773
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:5 setting Port 2230
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:9 setting Protocol 2
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:11 setting HostKey /etc/ssh/ssh_host_rsa_key
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:12 setting HostKey /etc/ssh/ssh_host_dsa_key
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:13 setting HostKey /etc/ssh/ssh_host_ecdsa_key
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:16 setting UsePrivilegeSeparation yes
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:19 setting KeyRegenerationInterval 3600
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:20 setting ServerKeyBits 1024
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:23 setting SyslogFacility AUTH
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:24 setting LogLevel VERBOSE
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:27 setting LoginGraceTime 120
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:28 setting PermitRootLogin without-password
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:29 setting StrictModes yes
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:31 setting RSAAuthentication yes
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:32 setting AuthorizedKeysFile %h/.ssh/authorized_keys
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:35 setting IgnoreRhosts yes
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:37 setting RhostsRSAAuthentication no
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:39 setting HostbasedAuthentication no
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:44 setting PermitEmptyPasswords no
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:48 setting ChallengeResponseAuthentication no
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:51 setting PasswordAuthentication no
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:63 setting X11Forwarding no
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:64 setting X11DisplayOffset 10
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:65 setting PrintMotd no
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:66 setting PrintLastLog yes
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:67 setting TCPKeepAlive yes
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:74 setting AcceptEnv LANG LC_*
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:76 setting Subsystem sftp /usr/lib/openssh/sftp-server
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:87 setting PubkeyAuthentication yes
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: rexec:88 setting UsePAM yes
Dec 7 17:31:47 jamesprecise sshd[1839]: debug1: sshd version OpenSSH_5.9p1 Debian-5ubuntu1.10
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: Incorrect RSA1 identifier
Dec 7 17:31:47 jamesprecise sshd[1839]: debug1: read PEM private key done: type RSA
Dec 7 17:31:47 jamesprecise sshd[1839]: debug1: Checking blacklist file /usr/share/ssh/blacklist.RSA-2048
Dec 7 17:31:47 jamesprecise sshd[1839]: debug1: Checking blacklist file /etc/ssh/blacklist.RSA-2048
Dec 7 17:31:47 jamesprecise sshd[1839]: debug1: private host key: #0 type 1 RSA
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: Incorrect RSA1 identifier
Dec 7 17:31:47 jamesprecise sshd[1839]: debug1: read PEM private key done: type DSA
Dec 7 17:31:47 jamesprecise sshd[1839]: debug1: Checking blacklist file /usr/share/ssh/blacklist.DSA-1024
Dec 7 17:31:47 jamesprecise sshd[1839]: debug1: Checking blacklist file /etc/ssh/blacklist.DSA-1024
Dec 7 17:31:47 jamesprecise sshd[1839]: debug1: private host key: #1 type 2 DSA
Dec 7 17:31:47 jamesprecise sshd[1839]: debug3: Incorrect RSA1 identifier
Dec 7 17:31:47 jamesprecise sshd[1839]: debug1: read PEM private key done: type ECDSA
Dec 7 17:31:47 jamesprecise sshd[1839]: debug1: Checking blacklist file /usr/share/ssh/blacklist.ECDSA-256
Dec 7 17:31:47 jamesprecise sshd[1839]: debug1: Checking blacklist file /etc/ssh/blacklist.ECDSA-256
Dec 7 17:31:47 jamesprecise sshd[1839]: debug1: private host key: #2 type 3 ECDSA
debug1: inetd sockets after dupping: 3, 3
Connection from 10.10.10.10 port 45036
debug1: Client protocol version 2.0; client software version OpenSSH_7.2p2 Ubuntu-4ubuntu2.1
debug1: match: OpenSSH_7.2p2 Ubuntu-4ubuntu2.1 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_5.9p1 Debian-5ubuntu1.10
debug2: fd 3 setting O_NONBLOCK
debug2: Network child is on pid 1840
debug3: preauth child monitor started
debug3: privsep user:group 105:65534 [preauth]
debug1: permanently_set_uid: 105/65534 [preauth]
debug1: list_hostkey_types: ssh-rsa,ssh-dss,ecdsa-sha2-nistp256 [preauth]
debug1: SSH2_MSG_KEXINIT sent [preauth]
debug1: SSH2_MSG_KEXINIT received [preauth]
debug2: kex_parse_kexinit: ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1 [preauth]
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss,ecdsa-sha2-nistp256 [preauth]
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc at lysator.liu.se [preauth]
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc at lysator.liu.se [preauth]
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64 at openssh.com,hmac-sha2-256,hmac-sha2-256-96,hmac-sha2-512,hmac-sha2-512-96,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96 [preauth]
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64 at openssh.com,hmac-sha2-256,hmac-sha2-256-96,hmac-sha2-512,hmac-sha2-512-96,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96 [preauth]
debug2: kex_parse_kexinit: none,zlib at openssh.com [preauth]
debug2: kex_parse_kexinit: none,zlib at openssh.com [preauth]
debug2: kex_parse_kexinit: [preauth]
debug2: kex_parse_kexinit: [preauth]
debug2: kex_parse_kexinit: first_kex_follows 0 [preauth]
debug2: kex_parse_kexinit: reserved 0 [preauth]
debug2: kex_parse_kexinit: curve25519-sha256 at libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,ext-info-c [preauth]
debug2: kex_parse_kexinit: ecdsa-sha2-nistp256-cert-v01 at openssh.com,ecdsa-sha2-nistp384-cert-v01 at openssh.com,ecdsa-sha2-nistp521-cert-v01 at openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519-cert-v01 at openssh.com,ssh-rsa-cert-v01 at openssh.com,ssh-ed25519,rsa-sha2-512,rsa-sha2-256,ssh-rsa [preauth]
debug2: kex_parse_kexinit: chacha20-poly1305 at openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm at openssh.com,aes256-gcm at openssh.com,aes128-cbc,aes192-cbc,aes256-cbc,3des-cbc [preauth]
debug2: kex_parse_kexinit: chacha20-poly1305 at openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm at openssh.com,aes256-gcm at openssh.com,aes128-cbc,aes192-cbc,aes256-cbc,3des-cbc [preauth]
debug2: kex_parse_kexinit: umac-64-etm at openssh.com,umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64 at openssh.com,umac-128 at openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth]
debug2: kex_parse_kexinit: umac-64-etm at openssh.com,umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64 at openssh.com,umac-128 at openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth]
debug2: kex_parse_kexinit: none,zlib at openssh.com,zlib [preauth]
debug2: kex_parse_kexinit: none,zlib at openssh.com,zlib [preauth]
debug2: kex_parse_kexinit: [preauth]
debug2: kex_parse_kexinit: [preauth]
debug2: kex_parse_kexinit: first_kex_follows 0 [preauth]
debug2: kex_parse_kexinit: reserved 0 [preauth]
debug2: mac_setup: found umac-64 at openssh.com [preauth]
debug1: kex: client->server aes128-ctr umac-64 at openssh.com none [preauth]
debug2: mac_setup: found umac-64 at openssh.com [preauth]
debug1: kex: server->client aes128-ctr umac-64 at openssh.com none [preauth]
debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
debug3: mm_key_sign entering [preauth]
debug3: mm_request_send entering: type 5 [preauth]
debug3: mm_request_receive entering
debug3: monitor_read: checking request 5
debug3: mm_answer_sign
debug3: mm_answer_sign: signature 0x7fcb152fe1a0(100)
debug3: mm_request_send entering: type 6
debug2: monitor_read: 5 used once, disabling now
debug3: mm_key_sign: waiting for MONITOR_ANS_SIGN [preauth]
debug3: mm_request_receive_expect entering: type 6 [preauth]
debug3: mm_request_receive entering [preauth]
debug2: kex_derive_keys [preauth]
debug2: set_newkeys: mode 1 [preauth]
debug1: SSH2_MSG_NEWKEYS sent [preauth]
debug1: expecting SSH2_MSG_NEWKEYS [preauth]
debug2: set_newkeys: mode 0 [preauth]
debug1: SSH2_MSG_NEWKEYS received [preauth]
debug1: KEX done [preauth]
debug1: userauth-request for user a_aaaaaaa.aaaaa at xxxxxxx.xxxx service ssh-connection method none [preauth]
debug1: attempt 0 failures 0 [preauth]
debug3: mm_getpwnamallow entering [preauth]
debug3: mm_request_send entering: type 7 [preauth]
debug3: mm_request_receive entering
debug3: monitor_read: checking request 7
debug3: mm_answer_pwnamallow
debug3: Trying to reverse map address 10.10.10.10.
debug2: parse_server_config: config reprocess config len 773
debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1
debug3: mm_request_send entering: type 8
debug2: monitor_read: 7 used once, disabling now
debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth]
debug3: mm_request_receive_expect entering: type 8 [preauth]
debug3: mm_request_receive entering [preauth]
debug2: input_userauth_request: setting up authctxt for a_aaaaaaa.aaaaa at xxxxxxx.xxxx [preauth]
debug3: mm_start_pam entering [preauth]
debug3: mm_request_send entering: type 50 [preauth]
debug3: mm_request_receive entering
debug3: monitor_read: checking request 50
debug1: PAM: initializing for "a_aaaaaaa.aaaaa at xxxxxxx.xxxx"
debug1: PAM: setting PAM_RHOST to "10.10.10.10"
debug1: PAM: setting PAM_TTY to "ssh"
debug2: monitor_read: 50 used once, disabling now
debug3: mm_inform_authserv entering [preauth]
debug3: mm_request_send entering: type 3 [preauth]
debug3: mm_request_receive entering
debug3: monitor_read: checking request 3
debug3: mm_answer_authserv: service=ssh-connection, style=, role=
debug2: monitor_read: 3 used once, disabling now
debug2: input_userauth_request: try method none [preauth]
debug1: userauth-request for user a_aaaaaaa.aaaaa at xxxxxxx.xxxx service ssh-connection method publickey [preauth]
debug1: attempt 1 failures 0 [preauth]
debug2: input_userauth_request: try method publickey [preauth]
debug1: test whether pkalg/pkblob are acceptable [preauth]
debug3: mm_key_allowed entering [preauth]
debug3: mm_request_send entering: type 21 [preauth]
debug3: mm_request_receive entering
debug3: monitor_read: checking request 21
debug3: mm_answer_keyallowed entering
debug3: mm_answer_keyallowed: key_from_blob: 0x7fcb15302ec0
debug1: Checking blacklist file /usr/share/ssh/blacklist.RSA-2048
debug1: Checking blacklist file /etc/ssh/blacklist.RSA-2048
debug1: temporarily_use_uid: 1039812876/1039812876 (e=0/0)
==> sssd/sssd_freeipa.domain.com.log <==
(Wed Dec 7 17:31:47 2016) [sssd[be[freeipa.domain.com]]] [be_get_account_info] (0x0100): Got request for [4099][1][name=a_aaaaaaa.aaaaa]
(Wed Dec 7 17:31:47 2016) [sssd[be[freeipa.domain.com]]] [acctinfo_callback] (0x0100): Request processed. Returned 3,95,Account info lookup failed
debug1: trying public key file /home/xxxxxxx.xxxx/a_aaaaaaa.aaaaa/.ssh/authorized_keys
debug1: fd 8 clearing O_NONBLOCK
debug1: matching key found: file /home/xxxxxxx.xxxx/a_aaaaaaa.aaaaa/.ssh/authorized_keys, line 8
Found matching RSA key: a6:61:f3:d1:f6:87:4f:e2:27:49:88:f8:09:93:11:27
debug1: restore_uid: 0/0
debug3: mm_answer_keyallowed: key 0x7fcb15302ec0 is allowed
debug3: mm_request_send entering: type 22
debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth]
debug3: mm_request_receive_expect entering: type 22 [preauth]
debug3: mm_request_receive entering [preauth]
debug2: userauth_pubkey: authenticated 0 pkalg ssh-rsa [preauth]
Postponed publickey for a_aaaaaaa.aaaaa at xxxxxxx.xxxx from 10.10.10.10 port 45036 ssh2 [preauth]
debug1: userauth-request for user a_aaaaaaa.aaaaa at xxxxxxx.xxxx service ssh-connection method publickey [preauth]
debug1: attempt 2 failures 0 [preauth]
debug2: input_userauth_request: try method publickey [preauth]
debug3: mm_key_allowed entering [preauth]
debug3: mm_request_send entering: type 21 [preauth]
debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth]
debug3: mm_request_receive_expect entering: type 22 [preauth]
debug3: mm_request_receive entering [preauth]
debug3: mm_request_receive entering
debug3: monitor_read: checking request 21
debug3: mm_answer_keyallowed entering
debug3: mm_answer_keyallowed: key_from_blob: 0x7fcb153143e0
debug1: Checking blacklist file /usr/share/ssh/blacklist.RSA-2048
debug1: Checking blacklist file /etc/ssh/blacklist.RSA-2048
debug1: temporarily_use_uid: 1039812876/1039812876 (e=0/0)
debug1: trying public key file /home/xxxxxxx.xxxx/a_aaaaaaa.aaaaa/.ssh/authorized_keys
debug1: fd 8 clearing O_NONBLOCK
debug1: matching key found: file /home/xxxxxxx.xxxx/a_aaaaaaa.aaaaa/.ssh/authorized_keys, line 8
Found matching RSA key: a6:61:f3:d1:f6:87:4f:e2:27:49:88:f8:09:93:11:27
debug1: restore_uid: 0/0
debug3: mm_answer_keyallowed: key 0x7fcb153143e0 is allowed
debug3: mm_request_send entering: type 22
debug3: mm_key_verify entering [preauth]
debug3: mm_request_send entering: type 23 [preauth]
debug3: mm_key_verify: waiting for MONITOR_ANS_KEYVERIFY [preauth]
debug3: mm_request_receive_expect entering: type 24 [preauth]
debug3: mm_request_receive entering [preauth]
debug3: mm_request_receive entering
debug3: monitor_read: checking request 23
debug1: ssh_rsa_verify: signature correct
debug3: mm_answer_keyverify: key 0x7fcb153143e0 signature verified
debug3: mm_request_send entering: type 24
debug3: mm_request_receive_expect entering: type 51
debug3: mm_request_receive entering
debug1: do_pam_account: called
(Wed Dec 7 17:31:47 2016) [sssd[be[freeipa.domain.com]]] [be_get_account_info] (0x0100): Got request for [3][1][name=a_aaaaaaa.aaaaa]
(Wed Dec 7 17:31:47 2016) [sssd[be[freeipa.domain.com]]] [acctinfo_callback] (0x0100): Request processed. Returned 3,95,Account info lookup failed
(Wed Dec 7 17:31:47 2016) [sssd[be[freeipa.domain.com]]] [be_pam_handler] (0x0100): Got request with the following data
(Wed Dec 7 17:31:47 2016) [sssd[be[freeipa.domain.com]]] [pam_print_data] (0x0100): command: PAM_ACCT_MGMT
(Wed Dec 7 17:31:47 2016) [sssd[be[freeipa.domain.com]]] [pam_print_data] (0x0100): domain: xxxxxxx.xxxx
(Wed Dec 7 17:31:47 2016) [sssd[be[freeipa.domain.com]]] [pam_print_data] (0x0100): user: a_aaaaaaa.aaaaa at xxxxxxx.xxxx
(Wed Dec 7 17:31:47 2016) [sssd[be[freeipa.domain.com]]] [pam_print_data] (0x0100): service: sshd
(Wed Dec 7 17:31:47 2016) [sssd[be[freeipa.domain.com]]] [pam_print_data] (0x0100): tty: ssh
(Wed Dec 7 17:31:47 2016) [sssd[be[freeipa.domain.com]]] [pam_print_data] (0x0100): ruser:
(Wed Dec 7 17:31:47 2016) [sssd[be[freeipa.domain.com]]] [pam_print_data] (0x0100): rhost: 10.10.10.10
(Wed Dec 7 17:31:47 2016) [sssd[be[freeipa.domain.com]]] [pam_print_data] (0x0100): authtok type: 0
(Wed Dec 7 17:31:47 2016) [sssd[be[freeipa.domain.com]]] [pam_print_data] (0x0100): newauthtok type: 0
(Wed Dec 7 17:31:47 2016) [sssd[be[freeipa.domain.com]]] [pam_print_data] (0x0100): priv: 1
(Wed Dec 7 17:31:47 2016) [sssd[be[freeipa.domain.com]]] [pam_print_data] (0x0100): cli_pid: 1839
(Wed Dec 7 17:31:47 2016) [sssd[be[freeipa.domain.com]]] [ipa_hostgroup_info_done] (0x0200): Dereferenced host group: servers
(Wed Dec 7 17:31:48 2016) [sssd[be[freeipa.domain.com]]] [hbac_get_category] (0x0200): Category is set to 'all'.
(Wed Dec 7 17:31:48 2016) [sssd[be[freeipa.domain.com]]] [ipa_hbac_evaluate_rules] (0x0080): Access denied by HBAC rules
(Wed Dec 7 17:31:48 2016) [sssd[be[freeipa.domain.com]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 6, <NULL>) [Success]
(Wed Dec 7 17:31:48 2016) [sssd[be[freeipa.domain.com]]] [be_pam_handler_callback] (0x0100): Sending result [6][xxxxxxx.xxxx]
==> auth.log <==
Dec 7 17:31:48 jamesprecise sshd[1839]: pam_sss(sshd:account): Access denied for user a_aaaaaaa.aaaaa at xxxxxxx.xxxx: 6 (Permission denied)
==> sssd/sssd_freeipa.domain.com.log <==
(Wed Dec 7 17:31:48 2016) [sssd[be[freeipa.domain.com]]] [be_pam_handler_callback] (0x0100): Sent result [6][xxxxxxx.xxxx]
debug3: PAM: do_pam_account pam_acct_mgmt = 6 (Permission denied)
debug3: mm_request_send entering: type 52
Failed publickey for a_aaaaaaa.aaaaa at xxxxxxx.xxxx from 10.10.10.10 port 45036 ssh2
debug2: userauth_pubkey: authenticated 1 pkalg ssh-rsa [preauth]
debug3: mm_do_pam_account entering [preauth]
debug3: mm_request_send entering: type 51 [preauth]
debug3: mm_request_receive_expect entering: type 52 [preauth]
debug3: mm_request_receive entering [preauth]
debug3: mm_do_pam_account returning 0 [preauth]
Access denied for user a_aaaaaaa.aaaaa at xxxxxxx.xxxx by PAM account configuration [preauth]
debug1: do_cleanup [preauth]
debug3: PAM: sshpam_thread_cleanup entering [preauth]
debug1: monitor_read_log: child log fd closed
debug3: mm_request_receive entering
debug1: do_cleanup
debug1: PAM: cleanup
debug3: PAM: sshpam_thread_cleanup entering
root at jamesprecise:/var/log# (Wed Dec 7 17:31:56 2016) [sssd[be[freeipa.domain.com]]] [sdap_id_conn_data_expire_handler] (0x0080): connection is about to expire, releasing it
(Wed Dec 7 17:32:04 2016) [sssd[be[freeipa.domain.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
(Wed Dec 7 17:32:04 2016) [sssd[be[freeipa.domain.com]]] [be_resolve_server_process] (0x0200): Found address for server freeipa.server.com: [11.11.11.11] TTL 1177
(Wed Dec 7 17:32:04 2016) [sssd[be[freeipa.domain.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
(Wed Dec 7 17:32:04 2016) [sssd[be[freeipa.domain.com]]] [be_resolve_server_process] (0x0200): Found address for server freeipa.server.com: [11.11.11.11] TTL 1177
==> sssd/ldap_child.log <==
(Wed Dec 7 17:32:04 2016) [[sssd[ldap_child[1841]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [host/client-freeipa.com at freeipa.domain.com]
(Wed Dec 7 17:32:04 2016) [[sssd[ldap_child[1841]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [default]
(Wed Dec 7 17:32:04 2016) [[sssd[ldap_child[1841]]]] [ldap_child_get_tgt_sync] (0x0100): Will canonicalize principals
==> syslog <==
Dec 7 17:32:04 jamesprecise kernel: [ 5423.086166] type=1400 audit(1481131924.403:53): apparmor="ALLOWED" operation="open" parent=952 profile="/usr/sbin/sssd" name="/var/lib/sss/pubconf/krb5.include.d/" pid=1841 comm="ldap_child" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Dec 7 17:32:04 jamesprecise kernel: [ 5423.086190] type=1400 audit(1481131924.403:54): apparmor="ALLOWED" operation="open" parent=952 profile="/usr/sbin/sssd" name="/var/lib/sss/pubconf/krb5.include.d/domain_realm_freeipa-realm" pid=1841 comm="ldap_child" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
==> sssd/sssd_freeipa.domain.com.log <==
(Wed Dec 7 17:32:04 2016) [sssd[be[freeipa.domain.com]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900
(Wed Dec 7 17:32:04 2016) [sssd[be[freeipa.domain.com]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: GSSAPI, user: host/client-freeipa.com
(Wed Dec 7 17:32:05 2016) [sssd[be[freeipa.domain.com]]] [child_sig_handler] (0x0100): child [1841] finished successfully.
(Wed Dec 7 17:32:05 2016) [sssd[be[freeipa.domain.com]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'freeipa.server.com' as 'working'
(Wed Dec 7 17:32:05 2016) [sssd[be[freeipa.domain.com]]] [set_server_common_status] (0x0100): Marking server 'freeipa.server.com' as 'working'
(Wed Dec 7 17:32:05 2016) [sssd[be[freeipa.domain.com]]] [sdap_sudo_set_usn] (0x0200): SUDO higher USN value: [572244]
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/freeipa-users/attachments/20161207/72f25035/attachment.htm>
More information about the Freeipa-users
mailing list