A combined audit event message

A combined audit event message

[Matthew Booth]

I've been looking into tuning an audit events analysis tool which
receives audit records over the network from a large number of systems.
It turns out that the most significant overhead (by far) on the
collection system is in stitching records from a single event back
together. This has lead me to explore combining records on the host
before sending them out. I'm currently intending to produce messages
like this:

audit(1235768839.011:68): type=SYSCALL arch=40000003 syscall=5
success=yes exit=3 a0=ad9c00 a1=8000 a2=1 a3=bfefd2d0 items=1 pid=6312
auid=500 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0
comm="echo" exe="/bin/echo" | type=CWD  cwd="/root" | type=PATH
name="/usr/lib/locale/locale-archive" flags=101 inode=126312 dev=03:01
mode=0100644 ouid=0 ogid=0 rdev=00:00

This seems considerably nicer than snare:

cent4.intersectalliance.com LinuxKAudit criticality,3
event,execve,20080613 16:06:29
       uid,0,root      gid,0,root     euid,0,root     egid,0,ro ot
process,2971,ls
       return,0,yes a0,8775a68        a1,875ec80      a2,8759448
a3,875ec80
       arch,40000003           auid,40000003 cwd,/var/log/audit
dev,fd:00          dev:1,fd:00
       exe,/bin/ls     flags,101      flags:1,101     fsgid,0,root
fsuid,0,root
       inode,97968 inode:1,146913             items,2         mode,0100755
       mode:1,0100755          name,/bin/ls ogid,0,root
ogid:1,0,root ouid,0,root
       ouid:1,0,root rdev,00:00       rdev:1,00:00 sgid,0,root
suid,0,root

which just munges all the fields together. It also has the advantage of
being extremely fast to generate from the existing messages without any
memory allocation or copying. Has anybody given this any thought? Has
anybody else got a similar format in the works/field?

Thanks,

Matt
-- 
Matthew Booth, RHCA, RHCSS
Red Hat, Global Professional Services

M:       +44 (0)7977 267231
GPG ID:  D33C3490
GPG FPR: 3733 612D 2D05 5458 8A8A 1600 3441 EA19 D33C 3490

Re: A combined audit event message

[Steve Grubb]

On Friday 27 February 2009 04:21:37 pm Matthew Booth wrote:
> This has lead me to explore combining records on the host
> before sending them out. I'm currently intending to produce messages
> like this

Combining like this means adding a new character '|' to the decision about 
what constitutes an encoded field. Personally, I am not in favor of any 
radical changes in the next 3-4 months. Just some slow evolution.

-Steve

Re: A combined audit event message

[Matthew Booth]

Steve Grubb wrote:
> On Friday 27 February 2009 04:21:37 pm Matthew Booth wrote:
>> This has lead me to explore combining records on the host
>> before sending them out. I'm currently intending to produce messages
>> like this
> 
> Combining like this means adding a new character '|' to the decision about 
> what constitutes an encoded field. Personally, I am not in favor of any 
> radical changes in the next 3-4 months. Just some slow evolution.
> 
> -Steve

A good point. What are the existing characters? Maybe one of them would
be suitable.

I'm going to make this change to austream. However, if anybody else has
anything similar on their roadmap, or has given thought to this problem
before I'd like to align with that. Ultimately I want to deprecate austream.

Matt
-- 
Matthew Booth, RHCA, RHCSS
Red Hat, Global Professional Services

M:       +44 (0)7977 267231
GPG ID:  D33C3490
GPG FPR: 3733 612D 2D05 5458 8A8A 1600 3441 EA19 D33C 3490

Re: A combined audit event message

[Matthew Booth]

Steve Grubb wrote:
> On Friday 27 February 2009 04:21:37 pm Matthew Booth wrote:
>> This has lead me to explore combining records on the host
>> before sending them out. I'm currently intending to produce messages
>> like this
> 
> Combining like this means adding a new character '|' to the decision about 
> what constitutes an encoded field. Personally, I am not in favor of any 
> radical changes in the next 3-4 months. Just some slow evolution.

Thinking about it, I'm using a combination of space (which presumably is
escaped) and a pipe. The space should mean that escaping isn't a
problem, while the pipe indicates the end of a record. '|' is just like
a field name in this respect. Have I missed something?

Matt
-- 
Matthew Booth, RHCA, RHCSS
Red Hat, Global Professional Services

M:       +44 (0)7977 267231
GPG ID:  D33C3490
GPG FPR: 3733 612D 2D05 5458 8A8A 1600 3441 EA19 D33C 3490

Re: A combined audit event message

[LC Bruzenak]

On Fri, 2009-02-27 at 21:21 +0000, Matthew Booth wrote:
> I've been looking into tuning an audit events analysis tool which
> receives audit records over the network from a large number of systems.
> It turns out that the most significant overhead (by far) on the
> collection system is in stitching records from a single event back
> together. This has lead me to explore combining records on the host
> before sending them out. I'm currently intending to produce messages
> like this:
> 
> audit(1235768839.011:68): type=SYSCALL arch=40000003 syscall=5
> success=yes exit=3 a0=ad9c00 a1=8000 a2=1 a3=bfefd2d0 items=1 pid=6312
> auid=500 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0
> comm="echo" exe="/bin/echo" | type=CWD  cwd="/root" | type=PATH
> name="/usr/lib/locale/locale-archive" flags=101 inode=126312 dev=03:01
> mode=0100644 ouid=0 ogid=0 rdev=00:00
> 

