Red Hat Bugzilla – Bug 1177140
gpo_child fails if "log level" is enabled in smb.conf
Last modified: 2015-08-13 05:15:44 EDT
Created attachment 972738 [details] sssd domain logs Description of problem: While testing the GPO functionality during a test day, I came across Internal error appearing in the domain logs and denying all users to login. Note: Testing on another 7.1 client against the same AD Server seems to work fine. Appropriate users were denied and appropriate users were allowed access. This could be an issue specific to a system, so I am logging this bug. Version-Release number of selected component (if applicable): # rpm -q sssd sssd-1.12.2-39.el7.x86_64 How reproducible: Always Steps to Reproduce: 1. Add a user allowed_user and denied_user to AD. 2. Add the denied_user to "deny log on locally" in the GPO of AD Server. 3. The GPO is set to enforcing. 4. On the client side, the domain has: [domain/sssdad2012.com] ad_domain = sssdad2012.com krb5_realm = SSSDAD2012.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/%d/%u access_provider = ad ad_gpo_access_control = enforcing debug_level = 9 5. Auth as allowed_user. Actual results: # ssh -l allowed_user@sssdad2012.com localhost allowed_user@sssdad2012.com@localhost's password: Connection closed by ::1 /var/log/secure shows: Dec 24 17:55:13 dhcp210-121 sshd[36662]: pam_sss(sshd:auth): authentication success; logname= uid=0 euid=0 tty=ssh ruser= rhost=localhost user=allowed_user@sssdad2012.com Dec 24 17:55:13 dhcp210-121 sshd[36662]: pam_sss(sshd:account): Access denied for user allowed_user@sssdad2012.com: 4 (System error) Domain log shows(the full domain log is attached): (Wed Dec 24 17:55:13 2014) [sssd[be[sssdad2012.com]]] [gpo_cse_done] (0x0020): Error in gpo_child: [1852383332][Unknown error 1852383332] (Wed Dec 24 17:55:13 2014) [sssd[be[sssdad2012.com]]] [ad_gpo_cse_done] (0x0400): gpo_guid: {6723952F-D149-416A-8EE0-7F3C4191A9B0} (Wed Dec 24 17:55:13 2014) [sssd[be[sssdad2012.com]]] [ad_gpo_cse_done] (0x0040): Unable to retrieve policy data: [1852383332](Unknown error 1852383332} (Wed Dec 24 17:55:13 2014) [sssd[be[sssdad2012.com]]] [ad_gpo_access_done] (0x0040): GPO-based access control failed. (Wed Dec 24 17:55:13 2014) [sssd[be[sssdad2012.com]]] [be_pam_handler_callback] (0x0100): Backend returned: (3, 4, Unknown error 1852383332) [Internal Error (System error)] Expected results: Additional info: Removing the option "ad_gpo_access_control = enforcing" from sssd.conf and restarting sssd, allows login to allowed_user: # ssh -l allowed_user@sssdad2012.com localhost allowed_user@sssdad2012.com@localhost's password: Last failed login: Wed Dec 24 17:55:13 IST 2014 from localhost on ssh:notty There were 8 failed login attempts since the last successful login. Last login: Wed Dec 24 15:30:07 2014 from localhost $
Do you still have a system that reproduces the error? If so, can you give me access?
Upstream ticket: https://fedorahosted.org/sssd/ticket/2542
Upstream ticket: https://fedorahosted.org/sssd/ticket/2543
Upstream ticket: https://fedorahosted.org/sssd/ticket/2544
The root cause is https://bugzilla.samba.org/show_bug.cgi?id=11036 but we need to work around the issue in SSSD...
QE: To reproduce, set "log level" to a high number in smb.conf
Prasad, I left a fixed version of sssd installed on the test machine, feel free to use it to verify the fix or run any additional test cases. Thank you very much for reporting the problem.
master: f00a61b6079d8de81432077a59daf015d85800d2 16cb0969f0a9ea71524d852077d6a480740d4f12 bb7ddd2be9847bfb07395341c7623da1b104b8a6 sssd-1-12: f00a61b6079d8de81432077a59daf015d85800d2 16cb0969f0a9ea71524d852077d6a480740d4f12 bb7ddd2be9847bfb07395341c7623da1b104b8a6
Additional fixes: master: ccff8e75940963a0f68f86efcddc37133318abfa sssd-1-12: 6cdefffcc399f09ee29aacf858905bfad179f1b3
*** Bug 1182183 has been marked as a duplicate of this bug. ***
Verified the fix in sssd-ad-1.12.2-39.el7.x86_64. Adding the log parameter in samba no longer breaks gpo_child ######################################################################### gpo_child.log:(Wed Jan 28 15:24:55 2015) [[sssd[gpo_child[16706]]]] [perform_smb_operations] (0x0400): sysvol_gpt_version: 65537 gpo_child.log:(Wed Jan 28 15:24:55 2015) [[sssd[gpo_child[16706]]]] [pack_buffer] (0x0400): result [0] gpo_child.log:(Wed Jan 28 15:24:55 2015) [[sssd[gpo_child[16706]]]] [prepare_response] (0x4000): r->size: 8 gpo_child.log:(Wed Jan 28 15:24:55 2015) [[sssd[gpo_child[16706]]]] [main] (0x0400): gpo_child completed successfully gpo_child.log:(Wed Jan 28 15:25:01 2015) [[sssd[gpo_child[16765]]]] [main] (0x0400): gpo_child started. gpo_child.log:(Wed Jan 28 15:25:01 2015) [[sssd[gpo_child[16765]]]] [main] (0x0400): context initialized gpo_child.log:(Wed Jan 28 15:25:01 2015) [[sssd[gpo_child[16765]]]] [unpack_buffer] (0x0400): cached_gpt_version: 65537 gpo_child.log:(Wed Jan 28 15:25:01 2015) [[sssd[gpo_child[16765]]]] [unpack_buffer] (0x4000): smb_server length: 23 gpo_child.log:(Wed Jan 28 15:25:01 2015) [[sssd[gpo_child[16765]]]] [unpack_buffer] (0x4000): smb_server: smb://ad1.example.local gpo_child.log:(Wed Jan 28 15:25:01 2015) [[sssd[gpo_child[16765]]]] [unpack_buffer] (0x4000): smb_share length: 7 gpo_child.log:(Wed Jan 28 15:25:01 2015) [[sssd[gpo_child[16765]]]] [unpack_buffer] (0x4000): smb_share: /sysvol gpo_child.log:(Wed Jan 28 15:25:01 2015) [[sssd[gpo_child[16765]]]] [unpack_buffer] (0x4000): smb_path length: 62 gpo_child.log:(Wed Jan 28 15:25:01 2015) [[sssd[gpo_child[16765]]]] [unpack_buffer] (0x4000): smb_path: /example.local/Policies/{03395DC9-7B06-47CA-B8B1-0BCACC9140DC} gpo_child.log:(Wed Jan 28 15:25:01 2015) [[sssd[gpo_child[16765]]]] [unpack_buffer] (0x4000): smb_cse_suffix length: 49 gpo_child.log:(Wed Jan 28 15:25:01 2015) [[sssd[gpo_child[16765]]]] [unpack_buffer] (0x4000): smb_cse_suffix: /Machine/Microsoft/Windows NT/SecEdit/GptTmpl.inf gpo_child.log:(Wed Jan 28 15:25:01 2015) [[sssd[gpo_child[16765]]]] [main] (0x0400): performing smb operations gpo_child.log:(Wed Jan 28 15:25:01 2015) [[sssd[gpo_child[16765]]]] [copy_smb_file_to_gpo_cache] (0x0400): smb_uri: smb://ad1.example.local/sysvol/example.local/Policies/{03395DC9-7B06-47CA-B8B1-0BCACC9 #########################################################################
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://rhn.redhat.com/errata/RHBA-2015-0441.html