On Monday, November 24, 2014 08:23:26 PM Guillaume Destuynder wrote:
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).
This seems to be a bug in the kernel code. Its a fundamental principle that
all records that make up an event have the same time stamp and serial number.
My guess (not having looked at the code) is that its calling a convenience
function that looks up the time anew for each record rather than reading it
once and reusing it as it outputs each record of the event.
The code in audit_log_exit is probably the only place where it really matters
because it can generate multiple records composing 1 event. We might need a
audit_log_start_time() function that takes the timestamp as a parameter. The
old audit_log_start can grab a new timestamp and call the new function with
the timestamp.
I think we should fix the source of the problem. This is a really good finding.
I didn't realize this was happening.
Thanks,
-Steve
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.