I'm trying to connect my server to a LDAP server. I get a correct answer after using *id* and *ldapsearch* commands. However, i still not able to login with SSH.
I can see on sssd_LDAP.log file that the server has received the request to login with the user (myuser), but the request was rejected.
tail -f /var/log/sssd/sssd_LDAP.log
(Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [be_get_account_info] (0x0200): Got request for [0x1001][FAST BE_REQ_USER][1][name=omri_w] (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP' (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [get_server_status] (0x0100): Hostname resolution expired, resetting the server status of 'ldap21v.walla.co.il' (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [set_server_common_status] (0x0100): Marking server 'ldap21v.walla.co.il' as 'name not resolved' (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'ldap21v.walla.co.il' in files (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [set_server_common_status] (0x0100): Marking server 'ldap21v.walla.co.il' as 'resolving name' (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'ldap21v.walla.co.il' in files (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'ldap21v.walla.co.il' in DNS (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [set_server_common_status] (0x0100): Marking server 'ldap21v.walla.co.il' as 'name resolved' (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [be_resolve_server_process] (0x0200): Found address for server ldap21v.walla.co.il: [192.168.50.21] TTL 600 (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [sdap_get_server_opts_from_rootdse] (0x0020): ldap_rootdse_last_usn configured but not found in rootdse! (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'ldap21v.walla.co.il' as 'working' (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [set_server_common_status] (0x0100): Marking server 'ldap21v.walla.co.il' as 'working' (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success (Success) (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [be_get_account_info] (0x0200): Got request for [0x1003][FAST BE_REQ_INITGROUPS][1][name=myuser] (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [sdap_initgr_nested_send] (0x0100): User entry lacks original memberof ? (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success (Success) (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [be_get_account_info] (0x0200): Got request for [0x3][BE_REQ_INITGROUPS][1][name=myuser] (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [sdap_initgr_nested_send] (0x0100): User entry lacks original memberof ? (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success (Success) (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [be_pam_handler] (0x0100): Got request with the following data (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): command: SSS_PAM_AUTHENTICATE (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): domain: LDAP (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): user: myuser (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): service: sshd (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): tty: ssh (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): ruser: (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): rhost: 192.118.68.5 (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): authtok type: 0 (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): newauthtok type: 0 (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): priv: 1 (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): cli_pid: 2208 (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): logon name: not set (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 7, <NULL>) [Success (Authentication failure)] (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [be_pam_handler_callback] (0x0100): Sending result [7][LDAP] (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [be_pam_handler_callback] (0x0100): Sent result [7][LDAP]
Does anyone know what is the issue?
On Tue, Dec 06, 2016 at 09:06:09AM -0000, E. Clapton wrote:
I'm trying to connect my server to a LDAP server. I get a correct answer after using *id* and *ldapsearch* commands. However, i still not able to login with SSH.
I can see on sssd_LDAP.log file that the server has received the request to login with the user (myuser), but the request was rejected.
tail -f /var/log/sssd/sssd_LDAP.log
(Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [be_get_account_info] (0x0200): Got request for [0x1001][FAST BE_REQ_USER][1][name=omri_w] (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP' (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [get_server_status] (0x0100): Hostname resolution expired, resetting the server status of 'ldap21v.walla.co.il' (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [set_server_common_status] (0x0100): Marking server 'ldap21v.walla.co.il' as 'name not resolved' (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'ldap21v.walla.co.il' in files (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [set_server_common_status] (0x0100): Marking server 'ldap21v.walla.co.il' as 'resolving name' (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'ldap21v.walla.co.il' in files (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'ldap21v.walla.co.il' in DNS (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [set_server_common_status] (0x0100): Marking server 'ldap21v.walla.co.il' as 'name resolved' (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [be_resolve_server_process] (0x0200): Found address for server ldap21v.walla.co.il: [192.168.50.21] TTL 600 (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [sdap_get_server_opts_from_rootdse] (0x0020): ldap_rootdse_last_usn configured but not found in rootdse! (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'ldap21v.walla.co.il' as 'working' (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [set_server_common_status] (0x0100): Marking server 'ldap21v.walla.co.il' as 'working' (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success (Success) (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [be_get_account_info] (0x0200): Got request for [0x1003][FAST BE_REQ_INITGROUPS][1][name=myuser] (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [sdap_initgr_nested_send] (0x0100): User entry lacks original memberof ? (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success (Success) (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [be_get_account_info] (0x0200): Got request for [0x3][BE_REQ_INITGROUPS][1][name=myuser] (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [sdap_initgr_nested_send] (0x0100): User entry lacks original memberof ? (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success (Success) (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [be_pam_handler] (0x0100): Got request with the following data (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): command: SSS_PAM_AUTHENTICATE (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): domain: LDAP (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): user: myuser (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): service: sshd (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): tty: ssh (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): ruser: (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): rhost: 192.118.68.5 (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): authtok type: 0
authtok type:0 indicates there was no password on the PAM stack. I would suggest to inspect your PAM configuration if pam_sss is set correctly and receives passwords.
(Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): newauthtok type: 0 (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): priv: 1 (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): cli_pid: 2208 (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): logon name: not set (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 7, <NULL>) [Success (Authentication failure)] (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [be_pam_handler_callback] (0x0100): Sending result [7][LDAP] (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [be_pam_handler_callback] (0x0100): Sent result [7][LDAP]
Does anyone know what is the issue? _______________________________________________ sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org
On Tue, Dec 06, 2016 at 09:06:09AM -0000, E. Clapton wrote:
I'm trying to connect my server to a LDAP server. I get a correct answer after using *id* and *ldapsearch* commands. However, i still not able to login with SSH.
I can see on sssd_LDAP.log file that the server has received the request to login with the user (myuser), but the request was rejected.
tail -f /var/log/sssd/sssd_LDAP.log
...
(Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [be_pam_handler] (0x0100): Got request with the following data (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): command: SSS_PAM_AUTHENTICATE (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): domain: LDAP (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): user: myuser (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): service: sshd (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): tty: ssh (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): ruser: (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): rhost: 192.118.68.5 (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): authtok type: 0
'authtok type: 0' means that no password was sent to SSSD. I suspect that there is something wrong with your PAM configuration. Can you send the PAM configuration for sshd? It is typically in /etc/pam.d/sshd, if additional file are included, please send them as well.
bye, Sumit
(Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): newauthtok type: 0 (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): priv: 1 (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): cli_pid: 2208 (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [pam_print_data] (0x0100): logon name: not set (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 7, <NULL>) [Success (Authentication failure)] (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [be_pam_handler_callback] (0x0100): Sending result [7][LDAP] (Mon Dec 5 12:39:48 2016) [sssd[be[LDAP]]] [be_pam_handler_callback] (0x0100): Sent result [7][LDAP]
Does anyone know what is the issue? _______________________________________________ sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org
I have configured my PAM configuration according to the following page: https://arthurdejong.org/nss-pam-ldapd/setup
Here is what i got after trying to login with my user: (Tue Dec 6 09:47:49 2016) [sssd[be[LDAP]]] [be_get_account_info] (0x0200): Got request for [0x1001][FAST BE_REQ_USER][1][name=myuser] (Tue Dec 6 09:47:49 2016) [sssd[be[LDAP]]] [sdap_get_users_done] (0x0040): Failed to retrieve users (Tue Dec 6 09:47:49 2016) [sssd[be[LDAP]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success (Success)
On Tue, Dec 06, 2016 at 10:01:09AM -0000, E. Clapton wrote:
I have configured my PAM configuration according to the following page: https://arthurdejong.org/nss-pam-ldapd/setup
Here is what i got after trying to login with my user: (Tue Dec 6 09:47:49 2016) [sssd[be[LDAP]]] [be_get_account_info] (0x0200): Got request for [0x1001][FAST BE_REQ_USER][1][name=myuser] (Tue Dec 6 09:47:49 2016) [sssd[be[LDAP]]] [sdap_get_users_done] (0x0040): Failed to retrieve users (Tue Dec 6 09:47:49 2016) [sssd[be[LDAP]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success (Success)
pam_ldap is not used by sssd. I would recommend to use a tool that sets up the PAM stack for you (like authconfig on Fedora/RHEL/Centos), not set up PAM yourself.
Actually I've used this command in order to setup to PAM. I get a response when i user the command "id myuser", but not able to login as i describe above.
Any idea?
On Tue, Dec 06, 2016 at 10:53:59AM -0000, E. Clapton wrote:
Actually I've used this command in order to setup to PAM. I get a response when i user the command "id myuser", but not able to login as i describe above.
Please paste your full PAM stack and the debug logs using that PAM stack.
Can you instruct me how to do so? I didn't manage to find that on Google, probably because i have zero experience with such as kind of things.
BY using jurnalctl, i have found the following errors:
Dec 06 16:35:04 localhost systemd[1]: Started OpenSSH per-connection server daemon (x.x.x.x:60759). Dec 06 16:35:04 localhost sshd[1637]: PAM unable to dlopen(/lib64/security/pam_ldap.so): /lib64/security/pam_ldap.so: cannot open shared object file: No such file or directory Dec 06 16:35:04 localhost sshd[1637]: PAM adding faulty module: /lib64/security/pam_ldap.so Dec 06 16:35:08 localhost sshd[1639]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=x.x.x.x. user=myuser Dec 06 16:35:10 localhost sshd[1637]: PAM: Authentication failure for omri_w from x.x.x.x
Please advise. BTW, I’m using CoreOS as operating system.
As for the last log file, the user is 'myuser' and not as appear (i missed that line when i replaced the username here).
On Tue, Dec 06, 2016 at 04:47:04PM -0000, E. Clapton wrote:
BY using jurnalctl, i have found the following errors:
Dec 06 16:35:04 localhost systemd[1]: Started OpenSSH per-connection server daemon (x.x.x.x:60759). Dec 06 16:35:04 localhost sshd[1637]: PAM unable to dlopen(/lib64/security/pam_ldap.so): /lib64/security/pam_ldap.so: cannot open shared object file: No such file or directory
This line probably means that PAM configuration refers to pam_ldap.so but pam_ldap is not installed on the system.
Dec 06 16:35:04 localhost sshd[1637]: PAM adding faulty module: /lib64/security/pam_ldap.so Dec 06 16:35:08 localhost sshd[1639]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=x.x.x.x. user=myuser Dec 06 16:35:10 localhost sshd[1637]: PAM: Authentication failure for omri_w from x.x.x.x
Please advise. BTW, I’m using CoreOS as operating system.
I've never used CoreOS myself, but the PAM configuration files are pretty much always at /etc/pam.d/*.
However, I don't think you should need to tune the PAM config yourself by hand-editing the files. Most distributions provide some sort of a configuration mechanism to set up the PAM stack, like authconfig on Fedora/RHEL. I would suggest to consult some CoreOS-specific documentation to see how should authentication be set up. In SSSD upstream, we can review the PAM configuration in general, but I'm not sure we have the knowledge to help you set up CoreOS..
It turned out that in CoreOS, the default PAM config under /usr enables sssd, so i deleted the configuration under /etc.
Here are my current errors: Dec 12 09:33:07 localhost sshd[3298]: pam_sss(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=x.x.x.x user=myuser Dec 12 09:33:07 localhost sshd[3298]: pam_sss(sshd:auth): received for user myuser: 7 (Authentication failure) Dec 12 09:33:11 localhost sshd[3298]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=x.x.x.x user=myuser Dec 12 09:33:14 localhost sshd[3296]: PAM: Authentication failure for myuser from x.x.x.x
Any idea?
On Mon, Dec 12, 2016 at 01:52:02PM -0000, E. Clapton wrote:
It turned out that in CoreOS, the default PAM config under /usr enables sssd, so i deleted the configuration under /etc.
Here are my current errors: Dec 12 09:33:07 localhost sshd[3298]: pam_sss(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=x.x.x.x user=myuser Dec 12 09:33:07 localhost sshd[3298]: pam_sss(sshd:auth): received for user myuser: 7 (Authentication failure) Dec 12 09:33:11 localhost sshd[3298]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=x.x.x.x user=myuser Dec 12 09:33:14 localhost sshd[3296]: PAM: Authentication failure for myuser from x.x.x.x
What version of sssd does coreos use?
Since pam_sss was called before pam_unix, I wonder if the pam stack is set up correctly in the sense that pam_sss asks for the password itself?
On Mon, Dec 12, 2016 at 01:52:02PM -0000, E. Clapton wrote:
What version of sssd does coreos use?
Since pam_sss was called before pam_unix, I wonder if the pam stack is set up correctly in the sense that pam_sss asks for the password itself?
sssd version - 1.13.1.
As for your second question/wonder, i'm not familiar enough with sssd in order to answer. Is there any kind of checks i can do?
On Mon, Dec 12, 2016 at 03:00:00PM -0000, E. Clapton wrote:
On Mon, Dec 12, 2016 at 01:52:02PM -0000, E. Clapton wrote:
What version of sssd does coreos use?
Since pam_sss was called before pam_unix, I wonder if the pam stack is set up correctly in the sense that pam_sss asks for the password itself?
sssd version - 1.13.1.
As for your second question/wonder, i'm not familiar enough with sssd in order to answer. Is there any kind of checks i can do?
Can you paste the PAM config files?
Tossing this here as well as I'm already chatting on the FreeIPA mailing list about this but figured I'd post here as well.
Is this considered a bug?
(Sun Dec 11 03:26:13 2016) [sssd[pam]] [pam_dp_process_reply] (0x0200): received: [4 (System error)][mds.xyz] (Sun Dec 11 03:26:13 2016) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [4]: System error.
Config is basic in what comes from the FreeIPA configuration:
[root@idmipa01 sssd]# cat /etc/sssd/sssd.conf [domain/nix.mds.xyz] debug_level = 9
cache_credentials = True krb5_store_password_if_offline = True ipa_domain = nix.mds.xyz id_provider = ipa auth_provider = ipa access_provider = ipa ipa_hostname = idmipa01.nix.mds.xyz chpass_provider = ipa ipa_server = idmipa01.nix.mds.xyz ipa_server_mode = True ldap_tls_cacert = /etc/ipa/ca.crt
[sssd] debug_level = 9 services = nss, sudo, pam, ssh config_file_version = 2 domains = nix.mds.xyz
[nss] debug_level = 9 memcache_timeout = 600 homedir_substring = /home
[pam] debug_level = 9
[sudo]
[autofs]
[ssh]
[pac] debug_level = 9
[ifp]
[root@idmipa01 sssd]# cat /etc/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 = NIX.MDS.XYZ # dns_lookup_realm = false 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] NIX.MDS.XYZ = { kdc = idmipa01.nix.mds.xyz:88 master_kdc = idmipa01.nix.mds.xyz:88 admin_server = idmipa01.nix.mds.xyz:749 default_domain = nix.mds.xyz pkinit_anchors = FILE:/etc/ipa/ca.crt
auth_to_local = RULE:[1:$1@$0](^.*@MDS.XYZ$)s/@MDS.XYZ/@mds.xyz/ auth_to_local = DEFAULT }
[domain_realm] .nix.mds.xyz = NIX.MDS.XYZ nix.mds.xyz = NIX.MDS.XYZ
[dbmodules] NIX.MDS.XYZ = { db_library = ipadb.so }
[root@idmipa01 sssd]#
On 12/13/2016 12:27 AM, TomK wrote:
Tossing this here as well as I'm already chatting on the FreeIPA mailing list about this but figured I'd post here as well.
Is this considered a bug?
(Sun Dec 11 03:26:13 2016) [sssd[pam]] [pam_dp_process_reply] (0x0200): received: [4 (System error)][mds.xyz] (Sun Dec 11 03:26:13 2016) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [4]: System error.
Config is basic in what comes from the FreeIPA configuration:
[root@idmipa01 sssd]# cat /etc/sssd/sssd.conf [domain/nix.mds.xyz] debug_level = 9
cache_credentials = True krb5_store_password_if_offline = True ipa_domain = nix.mds.xyz id_provider = ipa auth_provider = ipa access_provider = ipa ipa_hostname = idmipa01.nix.mds.xyz chpass_provider = ipa ipa_server = idmipa01.nix.mds.xyz ipa_server_mode = True ldap_tls_cacert = /etc/ipa/ca.crt
[sssd] debug_level = 9 services = nss, sudo, pam, ssh config_file_version = 2 domains = nix.mds.xyz
[nss] debug_level = 9 memcache_timeout = 600 homedir_substring = /home
[pam] debug_level = 9
[sudo]
[autofs]
[ssh]
[pac] debug_level = 9
[ifp]
[root@idmipa01 sssd]# cat /etc/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 = NIX.MDS.XYZ # dns_lookup_realm = false 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] NIX.MDS.XYZ = { kdc = idmipa01.nix.mds.xyz:88 master_kdc = idmipa01.nix.mds.xyz:88 admin_server = idmipa01.nix.mds.xyz:749 default_domain = nix.mds.xyz pkinit_anchors = FILE:/etc/ipa/ca.crt
auth_to_local = RULE:[1:$1@$0](^.*@MDS.XYZ$)s/@MDS.XYZ/@mds.xyz/ auth_to_local = DEFAULT }
[domain_realm] .nix.mds.xyz = NIX.MDS.XYZ nix.mds.xyz = NIX.MDS.XYZ
[dbmodules] NIX.MDS.XYZ = { db_library = ipadb.so }
[root@idmipa01 sssd]#
Ok, upgraded to sssd 1.14. Now the message reads:
(Tue Dec 13 00:49:24 2016) [sssd[pam]] [merge_msg_ts_attrs] (0x2000): No such DN in the timestamp cache: name=tom@mds.xyz,cn=users,cn=mds.xyz,cn=sysdb (Tue Dec 13 00:49:24 2016) [sssd[pam]] [sysdb_merge_res_ts_attrs] (0x2000): TS cache doesn't contain this DN, skipping (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_check_user_search] (0x0400): Returning info for user [tom@mds.xyz@mds.xyz] (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pd_set_primary_name] (0x0400): User's primary name is tom@mds.xyz (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_initgr_cache_set] (0x2000): [MDS.XYZ\tom] added to PAM initgroup cache (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data: (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_AUTHENTICATE (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): domain: mds.xyz (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): user: tom@mds.xyz (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): service: sshd (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): tty: ssh (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): rhost: 192.168.0.208 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 1 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 12455 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): logon name: MDS.XYZ\tom (Tue Dec 13 00:49:24 2016) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x7f4deb3736c0 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x7f4deab76c60:3:tom@mds.xyz@mds.xyz] (Tue Dec 13 00:49:24 2016) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x7f4deb3736c0 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x7f4deb36cf90 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching. (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_dp_process_reply] (0x0200): received: [6 (Permission denied)][mds.xyz] (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [6]: Permission denied. (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_reply] (0x0200): blen: 72 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7f4deb3685c0][21] (Tue Dec 13 00:49:29 2016) [sssd[pam]] [pam_initgr_cache_remove] (0x2000): [MDS.XYZ\tom] removed from PAM initgroup cache (Tue Dec 13 00:49:29 2016) [sssd[pam]] [pam_initgr_cache_remove] (0x2000): [MDS.XYZ\tom] removed from PAM initgroup cache (Tue Dec 13 00:50:24 2016) [sssd[pam]] [idle_handler] (0x2000): Terminating idle client [0x7f4deb3685c0][21] (Tue Dec 13 00:50:24 2016) [sssd[pam]] [client_close_fn] (0x2000): Terminated client [0x7f4deb3685c0][21]
On (13/12/16 00:52), TomK wrote:
On 12/13/2016 12:27 AM, TomK wrote:
Tossing this here as well as I'm already chatting on the FreeIPA mailing list about this but figured I'd post here as well.
Is this considered a bug?
(Sun Dec 11 03:26:13 2016) [sssd[pam]] [pam_dp_process_reply] (0x0200): received: [4 (System error)][mds.xyz] (Sun Dec 11 03:26:13 2016) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [4]: System error.
Config is basic in what comes from the FreeIPA configuration:
[root@idmipa01 sssd]# cat /etc/sssd/sssd.conf [domain/nix.mds.xyz] debug_level = 9
cache_credentials = True krb5_store_password_if_offline = True ipa_domain = nix.mds.xyz id_provider = ipa auth_provider = ipa access_provider = ipa ipa_hostname = idmipa01.nix.mds.xyz chpass_provider = ipa ipa_server = idmipa01.nix.mds.xyz ipa_server_mode = True ldap_tls_cacert = /etc/ipa/ca.crt
[sssd] debug_level = 9 services = nss, sudo, pam, ssh config_file_version = 2 domains = nix.mds.xyz
[nss] debug_level = 9 memcache_timeout = 600 homedir_substring = /home
[pam] debug_level = 9
[sudo]
[autofs]
[ssh]
[pac] debug_level = 9
[ifp]
[root@idmipa01 sssd]# cat /etc/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 = NIX.MDS.XYZ # dns_lookup_realm = false 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] NIX.MDS.XYZ = { kdc = idmipa01.nix.mds.xyz:88 master_kdc = idmipa01.nix.mds.xyz:88 admin_server = idmipa01.nix.mds.xyz:749 default_domain = nix.mds.xyz pkinit_anchors = FILE:/etc/ipa/ca.crt
auth_to_local = RULE:[1:$1@$0](^.*@MDS.XYZ$)s/@MDS.XYZ/@mds.xyz/ auth_to_local = DEFAULT }
[domain_realm] .nix.mds.xyz = NIX.MDS.XYZ nix.mds.xyz = NIX.MDS.XYZ
[dbmodules] NIX.MDS.XYZ = { db_library = ipadb.so }
[root@idmipa01 sssd]#
Ok, upgraded to sssd 1.14. Now the message reads:
(Tue Dec 13 00:49:24 2016) [sssd[pam]] [merge_msg_ts_attrs] (0x2000): No such DN in the timestamp cache: name=tom@mds.xyz,cn=users,cn=mds.xyz,cn=sysdb (Tue Dec 13 00:49:24 2016) [sssd[pam]] [sysdb_merge_res_ts_attrs] (0x2000): TS cache doesn't contain this DN, skipping (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_check_user_search] (0x0400): Returning info for user [tom@mds.xyz@mds.xyz] (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pd_set_primary_name] (0x0400): User's primary name is tom@mds.xyz (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_initgr_cache_set] (0x2000): [MDS.XYZ\tom] added to PAM initgroup cache (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data: (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_AUTHENTICATE (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): domain: mds.xyz (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): user: tom@mds.xyz (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): service: sshd (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): tty: ssh (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): rhost: 192.168.0.208 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 1 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 12455 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): logon name: MDS.XYZ\tom (Tue Dec 13 00:49:24 2016) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x7f4deb3736c0 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x7f4deab76c60:3:tom@mds.xyz@mds.xyz] (Tue Dec 13 00:49:24 2016) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x7f4deb3736c0 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x7f4deb36cf90 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching. (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_dp_process_reply] (0x0200): received: [6 (Permission denied)][mds.xyz]
I think this message is crystal clear.
I would recommend to look into domain log (and also probably krb5_child) @see also our wiki https://fedorahosted.org/sssd/wiki/Troubleshooting#TroubleshootingAuthentica...
LS
On Tue, Dec 13, 2016 at 09:22:36AM +0100, Lukas Slebodnik wrote:
On (13/12/16 00:52), TomK wrote:
On 12/13/2016 12:27 AM, TomK wrote:
Tossing this here as well as I'm already chatting on the FreeIPA mailing list about this but figured I'd post here as well.
Is this considered a bug?
(Sun Dec 11 03:26:13 2016) [sssd[pam]] [pam_dp_process_reply] (0x0200): received: [4 (System error)][mds.xyz] (Sun Dec 11 03:26:13 2016) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [4]: System error.
Config is basic in what comes from the FreeIPA configuration:
[root@idmipa01 sssd]# cat /etc/sssd/sssd.conf [domain/nix.mds.xyz] debug_level = 9
cache_credentials = True krb5_store_password_if_offline = True ipa_domain = nix.mds.xyz id_provider = ipa auth_provider = ipa access_provider = ipa ipa_hostname = idmipa01.nix.mds.xyz chpass_provider = ipa ipa_server = idmipa01.nix.mds.xyz ipa_server_mode = True ldap_tls_cacert = /etc/ipa/ca.crt
[sssd] debug_level = 9 services = nss, sudo, pam, ssh config_file_version = 2 domains = nix.mds.xyz
[nss] debug_level = 9 memcache_timeout = 600 homedir_substring = /home
[pam] debug_level = 9
[sudo]
[autofs]
[ssh]
[pac] debug_level = 9
[ifp]
[root@idmipa01 sssd]# cat /etc/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 = NIX.MDS.XYZ # dns_lookup_realm = false 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] NIX.MDS.XYZ = { kdc = idmipa01.nix.mds.xyz:88 master_kdc = idmipa01.nix.mds.xyz:88 admin_server = idmipa01.nix.mds.xyz:749 default_domain = nix.mds.xyz pkinit_anchors = FILE:/etc/ipa/ca.crt
auth_to_local = RULE:[1:$1@$0](^.*@MDS.XYZ$)s/@MDS.XYZ/@mds.xyz/ auth_to_local = DEFAULT }
[domain_realm] .nix.mds.xyz = NIX.MDS.XYZ nix.mds.xyz = NIX.MDS.XYZ
[dbmodules] NIX.MDS.XYZ = { db_library = ipadb.so }
[root@idmipa01 sssd]#
Ok, upgraded to sssd 1.14. Now the message reads:
(Tue Dec 13 00:49:24 2016) [sssd[pam]] [merge_msg_ts_attrs] (0x2000): No such DN in the timestamp cache: name=tom@mds.xyz,cn=users,cn=mds.xyz,cn=sysdb (Tue Dec 13 00:49:24 2016) [sssd[pam]] [sysdb_merge_res_ts_attrs] (0x2000): TS cache doesn't contain this DN, skipping (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_check_user_search] (0x0400): Returning info for user [tom@mds.xyz@mds.xyz] (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pd_set_primary_name] (0x0400): User's primary name is tom@mds.xyz (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_initgr_cache_set] (0x2000): [MDS.XYZ\tom] added to PAM initgroup cache (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data: (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_AUTHENTICATE (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): domain: mds.xyz (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): user: tom@mds.xyz (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): service: sshd (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): tty: ssh (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): rhost: 192.168.0.208 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 1 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 12455 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_print_data] (0x0100): logon name: MDS.XYZ\tom (Tue Dec 13 00:49:24 2016) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x7f4deb3736c0 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x7f4deab76c60:3:tom@mds.xyz@mds.xyz] (Tue Dec 13 00:49:24 2016) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x7f4deb3736c0 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x7f4deb36cf90 (Tue Dec 13 00:49:24 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching. (Tue Dec 13 00:49:24 2016) [sssd[pam]] [pam_dp_process_reply] (0x0200): received: [6 (Permission denied)][mds.xyz]
I think this message is crystal clear.
I would recommend to look into domain log (and also probably krb5_child) @see also our wiki https://fedorahosted.org/sssd/wiki/Troubleshooting#TroubleshootingAuthentica...
But at least now the authtok is being sent so the domain logs and the krb5_child should be more useful.
sssd-users@lists.fedorahosted.org