Bug 162239 - cups/pam/audit/selinux problem
Summary: cups/pam/audit/selinux problem
Keywords:
Status: CLOSED RAWHIDE
Alias: None
Product: Fedora
Classification: Fedora
Component: cups
Version: rawhide
Hardware: All
OS: Linux
medium
medium
Target Milestone: ---
Assignee: Tim Waugh
QA Contact:
URL:
Whiteboard:
Depends On:
Blocks: FC5Target
TreeView+ depends on / blocked
 
Reported: 2005-07-01 11:35 UTC by Tim Waugh
Modified: 2007-11-30 22:11 UTC (History)
2 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2005-07-25 11:29:51 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
http-request.sh (218 bytes, text/plain)
2005-07-01 11:35 UTC, Tim Waugh
no flags Details
test.sh (436 bytes, text/plain)
2005-07-01 11:36 UTC, Tim Waugh
no flags Details

Description Tim Waugh 2005-07-01 11:35:56 UTC
Description of problem:
I get this log message whenever I try to access http://localhost:631/admin --
and cannot display this page even with the correct username and password:

IsAuthorized: pam_authenticate() returned 4 (System error)!

Version-Release number of selected component (if applicable):
cups-1.1.23-16
audit-0.9.15-1
selinux-policy-targeted-1.24-1
(selinux enforcing)

How reproducible:
100%

Steps to Reproduce:
1. bash test.sh
  
Actual results:
Stopping cups:                                             [  OK  ]
Starting cups:                                             [  OK  ]
HTTP/1.1 401 Unauthorized
Date: Fri, 01 Jul 2005 11:10:30 GMT
Server: CUPS/1.1
WWW-Authenticate: Basic realm="CUPS"
Content-Language: en_US
Upgrade: TLS/1.0,HTTP/1.1
Connection: close
Content-Type: text/html
Content-Length: 168

<HTML><HEAD><TITLE>401
Unauthorized</TITLE></HEAD><BODY><H1>Unauthorized</H1>This server could not
verify that you are authorized to access the resource.</BODY></HTML>
I [01/Jul/2005:12:10:23 +0100] Listening to 7f000001:631
I [01/Jul/2005:12:10:23 +0100] Loaded configuration file "/etc/cups/cupsd.conf"
I [01/Jul/2005:12:10:23 +0100] Configured for up to 100 clients.
I [01/Jul/2005:12:10:23 +0100] Allowing up to 100 client connections per host.
I [01/Jul/2005:12:10:23 +0100] Full reload is required.
I [01/Jul/2005:12:10:23 +0100] LoadPPDs: Read "/etc/cups/ppds.dat", 17 PPDs...
I [01/Jul/2005:12:10:23 +0100] LoadPPDs: No new or changed PPDs...
I [01/Jul/2005:12:10:23 +0100] Full reload complete.
E [01/Jul/2005:12:10:30 +0100] IsAuthorized: pam_authenticate() returned 4
(System error)!

Expected results:
Authentication failure as above, but with pam_authenticate() returning something
other than "System error".

The correct username and password for http://localhost:631/admin is 'root' and
root's password (for pam_unix).

Additional info:
I stepped through pam_authenticate(), and the error code comes from the
_pam_auditlog() call.

Comment 1 Tim Waugh 2005-07-01 11:35:57 UTC
Created attachment 116236 [details]
http-request.sh

Comment 2 Tim Waugh 2005-07-01 11:36:39 UTC
Created attachment 116237 [details]
test.sh

Comment 3 Tim Waugh 2005-07-01 11:42:09 UTC
There are no audit.log messages during the test.  With 'setenforce 0', the error
message changes to this:

E [01/Jul/2005:12:38:29 +0100] IsAuthorized: pam_authenticate() returned 7
(Authentication failure)!

which is expected.  So SELinux is involved with this somehow.

Indeed, with 'setenforce 0', there *are* audit.log messages:

