Events Delayed in Example audisp Plugin

[Steve Grubb]

On Fri, 5 Apr 2019 11:35:03 -0700
Lukas Rupprecht <lukas.l.rupprecht at gmail.com> wrote:

> Hi All,
> 
> I'm, having problems with the example audisp plugin from
> https://github.com/linux-audit/audit-userspace/blob/master/contrib/plugin/audisp-example.c
> as sometimes, events seem to be delayed. 

It is always helpful to list which version of user space you have so
that if I know of any bug fixes, I can point you to that. That said,
there is a pending pull request that I am thinking to accept but
haven't yet that may solve your problem. It is against the example
code. See  https://github.com/linux-audit/audit-userspace/pull/83/files

It has to do with mixing raw and stdio which the latter is buffered.
Let me know if that fixes your problem.

Best Regards,
-Steve

>The scenario is as follows:
> 
> My audit rules are tracking clone, execve,setpgid, and exit_group
> calls and I changed the example plugin to just dump records in
> handle_event using the following code:
> 
> static void handle_event(auparse_state_t *au, auparse_cb_event_t
> cb_event_type, void *user_data) {
>     int type, num = 0;
> 
>     if (cb_event_type != AUPARSE_CB_EVENT_READY)
>         return;
> 
>     while (auparse_goto_record_num(au, num) > 0) {
>         type = auparse_get_type(au);
> 
>         // dump whole record
>         printf("%s: %s\n",
> audit_msg_type_to_name(auparse_get_type(au)),
> auparse_get_record_text(au));
> 
>         num++;
>     }
> }
> 
> When running a simple 'cat' command, I should see events for (in that
> order) clone, execve, setpgid, setpgid, exit_group. However, the
> plugin is only printing the first four events but not the exit_group.
> The event is printed eventually, but only, if there has been other
> system activity that triggered new, unrelated events (for example,
> another clone).
> 
> I added some instrumentation and found that, when the exit_group
> event arrives, fgets_unlocked (line 125) does read the SYSCALL record
> for exit_group but is missing the corresponding EOE record. A
> possible explanation could be that, when select unblocks,
> fgets_unlocked only reads a single line from stdin while the
> remaining data is buffered. Hence, when select is called the next
> time, it does not detect any activity on the file descriptor and
> blocks, and the buffered data is only read once select unblocks due
> to a new event.
> 
> To test this, I replaced the call to fgets_unlocked by a read call to
> consume all available bytes on stdin. The new code looks as follows
> (replacing lines 123-130 in audisp-example.c):
> 
> /* Now the event loop */
> if (!stop && !hup && retval > 0) {
>     ssize_t bytesRead = read(0, tmp, MAX_AUDIT_MESSAGE_LENGTH);
>     if (bytesRead > 0) {
>         // this is just for printf
>         tmp[bytesRead] = '\0';
>         printf("Read %d bytes from socket: %s", bytesRead, tmp);
> 
>         auparse_feed(au, tmp, bytesRead);
>     }
> }
> 
> Using this code, I can now see the EOE record for the corresponding
> exit_group SYSCALL record being read when the event arrives (I can
> see it printed by the printf in the event loop). However, the problem
> is that it is still not processed in handle_event until a new,
> unrelated event arrives, i.e. it is not printed immediately in
> handle_event. It should have been feed to the parser though as part
> of the last read. Could this be a bug or am I missing something? I
> tried this for versions 2.8.1 and 2.8.5.
> 
> Thanks for any help in advance!
> Lukas
> 
> 
> --
> Linux-audit mailing list
> Linux-audit at redhat.com
> https://www.redhat.com/mailman/listinfo/linux-audit