Can anyone help me to understand these logs... is there maybe a bug here? The basic situation is that there is no HBAC rule that would allow sudo. When people try it, sss accepts their password but then denies them access to the sudo command. But despite this, our logs still contain some entries indicating that sudo was actually run. Of course the sudoers file then denied them access and sent the sysadmin an email.
Here's a journal extract: Feb 09 11:34:58 hostname sudo[24453]: pam_unix(sudo:auth): authentication failure; logname=xxxx uid=12113 euid=0 tty=/dev/pts/1 ruser=xxxx rhost= user=xxxx Feb 09 11:34:58 hostname sudo[24453]: pam_sss(sudo:auth): authentication success; logname=xxxx uid=12113 euid=0 tty=/dev/pts/1 ruser=xxxx rhost= user=xxxx Feb 09 11:34:58 hostname audit[24453]: <audit-1100> pid=24453 uid=12113 auid=12113 ses=54 msg='op=PAM:authentication grantors=pam_succeed_if,pam_sss acct="xxxx" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1 res=success' Feb 09 11:34:58 hostname sudo[24453]: pam_sss(sudo:account): Access denied for user xxxx: 6 (Permission denied) Feb 09 11:34:58 hostname audit[24453]: <audit-1101> pid=24453 uid=12113 auid=12113 ses=54 msg='op=PAM:accounting grantors=? acct="xxxx" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1 res=failed' Feb 09 11:35:05 hostname sudo[24453]: pam_sss(sudo:auth): authentication success; logname=xxxx uid=12113 euid=0 tty=/dev/pts/1 ruser=xxxx rhost= user=xxxx Feb 09 11:35:05 hostname audit[24453]: <audit-1100> pid=24453 uid=12113 auid=12113 ses=54 msg='op=PAM:authentication grantors=pam_succeed_if,pam_sss acct="xxxx" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1 res=success' Feb 09 11:35:05 hostname sudo[24453]: pam_sss(sudo:account): Access denied for user xxxx: 6 (Permission denied) Feb 09 11:35:05 hostname audit[24453]: <audit-1101> pid=24453 uid=12113 auid=12113 ses=54 msg='op=PAM:accounting grantors=? acct="xxxx" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1 res=failed' Feb 09 11:35:08 hostname sudo[24453]: pam_unix(sudo:auth): auth could not identify password for [xxxx] Feb 09 11:35:08 hostname sudo[24453]: pam_sss(sudo:auth): authentication failure; logname=xxxx uid=12113 euid=0 tty=/dev/pts/1 ruser=xxxx rhost= user=xxxx Feb 09 11:35:08 hostname sudo[24453]: pam_sss(sudo:auth): received for user xxxx: 7 (Authentication failure) Feb 09 11:35:08 hostname audit[24453]: <audit-1100> pid=24453 uid=12113 auid=12113 ses=54 msg='op=PAM:authentication grantors=? acct="xxxx" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1 res=failed' Feb 09 11:35:08 hostname audit[24453]: <audit-1123> pid=24453 uid=12113 auid=12113 ses=54 msg='cwd=2F6175xxx cmd=617074xxx terminal=pts/1 res=failed' Feb 09 11:35:08 hostname audit[24453]: <audit-1123> pid=24453 uid=12113 auid=12113 ses=54 msg='cwd=2F6175xxx cmd=617074xxx terminal=pts/1 res=failed' Feb 09 11:35:08 hostname sudo[24453]: xxxx : user NOT in sudoers ; TTY=pts/1 ; PWD=/xxxxx ; USER=root ; COMMAND=xxxxx Feb 09 11:35:09 hostname sSMTP[24463]: Sent mail for [email protected] (221 mail.cs.ox.ac.uk closing connection) uid=0 xxxx=root outbytes=607 What this seems to say: 1. pam_unix failed the password (expected because passwords are managed by IPA) 2. pam_sss accepted the password 3. pam_sss denied access to sudo:account Presumably sudo asked the user to try again and they re-typed the password 4. pam_sss accepted the password 5. pam_sss denied access to sudo:account 6. Three seconds later pam_unix said it "could not identify password" (?) 7. This time pam_sss failed the password and returned 7 (Authentication failure) 8. sudo ran anyway! I can't duplicate this behaviour myself but looking through the logs in our computer lab there are a few of these. See for instance the following which appears to deny access three times and then just run it anyway: Feb 02 10:31:12 hostname2 sudo[24468]: pam_unix(sudo:auth): authentication failure; logname=xyyx uid=12106 euid=0 tty=/dev/pts/1 ruser=xyyx rhost= user=xyyx Feb 02 10:31:14 hostname2 sudo[24468]: pam_sss(sudo:auth): authentication success; logname=xyyx uid=12106 euid=0 tty=/dev/pts/1 ruser=xyyx rhost= user=xyyx Feb 02 10:31:14 hostname2 audit[24468]: <audit-1100> pid=24468 uid=12106 auid=12106 ses=39 msg='op=PAM:authentication grantors=pam_succeed_if,pam_sss acct="xyyx" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1 res=success' Feb 02 10:31:15 hostname2 sudo[24468]: pam_sss(sudo:account): Access denied for user xyyx: 6 (Permission denied) Feb 02 10:31:15 hostname2 audit[24468]: <audit-1101> pid=24468 uid=12106 auid=12106 ses=39 msg='op=PAM:accounting grantors=? acct="xyyx" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1 res=failed' Feb 02 10:31:26 hostname2 sudo[24468]: pam_sss(sudo:auth): authentication success; logname=xyyx uid=12106 euid=0 tty=/dev/pts/1 ruser=xyyx rhost= user=xyyx Feb 02 10:31:26 hostname2 audit[24468]: <audit-1100> pid=24468 uid=12106 auid=12106 ses=39 msg='op=PAM:authentication grantors=pam_succeed_if,pam_sss acct="xyyx" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1 res=success' Feb 02 10:31:26 hostname2 sudo[24468]: pam_sss(sudo:account): Access denied for user xyyx: 6 (Permission denied) Feb 02 10:31:26 hostname2 audit[24468]: <audit-1101> pid=24468 uid=12106 auid=12106 ses=39 msg='op=PAM:accounting grantors=? acct="xyyx" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1 res=failed' Feb 02 10:31:46 hostname2 sudo[24468]: pam_sss(sudo:auth): authentication success; logname=xyyx uid=12106 euid=0 tty=/dev/pts/1 ruser=xyyx rhost= user=xyyx Feb 02 10:31:46 hostname2 audit[24468]: <audit-1100> pid=24468 uid=12106 auid=12106 ses=39 msg='op=PAM:authentication grantors=pam_succeed_if,pam_sss acct="xyyx" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1 res=success' Feb 02 10:31:46 hostname2 sudo[24468]: pam_sss(sudo:account): Access denied for user xyyx: 6 (Permission denied) Feb 02 10:31:46 hostname2 audit[24468]: <audit-1101> pid=24468 uid=12106 auid=12106 ses=39 msg='op=PAM:accounting grantors=? acct="xyyx" exe="/usr/bin/sudo" hostname=? addr=? terminal=/dev/pts/1 res=failed' Feb 02 10:31:46 hostname2 audit[24468]: <audit-1123> pid=24468 uid=12106 auid=12106 ses=39 msg='cwd="/xxxx" cmd=6E616Exxx terminal=pts/1 res=failed' Feb 02 10:31:46 hostname2 audit[24468]: <audit-1123> pid=24468 uid=12106 auid=12106 ses=39 msg='cwd="/xxxx" cmd=6E616Exxx terminal=pts/1 res=failed' Feb 02 10:31:46 hostname2 sudo[24468]: xyyx : user NOT in sudoers ; TTY=pts/1 ; PWD=/xxxxxx ; USER=root ; COMMAND=xxxxxx Feb 02 10:31:47 hostname2 sSMTP[24489]: Sent mail for [email protected] (221 mail.cs.ox.ac.uk closing connection) uid=0 username=root outbytes=589 Now since sudoers denies access, this isn't necessarily a security problem for us. But it's rather puzzling and it does mean a trickle of incoming emails to the sysadmin. The clients here are Fedora 22 with pam 1.1.8, sssd 1.13.3 and sudo 1.8.15. The IPA servers are RHEL 6 with ipa-server 3.0.0. Ian Collier. -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
