Re: Maximum Value for q_depth

From: Steve Grubb <sgrubb@redhat.com>
To: linux-audit@redhat.com, Amjad Gabbar <amjadgabbar11@gmail.com>
Subject: Re: Maximum Value for q_depth
Date: Tue, 25 Jan 2022 15:30:34 -0500	[thread overview]
Message-ID: <8063516.NyiUUSuA9g@x2> (raw)
In-Reply-To: <CAJcJf=QE1jOZ5Uk_Nj=wbsvBv2h1tkyTd=1Cubbu9RfvwXJ21A@mail.gmail.com>

Hello,

On Tuesday, January 18, 2022 1:36:40 AM EST Amjad Gabbar wrote:
> Reaching out regarding the same issue of syslog containing *"auditd
> dispatch error (pipe full) event lost messages". *
> 
> Post excluding the default events(LOGIN, USER_START etc) mentioned in our
> previous chat, there has been a significant drop in the log volume and
> hence I was expecting these error messages to be resolved.
> 
> But unfortunately, even after increasing the dispatcher queue size(q_depth)
> and changing disp_qos to become lossless , I am still seeing mentions of
> these pipe full errors in my syslog.
> The surprising thing is if I try to take a look at the events/keys causing
> this issue, there doesn't seem to be a lot of events for messages to be
> dropped.

Dispatcher plugins can also cause things to get backed up. You mention that 
you have the af_unix plugin. Whatever reads from that needs to unload events 
quickly. It's recommended for the plugin to have 2 threads, one to dequeue 
and one to process the event. It should have storage to hold events if it's 
processing gets behind.

> Ex- Using the command *"aureport --summary -ts <start time of dropped
> messages start reported in syslog > -te < end time  of dropped messages
> end reported in syslog > -i (-x/-u/--key)"*, the total events are around
> 2000 during this time period. The dispatcher queue size is close to 25,000,
> So I am not really sure why the dispatcher is unable to handle these
> messages. The queue size is sufficient enough to handle 10x the total
> events being seen.

Its entirely depending on the plugin to grab it's event.

> Some other theoretical questions I had surrounding this are:
> 
> 
>    - The audit daemon picks events from the kernel buffer and sends it to
>    the dispatcher buffer. Who writes these logs to /var/log/audit.log - is
> it the daemon or the dispatcher?

The daemon

> And also, are the total events reported
> in /var/log/audit.log inclusive of the dropped events reported in syslog
> or exclusive?

It writes to the log and then dispatches the event.

> i.e is it possible that all the events have been recorded in
> audit.log but syslog has an issue in keeping up with the events as it is
> the only plugin that is being used by the dispatcher.

You previously mentioned an af_unix plugin. That would be my guess. You can 
disable the syslog plugin and find out if it's the cause.

>    - Is there a way to find out what is the total number of events dropped
>    by the dispatcher?

I don't think anything keeps metrics on that.

>    - In auditd v3+, the daemon itself handles dispatching capabilities. So,
> what does q_depth refer to in this scenario?

The internal queue between the logging thread and the dispatching thread.

>    - In the man pages for different distros for disp_qos the following
>    statement is common - " There is a 128k buffer between the audit daemon
>    and dispatcher." 

This buffer is the kernel inter-process pipe size. There are up to 4 buffers 
in the 2.8 series. The backlog, the inter-process kernel buffer between 
auditd and audispd, a buffer in audispd, and the inter-process kernel buffer 
with the plugin. Only 2 of those have config options.

>    But different distros seem to have different default
>    values for q_depth ranging from 80 to 1200. How is it possible that
> these numbers vary but the size of the buffer remains 128k.

It's a different buffer. The 128k refers to the inter-process pipe buffer.

-Steve

> On Tue, Dec 21, 2021 at 2:39 PM Steve Grubb <sgrubb@redhat.com> wrote:
> > Hello,
> > 
> > On Tuesday, December 21, 2021 12:55:47 AM EST Amjad Gabbar wrote:
> > > Based on our discussion above, I performed some analysis as to why we
> > 
> > were
> > 
> > > seeing so many events. The reason seems to be due to the default rules
> > > being triggered every time a cron job runs. We have numerous cron jobs
> > > running per minute as a result of which multiple different
> > > events(LOGIN,
> > > USER_END,CRED_DISP etc) are generated each time a cron job runs. As we
> > > do
> > > not enable SELinux, disabling these thing use subj_type=crond_t is not
> > > a
> > > viable option.
> > > 
> > > 1. I have tried the following way to exclude using msg_type and exe
> > > together and it seems to work.
> > > 
> > > -a exclude,always -F msgtype=MAC_IPSEC_EVENT -F exe=/usr/sbin/cron
> > > -a exclude,always -F msgtype=USER_AUTH -F exe=/usr/sbin/cron
> > > -a exclude,always -F msgtype=USER_ACCT -F exe=/usr/sbin/cron
> > > -a exclude,always -F msgtype=CRED_REFR -F exe=/usr/sbin/cron
> > > -a exclude,always -F msgtype=CRED_DISP -F exe=/usr/sbin/cron
> > > -a exclude,always -F msgtype=CRED_ACQ -F exe=/usr/sbin/cron
> > > -a exclude,always -F msgtype=USER_START -F exe=/usr/sbin/cron
> > > -a exclude,always -F msgtype=USER_END -F exe=/usr/sbin/cron
> > > -a exclude,always -F msgtype=SERVICE_START -F exe=/usr/sbin/cron
> > > 
> > > Just want to make sure there is nothing I am missing here and that this
> > > only excludes the msg types for the cron executable.
> > 
> > I think so. But it's easy enough to test. Just login and see if you get
> > any
> > USER_START events from something other than cron.
> > 
> > > 2. Apart from these messages, there is a LOGIN message that gets
> > 
> > generated
> > 
> > > each time a cron runs. Eventhough, the LOGIN message in auditd does not
> > > have an exe field, the following statement surprisingly seems to be
> > > working.
> > > 
> > > -a exclude,always -F msgtype=LOGIN -F exe=/usr/sbin/cron
> > > 
> > > I can still see LOGIN messages for other users but the cron LOGIN
> > 
> > messages
> > 
> > > seem to be suppressed. Could you provide some detail as to how this is
> > > happening and is the expected result.
> > 
> > It doesn't match against the text in the event. It matches against the
> > process's attributes.
> > 
> > > 3. Is there a better way to suppress these cron messages that I am not
> > > considering apart from the SELinux option mentioned.
> > 
> > I think you found the best way for a non-selinux system. Back when it was
> > documented that it could be supressed by selinux type, audit by
> > executable
> > did not exist. But as you found, that is an effective way to get rid of
> > the
> > events.
> > 
> > I also think the cronie program might be a little more audit friendly. It
> > does not call PAM for the system crontabs run under the root user. PAM is
> > run
> > only for the local crontab (i.e. the one edited by the crontab command)
> > and
> > in case of the system crontabs only for jobs that are run under non-root
> > user.
> > 
> > -Steve

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