auditd went crazy

Chuck Anderson cra at WPI.EDU
Wed Jul 2 15:27:26 UTC 2008 

July 1st at 00:18:02, I started getting thousands of audit messages 
(hundreds per second).  They didn't stop until I did "service auditd 
restart":

I finally noticed the problem when logwatch told me this:

 audit: audit_backlog=262 > audit_backlog_limit=256
  audit: audit_lost=1 audit_rate_limit=0 audit_backlog_limit=256
  audit: backlog limit exceeded
  audit: audit_backlog=262 > audit_backlog_limit=256
  audit: audit_lost=2 audit_rate_limit=0 audit_backlog_limit=256
  audit: backlog limit exceeded
  audit: audit_backlog=262 > audit_backlog_limit=256
  audit: audit_lost=3 audit_rate_limit=0 audit_backlog_limit=256
  audit: backlog limit exceeded
  audit: audit_backlog=262 > audit_backlog_limit=256


Here is the start of the messages, with a few normal audit messages 
before it:

type=LOGIN msg=audit(07/01/2008 00:10:01.754:139884) : login pid=24775 
uid=root old auid=unset new auid=root
----
type=USER_START msg=audit(07/01/2008 00:10:01.755:139885) : user 
pid=24775 uid=root auid=root 
subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg='op=PAM:session_open 
acct=root exe=/usr/sbin/crond (hostname=?, addr=?, terminal=cron 
res=success)'
----
type=CRED_DISP msg=audit(07/01/2008 00:10:01.763:139886) : user 
pid=24773 uid=root auid=root 
subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg='op=PAM:setcred 
acct=root exe=/usr/sbin/crond (hostname=?, addr=?, terminal=cron 
res=success)'
----
type=USER_END msg=audit(07/01/2008 00:10:01.763:139887) : user 
pid=24773 uid=root auid=root 
subj=system_u:system_r:crond_t:s0-s0:c0.c1023 
msg='op=PAM:session_close acct=root exe=/usr/sbin/crond (hostname=?, 
addr=?, terminal=cron res=success)'
----
type=CRED_DISP msg=audit(07/01/2008 00:10:01.770:139888) : user 
pid=24775 uid=root auid=root 
subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg='op=PAM:setcred 
acct=root exe=/usr/sbin/crond (hostname=?, addr=?, terminal=cron 
res=success)'
----
type=USER_END msg=audit(07/01/2008 00:10:01.770:139889) : user 
pid=24775 uid=root auid=root 
subj=system_u:system_r:crond_t:s0-s0:c0.c1023 
msg='op=PAM:session_close acct=root exe=/usr/sbin/crond (hostname=?, 
addr=?, terminal=cron res=success)'
----
type=USER_ACCT msg=audit(07/01/2008 00:15:01.775:139890) : user 
pid=24781 uid=root auid=unset 
subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg='op=PAM:accounting 
acct=root exe=/usr/sbin/crond (hostname=?, addr=?, terminal=cron 
res=success)'
----
type=CRED_ACQ msg=audit(07/01/2008 00:15:01.776:139891) : user 
pid=24781 uid=root auid=unset 
subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg='op=PAM:setcred 
acct=root exe=/usr/sbin/crond (hostname=?, addr=?, terminal=cron 
res=success)'
----
type=LOGIN msg=audit(07/01/2008 00:15:01.776:139892) : login pid=24781 
uid=root old auid=unset new auid=root
----
type=USER_START msg=audit(07/01/2008 00:15:01.777:139893) : user 
pid=24781 uid=root auid=root 
subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg='op=PAM:session_open 
acct=root exe=/usr/sbin/crond (hostname=?, addr=?, terminal=cron 
res=success)'
----
type=CRED_DISP msg=audit(07/01/2008 00:15:01.791:139894) : user 
pid=24781 uid=root auid=root 
subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg='op=PAM:setcred 
acct=root exe=/usr/sbin/crond (hostname=?, addr=?, terminal=cron 
res=success)'
----
type=USER_END msg=audit(07/01/2008 00:15:01.791:139895) : user 
pid=24781 uid=root auid=root 
subj=system_u:system_r:crond_t:s0-s0:c0.c1023 
msg='op=PAM:session_close acct=root exe=/usr/sbin/crond (hostname=?, 
addr=?, terminal=cron res=success)'
----
type=SYSCALL msg=audit(07/01/2008 00:18:02.766:139896) : arch=i386 
syscall=execve success=yes exit=0 a0=9c0aa40 a1=9c069a8 a2=9c0ab08 
a3=0 items=0 ppid=24821 pid=24826 auid=fs uid=root gid=root euid=root 
suid=root fsuid=root egid=root sgid=root fsgid=root tty=(none$
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13697886] 
dev=sockfs ino=13697886 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692415] 
dev=sockfs ino=13692415 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692404] 
dev=sockfs ino=13692404 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692402] 
dev=sockfs ino=13692402 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692400] 
dev=sockfs ino=13692400 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692398] 
dev=sockfs ino=13692398 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692396] 
dev=sockfs ino=13692396 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692394] 
dev=sockfs ino=13692394 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692392] 
dev=sockfs ino=13692392 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692390] 
dev=sockfs ino=13692390 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692388] 
dev=sockfs ino=13692388 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692386] 
dev=sockfs ino=13692386 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692380] 
dev=sockfs ino=13692380 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692377] 
dev=sockfs ino=13692377 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692375] 
dev=sockfs ino=13692375 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692326] 
dev=sockfs ino=13692326 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692301] 
dev=sockfs ino=13692301 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692299] 
dev=sockfs ino=13692299 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692297] 
dev=sockfs ino=13692297 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692226] 
dev=sockfs ino=13692226 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692219] 
dev=sockfs ino=13692219 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692217] 
dev=sockfs ino=13692217 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13648053] 
dev=sockfs ino=13648053 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692215] 
dev=sockfs ino=13692215 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13692087] 
dev=sockfs ino=13692087 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13698044] 
dev=sockfs ino=13698044 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13698042] 
dev=sockfs ino=13698042 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13698039] 
dev=sockfs ino=13698039 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13698037] 
dev=sockfs ino=13698037 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13698035] 
dev=sockfs ino=13698035 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13698033] 
dev=sockfs ino=13698033 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/01/2008 00:18:02.766:139896) : avc:  denied  { 
read write } for  pid=24826 comm=rndc path=socket:[13698029] 
dev=sockfs ino=13698029 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket

