kauditd hold queue overflow in 4.11

kauditd hold queue overflow in 4.11

[Laurent Bigonville]

Hi,

With 4.11.6 (that has been uploaded in debian unstable) I get a lot of 
messages in dmesg like

[100052.120468] audit: audit_lost=66041 audit_rate_limit=0 audit_backlog_limit=8192
[100052.120470] audit: kauditd hold queue overflow

And it also seems that the messages are not stored in auditd logs anymore.

https://git.kernel.org/linus/264d509637d95f9404e52ced5003ad352e0f6a26 
seems to be included in this release

An idea?

Regards,

Laurent Bigonville

Re: kauditd hold queue overflow in 4.11

[Paul Moore]

On Mon, Jul 10, 2017 at 10:59 AM, Laurent Bigonville <bigon@debian.org> wrote:
> Hi,
>
> With 4.11.6 (that has been uploaded in debian unstable) I get a lot of
> messages in dmesg like
>
> [100052.120468] audit: audit_lost=66041 audit_rate_limit=0
> audit_backlog_limit=8192
> [100052.120470] audit: kauditd hold queue overflow
>
> And it also seems that the messages are not stored in auditd logs anymore.
>
> https://git.kernel.org/linus/264d509637d95f9404e52ced5003ad352e0f6a26 seems
> to be included in this release
>
> An idea?

I'm going to assume that your backlog limit is set to a sane value for
your system's configuration, so that leaves me with two commits that
may be of interest:

