Re: Occasional delayed output of events

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(a)iinet.net.au&gt; 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 :)