Bug 1306707
Summary: | Need better debug message when krb5_child returns an unhandled error, leading to a System Error PAM code | ||
---|---|---|---|
Product: | Red Hat Enterprise Linux 7 | Reporter: | gagriogi |
Component: | sssd | Assignee: | SSSD Maintainers <sssd-maint> |
Status: | CLOSED ERRATA | QA Contact: | shridhar <sgadekar> |
Severity: | high | Docs Contact: | |
Priority: | unspecified | ||
Version: | 7.3 | CC: | agk, grajaiya, jhrozek, lslebodn, mkosek, mzidek, pbrezina, sgoveas, sssd-maint |
Target Milestone: | rc | ||
Target Release: | --- | ||
Hardware: | x86_64 | ||
OS: | Linux | ||
Whiteboard: | |||
Fixed In Version: | sssd-1.15.2-33.el7 | Doc Type: | If docs needed, set a value |
Doc Text: | Story Points: | --- | |
Clone Of: | Environment: | ||
Last Closed: | 2017-08-01 08:58:07 UTC | Type: | Bug |
Regression: | --- | Mount Type: | --- |
Documentation: | --- | CRM: | |
Verified Versions: | Category: | --- | |
oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |
Cloudforms Team: | --- | Target Upstream Version: | |
Embargoed: |
Description
gagriogi
2016-02-11 16:00:55 UTC
Upstream ticket: https://fedorahosted.org/sssd/ticket/2955 master: b4dd0867c48e74703f8f7afbf9d5634238dffc1c sssd-1-14: eb730befa09cbb69ee61bdedd14fc2c8bf8a3434 sssd-1-13: 3ed51ca2740981bdce4c5efe965c15d5f707b220 As per commit, the additional information will be added in logs. master: b4dd0867c48e74703f8f7afbf9d5634238dffc1c + DEBUG(SSSDBG_IMPORTANT_INFO, + "The krb5_child process returned an error. Please inspect the " + "krb5_child.log file or the journal for more information\n"); I'm testing with sssd-1.15.2-30.el7.x86_64 and with modification as per #10, I don't see proposed information in the log files (/var/log/messages, secure, sssd_*) With 700 permission on tmp, user authentication fails with system_error_4. Following messages are observed in various files: in /var/log/messages: May 18 05:59:23 shr-r7-permanent [sssd[krb5_child[24206]]]: Credentials cache permissions incorrect (filename: /tmp/user_616401111) May 18 05:59:27 shr-r7-permanent [sssd[krb5_child[24215]]]: Credentials cache permissions incorrect (filename: /tmp/user_616401111) May 18 05:59:29 shr-r7-permanent [sssd[krb5_child[24216]]]: Credentials cache permissions incorrect (filename: /tmp/user_616401111) In /var/log/secure May 18 05:59:27 shr-r7-permanent sshd[24203]: pam_sss(sshd:auth): received for user fu1: 4 (System error) May 18 05:59:27 shr-r7-permanent sshd[24203]: Failed password for fu1 from ::1 port 33876 ssh2 May 18 05:59: In /var/log/sssd_sssd16.qe (Thu May 18 05:06:31 2017) [sssd[be[sssd16.qe]]] [parse_krb5_child_response] (0x0020): message too short. (Thu May 18 05:06:31 2017) [sssd[be[sssd16.qe]]] [krb5_auth_done] (0x0040): Could not parse child response [22]: Invalid argument (Thu May 18 05:06:31 2017) [sssd[be[sssd16.qe]]] [check_wait_queue] (0x1000): Wait queue for user [fu1] is empty. (Thu May 18 05:06:31 2017) [sssd[be[sssd16.qe]]] [krb5_auth_queue_done] (0x0040): krb5_auth_recv failed with: 22 (Thu May 18 05:06:31 2017) [sssd[be[sssd16.qe]]] [dp_req_done] (0x0400): DP Request [PAM Authenticate #3]: Request handler finished [0]: Success (Thu May 18 05:06:31 2017) [sssd[be[sssd16.qe]]] [_dp_req_recv] (0x0400): DP Request [PAM Authenticate #3]: Receiving request data. In /var/log/sssd/krb5_child.log (Thu May 18 05:06:31 2017) [[sssd[krb5_child[23515]]]] [create_ccache_dir] (0x0010): Check the ownership and permissions of krb5_ccachedir: [/tmp] . (Thu May 18 05:06:31 2017) [[sssd[krb5_child[23515]]]] [k5c_precreate_ccache] (0x0040): ccache creation failed. (Thu May 18 05:06:31 2017) [[sssd[krb5_child[23515]]]] [k5c_ccache_setup] (0x0040): Cannot precreate ccache (Thu May 18 05:06:31 2017) [[sssd[krb5_child[23515]]]] [privileged_krb5_setup] (0x0020): k5c_ccache_setup failed. (Thu May 18 05:06:31 2017) [[sssd[krb5_child[23515]]]] [main] (0x0020): privileged_krb5_setup failed. (Thu May 18 05:06:31 2017) [[sssd[krb5_child[23515]]]] [main] (0x0020): krb5_child failed! * Which is the log file that should print information as per commit? Or * Is additional logs in /var/log/message sufficient? Thank you for testing, this case is then not handled well. Please switch the bug to assigned, the fix will be super-easy. (In reply to Jakub Hrozek from comment #12) > Thank you for testing, this case is then not handled well. Please switch the > bug to assigned, the fix will be super-easy. switching bug to assigned. (In reply to shridhar from comment #11) > As per commit, the additional information will be added in logs. > > master: b4dd0867c48e74703f8f7afbf9d5634238dffc1c > > + DEBUG(SSSDBG_IMPORTANT_INFO, > + "The krb5_child process returned an error. Please inspect the > " > + "krb5_child.log file or the journal for more information\n"); > > > > I'm testing with sssd-1.15.2-30.el7.x86_64 and with modification as per > #10, I don't see proposed information in the log files (/var/log/messages, > secure, sssd_*) > > With 700 permission on tmp, user authentication fails with system_error_4. > Following messages are observed in various files: > > in /var/log/messages: > May 18 05:59:23 shr-r7-permanent [sssd[krb5_child[24206]]]: Credentials > cache permissions incorrect (filename: /tmp/user_616401111) > May 18 05:59:27 shr-r7-permanent [sssd[krb5_child[24215]]]: Credentials > cache permissions incorrect (filename: /tmp/user_616401111) > May 18 05:59:29 shr-r7-permanent [sssd[krb5_child[24216]]]: Credentials > cache permissions incorrect (filename: /tmp/user_616401111) > > In /var/log/secure > May 18 05:59:27 shr-r7-permanent sshd[24203]: pam_sss(sshd:auth): received > for user fu1: 4 (System error) > May 18 05:59:27 shr-r7-permanent sshd[24203]: Failed password for > fu1 from ::1 port 33876 ssh2 > May 18 05:59: > > > In /var/log/sssd_sssd16.qe > (Thu May 18 05:06:31 2017) [sssd[be[sssd16.qe]]] [parse_krb5_child_response] > (0x0020): message too short. > (Thu May 18 05:06:31 2017) [sssd[be[sssd16.qe]]] [krb5_auth_done] (0x0040): > Could not parse child response [22]: Invalid argument > (Thu May 18 05:06:31 2017) [sssd[be[sssd16.qe]]] [check_wait_queue] > (0x1000): Wait queue for user [fu1] is empty. > (Thu May 18 05:06:31 2017) [sssd[be[sssd16.qe]]] [krb5_auth_queue_done] > (0x0040): krb5_auth_recv failed with: 22 > (Thu May 18 05:06:31 2017) [sssd[be[sssd16.qe]]] [dp_req_done] (0x0400): DP > Request [PAM Authenticate #3]: Request handler finished [0]: Success > (Thu May 18 05:06:31 2017) [sssd[be[sssd16.qe]]] [_dp_req_recv] (0x0400): DP > Request [PAM Authenticate #3]: Receiving request data. > > In /var/log/sssd/krb5_child.log > (Thu May 18 05:06:31 2017) [[sssd[krb5_child[23515]]]] [create_ccache_dir] > (0x0010): Check the ownership and permissions of krb5_ccachedir: [/tmp] > . > (Thu May 18 05:06:31 2017) [[sssd[krb5_child[23515]]]] > [k5c_precreate_ccache] (0x0040): ccache creation failed. > (Thu May 18 05:06:31 2017) [[sssd[krb5_child[23515]]]] [k5c_ccache_setup] > (0x0040): Cannot precreate ccache > (Thu May 18 05:06:31 2017) [[sssd[krb5_child[23515]]]] > [privileged_krb5_setup] (0x0020): k5c_ccache_setup failed. > (Thu May 18 05:06:31 2017) [[sssd[krb5_child[23515]]]] [main] (0x0020): > privileged_krb5_setup failed. > (Thu May 18 05:06:31 2017) [[sssd[krb5_child[23515]]]] [main] (0x0020): > krb5_child failed! > > > > * Which is the log file that should print information as per commit? > Or > * Is additional logs in /var/log/message sufficient? Error message will be in /var/log/sssd/sssd_${domain}.log But you would need to increase debug_level to 2, which is not enabled by default. This use-case should be solved with the following commit: 7410f735b64937e0c2401c09b5cffc9c78b11849 verified with [root@shr-r7-permanent ~]# rpm -q sssd sssd-1.15.2-33.el7.x86_64 root@shr-r7-permanent ~]# cat /etc/sssd/sssd.conf [sssd] domains = sssd16.qe config_file_version = 2 services = nss, pam [domain/sssd16.qe] ad_domain = sssd16.qe krb5_realm = SSSD16.QE realmd_tags = manages-system joined-with-adcli cache_credentials = True id_provider = ad krb5_store_password_if_offline = True default_shell = /bin/bash #ldap_sasl_authid = SHR-R7-PERMANEN$ ldap_id_mapping = True use_fully_qualified_names = True fallback_homedir = /home/%u@%d access_provider = ad ldap_user_search_base = CN=Users,DC=sssd16,DC=qe ldap_group_search_base = CN=Users,DC=sssd16,DC=qe debug_level = 2 [root@shr-r7-permanent ~]# service sssd stop ; rm -rf /var/lib/sss/db/* ; rm -rf /var/log/sssd/* ; service sssd start Redirecting to /bin/systemctl stop sssd.service Redirecting to /bin/systemctl start sssd.service [root@shr-r7-permanent ~]# ll -d /tmp/ drwx------. 13 root root 4096 May 25 11:19 /tmp/ [root@shr-r7-permanent ~]# ssh -l fu1 localhost fu1@localhost's password: Permission denied, please try again. fu1@localhost's password: [root@shr-r7-permanent ~]# egrep 'krb5_auth_done' /var/log/sssd/sssd_sssd16.qe.log (Thu May 25 11:20:03 2017) [sssd[be[sssd16.qe]]] [krb5_auth_done] (0x0040): The krb5_child process returned an error. Please inspect the krb5_child.log file or the journal for more information (Thu May 25 11:20:03 2017) [sssd[be[sssd16.qe]]] [krb5_auth_done] (0x0040): Could not parse child response [22]: Invalid argument 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://access.redhat.com/errata/RHEA-2017:2294 |