Re: [PATCH] auparse.c events_are_equal() and event matching

Trying to reproduce, I got this instead (it seems to happen every few thousands of msgs): type=SYSCALL msg=audit(1418253698.016:418143181): arch=c000003e syscall=59 success=yes exit=0 a0=663e42 a1=7ffffeb612c0 a2=7ffffeb65fd0 a3= 341f418240 items=2 ppid=2101 pid=2848 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=65254 comm="sh" exe="/b in/bash" key="exec" type=EXECVE msg=audit(1418253698.016:418143181): argc=3 a0="sh" a1="-c" a2=[redacted] type=CWD msg=audit(1418253698.016:418143181): cwd="/opt/observium" type=SYSCALL msg=audit(1418253698.016:418143182): arch=c000003e syscall=59 success=yes exit=0 a0=663e42 a1=7fff7d1ac220 a2=7fff7d1b0f30 a3= 341f418240 items=2 ppid=2744 pid=2849 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=65254 comm="sh" exe="/b in/bash" key="exec" type=PATH msg=audit(1418253698.016:418143181): item=0 name="/bin/sh" inode=1046605 dev=08:03 mode=0100755 ouid=0 ogid=0 rdev=00:00 nametype =NORMAL type=PATH msg=audit(1418253698.016:418143181): item=1 name=(null) inode=2093138 dev=08:03 mode=0100755 ouid=0 ogid=0 rdev=00:00 nametype=NO RMAL type=EXECVE msg=audit(1418253698.016:418143182): argc=3 a0="sh" a1="-c" a2=[redacted] type=CWD msg=audit(1418253698.016:418143182): cwd="/opt/observium" type=PATH msg=audit(1418253698.016:418143182): item=0 name="/bin/sh" inode=1046605 dev=08:03 mode=0100755 ouid=0 ogid=0 rdev=00:00 nametype =NORMAL type=PATH msg=audit(1418253698.016:418143182): item=1 name=(null) inode=2093138 dev=08:03 mode=0100755 ouid=0 ogid=0 rdev=00:00 nametype=NO RMAL If you look carefully: type=SYSCALL msg=audit(1418253698.016:418143182): arch=c000003e syscall=59 success=yes exit=0 a0=663e42 a1=7fff7d1ac220 a2=7fff7d1b0f30 a3= 341f418240 items=2 ppid=2744 pid=2849 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=65254 comm="sh" exe="/b in/bash" key="exec" is "out of order" even thus timestamp/event id are correct. This causes libaudit to also fail (as in doesnt output the complete message when calling auparse_feed() )

That one machine is running 2.6.32-431.17.1.el6.x86_64 (RHEL6 kernel package). I'm trying to get the timestamp issue reproduced as I played quite a bit with my local files - however this one is much harder to get. It was also part of a type=EXECVE message however.

I suspect it was part of the errors either through UDP/syslog corruption or different kernel. I'll keep looking tho.

Guillaume On 12/10/2014 03:54 AM, Richard Guy Briggs wrote: > On 14/11/24, Guillaume Destuynder wrote: >> Hi, > > Hi Guillaume, > >> on our RHEL6 machines, with kernel 2.6.32, we noticed that sometimes an >> audit message comes in but libaudit does not see it as the same event. >> >> The milliseconds field of the timestamp differs (but the timestamp >> seconds and event serial are identical). >> >> The check to determine if 2 messages are part of the same event is done >> by events_are_equal() in auparse/auparse.c (audit userspace library). >> >> There is a comment that indicate that this is voluntary - however, I >> could not find why. I suspect this is for searches over long periods of >> time when the serial may roll over. >> >> In case this was simply overlooked I'm attaching a patch that fixes it >> for us. It keeps the timestamp check for the seconds, which works fine >> and would still work with serial rolling over. >> >> Again- its relatively rare in our logs that the timestamp's millisecond >> field differs and we log very heavily - so it's not that easy to reproduce. > > Do you have a set (or three) of messages that fit this situation as a > sample? I'm looking through the kernel code to try and see how this is > possible. So far I am not convincing myself this is possible, but > perhaps I am missing a combination of messages that fits this scenario. > >> Thanks! > > Thanks! > >> Guillaume >> >> Index: trunk/auparse/auparse.c >> =================================================================== >> --- trunk/auparse/auparse.c (revision 1063) >> +++ trunk/auparse/auparse.c (working copy) >> @@ -752,10 +752,10 @@ >> >> static int inline events_are_equal(au_event_t *e1, au_event_t *e2) >> { >> - // Check time & serial first since its most likely way >> - // to spot 2 different events >> - if (!(e1->serial == e2->serial && e1->milli == e2->milli && >> - e1->sec == e2->sec)) >> + // Check serial and timestamp - but not milliseconds >> + // as, even if rare, these may not match for the same message due to >> + // kernel processing delays >> + if (!(e1->serial == e2->serial && e1->sec == e2->sec)) >> return 0; >> // Hmm...same so far, check if both have a host, only a string >> // compare can tell if they are the same. Otherwise, if only one > > - RGB > > -- > Richard Guy Briggs <rbriggs(a)redhat.com&gt; > Senior Software Engineer, Kernel Security, AMER ENG Base Operating Systems, Red Hat > Remote, Ottawa, Canada > Voice: +1.647.777.2635, Internal: (81) 32635, Alt: +1.613.693.0684x3545 > -- Security engineer @ Mozilla -- Linux-audit mailing list Linux-audit(a)redhat.com https://www.redhat.com/mailman/listinfo/linux-audit