Bug 1177140 - gpo_child fails if "log level" is enabled in smb.conf
Summary: gpo_child fails if "log level" is enabled in smb.conf
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: sssd
Version: 7.1
Hardware: All
OS: Linux
medium
medium
Target Milestone: rc
: ---
Assignee: Jakub Hrozek
QA Contact: Kaushik Banerjee
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2014-12-24 12:50 UTC by Prasad Kulkarni
Modified: 2020-05-02 17:54 UTC (History)
13 users (show)

Fixed In Version: sssd-1.12.2-40.el7
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2015-03-05 10:35:12 UTC
Target Upstream Version:


Attachments (Terms of Use)
sssd domain logs (79.35 KB, text/plain)
2014-12-24 12:50 UTC, Prasad Kulkarni
no flags Details


Links
System ID Private Priority Status Summary Last Updated
Github SSSD sssd issues 3584 0 None None None 2020-05-02 17:54:40 UTC
Github SSSD sssd issues 3585 0 None None None 2020-05-02 17:54:46 UTC
Github SSSD sssd issues 3586 0 None None None 2020-05-02 17:54:53 UTC
Red Hat Product Errata RHBA-2015:0441 0 normal SHIPPED_LIVE sssd bug fix and enhancement update 2015-03-05 15:05:27 UTC

Description Prasad Kulkarni 2014-12-24 12:50:12 UTC
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
$

Comment 2 Jakub Hrozek 2015-01-05 13:38:48 UTC
Do you still have a system that reproduces the error? If so, can you give me access?

Comment 7 Jakub Hrozek 2015-01-06 13:56:09 UTC
Upstream ticket:
https://fedorahosted.org/sssd/ticket/2542

Comment 8 Jakub Hrozek 2015-01-06 13:56:16 UTC
Upstream ticket:
https://fedorahosted.org/sssd/ticket/2543

Comment 11 Jakub Hrozek 2015-01-07 08:27:13 UTC
Upstream ticket:
https://fedorahosted.org/sssd/ticket/2544

Comment 12 Jakub Hrozek 2015-01-07 08:37:43 UTC
The root cause is https://bugzilla.samba.org/show_bug.cgi?id=11036 but we need to work around the issue in SSSD...

Comment 13 Jakub Hrozek 2015-01-07 08:52:35 UTC
QE: To reproduce, set "log level" to a high number in smb.conf

Comment 14 Jakub Hrozek 2015-01-07 10:40:39 UTC
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.

Comment 15 Jakub Hrozek 2015-01-13 16:56:19 UTC
    master:
        f00a61b6079d8de81432077a59daf015d85800d2
        16cb0969f0a9ea71524d852077d6a480740d4f12
        bb7ddd2be9847bfb07395341c7623da1b104b8a6 
    sssd-1-12:
        f00a61b6079d8de81432077a59daf015d85800d2
        16cb0969f0a9ea71524d852077d6a480740d4f12
        bb7ddd2be9847bfb07395341c7623da1b104b8a6

Comment 16 Jakub Hrozek 2015-01-13 17:11:48 UTC
Additional fixes:
    master: ccff8e75940963a0f68f86efcddc37133318abfa
    sssd-1-12: 6cdefffcc399f09ee29aacf858905bfad179f1b3

Comment 18 Sumit Bose 2015-01-14 15:05:31 UTC
*** Bug 1182183 has been marked as a duplicate of this bug. ***

Comment 19 Dan Lavu 2015-01-29 23:59:08 UTC
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
#########################################################################

Comment 21 errata-xmlrpc 2015-03-05 10:35:12 UTC
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


Note You need to log in before you can comment on or make changes to this bug.