Matt,

If you don't mind indulging me a moment...I am very interested in the
ultimate goal you stated, "tuning an audit events analysis tool which
receives audit records over the network from a large number of systems",
since that is where I am headed...

For example I see the following from an ausearch :
...
----
node=jcdx type=PATH msg=audit(02/27/2009 15:32:41.747:2986) : item=0
name=/var/log/audit/audit.log inode=375 dev=fd:00 mode=file,600
ouid=root ogid=root rdev=00:00
obj=system_u:object_r:auditd_log_t:s15:c0.c1023 
node=jcdx type=CWD msg=audit(02/27/2009 15:32:41.747:2986) :  cwd=/root 
node=jcdx type=SYSCALL msg=audit(02/27/2009 15:32:41.747:2986) :
arch=x86_64 syscall=open success=yes exit=4 a0=7fffe635efeb a1=0
a2=f71a60 a3=f71a58 items=1 ppid=9014 pid=9492 auid=root uid=root
gid=root euid=root suid=root fsuid=root egid=root sgid=root fsgid=root
tty=pts1 ses=8 comm=ausearch exe=/sbin/ausearch
subj=root:auditadm_r:auditadm_t:s0-s15:c0.c1023 key=(null) 
node=jcdx type=AVC msg=audit(02/27/2009 15:32:41.747:2986) : avc:
denied  { read } for  pid=9492 comm=ausearch name=audit.log dev=dm-0
ino=375 scontext=root:auditadm_r:auditadm_t:s0-s15:c0.c1023
tcontext=system_u:object_r:auditd_log_t:s15:c0.c1023 tclass=file 
node=jcdx type=AVC msg=audit(02/27/2009 15:32:41.747:2986) : avc:
denied  { search } for  pid=9492 comm=ausearch name=audit dev=dm-0
ino=33885 scontext=root:auditadm_r:auditadm_t:s0-s15:c0.c1023
tcontext=system_u:object_r:auditd_log_t:s15:c0.c1023 tclass=dir 

And the corresponding raw file has this:
...
node=jcdx type=AVC msg=audit(1235770361.747:2986): avc:  denied
{ search } for  pid=9492 comm="ausearch" name="audit" dev=dm-0 ino=33885
scontext=root:auditadm_r:auditadm_t:s0-s15:c0.c1023
tcontext=system_u:object_r:auditd_log_t:s15:c0.c1023 tclass=dir
node=jcdx type=AVC msg=audit(1235770361.747:2986): avc:  denied
{ read } for  pid=9492 comm="ausearch" name="audit.log" dev=dm-0 ino=375
scontext=root:auditadm_r:auditadm_t:s0-s15:c0.c1023
tcontext=system_u:object_r:auditd_log_t:s15:c0.c1023 tclass=file
node=jcdx type=SYSCALL msg=audit(1235770361.747:2986): arch=c000003e
syscall=2 success=yes exit=4 a0=7fffe635efeb a1=0 a2=f71a60 a3=f71a58
items=1 ppid=9014 pid=9492 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0
egid=0 sgid=0 fsgid=0 tty=pts1 ses=8 comm="ausearch"
exe="/sbin/ausearch" subj=root:auditadm_r:auditadm_t:s0-s15:c0.c1023
key=(null)
node=jcdx type=CWD msg=audit(1235770361.747:2986):  cwd="/root"
node=jcdx type=PATH msg=audit(1235770361.747:2986): item=0
name="/var/log/audit/audit.log" inode=375 dev=fd:00 mode=0100600 ouid=0
ogid=0 rdev=00:00 obj=system_u:object_r:auditd_log_t:s15:c0.c1023

And what you are saying is that rather than use the ausearch equivalent
(or whatever tool which uses auparse library) on the receiving end, it
is more expedient to combine the record into one event prior to sending?
IIUC, is it because of the reduced amount of data flowing or less
processing needed on the receiving end (or both)?

Thx,
LCB.

-- 
LC (Lenny) Bruzenak
lenny@magitekltd.com

Re: A combined audit event message

[Matthew Booth]

LC Bruzenak wrote:
> And what you are saying is that rather than use the ausearch equivalent
> (or whatever tool which uses auparse library) on the receiving end, it
> is more expedient to combine the record into one event prior to sending?
> IIUC, is it because of the reduced amount of data flowing or less
> processing needed on the receiving end (or both)?
> 

Well, I'm tuning for the particular tool in use by my customer. This
particular tool has problems with this workload. I can't back up a
generalisation with numbers.

However, architecturally the host seems like the right place to do this.
It's much cheaper to do on the host as you don't have to filter out
events from other hosts, and you're also distributing the load somewhat.

Interestingly on the host load point, I quite unexpectedly saw an
improvement in host performance when sending combined messages. Run time
of a pathological test case improved about 5%. The code isn't production
quality yet, and I haven't done any major analysis of that, but my guess
is that the slight increase in work to stitch the messages together is
outweighed by the reduction in the number of network system calls.

Matt
-- 
Matthew Booth, RHCA, RHCSS
Red Hat, Global Professional Services

M:       +44 (0)7977 267231
GPG ID:  D33C3490
GPG FPR: 3733 612D 2D05 5458 8A8A 1600 3441 EA19 D33C 3490