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=[e-mail]
Jul 10 17:37:47 MyIssueMachine sshd[42400]: pam_sss(sshd:account): Access denied for user [e-mail]: 4 (System error)
Jul 10 17:37:47 MyIssueMachine sshd[42400]: Failed password for [e-mail] from 192.168.150.15 port 51594 ssh2
Jul 10 17:37:47 MyIssueMachine sshd[42400]: fatal: Access denied for user [e-mail] 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!

[Striker Leggette]

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=[e-mail]
> Jul 10 17:37:47 MyIssueMachine sshd[42400]: pam_sss(sshd:account): 
> Access denied for user [e-mail]:4 (System error)
> Jul 10 17:37:47 MyIssueMachine sshd[42400]: Failed password for 
> [e-mail] from 192.168.150.15 port 51594 ssh2
> Jul 10 17:37:47 MyIssueMachine sshd[42400]: fatal: Access denied for 
> user [e-mail] by PAM account configuration [preauth]

答复: Re: The Direct Integration between SSSD and Active Directory , Access Control via GPO, logon to server failed uncertain

[程 波]

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 
发送时间: 2017年7月10日 21:05
收件人: [e-mail]
主题: [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=[e-mail]
Jul 10 17:37:47 MyIssueMachine sshd[42400]: pam_sss(sshd:account): Access denied for user [e-mail]: 4 (System error)
Jul 10 17:37:47 MyIssueMachine sshd[42400]: Failed password for [e-mail] from 192.168.150.15 port 51594 ssh2
Jul 10 17:37:47 MyIssueMachine sshd[42400]: fatal: Access denied for user [e-mail] by PAM account configuration [preauth]

答复: Re: The Direct Integration between SSSD and Active Directory , Access Control via GPO, logon to server failed uncertain

[程 波]

程 波 已与你共享 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 
发送时间: 2017年7月10日 21:05
收件人: [e-mail]
主题: [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=[e-mail]
Jul 10 17:37:47 MyIssueMachine sshd[42400]: pam_sss(sshd:account): Access denied for user [e-mail]: 4 (System error)
Jul 10 17:37:47 MyIssueMachine sshd[42400]: Failed password for [e-mail] from 192.168.150.15 port 51594 ssh2
Jul 10 17:37:47 MyIssueMachine sshd[42400]: fatal: Access denied for user [e-mail] by PAM account configuration [preauth]

����: Re: The Direct Integration between SSSD and Active Directory , Access Control via GPO, logon to server failed uncertain

[Jakub Hrozek]

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?

����: Re: The Direct Integration between SSSD and Active Directory , Access Control via GPO, logon to server failed uncertain

[Michal Židek]

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 -- [e-mail]
> To unsubscribe send an email to [e-mail]

����: Re: The Direct Integration between SSSD and Active Directory , Access Control via GPO, logon to server failed uncertain

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.

����: Re: The Direct Integration between SSSD and Active Directory , Access Control via GPO, logon to server failed uncertain

[Jakub Hrozek]

On Fri, Jul 14, 2017 at 02:31:39AM -0000, [e-mail] 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..