type=AVC msg=audit(1120218062.686:9886587): avc:  denied  { create } for 
pid=28128 comm="cupsd" scontext=root:system_r:cupsd_t
tcontext=root:system_r:cupsd_t tclass=netlink_route_socket
type=SYSCALL msg=audit(1120218062.686:9886587): arch=40000003 syscall=102
success=yes exit=6 a0=1 a1=bfcb24bc a2=343ff4 a3=bfcb2578 items=0 pid=28128
auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 comm="cupsd"
exe="/usr/sbin/cupsd"
type=SOCKETCALL msg=audit(1120218062.686:9886587): nargs=3 a0=10 a1=3 a2=0
type=AVC msg=audit(1120218062.688:9886622): avc:  denied  { bind } for 
pid=28128 comm="cupsd" scontext=root:system_r:cupsd_t
tcontext=root:system_r:cupsd_t tclass=netlink_route_socket
type=SYSCALL msg=audit(1120218062.688:9886622): arch=40000003 syscall=102
success=yes exit=0 a0=2 a1=bfcb24bc a2=343ff4 a3=bfcb2578 items=0 pid=28128
auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 comm="cupsd"
exe="/usr/sbin/cupsd"
type=SOCKADDR msg=audit(1120218062.688:9886622): saddr=100000000000000000000000
type=SOCKETCALL msg=audit(1120218062.688:9886622): nargs=3 a0=6 a1=bfcb24c8
a2=ctype=AVC msg=audit(1120218062.689:9886623): avc:  denied  { getattr } for 
pid=28128 comm="cupsd" scontext=root:system_r:cupsd_t
tcontext=root:system_r:cupsd_t tclass=netlink_route_socket
type=SYSCALL msg=audit(1120218062.689:9886623): arch=40000003 syscall=102
success=yes exit=0 a0=6 a1=bfcb24bc a2=343ff4 a3=bfcb2578 items=0 pid=28128
auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 comm="cupsd"
exe="/usr/sbin/cupsd"
type=SOCKETCALL msg=audit(1120218062.689:9886623): nargs=3 a0=6 a1=bfcb24c8
a2=bfcb24d4
type=AVC msg=audit(1120218062.689:9886625): avc:  denied  { write } for 
pid=28128 comm="cupsd" scontext=root:system_r:cupsd_t
tcontext=root:system_r:cupsd_t tclass=netlink_route_socket
type=AVC msg=audit(1120218062.689:9886625): avc:  denied  { nlmsg_read } for 
pid=28128 comm="cupsd" scontext=root:system_r:cupsd_t
tcontext=root:system_r:cupsd_t tclass=netlink_route_socket
type=SYSCALL msg=audit(1120218062.689:9886625): arch=40000003 syscall=102
success=yes exit=20 a0=b a1=bfcb2440 a2=343ff4 a3=ffffffe0 items=0 pid=28128
auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 comm="cupsd"
exe="/usr/sbin/cupsd"
type=SOCKADDR msg=audit(1120218062.689:9886625): saddr=100000000000000000000000
type=SOCKETCALL msg=audit(1120218062.689:9886625): nargs=6 a0=6 a1=bfcb24a4
a2=14 a3=0 a4=bfcb24b8 a5=c
type=AVC msg=audit(1120218062.690:9886626): avc:  denied  { read } for 
pid=28128 comm="cupsd" scontext=root:system_r:cupsd_t
tcontext=root:system_r:cupsd_t tclass=netlink_route_socket
type=SYSCALL msg=audit(1120218062.690:9886626): arch=40000003 syscall=102
success=yes exit=688 a0=11 a1=bfcb1430 a2=343ff4 a3=0 items=0 pid=28128 auid=0
uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 comm="cupsd"
exe="/usr/sbin/cupsd"
type=SOCKETCALL msg=audit(1120218062.690:9886626): nargs=3 a0=6 a1=bfcb2488 a2=0

What do these messages mean?

Comment 4 Steve Grubb 2005-07-01 12:21:51 UTC
These are easier to understand if you use ausearch -i to look at the logs. The
man page for ausearch is pretty good.

The first SYSCALL is creating a netlink socket, the second is a bind call to
bind to routing netlink family, the third is getsockname, the last is a sendto.

Comment 5 Tim Waugh 2005-07-01 12:26:47 UTC
But these are all for writing an audit log, aren't they?  The policy already has
this:

allow cupsd_t self:netlink_audit_socket { create_netlink_socket_perms nlmsg_relay };


Comment 6 Steve Grubb 2005-07-01 12:46:38 UTC
This is a routing socket. In the first SOCKETCALL, all the args to socket are
captured. This means:

socket(PF_NETLINK, SOCK_RAW, NETLINK_ROUTE);

I don't know if this is in the policy.

Comment 7 Tim Waugh 2005-07-01 12:57:50 UTC
Well, this isn't anything that CUPS is doing, but pam.  So what do I need to put
in the cups.te file?  Is there a macro for 'allow _pam_auditlog to work'?

Comment 8 Steve Grubb 2005-07-01 13:51:20 UTC
If I had to guess, I'd say this is originating in glibc or another library. pam
shouldn't be doing anything with the routing table. Still looking...

Comment 9 Daniel Walsh 2005-07-11 18:20:25 UTC
Fixed in selinux-policy-targeted-1.25.1-7

Comment 10 Tim Waugh 2005-07-25 11:29:51 UTC
Confirmed.


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