* 1df30f8264b8 ("audit: fix the RCU locking for the auditd_connection
structure")

This was a manual backport of a v4.12 patch to v4.11, looking now, I
see it should be in +v4.11.5 so that probably isn't your problem ...

* c81be52a3ac0 ("audit: fix a race condition with the auditd tracking code")

This patch is relatively new and was just sent up to Linus during the
next merge window; it's a race condition fix so reproducing it can be
tricky, although it may be easily reproducible on your system at the
moment (luck you!).  If you aren't in a position to apply the patch,
the workaround is rather simple: restart auditd.

If none of the above works, let me know, but I strongly suspect you're
tripping over the race condition fixed in that last patch.

-- 
paul moore
www.paul-moore.com

Re: kauditd hold queue overflow in 4.11

[Laurent Bigonville]

Le 10/07/17 à 18:00, Paul Moore a écrit :
> On Mon, Jul 10, 2017 at 10:59 AM, Laurent Bigonville <bigon@debian.org> wrote:
>> Hi,
>>
>> With 4.11.6 (that has been uploaded in debian unstable) I get a lot of
>> messages in dmesg like
>>
>> [100052.120468] audit: audit_lost=66041 audit_rate_limit=0
>> audit_backlog_limit=8192
>> [100052.120470] audit: kauditd hold queue overflow
>>
>> And it also seems that the messages are not stored in auditd logs anymore.
>>
>> https://git.kernel.org/linus/264d509637d95f9404e52ced5003ad352e0f6a26 seems
>> to be included in this release
>>
>> An idea?
> I'm going to assume that your backlog limit is set to a sane value for
> your system's configuration, so that leaves me with two commits that
> may be of interest:
>
> * 1df30f8264b8 ("audit: fix the RCU locking for the auditd_connection
> structure")
>
> This was a manual backport of a v4.12 patch to v4.11, looking now, I
> see it should be in +v4.11.5 so that probably isn't your problem ...
>
> * c81be52a3ac0 ("audit: fix a race condition with the auditd tracking code")
>
> This patch is relatively new and was just sent up to Linus during the
> next merge window; it's a race condition fix so reproducing it can be
> tricky, although it may be easily reproducible on your system at the
> moment (luck you!).  If you aren't in a position to apply the patch,
> the workaround is rather simple: restart auditd.
>
> If none of the above works, let me know, but I strongly suspect you're
> tripping over the race condition fixed in that last patch.
>
I didn't test the patch yet, but I restarted the auditd daemon 2 times 
and after that the queue has been flushed and I got all the message 
since this noon in the audit logs.

It's auditd 2.7.7 if that matters.

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

Re: kauditd hold queue overflow in 4.11

[Paul Moore]

On Mon, Jul 10, 2017 at 4:01 PM, Laurent Bigonville <bigon@debian.org> wrote:
> Le 10/07/17 à 18:00, Paul Moore a écrit :
>
>> On Mon, Jul 10, 2017 at 10:59 AM, Laurent Bigonville <bigon@debian.org>
>> wrote:
>>>
>>> Hi,
>>>
>>> With 4.11.6 (that has been uploaded in debian unstable) I get a lot of
>>> messages in dmesg like
>>>
>>> [100052.120468] audit: audit_lost=66041 audit_rate_limit=0
>>> audit_backlog_limit=8192
>>> [100052.120470] audit: kauditd hold queue overflow
>>>
>>> And it also seems that the messages are not stored in auditd logs
>>> anymore.
>>>
>>> https://git.kernel.org/linus/264d509637d95f9404e52ced5003ad352e0f6a26
>>> seems
>>> to be included in this release
>>>
>>> An idea?
>>
>> I'm going to assume that your backlog limit is set to a sane value for
>> your system's configuration, so that leaves me with two commits that
>> may be of interest:
>>
>> * 1df30f8264b8 ("audit: fix the RCU locking for the auditd_connection
>> structure")
>>
>> This was a manual backport of a v4.12 patch to v4.11, looking now, I
>> see it should be in +v4.11.5 so that probably isn't your problem ...
>>
>> * c81be52a3ac0 ("audit: fix a race condition with the auditd tracking
>> code")
>>
>> This patch is relatively new and was just sent up to Linus during the
>> next merge window; it's a race condition fix so reproducing it can be
>> tricky, although it may be easily reproducible on your system at the
>> moment (luck you!).  If you aren't in a position to apply the patch,
>> the workaround is rather simple: restart auditd.
>>
>> If none of the above works, let me know, but I strongly suspect you're
>> tripping over the race condition fixed in that last patch.
>>
> I didn't test the patch yet, but I restarted the auditd daemon 2 times and
> after that the queue has been flushed and I got all the message since this
> noon in the audit logs.

That sounds right; I'm guessing the patch above should be a more permanent fix.

> It's auditd 2.7.7 if that matters.

It shouldn't, at least not in this case.

-- 
paul moore
www.paul-moore.com

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

Re: kauditd hold queue overflow in 4.11

[Laurent Bigonville]

Le 11/07/17 à 00:23, Paul Moore a écrit :
> On Mon, Jul 10, 2017 at 4:01 PM, Laurent Bigonville <bigon@debian.org> wrote:
>> Le 10/07/17 à 18:00, Paul Moore a écrit :
>>
>>> On Mon, Jul 10, 2017 at 10:59 AM, Laurent Bigonville <bigon@debian.org>
>>> wrote:
>>>> Hi,
>>>>
>>>> With 4.11.6 (that has been uploaded in debian unstable) I get a lot of
>>>> messages in dmesg like
>>>>
>>>> [100052.120468] audit: audit_lost=66041 audit_rate_limit=0
>>>> audit_backlog_limit=8192
>>>> [100052.120470] audit: kauditd hold queue overflow
>>>>
>>>> And it also seems that the messages are not stored in auditd logs
>>>> anymore.
>>>>
>>>> https://git.kernel.org/linus/264d509637d95f9404e52ced5003ad352e0f6a26
>>>> seems
>>>> to be included in this release
>>>>
>>>> An idea?
>>> 7
>>> I'm going to assume that your backlog limit is set to a sane value for
>>> your system's configuration, so that leaves me with two commits that
>>> may be of interest:
>>>
>>> * 1df30f8264b8 ("audit: fix the RCU locking for the auditd_connection
>>> structure")
>>>
>>> This was a manual backport of a v4.12 patch to v4.11, looking now, I
>>> see it should be in +v4.11.5 so that probably isn't your problem ...
>>>
>>> * c81be52a3ac0 ("audit: fix a race condition with the auditd tracking
>>> code")
>>>
>>> This patch is relatively new and was just sent up to Linus during the
>>> next merge window; it's a race condition fix so reproducing it can be
>>> tricky, although it may be easily reproducible on your system at the
>>> moment (luck you!).  If you aren't in a position to apply the patch,
>>> the workaround is rather simple: restart auditd.
>>>
>>> If none of the above works, let me know, but I strongly suspect you're
>>> tripping over the race condition fixed in that last patch.
>>>
>> I didn't test the patch yet, but I restarted the auditd daemon 2 times and
>> after that the queue has been flushed and I got all the message since this
>> noon in the audit logs.
> That sounds right; I'm guessing the patch above should be a more permanent fix.
>

The patch should be applied in 4.13-rc7 right?

It seems to fix the main issue (all the audit messages being logged in 
dmesg) but I can still see from time to time the following message:

[   14.747565] audit: audit_lost=59 audit_rate_limit=0 audit_backlog_limit=64
[   14.747566] audit: kauditd hold queue overflow


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

Re: kauditd hold queue overflow in 4.11

[Steve Grubb]

On Saturday, September 9, 2017 6:02:02 AM EDT Laurent Bigonville wrote:
> Le 11/07/17 à 00:23, Paul Moore a écrit :
> > On Mon, Jul 10, 2017 at 4:01 PM, Laurent Bigonville <bigon@debian.org> 
wrote:
> >> Le 10/07/17 à 18:00, Paul Moore a écrit :
> >>> On Mon, Jul 10, 2017 at 10:59 AM, Laurent Bigonville <bigon@debian.org>
> >>> 
> >>> wrote:
> >>>> Hi,
> >>>> 
> >>>> With 4.11.6 (that has been uploaded in debian unstable) I get a lot of
> >>>> messages in dmesg like
> >>>> 
> >>>> [100052.120468] audit: audit_lost=66041 audit_rate_limit=0
> >>>> audit_backlog_limit=8192
> >>>> [100052.120470] audit: kauditd hold queue overflow
> >>>> 
> >>>> And it also seems that the messages are not stored in auditd logs
> >>>> anymore.
> >>>> 
> >>>> https://git.kernel.org/linus/264d509637d95f9404e52ced5003ad352e0f6a26
> >>>> seems
> >>>> to be included in this release
> >>>> 
> >>>> An idea?
> >>> 
> >>> 7
> >>> I'm going to assume that your backlog limit is set to a sane value for
> >>> your system's configuration, so that leaves me with two commits that
> >>> may be of interest:
> >>> 
> >>> * 1df30f8264b8 ("audit: fix the RCU locking for the auditd_connection
> >>> structure")
> >>> 
> >>> This was a manual backport of a v4.12 patch to v4.11, looking now, I
> >>> see it should be in +v4.11.5 so that probably isn't your problem ...
> >>> 
> >>> * c81be52a3ac0 ("audit: fix a race condition with the auditd tracking
> >>> code")
> >>> 
> >>> This patch is relatively new and was just sent up to Linus during the
> >>> next merge window; it's a race condition fix so reproducing it can be
> >>> tricky, although it may be easily reproducible on your system at the
> >>> moment (luck you!).  If you aren't in a position to apply the patch,
> >>> the workaround is rather simple: restart auditd.
> >>> 
> >>> If none of the above works, let me know, but I strongly suspect you're
> >>> tripping over the race condition fixed in that last patch.
> >> 
> >> I didn't test the patch yet, but I restarted the auditd daemon 2 times
> >> and
> >> after that the queue has been flushed and I got all the message since
> >> this
> >> noon in the audit logs.
> > 
> > That sounds right; I'm guessing the patch above should be a more permanent
> > fix.
> The patch should be applied in 4.13-rc7 right?
> 
> It seems to fix the main issue (all the audit messages being logged in
> dmesg) but I can still see from time to time the following message:
> 
> [   14.747565] audit: audit_lost=59 audit_rate_limit=0
> audit_backlog_limit=64 [   14.747566] audit: kauditd hold queue overflow

That is a very low backlog_limit. Is this during boot?

-Steve

Re: kauditd hold queue overflow in 4.11

[Paul Moore]

On Sat, Sep 9, 2017 at 6:02 AM, Laurent Bigonville <bigon@debian.org> wrote:
> Le 11/07/17 à 00:23, Paul Moore a écrit :
>>
>> On Mon, Jul 10, 2017 at 4:01 PM, Laurent Bigonville <bigon@debian.org>
>> wrote:
>>>
>>> Le 10/07/17 à 18:00, Paul Moore a écrit :
>>>
>>>> On Mon, Jul 10, 2017 at 10:59 AM, Laurent Bigonville <bigon@debian.org>
>>>> wrote:
>>>>>
>>>>> Hi,
>>>>>
>>>>> With 4.11.6 (that has been uploaded in debian unstable) I get a lot of
>>>>> messages in dmesg like
>>>>>
>>>>> [100052.120468] audit: audit_lost=66041 audit_rate_limit=0
>>>>> audit_backlog_limit=8192
>>>>> [100052.120470] audit: kauditd hold queue overflow
>>>>>
>>>>> And it also seems that the messages are not stored in auditd logs
>>>>> anymore.
>>>>>
>>>>> https://git.kernel.org/linus/264d509637d95f9404e52ced5003ad352e0f6a26
>>>>> seems
>>>>> to be included in this release
>>>>>
>>>>> An idea?
>>>>
>>>> 7
>>>> I'm going to assume that your backlog limit is set to a sane value for
>>>> your system's configuration, so that leaves me with two commits that
>>>> may be of interest:
>>>>
>>>> * 1df30f8264b8 ("audit: fix the RCU locking for the auditd_connection
>>>> structure")
>>>>
>>>> This was a manual backport of a v4.12 patch to v4.11, looking now, I
>>>> see it should be in +v4.11.5 so that probably isn't your problem ...
>>>>
>>>> * c81be52a3ac0 ("audit: fix a race condition with the auditd tracking
>>>> code")
>>>>
>>>> This patch is relatively new and was just sent up to Linus during the
>>>> next merge window; it's a race condition fix so reproducing it can be
>>>> tricky, although it may be easily reproducible on your system at the
>>>> moment (luck you!).  If you aren't in a position to apply the patch,
>>>> the workaround is rather simple: restart auditd.
>>>>
>>>> If none of the above works, let me know, but I strongly suspect you're
>>>> tripping over the race condition fixed in that last patch.
>>>>
>>> I didn't test the patch yet, but I restarted the auditd daemon 2 times
>>> and
>>> after that the queue has been flushed and I got all the message since
>>> this
>>> noon in the audit logs.
>>
>> That sounds right; I'm guessing the patch above should be a more permanent
>> fix.
>>
>
> The patch should be applied in 4.13-rc7 right?

Yes, commit c81be52a3ac0 landed in Linus' tree during the v4.13 merge
window, it is present in v4.13-rc1 and all later kernels.

> It seems to fix the main issue (all the audit messages being logged in
> dmesg) but I can still see from time to time the following message:
>
> [   14.747565] audit: audit_lost=59 audit_rate_limit=0
> audit_backlog_limit=64
> [   14.747566] audit: kauditd hold queue overflow

I agree with Steve, you might try increasing your backlog limit to see
if that helps.

-- 
paul moore
www.paul-moore.com

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

Re: kauditd hold queue overflow in 4.11

[Laurent Bigonville]

Le 09/09/17 à 16:22, Steve Grubb a écrit :
> On Saturday, September 9, 2017 6:02:02 AM EDT Laurent Bigonville wrote:
>> Le 11/07/17 à 00:23, Paul Moore a écrit :
>>> On Mon, Jul 10, 2017 at 4:01 PM, Laurent Bigonville <bigon@debian.org>
> wrote:
>>>> Le 10/07/17 à 18:00, Paul Moore a écrit :
>>>>> On Mon, Jul 10, 2017 at 10:59 AM, Laurent Bigonville <bigon@debian.org>
>>>>>
>>>>> wrote:
>>>>>> Hi,
>>>>>>
>>>>>> With 4.11.6 (that has been uploaded in debian unstable) I get a lot of
>>>>>> messages in dmesg like
>>>>>>
>>>>>> [100052.120468] audit: audit_lost=66041 audit_rate_limit=0
>>>>>> audit_backlog_limit=8192
>>>>>> [100052.120470] audit: kauditd hold queue overflow
>>>>>>
>>>>>> And it also seems that the messages are not stored in auditd logs
>>>>>> anymore.
>>>>>>
>>>>>> https://git.kernel.org/linus/264d509637d95f9404e52ced5003ad352e0f6a26
>>>>>> seems
>>>>>> to be included in this release
>>>>>>
>>>>>> An idea?
>>>>> 7
>>>>> I'm going to assume that your backlog limit is set to a sane value for
>>>>> your system's configuration, so that leaves me with two commits that
>>>>> may be of interest:
>>>>>
>>>>> * 1df30f8264b8 ("audit: fix the RCU locking for the auditd_connection
>>>>> structure")
>>>>>
>>>>> This was a manual backport of a v4.12 patch to v4.11, looking now, I
>>>>> see it should be in +v4.11.5 so that probably isn't your problem ...
>>>>>
>>>>> * c81be52a3ac0 ("audit: fix a race condition with the auditd tracking
>>>>> code")
>>>>>
>>>>> This patch is relatively new and was just sent up to Linus during the
>>>>> next merge window; it's a race condition fix so reproducing it can be
>>>>> tricky, although it may be easily reproducible on your system at the
>>>>> moment (luck you!).  If you aren't in a position to apply the patch,
>>>>> the workaround is rather simple: restart auditd.
>>>>>
>>>>> If none of the above works, let me know, but I strongly suspect you're
>>>>> tripping over the race condition fixed in that last patch.
>>>> I didn't test the patch yet, but I restarted the auditd daemon 2 times
>>>> and
>>>> after that the queue has been flushed and I got all the message since
>>>> this
>>>> noon in the audit logs.
>>> That sounds right; I'm guessing the patch above should be a more permanent
>>> fix.
>> The patch should be applied in 4.13-rc7 right?
>>
>> It seems to fix the main issue (all the audit messages being logged in
>> dmesg) but I can still see from time to time the following message:
>>
>> [   14.747565] audit: audit_lost=59 audit_rate_limit=0
>> audit_backlog_limit=64 [   14.747566] audit: kauditd hold queue overflow
> That is a very low backlog_limit. Is this during boot?

Yes that's during boot (64 is the kernel's default)

In my audit.rules I have '-b 8192'

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

Re: kauditd hold queue overflow in 4.11

[Steve Grubb]

On Saturday, September 9, 2017 4:41:19 PM EDT Laurent Bigonville wrote:
> Le 09/09/17 à 16:22, Steve Grubb a écrit :
> > On Saturday, September 9, 2017 6:02:02 AM EDT Laurent Bigonville wrote:
> >> Le 11/07/17 à 00:23, Paul Moore a écrit :
> >>> On Mon, Jul 10, 2017 at 4:01 PM, Laurent Bigonville <bigon@debian.org>
> > wrote:
> >>>> Le 10/07/17 à 18:00, Paul Moore a écrit :
> >>>>> On Mon, Jul 10, 2017 at 10:59 AM, Laurent Bigonville
> >>>>> <bigon@debian.org> wrote:
> >>>>>> Hi,
> >>>>>> 
> >>>>>> With 4.11.6 (that has been uploaded in debian unstable) I get a lot
> >>>>>> of messages in dmesg like
> >>>>>> 
> >>>>>> [100052.120468] audit: audit_lost=66041 audit_rate_limit=0
> >>>>>> audit_backlog_limit=8192
> >>>>>> [100052.120470] audit: kauditd hold queue overflow
> >>>>>> 
> >>>>>> And it also seems that the messages are not stored in auditd logs
> >>>>>> anymore.
> >>>>>> 
> >>>>>> https://git.kernel.org/linus/264d509637d95f9404e52ced5003ad352e0f6a26
> >>>>>> seems to be included in this release
> >>>>>> 
> >>>>>> Any idea?
> >>>>> 
> >>>>> I'm going to assume that your backlog limit is set to a sane value for
> >>>>> your system's configuration, so that leaves me with two commits that
> >>>>> may be of interest:
> >>>>> 
> >>>>> * 1df30f8264b8 ("audit: fix the RCU locking for the auditd_connection
> >>>>> structure")
> >>>>> 
> >>>>> This was a manual backport of a v4.12 patch to v4.11, looking now, I
> >>>>> see it should be in +v4.11.5 so that probably isn't your problem ...
> >>>>> 
> >>>>> * c81be52a3ac0 ("audit: fix a race condition with the auditd tracking
> >>>>> code")
> >>>>> 
> >>>>> This patch is relatively new and was just sent up to Linus during the
> >>>>> next merge window; it's a race condition fix so reproducing it can be
> >>>>> tricky, although it may be easily reproducible on your system at the
> >>>>> moment (luck you!).  If you aren't in a position to apply the patch,
> >>>>> the workaround is rather simple: restart auditd.
> >>>>> 
> >>>>> If none of the above works, let me know, but I strongly suspect you're
> >>>>> tripping over the race condition fixed in that last patch.
> >>>> 
> >>>> I didn't test the patch yet, but I restarted the auditd daemon 2 times
> >>>> and after that the queue has been flushed and I got all the message since
> >>>> this noon in the audit logs.
> >>> 
> >>> That sounds right; I'm guessing the patch above should be a more
> >>> permanent fix.
> >> 
> >> The patch should be applied in 4.13-rc7 right?
> >> 
> >> It seems to fix the main issue (all the audit messages being logged in
> >> dmesg) but I can still see from time to time the following message:
> >> 
> >> [   14.747565] audit: audit_lost=59 audit_rate_limit=0
> >> audit_backlog_limit=64 [   14.747566] audit: kauditd hold queue overflow
> > 
> > That is a very low backlog_limit. Is this during boot?
> 
> Yes that's during boot (64 is the kernel's default)
> 
> In my audit.rules I have '-b 8192'

OK. I blogged about this issue back in May:

http://security-plus-data-science.blogspot.com/2017/05/a-suggested-change-for-rhel-7-disa-stig.html

TL;DR, you have to set a boot command line option
audit_backlog_limit=8192. I'm also starting to wonder if we can set the
backlog to 6144 now that auditd runs much faster (~90x).

-Steve