Hello Steve, thanks for your reply, very helpful. :-) [...] by the jiffy/system ticks since boot (at least did I find comments that suggest so). I still have to verify how it is translated. There still is the issue of translating ticks into seconds since 1970. So far I have only achieved to get hands on system boot time in a granularity of one second. I have no clue if that is the same time used in the kernel to offset the ticks value. I will make a delta test once I can. But suspect would be that the real time clock has better time than one second, which is all that I get from /proc/stat btime: field. More importantly, and somewhat blocking my tests: With the improved rules I get this when compiling quite well reproducible: type=SYSCALL msg=audit(1218773075.500:118620): arch=c000003e syscall=59 success=yes exit=0 a0=7fff6f78cf90 a1=7fff6f78cf40 a2=7fff6f78f068 a3=0 items=2 pp id=11412 pid=11421 auid=4294967295 uid=1000 gid=1000 euid=1000 suid=1000 fsuid=1000 egid=1000 sgid=1000 fsgid=1000 tty=pts3 ses=4294967295 comm="gcc-4.3" exe="/usr/bin/gcc-4.3" key=(null) [...] type=SYSCALL msg=audit(1218773075.496:118624): arch=c000003e syscall=56 success=yes exit=11421 a0=1200011 a1=0 a2=0 a3=7fc067776770 items=0 ppid=11407 pid =11412 auid=4294967295 uid=1000 gid=1000 euid=1000 suid=1000 fsuid=1000 egid=1000 sgid=1000 fsgid=1000 tty=pts3 ses=4294967295 comm="gnatchop" exe="/usr/b in/gnatchop" key=(null) Please note the _ascending_ sequence number but _descending_ time. This is pasted from my audit.log and quite surprising. It triggers an assertion in our code, because we also seem receive things in the wrong order from the socket. There was not FORK before the EXECVE that refers to the pid. We tolerate that (obviously there are going to be processes that we didn't see fork once we start, we don't do an initial scan yet), but we don't tolerate that fork returns an existing pid. Seems like a bug? Can you have a look at it? I was using for that: -a entry,always -F arch=b32 -S clone -S fork -S vfork -a entry,always -F arch=b64 -S clone -S fork -S vfork -a entry,always -S execve -a entry,always -S exit_group -S exit I didn't apply the arch to exit, etc. yet, but there wasn't an pid rollover yet, so I don't think that missing an exit is really the issue here. Plus I still did't fully grasp why that arch filter was necessary in the first place. I mean, after all, I was simply expecting that per default no filter should give all arches. Is that filter actually a selector? Does it have to do with the fact that syscall numbers are arch dependent? Thanks for the pointer. That looks indeed like nothing can go wrong on the reliability side of time and serial. The more astounding my report from above is. That's fine with us. We just wouldn't want to be in an inconistent state after a load peek. I think with a decicated core for our supervision processes, everything except benchmarks of clone performance (aka fork bombs) will be able to trigger any actual issue. I will have to check if this affects our intended process tracing. The parsing is certainly not simplified by it, for a possibly unrelated reason. We read from a socket, and in data chunks, which are then processed. For that, we want to identify the end of a message before processing it. Right now, we have switched to waiting for type=EOE and its new line. Without that, the fact that type=non-EOE may be a multi-line thing. I think parameters are on new lines and that makes it a bit hard to detect the end of a complete type= trace. I don't see that in the audit.log, so probably it's a problem of the sub-daemon: type=EXECVE msg=audit(1218774568.173:129440): argc=4 a0="/bin/sh" a1="..." a2="..." a3="..." 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. What we first, once we got a message is the following code: # 1. Some lines are split across multiple lines. The good thing is that these never start # with whitespace and so we can make them back into single lines. This makes the next # part easier. lines = [] for line in message.split( "\n" ): if line.strip() == "": pass elif line.startswith( " type=" ): lines.append( line ) else: assert line[0] != ' ' lines[-1] = lines[-1] + ' ' + line 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? 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. That's OK for us. And until then self-compiled will do. Actually that solved the trouble of not seeing anything on "Debian". The fact is that we are using RHEL x86 for production and Debian (or Ubuntu) amd64 on our development machines. So we never checked RHEL amd64, which likely would show the same thing. But see above, this possibly a bug? 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? 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. :-) Increasingly we in the ATC need to provide a "Software Assurance Level" (SWAL) to our customers and those to their regulators. That's one of many standards to define "safety". Depending on the level, you may not only need to document the requirements of your software or you have to relate each line of code with them and ultimately prove the correctness of compiler output. I believe they do this for fighter planes. We currently target level 3, which means that we will have to prove that we have concerned ourselves with all possible hazards and their combinations and if that would lead to "safety" relevant things. For the running system, we don't have to prove anything. There are "legal recordings" of the input and output data, but no complete logs of the operation are required per se, although of course, as we support the analysis of trouble reports, that is ver welcome. That level is acceptable for non-airborne systems. So if we are running and monitoring a system, and if e.g. certain process must run to prevent planes from colliding, we must provide explanations (and tests) of why we are at any time sure _if_ (not "that") the process is running or how the problem will be noted by the software and ultimately the operators through other means, if that fails. On a general level, redundancy is normally the solution to hazards. Everything is doubled, and you normally have 2 trackers, etc. so you use not only one software, but multiple implementations. When something fails, we generally stop the software unless we are sure it's an isolated event. That is because data corruption is worse than no data at all. An unseen flight or a falsely reported flight is a lot worse than a crashed system that only needs a restart and will be back in operation within time limits. Our concern is not at all to prevent or detect malicious use of the system. If somebody wants to run a binary in a hidden way and takes effort to achieve that, other processes have failed already. Our systems always run in an environment where security is already solved through other means. The systems e.g. do allow rsh login, without a password, as root. I hope you can continue breathing now. :-) It certainly will be very helpful to have the audit log and it searchable and I understand we get that automatic by leaving audit enabled, but configured correctly. In the past we have disabled it, because it caused a full disk and boot failure on RHEL 3 after only a month or so. I think it complained about the UDP echo packets that we use to check our internal LAN operations, but it could have been SELinux too. So, what we will do with audit is to look at source code, identify design principles that make errors impossible, write that down, define our requirements of it, test these. And ultimately we may have to provide an alternative implementation without audit at all, with probably worse latency, and the ability to detect and compensate (simulated) audit bugs. And test that as well. And in some figure, we will say: If the tracker process exits, we will detect that on avarage after 1 ms, and at latest after 50ms. And that will play a role in the time it takes to switch to the standby tracker process on another hardware. And that will e.g. have the requirement to be able to take over in 1 or 3 seconds, and that will be possible, because the process that hands over started early enough and takes itself a limited time. The ultimate benefits of auditd would be to us: a) Achieve very low values in latency, being able to observe an "exit" as it happens, not just when a periodic timer makes a test. We can only achieve these kinds of performance through child process SIGCHLD so far and signals are not an ideal interface. Being able to monitor non-childs is very good for us, actually what made us interested in audit in the first place. b) Robust operation. In theory the audit approach should be able to receive assurances that certain hazards just cannot happen that's very nice and certainly increases the assurances we can give for our process supervision, a key stone building part for every system. c) Our middleware may suddenly offer to monitor processes like ntpd, cron jobs, etc. very easily and without system changes. There are systems that work with "ps", "grep" and "kill" to achieve this, but as you can imagine, that only goes so far. Security, in the sense of intrusion detection, authorization, etc. doesn't play a role to us. So we don't need audit trails for our live supervision, we "only want to know" what was running, what is running. Did you mean for the periodic check, or for the whole job, that means our supervision process? We certainly would prefer the plugin approach for such a test, esp. if there is hope that you accept it into your code. The closing of the socket in case of loss of service would be sufficient signal to us. Regarding performance I would like to say, you are likely right in that it's a non-issue. It has something of a bike-shed to me though. :-) I think I still have http://lwn.net/Articles/290428/ on my mind, where I had the impression that kernel markers would only require a few noop instructions as place holders for a jumps that would cause audit code to run. 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... Best regards, Kay Hayen

