From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-0.8 required=3.0 tests=BAYES_00, HEADER_FROM_DIFFERENT_DOMAINS,HTML_MESSAGE,MAILING_LIST_MULTI,SPF_HELO_NONE, SPF_PASS,URIBL_BLOCKED autolearn=no autolearn_force=no version=3.4.0 Received: from mail.kernel.org (mail.kernel.org [198.145.29.99]) by smtp.lore.kernel.org (Postfix) with ESMTP id 8B651C433DB for ; Wed, 20 Jan 2021 06:39:23 +0000 (UTC) Received: from us-smtp-delivery-124.mimecast.com (us-smtp-delivery-124.mimecast.com [216.205.24.124]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-SHA384 (256/256 bits)) (No client certificate requested) by mail.kernel.org (Postfix) with ESMTPS id 193212313B for ; Wed, 20 Jan 2021 06:39:21 +0000 (UTC) DMARC-Filter: OpenDMARC Filter v1.3.2 mail.kernel.org 193212313B Authentication-Results: mail.kernel.org; dmarc=none (p=none dis=none) header.from=iinet.net.au Authentication-Results: mail.kernel.org; spf=pass smtp.mailfrom=linux-audit-bounces@redhat.com Received: from mimecast-mx01.redhat.com (mimecast-mx01.redhat.com [209.132.183.4]) (Using TLS) by relay.mimecast.com with ESMTP id us-mta-33-jiy97MXqPU6vfm8vqrySWg-1; Wed, 20 Jan 2021 01:39:18 -0500 X-MC-Unique: jiy97MXqPU6vfm8vqrySWg-1 Received: from smtp.corp.redhat.com (int-mx02.intmail.prod.int.phx2.redhat.com [10.5.11.12]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by mimecast-mx01.redhat.com (Postfix) with ESMTPS id 9368D10054FF; Wed, 20 Jan 2021 06:39:14 +0000 (UTC) Received: from colo-mx.corp.redhat.com (colo-mx01.intmail.prod.int.phx2.redhat.com [10.5.11.20]) by smtp.corp.redhat.com (Postfix) with ESMTPS id C370260C0F; Wed, 20 Jan 2021 06:39:13 +0000 (UTC) Received: from lists01.pubmisc.prod.ext.phx2.redhat.com (lists01.pubmisc.prod.ext.phx2.redhat.com [10.5.19.33]) by colo-mx.corp.redhat.com (Postfix) with ESMTP id 3A37B180954D; Wed, 20 Jan 2021 06:38:54 +0000 (UTC) Received: from smtp.corp.redhat.com (int-mx04.intmail.prod.int.rdu2.redhat.com [10.11.54.4]) by lists01.pubmisc.prod.ext.phx2.redhat.com (8.13.8/8.13.8) with ESMTP id 10K6cpd3026171 for ; Wed, 20 Jan 2021 01:38:51 -0500 Received: by smtp.corp.redhat.com (Postfix) id 3B8BA2026D11; Wed, 20 Jan 2021 06:38:51 +0000 (UTC) Received: from mimecast-mx02.redhat.com (mimecast03.extmail.prod.ext.rdu2.redhat.com [10.11.55.19]) by smtp.corp.redhat.com (Postfix) with ESMTPS id 360002026D5D for ; Wed, 20 Jan 2021 06:38:49 +0000 (UTC) Received: from us-smtp-1.mimecast.com (us-smtp-delivery-1.mimecast.com [205.139.110.120]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-SHA384 (256/256 bits)) (No client certificate requested) by mimecast-mx02.redhat.com (Postfix) with ESMTPS id 24695811E84 for ; Wed, 20 Jan 2021 06:38:49 +0000 (UTC) Received: from icp-osb-irony-out4.external.iinet.net.au (icp-osb-irony-out4.external.iinet.net.au [203.59.1.220]) by relay.mimecast.com with ESMTP id us-mta-108-ayfo_6I0OhGpVADeWGtssQ-1; Wed, 20 Jan 2021 01:38:43 -0500 X-MC-Unique: ayfo_6I0OhGpVADeWGtssQ-1 X-SMTP-MATCH: 1 X-IronPort-Anti-Spam-Filtered: true X-IronPort-Anti-Spam-Result: =?us-ascii?q?A2AGAQCEzwdg/3zSRWpiGgEBAQEBAQE?= =?us-ascii?q?BAQEDAQEBARIBAQEBAgIBAQEBR4FIgXyBfGKEQIkEhjaCFgM4g2yWPYFcCwE?= =?us-ascii?q?BAQEBAQEBATUBAgQBAYREBAICgXQmOBMCEAEBAQUBAQEBAQYDAYZehXQBBSM?= =?us-ascii?q?zIxALCAYKHA4CAlcGARKCW0uCVgEBLq9wgTKFRxOCIQaBDYFDgTiGdgGCToN?= =?us-ascii?q?yNYFNP4FHgi41PodXgmAEgU9vB4FQBkBiFREBWAKTIYh7inGREywHgnqBFwU?= =?us-ascii?q?LhlGINYs7IqJqhiIYjWGjZoF6MxofghYYgQ9QGQ2OLReBAgEJjS4wMDcCBgo?= =?us-ascii?q?BAQMJWQEBi0cBAQ?= X-IPAS-Result: =?us-ascii?q?A2AGAQCEzwdg/3zSRWpiGgEBAQEBAQEBAQEDAQEBARIBA?= =?us-ascii?q?QEBAgIBAQEBR4FIgXyBfGKEQIkEhjaCFgM4g2yWPYFcCwEBAQEBAQEBATUBA?= =?us-ascii?q?gQBAYREBAICgXQmOBMCEAEBAQUBAQEBAQYDAYZehXQBBSMzIxALCAYKHA4CA?= =?us-ascii?q?lcGARKCW0uCVgEBLq9wgTKFRxOCIQaBDYFDgTiGdgGCToNyNYFNP4FHgi41P?= =?us-ascii?q?odXgmAEgU9vB4FQBkBiFREBWAKTIYh7inGREywHgnqBFwULhlGINYs7IqJqh?= =?us-ascii?q?iIYjWGjZoF6MxofghYYgQ9QGQ2OLReBAgEJjS4wMDcCBgoBAQMJWQEBi0cBA?= =?us-ascii?q?Q?= X-IronPort-AV: E=Sophos;i="5.79,360,1602518400"; d="scan'208,217";a="288402583" Received: from 106-69-210-124.dyn.iinet.net.au (HELO swtf.swtf.dyndns.org) ([106.69.210.124]) by icp-osb-irony-out4.iinet.net.au with ESMTP; 20 Jan 2021 14:38:27 +0800 Message-ID: Subject: Re: Occasional delayed output of events From: Burn Alting To: Steve Grubb , Paul Moore Date: Wed, 20 Jan 2021 17:38:26 +1100 In-Reply-To: <805552026.0ifERbkFSE@x2> References: <30c5dbc14368a1919717e2f39d2d4c29463c3108.camel@iinet.net.au> <9fd0d1b4585214eb3ed8db6da066b571563f19bc.camel@iinet.net.au> <805552026.0ifERbkFSE@x2> Mime-Version: 1.0 X-Mimecast-Impersonation-Protect: Policy=CLT - Impersonation Protection Definition; Similar Internal Domain=false; Similar Monitored External Domain=false; Custom External Domain=false; Mimecast External Domain=false; Newly Observed Domain=false; Internal User Name=false; Custom Display Name List=false; Reply-to Address Mismatch=false; Targeted Threat Dictionary=false; Mimecast Threat Dictionary=false; Custom Threat Dictionary=false X-Scanned-By: MIMEDefang 2.78 on 10.11.54.4 X-loop: linux-audit@redhat.com Cc: Richard Guy Briggs , Linux Audit X-BeenThere: linux-audit@redhat.com X-Mailman-Version: 2.1.12 Precedence: junk Reply-To: burn@swtf.dyndns.org List-Id: Linux Audit Discussion List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Sender: linux-audit-bounces@redhat.com Errors-To: linux-audit-bounces@redhat.com X-Scanned-By: MIMEDefang 2.79 on 10.5.11.12 Authentication-Results: relay.mimecast.com; auth=pass smtp.auth=CUSA124A263 smtp.mailfrom=linux-audit-bounces@redhat.com X-Mimecast-Spam-Score: 0 X-Mimecast-Originator: redhat.com Content-Type: multipart/mixed; boundary="===============5056032989924201784==" --===============5056032989924201784== Content-Type: multipart/alternative; boundary="=-dpbaFNmXTNIiAcqPw2Am" --=-dpbaFNmXTNIiAcqPw2Am Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: 7bit 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 > 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 :) > > > --=-dpbaFNmXTNIiAcqPw2Am Content-Type: text/html; charset="utf-8" Content-Transfer-Encoding: quoted-printable
All,

