Skip to contentSkip to conversation

A combined audit event message

DISCUSSION Matthew Booth 3 participants 6 messages Feb 27, 2009

lore
Share & tools
lore
#0 lore raw

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

Signature · 6 lines
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
#1 lore raw
Quoted 3 lines · Matthew Booth

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

#2 lore raw
Quoted 10 lines · Steve Grubb
Quoted 3 lines · Matthew Booth

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

Signature · 6 lines
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
#3 lore raw
In reply to Steve Grubb
Quoted 8 lines · Steve Grubb
Quoted 3 lines · Matthew Booth

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

Signature · 6 lines
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
#4 lore raw
In reply to Matthew Booth
Quoted 8 lines · 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:

Quoted 7 lines

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.

Signature · 2 lines
LC (Lenny) Bruzenak
[email protected]
#5 lore raw
Quoted 6 lines · LC Bruzenak

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

Signature · 6 lines
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