Hello Steve, [ time descending, sequence number ascending problem ] 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. Thanks a lot. I guess, the expectation could be that "exit" traces have the datation of the "exit" and not "entry". 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 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? 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? [Example deleted] 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? Our assumption was also that it should be easy enough to parse the text. Well you know assumptions. Rarely ever true. :-) 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. 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. 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. Well, that's perfect. :-) 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. 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? Ah I see. Thanks for the explanation. :-) Best regards, Kay Hayen

Hello Steve, The missing FORK return is incidentally the one we care about. We have no concern if a process forks or not, we only want to know and see the new process. It doesn't matter if the parent ever got to notice it. Is there any hope such a patch could be part of RHEL 5.3, given that Redhat has its own kernel release process? I am not that much into security, but I could imagine that it's possible to carefully craft a process that escapes the audit trail with SIGKILL to a forker. All you got to do is to fork a process that will fork another and with increasingly bigger times, you SIGKILL the process until its child will secretely survive. Well for the functionality of ausyscall. If we could query the current arch, well it's b32/b64 arches, then we could build that table at run time, couldn't we? That would be a whole lot nicer than hardcoded values, even if they are generated using ausyscall. No, when opening the socket the to the sub deamon audisp. I couldn't convice myself how the API would work with a socket. Does it? I read that as that we can use the netlink socket with the libaudit directly, which sort of could be exactly what we want. That would mean we wouldn't use audit user space (processes) at all, right? I see. Strange to see line formatting like that in the kernel in the first place. But libaudit doesn't care about them anyway I suppose. And I read that as the libaudit library being unable to use the netlink socket directly. [ Options for listening] The latency is getting higher with each step. For optimal performance we would listen to the netlink socket and duplicate only the code essential to process what we are interested it. For extra points and hurt, we would do it in Ada and inside the target process, really achieving the low latency. It may be the only realistic option, but it also feels like duplication of effort. We have done netlink interfaces in Ada before, but also have on our mind that it was said that the netlink interface was said (not by you) to be still in flux. Is that still true? It certainly would be nice if the audisp had some form of output that can be fed directly into libaudit parsing as it comes in. But that may be an unrealistic expectation, is it? Well, as it is, the parsing must be done in lines, and you must be stateful to know how many of them to expect, because of two bugs only: a) "Random" newlines for some type=xxx values. b) No item= for type=EXECVE and similar. If it were not for that, the parsing of socket output would be much easier. I understand both issues will be addressed in future releases, which is a good outcome. The difference between disk and audisp socket was also confusing to us. Some corrections (removal of newlines) were applied to only one part. Overall I would like to thank you for clarifying the supposed workings, addressing found bugs, and advising us very well. If we choose to use the netlink socket for audit messages, we are of course interested about the kernel changes. The missing fork exits more so than the EXECVE extra newlines which should be easy enough to compensate. Best regards, Kay Hayen

