Re: Occasional delayed output of events

From: Burn Alting <burn.alting@iinet.net.au>
To: Steve Grubb <sgrubb@redhat.com>, Paul Moore <paul@paul-moore.com>
Cc: Richard Guy Briggs <rgb@redhat.com>,
	Linux Audit <linux-audit@redhat.com>
Subject: Re: Occasional delayed output of events
Date: Wed, 20 Jan 2021 17:38:26 +1100	[thread overview]
Message-ID: <ebcdc0bc829e126c9fb9747b2457c5211527c8b1.camel@iinet.net.au> (raw)
In-Reply-To: <805552026.0ifERbkFSE@x2>


[-- Attachment #1.1: Type: text/plain, Size: 3186 bytes --]

All,
How is the following for a way forward.
a. I will author a patch to the user space code to correctly parse this condition
and submit it on the weekend. It will be via a new configuration item to auditd.conf
just in case placing a fixed extended timeout (15-20 secs) affects memory usage for
users of the auparse library. This solves the initial problem of ausearch/auparse
failing to parse generated audit.b. I am happy to instrument what ever is
recommended on my hosts at home (vm's and bare metal) to provide more information,
should we want to 'explain' the occurrence, given I see this every week or two and
report back.
On Tue, 2021-01-19 at 16:51 -0500, Steve Grubb wrote:
> On Tuesday, January 19, 2021 3:26:04 PM EST Paul Moore wrote:
> > On Tue, Jan 19, 2021 at 2:38 PM Burn Alting <burn.alting@iinet.net.au> 
> wrote:
> > > All systems use chrony (current NTP daemon). One is a VM (on top of KVM)and
> > > the other a bare metal deployment. Does the above explain my seconddata set
> > > (in the issue) from a bare metal Centos 8 host? Perhaps Lenny'scomments bare
> > > investigation. Either way, I will offer a patch to theuser space code to,
> > > based on a configuration value, manage correctlysuch activity.
> > ...
> > > msg=audit(1609920994.483:1787848):msg=audit(1609920994.483:1787848):msg=audit(
> > > 1609920994.483:1787848):msg=audit(1609920994.483:1787848):msg=audit(1609920994
> > > .483:1787848):msg=audit(1609920994.484:1787849):msg=audit(1609920994.484:17878
> > > 49):msg=audit(1609921000.636:1787850):msg=audit(1609921000.636:1787850):msg=au
> > > dit(1609921000.636:1787850):msg=audit(1609921008.456:1787851):msg=audit(160992
> > > 1008.456:1787851):msg=audit(1609921008.456:1787851):msg=audit(1609921008.456:1
> > > 787851):msg=audit(1609921008.456:1787851):msg=audit(1609921008.456:1787851):ms
> > > g=audit(1609920994.484:1787849):msg=audit(1609920994.484:1787849):msg=audit(16
> > > 09920994.484:1787849):msg=audit(1609921010.837:1787852):msg=audit(1609921010.8
> > > 37:1787852):msg=audit(1609921010.837:1787852):
> > > msg=audit(1609921010.837:1787852):
> > Looking at the extracted snippet above where event 1787849 is out of
> > order we see the following timestamps:
> > > msg=audit(1609920994.483:1787848):msg=audit(1609920994.484:1787849):msg=audit(
> > > 1609921000.636:1787850):msg=audit(1609921008.456:1787851):
> > > msg=audit(1609921010.837:1787852):
> > 
> > ... which looks correct in as much that the time doesn't appear to gobackwards
> > between events.  As I said before, I'm not sure how Steve'suserspace works so
> > the time may be a red herring.
> 
> It only handles one record at a time. No chance to mix things up.
> The github issue says that 30-stig.rules is being used. If the system time changed
> with chrony, I would expect syscall events with adjtimex. But the only ones given
> are execve.
> -Steve
> > Barring some weird condition where auditd disconnects and quicklyreconnects to
> > the kernel, and/or dies and is replaced quickly, I'm notseeing anything obvious
> > in the kernel which would cause this.  I'm notsaying there isn't anything there,
> > just that it isn't obvious to me atthe moment :)
> 
> 
> 

[-- Attachment #1.2: Type: text/html, Size: 5009 bytes --]

[-- Attachment #2: Type: text/plain, Size: 102 bytes --]

--
Linux-audit mailing list
Linux-audit@redhat.com
https://www.redhat.com/mailman/listinfo/linux-audit