...

type=AVC msg=audit(07/02/2008 10:54:46.348:144433) : avc:  denied  { 
read write } for  pid=9726 comm=rndc path=socket:[13830554] dev=sockfs 
ino=13830554 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/02/2008 10:54:46.348:144433) : avc:  denied  { 
read write } for  pid=9726 comm=rndc path=socket:[13830552] dev=sockfs 
ino=13830552 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/02/2008 10:54:46.348:144433) : avc:  denied  { 
read write } for  pid=9726 comm=rndc path=socket:[13830550] dev=sockfs 
ino=13830550 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/02/2008 10:54:46.348:144433) : avc:  denied  { 
read write } for  pid=9726 comm=rndc path=socket:[13830548] dev=sockfs 
ino=13830548 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/02/2008 10:54:46.348:144433) : avc:  denied  { 
read write } for  pid=9726 comm=rndc path=socket:[13830546] dev=sockfs 
ino=13830546 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/02/2008 10:54:46.348:144433) : avc:  denied  { 
read write } for  pid=9726 comm=rndc path=socket:[13830544] dev=sockfs 
ino=13830544 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/02/2008 10:54:46.348:144433) : avc:  denied  { 
read write } for  pid=9726 comm=rndc path=socket:[13830542] dev=sockfs 
ino=13830542 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/02/2008 10:54:46.348:144433) : avc:  denied  { 
read write } for  pid=9726 comm=rndc path=socket:[13830540] dev=sockfs 
ino=13830540 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/02/2008 10:54:46.348:144433) : avc:  denied  { 
read write } for  pid=9726 comm=rndc path=socket:[13830538] dev=sockfs 
ino=13830538 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/02/2008 10:54:46.348:144433) : avc:  denied  { 
read write } for  pid=9726 comm=rndc path=socket:[13830536] dev=sockfs 
ino=13830536 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/02/2008 10:54:46.348:144433) : avc:  denied  { 
read write } for  pid=9726 comm=rndc path=socket:[13830530] dev=sockfs 
ino=13830530 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/02/2008 10:54:46.348:144433) : avc:  denied  { 
read write } for  pid=9726 comm=rndc path=socket:[13830460] dev=sockfs 
ino=13830460 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/02/2008 10:54:46.348:144433) : avc:  denied  { 
read write } for  pid=9726 comm=rndc path=socket:[13830435] dev=sockfs 
ino=13830435 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/02/2008 10:54:46.348:144433) : avc:  denied  { 
read write } for  pid=9726 comm=rndc path=socket:[13830238] dev=sockfs 
ino=13830238 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/02/2008 10:54:46.348:144433) : avc:  denied  { 
read write } for  pid=9726 comm=rndc path=socket:[13830433] dev=sockfs 
ino=13830433 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/02/2008 10:54:46.348:144433) : avc:  denied  { 
read write } for  pid=9726 comm=rndc path=socket:[13830431] dev=sockfs 
ino=13830431 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket
type=AVC msg=audit(07/02/2008 10:54:46.348:144433) : avc:  denied  { 
read write } for  pid=9726 comm=rndc path=socket:[13830360] dev=sockfs 
ino=13830360 scontext=unconfined_u:system_r:ndc_t:s0 
tcontext=unconfined_u:system_r:initrc_t:s0 tclass=tcp_socket

Anyone know what happened?

More information about the fedora-selinux-list mailing list