How is the following for a way forwa= rd.

a. I will author a patch to the user space cod= e to correctly parse this condition and submit it on the weekend. It will b= e 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 pa= rse generated audit.
b. I am happy to instrument what ever is rec= ommended on my hosts at home (vm's and bare metal) to provide more informat= ion, should we want to 'explain' the occurrence, given I see this every wee= k or two and report back.

On Tue, 2021-01-19 at 16= :51 -0500, Steve Grubb wrote:
On Tuesd=
ay, 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
<= /a>
> 
wrote:
All systems use chrony (current NTP daemon=
). One is a VM (on top of KVM)
and the other a bare metal deploym=
ent. Does the above explain my second
data set (in the issue) fro=
m a bare metal Centos 8 host? Perhaps Lenny's
comments bare inves=
tigation. Either way, I will offer a patch to the
user space code=
 to, based on a configuration value, manage correctly
such activi=
ty.
...

msg=3Daudit(1609920994.483:1787848):
msg=3Daudit(16099209=
94.483:1787848):
msg=3Daudit(1609920994.483:1787848):
m=
sg=3Daudit(1609920994.483:1787848):
msg=3Daudit(1609920994.483:17=
87848):
msg=3Daudit(1609920994.484:1787849):
msg=3Daudi=
t(1609920994.484:1787849):
msg=3Daudit(1609921000.636:1787850):
msg=3Daudit(1609921000.636:1787850):
msg=3Daudit(1609921=
000.636:1787850):
msg=3Daudit(1609921008.456:1787851):
=
msg=3Daudit(1609921008.456:1787851):
msg=3Daudit(1609921008.456:1=
787851):
msg=3Daudit(1609921008.456:1787851):
msg=3Daud=
it(1609921008.456:1787851):
msg=3Daudit(1609921008.456:1787851):<=
/pre>
msg=3Daudit(1609920994.484:1787849):
msg=3Daudit(160992=
0994.484:1787849):
msg=3Daudit(1609920994.484:1787849):
msg=3Daudit(1609921010.837:1787852):
msg=3Daudit(1609921010.837:=
1787852):
msg=3Daudit(1609921010.837:1787852):
= 

msg=3Daudit(1609921010.837:1=
787852):
Looking at the extracted snippet above wher=
e event 1787849 is out of

order we see the followi=
ng timestamps:
msg=3Daudit(1609920994.=
483:1787848):
msg=3Daudit(1609920994.484:1787849):
msg=
=3Daudit(1609921000.636:1787850):
msg=3Daudit(1609921008.456:1787=
851):

msg=
=3Daudit(1609921010.837:1787852):

...=
 which looks correct in as much that the time doesn't appear to go
backwards between events. As I said before, I'm not sure how Steve's
userspace 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.rule=
s is being used. If the system time 
changed with chrony, I would=
 expect syscall events with adjtimex. But the 
only ones given ar=
e execve.

-Steve

Barring some weird condition where auditd disconnects an=
d quickly
reconnects to the kernel, and/or dies and is replaced q=
uickly, I'm not
seeing anything obvious in the kernel which would=
 cause this.  I'm not
saying there isn't anything there, just tha=
t it isn't obvious to me at
the moment :)
=



= --=-dpbaFNmXTNIiAcqPw2Am-- --===============5056032989924201784== Content-Type: text/plain; charset="us-ascii" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit Content-Disposition: inline -- Linux-audit mailing list Linux-audit@redhat.com https://www.redhat.com/mailman/listinfo/linux-audit --===============5056032989924201784==--