> Does anyone know of any other bugs regarding audit daemon & utilities?
I don't know that what I'm seeing is a problem with the tools or with
the kernel but I can get my system into a state where I'm seeing lots
of audit records for auditd. The records are for a pid one greater
than the pid that 'auditctl -s' reports.
I'm running the .74 kernel and the 0.9.16 tools on a 2-cpu em64t system
running the x84_64 kernel. I've seen the same condition on my 2-cpu
ia64 box. The condition is semi-repeatable and happens when I've
got a heavy audit load going.
I first saw the condition when running the testfileperms test, trying
to reproduce the panic that Tim/Michael reported. I start it up as
root in a loop in one window:
# while true ; do testfileperms /proc ljk ljk ; done
While this is running, I go through a sequence of restarting the
auditd and enabling syscall auditing for uid=0. (See attached
script.) When the condition happens (it doesn't always), the
system will appear to freeze for about a minute and then start
going again. At this point the audit logs will show huge numbers
of audit records for auditd, then a few for the test program, then
a huge number for auditd, etc. My script shuts off auditing right
away as this test will cycle through the logs very quickly.
What I see is stuff like this. If 'auditctl -s' shows this:
# /sbin/auditctl -s
AUDIT_STATUS: enabled=1 flag=1 pid=3332 rate_limit=0 backlog_limit=256 lost=17986 backlog=0
I'll get audit records like this:
type=SYSCALL msg=audit(1121284091.842:3559675): arch=c000003e syscall=1 success=yes exit=246 a0=4
a1=2a9556c000 a2=f6 a3=53 items=0 pid=3333 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0
sgid=0 fsgid=0 comm="auditd" exe="/sbin/auditd"
type=SYSCALL msg=audit(1121284091.842:3559676): arch=c000003e syscall=5 success=yes exit=0 a0=4
a1=409fffd0 a2=409fffd0 a3=1 items=0 pid=3333 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0
egid=0 sgid=0 fsgid=0 comm="auditd" exe="/sbin/auditd"
type=SYSCALL msg=audit(1121284091.842:3559677): arch=c000003e syscall=138 success=yes exit=0 a0=4
a1=40a00000 a2=409fffd0 a3=1 items=0 pid=3333 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0
egid=0 sgid=0 fsgid=0 comm="auditd" exe="/sbin/auditd"
type=SYSCALL msg=audit(1121284091.842:3559678): arch=c000003e syscall=202 success=yes exit=1
a0=552abc7b28 a1=1 a2=1 a3=1 items=0 pid=3333 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0
egid=0 sgid=0 fsgid=0 comm="auditd" exe="/sbin/auditd"
Notice the pid. Is this the worker thread? I don't have sysrq-T data
from this example but from a previous examples, its shown auditd info like
this:
Jul 13 15:18:53 cert-e2 kernel: auditd S 0000000100426fe9 0 3174 1 3175
2218 (NOTLB)
Jul 13 15:18:53 cert-e2 kernel: 000001007041bd48 0000000000000006 0000211c00000040 000000d000000004
Jul 13 15:18:53 cert-e2 kernel: 000001007e5ed690 0000000000003139 ffffffff80411b00
000001007e5ed978
Jul 13 15:18:53 cert-e2 kernel: 00000000000000d0 0000000000000246
Jul 13 15:18:53 cert-e2 kernel: Call Trace:<ffffffff8034ad3e>{schedule_timeout+287}
<ffffffff80142e28>{process_timeout+0}
Jul 13 15:18:53 cert-e2 kernel: <ffffffff802e496b>{datagram_poll+42}
<ffffffff801a17c6>{do_select+1435}
Jul 13 15:18:53 cert-e2 kernel: <ffffffff801a1171>{__pollwait+0}
<ffffffff801a1b45>{sys_select+820}
Jul 13 15:18:53 cert-e2 kernel: <ffffffff80110a2a>{tracesys+209}
Jul 13 15:18:53 cert-e2 kernel: auditd S 000001007041ddf8 0 3175 1
3174 (NOTLB)
Jul 13 15:18:53 cert-e2 kernel: 000001007041dd48 0000000000000006 0000000042d568a5 000000732931e820
Jul 13 15:18:53 cert-e2 kernel: 000001006ecef2d0 000000000001a5eb 00000100727f5710
000001006ecef5b8
Jul 13 15:18:53 cert-e2 kernel: 0000000000000004 0000000000000000
Jul 13 15:18:53 cert-e2 kernel: Call Trace:<ffffffff8034ac84>{schedule_timeout+101}
<ffffffff8017a389>{find_extend_vma+22}
Jul 13 15:18:53 cert-e2 kernel: <ffffffff80154dfa>{queue_me+95} <ffffffff80155283>{do_futex+422}
Jul 13 15:18:53 cert-e2 kernel: <ffffffff8013377e>{default_wake_function+0}
<ffffffff8013377e>{default_wake_function+0}
Jul 13 15:18:53 cert-e2 kernel: <ffffffff80188695>{sys_fstatfs+98}
<ffffffff8015573d>{sys_futex+204}
Jul 13 15:18:53 cert-e2 kernel: <ffffffff80110a2a>{tracesys+209}
I can get this to happen on perhaps half my attempts on the x86_64 system.
Let me know if more info would be helpful.
-- ljk
-------------- next part --------------
An embedded and charset-unspecified text was scrubbed...
Name: breakit.txt
URL: <http://listman.redhat.com/archives/linux-audit/attachments/20050713/f9df0b9f/attachment.txt>
-------------- next part --------------
An embedded and charset-unspecified text was scrubbed...
Name: testfileperms.c
URL: <http://listman.redhat.com/archives/linux-audit/attachments/20050713/f9df0b9f/attachment.c>