Hello John, Am Dienstag, 19. August 2008 16:14:54 schrieb John Dennis: That's great. We can use the first approach initially (unix socket), a plugin is not so good for us, because our supervision process would need to receive from it anyway. The next best step would be to use the netlink socket directly. From what Steve wrote, that doesn't seem entirely difficult either: Steve wrote: That seems pretty direct too. If it's that easy to use auparse with either audisp socket or netlink socket, all the blame on us for not discovering it on our own. :-) The extra handling of the netlink socket may not be that much code then, allthough I suspect it requires a root rights (or simply a capability I would hope). Well, for lowest latency possible (note the "live" in subject), it would be ideal to avoid context switches auditd -> audisp -> our supervisor and instead simply run an additional netlink socket in addition to auditd (if that is allowed). That way we would have a lot less latency, at least in theory. But that could well be a final step only and future work and be judged by measurements of what we get from the relatively easy solution. I am going to try out that approach of AUSOURCE_FEED and report. Best regards, Kay Hayen

On Tuesday 19 August 2008 02:45:00 Kay Hayen wrote: <snip> Just because a process exists is not a security concern. The process actually has to do something related to security - e.g. access resources. At that point we will pick it up. I can see that we should probably have 2 records on the clone syscall if that is being audited. Sure, but as soon as it touches something or makes any syscall, its potentially auditable. Sure. If you look at the code for ausyscall, it simply calls audit_syscall_to_name() in libaudit. On number to string its a straight lookup, for string to number, we have to brute force search for it. Sure. Occassionally syscalls get added to the upstream kernel and very rarely to a RHEL kernel. So, using libaudit would future-proof the code. Not directly because the audit internal API has the type as an integer separate from the text of the event. Its really simple to create a string that auparse can use and then use the feed interface. A working example of the feed interface can be found in audisp/plugins/prelude/audisp-prelude.c. True. You would have to load your own rules since that is done by the audit user space. No it doesn't. Things down stream from it might, but its stripped going to disk. No, libaudit is the I/O inteface with the kernel. The audit daemon and auditctl make extensive use of it when talking to the kernel about audit events. wrt auparse (if that's what you meant) you just run the data through: asprintf(&v, "type=%s msg=%.*s\n", type, e->hdr.size, e->data); and "v" has the string ready for auparse use. asprinf() allocates memory, so watch that it doesn't create a memory leak. Sure We are in the process of migrating from the old rules to the new rules API. from kernel 2.6.6 to around 2.6.16 had one API (audit_add_rule) and replaced with a new and improved API (audit_add_rule_data) for kernels after that. The deprecated functions should be removed from libaudit.h so that there is binary compatibility for prebuilt apps and newly built apps won't be able to use the old functions. one note...libaudit is an I/O library, libauparse is the library that parses audit events. Assuming you meant the latter...they are built for one another. The audispd feeds data to siblings. In the configuration file, you just specify that the child app wants string data and it takes care of the conversion. The prelude plugin is a good example. However, audispd plugins are probably too high of latency for you. Converting the kernel's data into a string is simple as code snippet above shows. -Steve

On Tuesday 19 August 2008 14:23:21 Kay Hayen wrote: Only one audit pid is allowed for security purposes. Nope, it only allows one. If you want to co-exist with auditd, then you want to write your own audispd. I pointed you to the skeleton.c code in the other email. No pitfalls except watching for memory leaks. Audispd used the same code. -Steve

On Tuesday 19 August 2008 16:33:58 Kay Hayen wrote: Its been there since 2.6.6 kernel. IOW - day 1. The queueing is complicated and if you have a group of processes it gets real messy. The audit queue tries hard for guaranteed delivery or take the system down if the flow is not working right. Its not like syslog or iptables logging. SE Linux helps for MLS systems, but for CAPP, it doesn't come into play. The data flowing through the audit system could be very sensitive. Anyone needing access to the stream either needs to replace auditd, write their own dispatcher, or write a plugin to the shipped dispatcher. This way the admin knows exactly what processes have access to the data. -Steve

On Tuesday 19 August 2008 17:35:14 Kay Hayen wrote: Sort of. The initscripts of auditd load the rules using auditctl -R /etc/audit/audit.rules. So, you'd want to do that in your initscript if you decide to replace auditd. -Steve