Bug 742652

setroubleshoot unfortunately didn't ask me for further details on this issue, so here they are now:

* increased the CPU time and RAM in boincmgr
* hard disk makes strange sounds (well the sounds may be another issue, but at least the I/O is)
* process `/usr/bin/python --Es /usr/sbin/setroubleshootd -f` has high CPU load and cannot be killed (it respawns automagically) - only solution seems a reboot then
* /var/log/messages is filled in seconds interval with following messages:

Oct  1 00:17:39 hellraiser audispd: queue is full - dropping event
Oct  1 00:17:39 hellraiser setroubleshoot: SELinux is preventing wcg_dsfl_6.19_i from read access on the file stat. For complete SELinux messages. run sealert -l be7515d7-33ff-4f7a-9327-10274a94ab72

# grep "be7515d7-33ff-4f7a-9327-10274a94ab72" /var/log/messages | wc -l
557
# grep "dropping event" /var/log/messages | wc -l
67546

The issue is still present after generating a custom SELinux policy like setroubleshoot suggested:

You should report this as a bug.
You can generate a local policy module to allow this access.
Allow this access for now by executing:
# grep wcg_dsfl_6.19_i /var/log/audit/audit.log | audit2allow -M mypol
# semodule -i mypol.pp


Hope this helps getting a clue about this issue, according to the sound of my hard disk it is very serious.. ;)

Switching to audit for a clue.

What this audit log is saying is there are so many events coming in, that its overflowing the internal queues and its dropping events because it has no room to put it. Normally you would increase queue sizes or increase priority, but this sounds like something else is wrong. You might try something like:

ausearch --start 10:00:00 --end 11:00:00 -m avc | audit2allow

where the start and end time is replaced with the time this actually occurred to see if there are other AVCs. You can also run:

aureport --start 10:00:00 --end 11:00:00 --summary

to see what kinds of things were happening to your system during that time range, too.

Hey Guys,

I'm sorry if I may confused you with that "dropping event" message, I think it is quiet sure this issue is related somehow to BOINC. I'd suggest to investigate deeper into that direction, since that message seems to be the reason for the "dropping event" stuff.  I just noted why:

# ls -lh /var/log/audit/
total 28M
-rw-------. 1 root root 3.9M Oct  3 17:10 audit.log
-r--------. 1 root root 6.1M Oct  1 00:33 audit.log.1
-r--------. 1 root root 6.1M Oct  1 00:32 audit.log.2
-r--------. 1 root root 6.1M Oct  1 00:32 audit.log.3
-r--------. 1 root root 6.1M Oct  1 00:31 audit.log.4

# grep wcg_dsfl_6.19_i /var/log/audit/audit.log* | wc -l
84119

The first time stamp in audit.log.4 is pointing to 2011-10-01 00:30:23, the last time stamp in audit.log is pointing to 2011-10-01 00:34:11. The messages are all of the same kind:

type=SYSCALL msg=audit(1317422051.223:183461): arch=40000003 syscall=5 success=no exit=-13 a0=ffc8e834 a1=8000 a2=1b6 a3=0 items=0 ppid=2596 pid=3462 auid=4294967295 uid=491 gid=473 euid=491 suid=491 fsuid=491 egid=473 sgid=473 fsgid=473 tty=(none) ses=4294967295 comm="wcg_dsfl_6.19_i" exe="/var/lib/boinc/projects/www.worldcommunitygrid.org/wcg_dsfl_6.19_i686-pc-linux-gnu" subj=system_u:system_r:boinc_project_t:s0 key=(null)


There were more than 84000 messages in less than five minutes, this explains why the audit log had those problems, I actually didn't expect the log files to be rotated that fast, this is why i didn't noticed this earlier.

It is still unclear to me why this happens, though. :(

Regards,
Dominic

The syscall is an fstat which returns -EACCES. But there is not quite enough detail as to what the whole event is. You might run this:

ausearch --just-one -sc fstat --success no -i

and paste it here. That should have a path record so that we can see what its trying to access and what its permissions are.

(In reply to comment #5)
> The syscall is an fstat which returns -EACCES. But there is not quite enough
> detail as to what the whole event is. You might run this:
> 
> ausearch --just-one -sc fstat --success no -i
> 
> and paste it here. That should have a path record so that we can see what its
> trying to access and what its permissions are.

So here we go:

# ausearch --just-one -sc fstat --success no -i
----
type=SYSCALL msg=audit(10/01/11 00:30:23.249:141357) : arch=i386 syscall=open success=no exit=-13(Permission denied) a0=ffc8e874 a1=8000 a2=1b6 a3=0 items=0 ppid=2596 pid=3462 auid=unset uid=boinc gid=boinc euid=boinc suid=boinc fsuid=boinc egid=boinc sgid=boinc fsgid=boinc tty=(none) ses=unset comm=wcg_dsfl_6.19_i exe=/var/lib/boinc/projects/www.worldcommunitygrid.org/wcg_dsfl_6.19_i686-pc-linux-gnu subj=system_u:system_r:boinc_project_t:s0 key=(null)

Same here.
The "audit" logfiles are growing and rotating like madmen.

# ls -l /var/log/audit
total 29332
-rw-------. 1 root root 4788427 Oct 12 21:17 audit.log
-r--------. 1 root root 6291639 Oct 12 21:17 audit.log.1
-r--------. 1 root root 6291819 Oct 12 21:16 audit.log.2
-r--------. 1 root root 6291746 Oct 12 21:16 audit.log.3
-r--------. 1 root root 6291691 Oct 12 21:16 audit.log.4

# ausearch --just-one -sc fstat --success no -i
----
type=SYSCALL msg=audit(10/12/2011 21:15:41.533:27949650) : arch=i386 syscall=open success=no exit=-13(Permission denied) a0=ffb7f594 a1=8000 a2=1b6 a3=0 items=0 ppid=1896 pid=12739 auid=unset uid=boinc gid=boinc euid=boinc suid=boinc fsuid=boinc egid=boinc sgid=boinc fsgid=boinc tty=(none) ses=unset comm=wcg_dsfl_6.19_i exe=/var/lib/boinc/projects/www.worldcommunitygrid.org/wcg_dsfl_6.19_i686-pc-linux-gnu subj=system_u:system_r:boinc_project_t:s0 key=(null) 
type=AVC msg=audit(10/12/2011 21:15:41.533:27949650) : avc:  denied  { read } for  pid=12739 comm=wcg_dsfl_6.19_i name=stat dev=proc ino=1661341 scontext=system_u:system_r:boinc_project_t:s0 tcontext=system_u:system_r:kernel_t:s0 tclass=file

Since the update to F16 and several selinux-* and boinc-* updates (also from updates-testing in F16) in the meanwhile this issue seems to be gone for me. I guess it was fixed, either with an selinux policy update or with a boinc update. I unfortunately am not able anymore to tell you if this is also fixed for F15. If that is the actual case I think you can close this issue.