The Direct Integration between SSSD and Active Directory , Access Control via GPO, logon to server failed uncertain
Hi Expert,
1. Environment * Windows Server 2012 R2 Active Directory. * sudoRule schema extended * CentOS 7.3 (1611) Client, joined to domain by using realm * selinux -> permissive 2. Configuration file * sssd.conf [sssd] domains = mydomain.com config_file_version = 2 services = nss, pam, sudo
[domain/mydomain.com] ad_domain = mydomain.com krb5_realm = MYDOMAIN.COM realmd_tags = manages-system joined-with-samba cache_credentials = True id_provider = ad krb5_store_password_if_offline = True default_shell = /bin/bash ldap_id_mapping = True use_fully_qualified_names = True fallback_homedir = /home/%u@%d access_provider = ad ad_gpo_access_control = enforcing
* smb.conf [global] workgroup = SAMBA security = user
passdb backend = tdbsam
printing = cups printcap name = cups load printers = yes cups options = raw
[homes] comment = Home Directories valid users = %S, %D%w%S browseable = No read only = No inherit acls = Yes
[printers] comment = All Printers path = /var/tmp printable = Yes create mask = 0600 browseable = No
[print$] comment = Printer Drivers path = /var/lib/samba/drivers write list = root create mask = 0664 directory mask = 0775
* nsswitch.conf passwd: files sss shadow: files sss group: files sss hosts: files dns myhostname bootparams: nisplus [NOTFOUND=return] files ethers: files netmasks: files networks: files protocols: files rpc: files services: files sss netgroup: files sss publickey: nisplus automount: files sss aliases: files nisplus sudoers: files sss
3. problem description * after joining the CentOS7 to Active Directory domain , it's not stable that a domain user logon to the machina via ssh. * /var/log/secure show Jul 10 17:37:47 MyIssueMachine sshd[42400]: pam_sss(sshd:auth): authentication success; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.150.15 user=MyUser@mydomain.com Jul 10 17:37:47 MyIssueMachine sshd[42400]: pam_sss(sshd:account): Access denied for user MyUser@mydomain.com: 4 (System error) Jul 10 17:37:47 MyIssueMachine sshd[42400]: Failed password for MyUser@mydomain.com from 192.168.150.15 port 51594 ssh2 Jul 10 17:37:47 MyIssueMachine sshd[42400]: fatal: Access denied for user MyUser@mydomain.com by PAM account configuration [preauth] * /var/log/sssd/sssd_pam.log (Mon Jul 10 16:02:24 2017) [sssd[pam]] [pam_dp_process_reply] (0x0200): received: [4 (System error)][mydomain.com] (Mon Jul 10 16:02:24 2017) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [4]: System error. (Mon Jul 10 16:02:24 2017) [sssd[pam]] [pam_reply] (0x0200): blen: 30 (Mon Jul 10 16:02:24 2017) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7fe3abac60a0][23] (Mon Jul 10 16:02:24 2017) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7fe3abac60a0][23] (Mon Jul 10 16:02:24 2017) [sssd[pam]] [client_recv] (0x0200): Client disconnected! (Mon Jul 10 16:02:24 2017) [sssd[pam]] [client_close_fn] (0x2000): Terminated client [0x7fe3abac60a0][23]
Thanks in advance!
You will need to add 'debug_level = 9' within the [domain/mydomain.com] section of sssd, restart sssd and then provide the logs from /var/log/sssd/sssd_mydomain.com.log for the block of time when this happened:
On 07/10/2017 06:12 AM, 程 波 wrote:
Jul 10 17:37:47 MyIssueMachine sshd[42400]: pam_sss(sshd:auth): authentication success; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.150.15 user=MyUser@mydomain.com Jul 10 17:37:47 MyIssueMachine sshd[42400]: pam_sss(sshd:account): Access denied for user MyUser@mydomain.com:4 (System error) Jul 10 17:37:47 MyIssueMachine sshd[42400]: Failed password for MyUser@mydomain.com from 192.168.150.15 port 51594 ssh2 Jul 10 17:37:47 MyIssueMachine sshd[42400]: fatal: Access denied for user MyUser@mydomain.com by PAM account configuration [preauth]
before getting the log , I've set sss_debuglevel=9.
I got the info from https://docs.pagure.org/SSSD.sssd/users/troubleshooting.html :
and "System Error （4） also be found from my logs"
---
I’m receiving System Error (4) in the authentication logs
* System Error is an “Unhandled Exception” during authentication. It can either be an SSSD bug or a fatal error during authentication. Either way, please bring up your issue on the sssd-users mailing listhttps://lists.fedorahosted.org/admin/lists/sssd-users.lists.fedorahosted.org/
---
Debugging and troubleshooting SSSD — SSSD documentationhttps://docs.pagure.org/SSSD.sssd/users/troubleshooting.html docs.pagure.org SSSD debug logs¶ Each process that SSSD consists of is represented by a section in the sssd.conf config file. To enable debugging persistently across SSSD service ...
________________________________ 发件人: Striker Leggette striker@terranforge.com 发送时间: 2017年7月10日 21:05 收件人: sssd-users@lists.fedorahosted.org 主题: [SSSD-users] Re: The Direct Integration between SSSD and Active Directory , Access Control via GPO, logon to server failed uncertain
You will need to add 'debug_level = 9' within the [domain/mydomain.com] section of sssd, restart sssd and then provide the logs from /var/log/sssd/sssd_mydomain.com.log for the block of time when this happened:
On 07/10/2017 06:12 AM, 程 波 wrote: Jul 10 17:37:47 MyIssueMachine sshd[42400]: pam_sss(sshd:auth): authentication success; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.150.15 user=MyUser@mydomain.commailto:user=MyUser@mydomain.com Jul 10 17:37:47 MyIssueMachine sshd[42400]: pam_sss(sshd:account): Access denied for user MyUser@mydomain.commailto:MyUser@mydomain.com: 4 (System error) Jul 10 17:37:47 MyIssueMachine sshd[42400]: Failed password for MyUser@mydomain.commailto:MyUser@mydomain.com from 192.168.150.15 port 51594 ssh2 Jul 10 17:37:47 MyIssueMachine sshd[42400]: fatal: Access denied for user MyUser@mydomain.commailto:MyUser@mydomain.com by PAM account configuration [preauth]
程 波 已与你共享 OneDrive 文件。若要查看，请单击下面的链接。
https://1drv.ms/u/s!AnBXPe2fk7BFjDE6MV_iHeIJ6Xub [https://r1.res.office365.com/owa/prem/images/dc-generic_20.png]https://1drv.ms/u/s!AnBXPe2fk7BFjDE6MV_iHeIJ6Xub
sssd_mydomain.com.loghttps://1drv.ms/u/s!AnBXPe2fk7BFjDE6MV_iHeIJ6Xub
the debug log attached.
________________________________ 发件人: Striker Leggette striker@terranforge.com 发送时间: 2017年7月10日 21:05 收件人: sssd-users@lists.fedorahosted.org 主题: [SSSD-users] Re: The Direct Integration between SSSD and Active Directory , Access Control via GPO, logon to server failed uncertain
You will need to add 'debug_level = 9' within the [domain/mydomain.com] section of sssd, restart sssd and then provide the logs from /var/log/sssd/sssd_mydomain.com.log for the block of time when this happened:
On 07/10/2017 06:12 AM, 程 波 wrote: Jul 10 17:37:47 MyIssueMachine sshd[42400]: pam_sss(sshd:auth): authentication success; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.150.15 user=MyUser@mydomain.commailto:user=MyUser@mydomain.com Jul 10 17:37:47 MyIssueMachine sshd[42400]: pam_sss(sshd:account): Access denied for user MyUser@mydomain.commailto:MyUser@mydomain.com: 4 (System error) Jul 10 17:37:47 MyIssueMachine sshd[42400]: Failed password for MyUser@mydomain.commailto:MyUser@mydomain.com from 192.168.150.15 port 51594 ssh2 Jul 10 17:37:47 MyIssueMachine sshd[42400]: fatal: Access denied for user MyUser@mydomain.commailto:MyUser@mydomain.com by PAM account configuration [preauth]
On Tue, Jul 11, 2017 at 07:22:41AM +0000, 程 波 wrote:
程 波 已与你共享 OneDrive 文件。若要查看，请单击下面的链接。
https://1drv.ms/u/s!AnBXPe2fk7BFjDE6MV_iHeIJ6Xub [https://r1.res.office365.com/owa/prem/images/dc-generic_20.png]https://1drv.ms/u/s!AnBXPe2fk7BFjDE6MV_iHeIJ6Xub
sssd_mydomain.com.loghttps://1drv.ms/u/s!AnBXPe2fk7BFjDE6MV_iHeIJ6Xub
the debug log attached.
From the debug logs: (Tue Jul 11 15:08:25 2017) [sssd[be[mydomain.com]]] [gpo_cse_done] (0x0020): ad_gpo_parse_gpo_child_response failed: [22][Invalid argument] (Tue Jul 11 15:08:25 2017) [sssd[be[mydomain.com]]] [ad_gpo_cse_done] (0x0400): gpo_guid: {241B7E35-2AA1-4004-A82B-DA333FE6DC2C} (Tue Jul 11 15:08:25 2017) [sssd[be[mydomain.com]]] [ad_gpo_cse_done] (0x0040): Unable to retrieve policy data: [22](Invalid argument} (Tue Jul 11 15:08:25 2017) [sssd[be[mydomain.com]]] [ad_gpo_access_done] (0x0040): GPO-based access control failed. (Tue Jul 11 15:08:25 2017) [sssd[be[mydomain.com]]] [dp_req_done] (0x0400): DP Request [PAM Account #3]: Request handler finished [0]: Success (Tue Jul 11 15:08:25 2017) [sssd[be[mydomain.com]]] [_dp_req_recv] (0x0400): DP Request [PAM Account #3]: Receiving request data. (Tue Jul 11 15:08:25 2017) [sssd[be[mydomain.com]]] [dp_req_destructor] (0x0400): DP Request [PAM Account #3]: Request removed. (Tue Jul 11 15:08:25 2017) [sssd[be[mydomain.com]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 (Tue Jul 11 15:08:25 2017) [sssd[be[mydomain.com]]] [dp_method_enabled] (0x0400): Target selinux is not configured (Tue Jul 11 15:08:25 2017) [sssd[be[mydomain.com]]] [dp_pam_reply] (0x1000): DP Request [PAM Account #3]: Sending result [4][mydomain.com]
So there was some error during access control. If you are not using GPO access control from your Windows domain, then you can disable the GPO processing with: ad_gpo_access_control = permissive
I don't know specifically what causes the error. Maybe Michal knows?
On 07/12/2017 04:36 PM, Jakub Hrozek wrote:
On Tue, Jul 11, 2017 at 07:22:41AM +0000, 程 波 wrote:
程 波 已与你共享 OneDrive 文件。若要查看，请单击下面的链接。
https://1drv.ms/u/s!AnBXPe2fk7BFjDE6MV_iHeIJ6Xub [https://r1.res.office365.com/owa/prem/images/dc-generic_20.png]https://1drv.ms/u/s!AnBXPe2fk7BFjDE6MV_iHeIJ6Xub
sssd_mydomain.com.loghttps://1drv.ms/u/s!AnBXPe2fk7BFjDE6MV_iHeIJ6Xub
the debug log attached.
From the debug logs: (Tue Jul 11 15:08:25 2017) [sssd[be[mydomain.com]]] [gpo_cse_done] (0x0020): ad_gpo_parse_gpo_child_response failed: [22][Invalid argument]
The above means that the GPO child response does not have expected format. gpo_child.log (in the same directory as domain log) could provide more info.
Michal
(Tue Jul 11 15:08:25 2017) [sssd[be[mydomain.com]]] [ad_gpo_cse_done] (0x0400): gpo_guid: {241B7E35-2AA1-4004-A82B-DA333FE6DC2C} (Tue Jul 11 15:08:25 2017) [sssd[be[mydomain.com]]] [ad_gpo_cse_done] (0x0040): Unable to retrieve policy data: [22](Invalid argument} (Tue Jul 11 15:08:25 2017) [sssd[be[mydomain.com]]] [ad_gpo_access_done] (0x0040): GPO-based access control failed. (Tue Jul 11 15:08:25 2017) [sssd[be[mydomain.com]]] [dp_req_done] (0x0400): DP Request [PAM Account #3]: Request handler finished [0]: Success (Tue Jul 11 15:08:25 2017) [sssd[be[mydomain.com]]] [_dp_req_recv] (0x0400): DP Request [PAM Account #3]: Receiving request data. (Tue Jul 11 15:08:25 2017) [sssd[be[mydomain.com]]] [dp_req_destructor] (0x0400): DP Request [PAM Account #3]: Request removed. (Tue Jul 11 15:08:25 2017) [sssd[be[mydomain.com]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 (Tue Jul 11 15:08:25 2017) [sssd[be[mydomain.com]]] [dp_method_enabled] (0x0400): Target selinux is not configured (Tue Jul 11 15:08:25 2017) [sssd[be[mydomain.com]]] [dp_pam_reply] (0x1000): DP Request [PAM Account #3]: Sending result [4][mydomain.com]
So there was some error during access control. If you are not using GPO access control from your Windows domain, then you can disable the GPO processing with: ad_gpo_access_control = permissive
I don't know specifically what causes the error. Maybe Michal knows? _______________________________________________ sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org
only a few logs in gpo_child.log,see below: ------------- (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [main] (0x0400): gpo_child started. (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [main] (0x0400): context initialized (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [unpack_buffer] (0x0400): cached_gpt_version: 1179676 (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [unpack_buffer] (0x4000): smb_server length: 33 (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [unpack_buffer] (0x4000): smb_server: smb://MyDC.mydoman.com (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [unpack_buffer] (0x4000): smb_share length: 7 (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [unpack_buffer] (0x4000): smb_share: /SysVol (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [unpack_buffer] (0x4000): smb_path length: 62 (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [unpack_buffer] (0x4000): smb_path: /mydomain.com/Policies/{241B7E35-2AA1-4004-A82B-DA333FE6DC2C} (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [unpack_buffer] (0x4000): smb_cse_suffix length: 49 (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [unpack_buffer] (0x4000): smb_cse_suffix: /Machine/Microsoft/Windows NT/SecEdit/GptTmpl.inf (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [main] (0x0400): performing smb operations (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [copy_smb_file_to_gpo_cache] (0x0400): smb_uri: smb://vwsr003105003.mydomain.com/SysVol/mydomain.com/Policies/{241B7E35-2AA1-4004-A82B-DA333FE6DC2C}/GPT.INI (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [copy_smb_file_to_gpo_cache] (0x0020): smbc_getFunctionOpen failed [110][Connection timed out] (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [perform_smb_operations] (0x0020): copy_smb_file_to_gpo_cache failed [110][Connection timed out] (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [main] (0x0020): perform_smb_operations failed.[110][Connection timed out]. (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [main] (0x0020): gpo_child failed!
----- Then I tried to test \mydomain.com samba share by using smbclient -L mydc.mydomain.com, looks like it works.
On Fri, Jul 14, 2017 at 02:31:39AM -0000, amoschb@hotmail.com wrote:
only a few logs in gpo_child.log,see below:
(Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [main] (0x0400): gpo_child started. (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [main] (0x0400): context initialized (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [unpack_buffer] (0x0400): cached_gpt_version: 1179676 (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [unpack_buffer] (0x4000): smb_server length: 33 (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [unpack_buffer] (0x4000): smb_server: smb://MyDC.mydoman.com (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [unpack_buffer] (0x4000): smb_share length: 7 (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [unpack_buffer] (0x4000): smb_share: /SysVol (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [unpack_buffer] (0x4000): smb_path length: 62 (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [unpack_buffer] (0x4000): smb_path: /mydomain.com/Policies/{241B7E35-2AA1-4004-A82B-DA333FE6DC2C} (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [unpack_buffer] (0x4000): smb_cse_suffix length: 49 (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [unpack_buffer] (0x4000): smb_cse_suffix: /Machine/Microsoft/Windows NT/SecEdit/GptTmpl.inf (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [main] (0x0400): performing smb operations (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [copy_smb_file_to_gpo_cache] (0x0400): smb_uri: smb://vwsr003105003.mydomain.com/SysVol/mydomain.com/Policies/{241B7E35-2AA1-4004-A82B-DA333FE6DC2C}/GPT.INI (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [copy_smb_file_to_gpo_cache] (0x0020): smbc_getFunctionOpen failed [110][Connection timed out] (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [perform_smb_operations] (0x0020): copy_smb_file_to_gpo_cache failed [110][Connection timed out] (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [main] (0x0020): perform_smb_operations failed.[110][Connection timed out]. (Tue Jul 11 15:08:25 2017) [[sssd[gpo_child[50647]]]] [main] (0x0020): gpo_child failed!
Well, here you go, the connection to the AD DC timed out. Is vwsr003105003.mydomain.com the DC you would expect to be contacted?
Either way, I think this is a bug, we should not return System Error here, but a nicer error message and switch to offline mode..
sssd-users@lists.fedorahosted.org
-
amoschb＠hotmail.com -
Jakub Hrozek -
Michal Židek -
Striker Leggette -
程 波