From mboxrd@z Thu Jan 1 00:00:00 1970 From: Guillaume Destuynder Subject: Re: [PATCH] auparse.c events_are_equal() and event matching Date: Thu, 11 Dec 2014 01:12:32 +0100 Message-ID: <5488E170.2090600@mozilla.com> References: <5474043E.4010407@mozilla.com> <20141210025438.GB29998@madcap2.tricolour.ca> Mime-Version: 1.0 Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit Return-path: Received: from mx2.redhat.com (ext-mx01.extmail.prod.ext.rdu2.redhat.com [10.11.55.1]) by int-mx11.intmail.prod.int.phx2.redhat.com (8.14.4/8.14.4) with ESMTP id sBB0Ccuo007759 for ; Wed, 10 Dec 2014 19:12:38 -0500 Received: from smtp.mozilla.org (mx1.corp.phx1.mozilla.com [63.245.216.69]) by mx2.redhat.com (8.14.4/8.14.4) with ESMTP id sBB0CZer005436 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-GCM-SHA384 bits=256 verify=NO) for ; Wed, 10 Dec 2014 19:12:36 -0500 Received: from localhost.localdomain (insecure.ws [82.231.161.45]) (Authenticated sender: gdestuynder@mozilla.com) by mx1.mail.corp.phx1.mozilla.com (Postfix) with ESMTPSA id 01B2FF228D for ; Wed, 10 Dec 2014 16:12:33 -0800 (PST) In-Reply-To: <20141210025438.GB29998@madcap2.tricolour.ca> List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Sender: linux-audit-bounces@redhat.com Errors-To: linux-audit-bounces@redhat.com To: linux-audit@redhat.com List-Id: linux-audit@redhat.com 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 > 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