event loss with dispatcher?
Klaus Heinrich Kiwi
klausk at br.ibm.com
Thu Nov 8 23:15:08 UTC 2007
On Thu, 08 Nov 2007 16:55:22 -0500, Steve Grubb wrote:
> On Thursday 08 November 2007 16:17:52 klausk at br.ibm.com wrote:
>> Any tips on how can I debug this further?
>
> I'd put some syslog()'s in the main event loop of the dispatcher to see
> what is coming in and some in the output where its writing to the
> descriptor.
>
> -Steve
Added a syslog() in the auditd code just before writev() to pipe, and
another in audit dispatcher just after readv() from pipe (code attached
in the end). I see every record coming out of the daemon, but some
records are lost at the dispatcher input:
[watch event]
Nov 8 17:57:13 kwuser3 auditd[10304]: auditd, **out**: audit(1194562633.937:58313): arch=80000016 syscall=5 success=yes exit=3 a0=800fa310 a1=241 a2=1b6 a3=0 items=1 ppid=28559 pid=28561 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=pts1 comm="bash" exe="/bin/bash" subj=root:system_r:unconfined_t:s0-s0:c0.c1023 key=(null)
Nov 8 17:57:13 kwuser3 auditd[10304]: auditd, **out**: audit(1194562633.937:58313): cwd="/root/audit-1.6.2_"
Nov 8 17:57:13 kwuser3 auditd[10304]: auditd, **out**: audit(1194562633.937:58313): item=0 name="/root/file" inode=1109999 dev=fd:00 mode=0100644 ouid=0 ogid=0 rdev=00:00 obj=root:object_r:user_home_t:s0
Nov 8 17:57:13 kwuser3 audispd: audispd, **in**: audit(1194562633.937:58313): arch=80000016 syscall=5 success=yes exit=3 a0=800fa310 a1=241 a2=1b6 a3=0 items=1 ppid=28559 pid=28561 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=pts1 comm="bash" exe="/bin/bash" subj=root:system_r:unconfined_t:s0-s0:c0.c1023 key=(null)
Nov 8 17:57:13 kwuser3 audispd: audispd, **in**: audit(1194562633.937:58313): item=0 name="/root/file" inode=1109999 dev=fd:00 mode=0100644 ouid=0 ogid=0 rdev=00:00 obj=root:object_r:user_home_t:s0
[remove rules]
Nov 8 17:58:01 kwuser3 auditd[10304]: auditd, **out**: audit(1194562681.217:58314): auid=0 subj=root:system_r:auditctl_t:s0-s0:c0.c1023 op=remove rule key=(null) list=4 res=1
Nov 8 17:58:01 kwuser3 audispd: audispd, **in**: audit(1194562681.217:58314): auid=0 subj=root:system_r:auditctl_t:s0-s0:c0.c1023 op=remove rule key=(null) list=4 res=1
[add watch again]
Nov 8 17:58:16 kwuser3 auditd[10304]: auditd, **out**: audit(1194562696.747:58315): auid=0 subj=root:system_r:auditctl_t:s0-s0:c0.c1023 op=add rule key=(null) list=4 res=1
Nov 8 17:58:16 kwuser3 audispd: audispd, **in**: audit(1194562696.747:58315): auid=0 subj=root:system_r:auditctl_t:s0-s0:c0.c1023 op=add rule key=(null) list=4 res=1
[watch event - this time not event the PATH record came through]
Nov 8 17:58:21 kwuser3 auditd[10304]: auditd, **out**: audit(1194562701.897:58316): arch=80000016 syscall=5 success=yes exit=3 a0=80122b40 a1=241 a2=1b6 a3=0 items=1 ppid=28559 pid=28561 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=pts1 comm="bash" exe="/bin/bash" subj=root:system_r:unconfined_t:s0-s0:c0.c1023 key=(null)
Nov 8 17:58:21 kwuser3 auditd[10304]: auditd, **out**: audit(1194562701.897:58316): cwd="/root/audit-1.6.2_"
Nov 8 17:58:21 kwuser3 auditd[10304]: auditd, **out**: audit(1194562701.897:58316): item=0 name="/root/file" inode=1109999 dev=fd:00 mode=0100644 ouid=0 ogid=0 rdev=00:00 obj=root:object_r:user_home_t:s0
Nov 8 17:58:21 kwuser3 audispd: audispd, **in**: audit(1194562701.897:58316): arch=80000016 syscall=5 success=yes exit=3 a0=80122b40 a1=241 a2=1b6 a3=0 items=1 ppid=28559 pid=28561 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=pts1 comm="bash" exe="/bin/bash" subj=root:system_r:unconfined_t:s0-s0:c0.c1023 key=(null)
--------------
Still don't have a clue of what's going on. here's the patch used:
diff -purN audit-1.6.2/audisp/audispd.c audit-1.6.2_/audisp/audispd.c
--- audit-1.6.2/audisp/audispd.c 2007-11-08 18:06:28.000000000 -0500
+++ audit-1.6.2_/audisp/audispd.c 2007-11-08 17:48:30.000000000 -0500
@@ -697,6 +697,11 @@ static void process_inbound_event(int fd
rc = readv(fd, vec, 2);
} while (rc < 0 && errno == EINTR);
if (rc > 0) {
+ char buf[MAX_AUDIT_MESSAGE_LENGTH];
+ strncpy(buf, vec[1].iov_base, vec[1].iov_len);
+ buf[vec[1].iov_len] = '\0';
+ syslog(LOG_ERR, "audispd, **in**: %s", buf);
+
enqueue(e);
}
}
diff -purN audit-1.6.2/src/auditd-dispatch.c audit-1.6.2_/src/auditd-dispatch.c
--- audit-1.6.2/src/auditd-dispatch.c 2007-09-17 10:43:01.000000000 -0400
+++ audit-1.6.2_/src/auditd-dispatch.c 2007-11-08 17:47:00.000000000 -0500
@@ -160,6 +160,13 @@ int dispatch_event(const struct audit_re
vec[1].iov_base = (void*)rep->message;
vec[1].iov_len = rep->len;
+ {
+ char buf[MAX_AUDIT_MESSAGE_LENGTH];
+ strncpy(buf, vec[1].iov_base, vec[1].iov_len);
+ buf[vec[1].iov_len] = '\0';
+ syslog(LOG_ERR, "auditd, **out**: %s", buf);
+ }
+
do {
rc = writev(disp_pipe[1], vec, 2);
} while (rc < 0 && errno == EAGAIN && count++ < 8);
More information about the Linux-audit
mailing list