6:19 a.m.
Hello Steve,
[ time descending, sequence number ascending problem ]
What this indicates is that there was some recursion before the
syscall
triggered an event. The syscall context exists from sycall entry to exit.
If during the middle a signal is delivered, the syscall is not finished.
Instead it runs the signal handler associated with the signal. The signal
handler might make syscalls which are then handled using the existing
syscall context via linked list. When that occurs, the timestamp is not
being updated. Not sure that is appropriate or why the original time really
mattered. But that is what you are observing. My guess is SIGTERM is being
delivered during another syscall.
That raised the following question to me: We have "entry" rules defined. When
we saw that we get exit codes, the conclusion was that "entry" and
"exit" are
not different for every syscall. Can you confirm?
And assuming that, indeed the may fork complete only after its has completed
its signal handlers. The expectation would be that this is not an issue
though, because the new process is inactive. Wrong assumption. The new
process seemingly can already EXECVE with its fresh life, if the call of FORK
is interrupted after the process exists.
Now that poses an interesting problem. I guess, what we are missing is that
FORK should actually enter once and return up to _two_ times, and we need to
handle and see traces of these. That way we would simply see FORK return with
0 for the child before it does EXECVE, and so we would know who created it
(ppid) and know that it exists.
I tried to change our rules to "exit,always" from "entry,always", but
it
didn't make a difference. Can you confirm that only one exit is traced and do
you think audit can be enhanced to trace these extra exits of syscalls like
FORK.
For every workaround, a SIGKILL signal towards the FORK making process would
probably leave us even without a trace, forever possibly.
As for the signal at hand here, I think we have ant (gcj based Java) doing
multi-threading (parallel building). That would be FORKs series with probably
a SIGALARM or whatever they use to switch target execution without resorting
to threading.
> Seems like a bug? Can you have a look at it?
I'll check on why we don't update the time stamp during syscall recursion.
Thanks a lot. I guess, the expectation could be that "exit" traces have the
datation of the "exit" and not "entry".
Then there is a problem of correlation. If I have 1 rule that expands
to 2,
then how can I do a compare of what's in memory vs what rules are on disk?
IOW, how do I tell that someone typed:
-a entry,always -F arch=b32 -S clone -S fork -S vfork
-a entry,always -F arch=b64 -S clone -S fork -S vfork
or just
-a entry,always -S clone -S fork -S vfork
because auditctl would make 2 from 1. This is a really tricky issue and if
we didn't care about correlation...or about outdated tools we trust too
much...we could do this.
That's understood. And a typical danger of user friendly abstraction is that
it causes confusion. As I said, -F was bound to "filter" in my mind.
For "arch" it's suddenly a selector. I would find something like this more
logical:
-a entry,always,any -S clone -S fork -S vfork
and if I really only wanted a certain arch, make me say so:
-a entry,always,b64 -S clone -S fork -S vfork
ausyscall x86_64 clone
56
ausyscall i386 clone
120
Very good. We have initially defined a hash in Python manually with what we
encounter, but we can rather use that to create them. We specifically have
the problem of visiting a s390 site, where it will handy to have these
already in place. There is no such function in libaudit, is there?
We have an audit parsing library. It takes this into account.
I have looked at it, and auparse_init doesn't seem to support reading from the
socket itself, does it? It could be AUSOURCE_FILE. And there there is the
issue that the logs on disk seem to be different from what format we get on
the socket. The node= is not on disk, newlines, empty lines, etc. see below
about that.
In an ideal world, we would like to note that the audit socket is readable,
hand it (or an arbitrarily truncated chunk of data) from it to libaudit, ask
it for events until it says there are not more. That would leave the
truncated line/event issue to libaudit. Is that part of the code?
> Without a very stateful message parser, one that e.g. knows how
many
> lines are to follow an EXECVE, we don't know when to forward it the part
> that should process it.
[Example deleted]
Look at the syscall record. It is always emitted with multi-line
records.
It has an items count. Each auxiliary (path in this case) record has an
item number. You can tell when you have everything. Single line entries do
not have an items field. Also note that the record comprising an event
comes out of the kernel in a backwards order.
Ah, we simply ignored the type=PATH etc. elements. But what I mean is that of
the syscall itself, the arguments seemed to be on new lines:
This is from Python code:
data = _audit_socket.recv( 32*1024 )
print data
node=Annuitka type=SYSCALL msg=audit(1218880198.814:42205): arch=c000003e
syscall=59 success=yes exit=0 a0=16cc168 a1=1464c08 a2=1588008 a3=0 items=2
ppid=3864 pid=19928 auid=4294967295 uid=1000 gid=1000 euid=1000 suid=1000
fsuid=1000 egid=1000 sgid=1000 fsgid=1000 tty=pts3 ses=4294967295 comm="ls"
exe="/bin/ls" key=(null)
node=Annuitka type=EXECVE msg=audit(1218880198.814:42205): argc=2 a0="ls"
a1="--color=auto"
node=Annuitka type=CWD msg=audit(1218880198.814:42205):
cwd="/data/home/anna/comsoft/v7a1-ps2-acs/src/acs"
node=Annuitka type=PATH msg=audit(1218880198.814:42205): item=0 name="/bin/ls"
inode=1651626 dev=08:12 mode=0100755 ouid=0 ogid=0 rdev=00:00
node=Annuitka type=PATH msg=audit(1218880198.814:42205): item=1 name=(null)
inode=779612 dev=08:12 mode=0100755 ouid=0 ogid=0 rdev=00:00
node=Annuitka type=EOE msg=audit(1218880198.814:42205):
Note that we get a SYSCALL with 2 items, and then in order the items - from
the socket. But inbetween we get type=EXECVE it doesn't have an item number,
and worse the new line before 'a1=--color-auto' is real and so is the empty
line after it. I have another example of a "gnash" call from Konqueror with
no less than 29 arguments.
That means, in order to parse the socket, we should check argc, right? I think
we would prefer very long lines like they are in /var/log/audit instead,
making these kinds of steps optional.
Actually I don't understand the differences in format. I assume they serve the
purpose of making things readable?
Did you know about the audit parsing library?
Our assumption was also that it should be easy enough to parse the text. Well
you know assumptions. Rarely ever true. :-)
> This is in hope that indeed continued lines always start with a
non-space
> and type lines always start with a space. Would you consider this format
> worthy and possible to change?
Don't like changing formats as that affects test suites.
That " type=" start is a self-confusion of ours. Starting with 1.6 the node=
part was added, and some hack was still in place that removes "node=hostname"
and leaves the space there. Sorry about that.
> I have no idea how much it represents and existing external
interface,
> but I can imagine you can't change it (easily). Probably the end of type=
> must be detected by terminating empty line in case of those that can be
> continued. But it would be very ugly to have to know the event types that
> have this so early in the decoding process.
We have a parsing library, auparse, that handles the rules of audit
parsing. Look for auparse.h for the API.
If you confirm that can handles the parsing from the socket, as suggested
above, we may persue that path and can ignore strangeness of the format once
its handled by the library.
> > There might be tunables that different distros can used
with glibc.
> > strace is your friend...and having both 32/64 bit rules if amd64 is the
> > target platform.
>
> We did that of course. And what was confusing us was that the audit.log
> did actually seem to show the calls. Can that even be?
Yes, as explained above.
Sorry, I am still confused. Can you explain why the socket and the audit.log
can have different contents. I was blaming my (usually bad) memory.
> I see. Luckily we are not into security, but only
"safety". I can't find
> anything on Wikipedia about it, so I will try to explain it briefly,
> please forgive my limited understanding of it. :-)
At one point, I worked on Space Shuttle software. I know a little on how
they think about this.
Well, that's perfect. :-)
> > > 2. We don't want to poll periodically, but rather
only wake up (and
> > > then with minimal latency) when something interesting happened. We
> > > would want to poll a periodic check that forks are still reported, so
> > > we would detect a loss of service from audit.
> >
> > You might write a audispd plugin for this.
>
> Did you mean for the periodic check,
There is a realtime interface for the audit stream. You can write either a
new event dispatcher or a plugin to the existing one. Seeing as you are
more concerned with assurance, I'd just replace the current dispatcher with
your own. I have a description of this here:
http://people.redhat.com/sgrubb/audit/audit-rt-events.txt
I saw that too, but I thought it would be better to build upon the existing
effort. I think that's a viable alternative and potentially could be more
robust to us. At least it could be that audisp seems to try and solve
problems we don't have or want.
Looking at the source I saw that node name is something that audisp indeed
adds the node name and that auditd doesn't log EOEs, explaining some of the
differences. I didn't find why audisp has extra new lines, or if auditd
removed these.
I think we will make a prototype for the RT interface and see what it gives
us.
> or for the whole job, that means our supervision process?
The supervision process. Then again, maybe you want to replace the audit
daemon and handle events your own way. libaudit has all the primitives for
that. So, I guess that brings up the question of how you are accessing the
audit event stream. Are you reading straight from netlink or the disk?
From the files is out of question. We thought of the audit sub deamon
as
something that simply allows to access the audit stream live, but that it is
otherwise the same as the file. Like auditd would accept things from the
kernel, write it to a file and hand it to audisp as well which would then
provide it to others. Isn't that the design?
> I was wondering why audit wouldn't use that. Is that
historic (didn't
> exist, nobody made a patch for it) or conscious decision (too difficult,
> not worth it). Just curious here and of course the comment could be read
> as a bit scary, because it actually means we will have to benchmark the
> impact...
systemtap came after audit. They have 2 different purposes. One is
debugging/profiling, the other is regulatory compliance and security. The
system tap people have no gurantees about what kinds of data is contained
in the stream or the reliability of delivery. There was some talk about
combining hooks and in the end it was decided that we should leave them
disconnected as they serve entirely different purposes.
Ah I see. Thanks for the explanation. :-)
Best regards,
Kay Hayen