* why I have lost messages on boot even with very big backlog while I hunting only 2 syscalls?
@ 2017-09-27 20:41 Lev Olshvang
2017-09-27 21:32 ` Steve Grubb
0 siblings, 1 reply; 7+ messages in thread
From: Lev Olshvang @ 2017-09-27 20:41 UTC (permalink / raw)
To: linux-audit
Hello list !
A very technical question
I have Ubuntu 16.10 Virtual Box , auditd 2.7.8
I have audit=1 parameter in grub.cfg
I see that /proc/cmdline indeed sees it
I see that auditd is started with PID 564
root 312 2 0 23:12 ? 00:00:00 [kauditd]
root 564 1 0 23:12 ? 00:00:00 /sbin/auditd
And I have 15 lost messages ???
auditctl -s
enabled 1
failure 1
pid 564
rate_limit 0
backlog_limit 16384
lost 15
backlog 0
backlog_wait_time 30
loginuid_immutable 0 unlocked
auditctl -l
-a always,exit -F arch=b64 -S execve,execveat -F key=exec
Do I understand correctly that auiditd is indeed started by systemd before other services, except 2 that is listed in auditd.service dependencuies - local-fs and some temp setup of systemd ?
Regards,
Lev
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: why I have lost messages on boot even with very big backlog while I hunting only 2 syscalls?
2017-09-27 20:41 why I have lost messages on boot even with very big backlog while I hunting only 2 syscalls? Lev Olshvang
@ 2017-09-27 21:32 ` Steve Grubb
2017-09-28 8:51 ` Lev Olshvang
0 siblings, 1 reply; 7+ messages in thread
From: Steve Grubb @ 2017-09-27 21:32 UTC (permalink / raw)
To: linux-audit
On Wednesday, September 27, 2017 4:41:29 PM EDT Lev Olshvang wrote:
> Hello list !
>
> A very technical question
> I have Ubuntu 16.10 Virtual Box , auditd 2.7.8
> I have audit=1 parameter in grub.cfg
> I see that /proc/cmdline indeed sees it
>
> I see that auditd is started with PID 564
>
> root 312 2 0 23:12 ? 00:00:00 [kauditd]
> root 564 1 0 23:12 ? 00:00:00 /sbin/auditd
>
> And I have 15 lost messages ???
> auditctl -s
> enabled 1
> failure 1
> pid 564
> rate_limit 0
> backlog_limit 16384
> lost 15
> backlog 0
> backlog_wait_time 30
> loginuid_immutable 0 unlocked
>
> auditctl -l
> -a always,exit -F arch=b64 -S execve,execveat -F key=exec
>
> Do I understand correctly that auiditd is indeed started by systemd before
> other services, except 2 that is listed in auditd.service dependencuies -
> local-fs and some temp setup of systemd ?
Yes, it is started before most services. However. systemd-journal for some
reason feels obligated to enable auditing. And sometimes people put audit=1 on
the kernel command line. Either way, auditing is on way before auditd starts.
The audit logs have a 64 entry buffer by default. So, as the system boots
events pile up and eventually overflows the 64 entry limit.
The fix is to add another boot command option audit_backlog_limit=8192 or some
other suitable number. The test to check for this is to boot your system,
login and run auditctl -s. If you have just booted and lost events during
boot, this should fix it.
-Steve
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: why I have lost messages on boot even with very big backlog while I hunting only 2 syscalls?
2017-09-27 21:32 ` Steve Grubb
@ 2017-09-28 8:51 ` Lev Olshvang
2017-09-28 14:02 ` Steve Grubb
0 siblings, 1 reply; 7+ messages in thread
From: Lev Olshvang @ 2017-09-28 8:51 UTC (permalink / raw)
To: Steve Grubb, linux-audit
28.09.2017, 00:32, "Steve Grubb" <sgrubb@redhat.com>:
> On Wednesday, September 27, 2017 4:41:29 PM EDT Lev Olshvang wrote:
>> Hello list !
>>
>> A very technical question
>> I have Ubuntu 16.10 Virtual Box , auditd 2.7.8
>> I have audit=1 parameter in grub.cfg
>> I see that /proc/cmdline indeed sees it
>>
>> I see that auditd is started with PID 564
>>
>> root 312 2 0 23:12 ? 00:00:00 [kauditd]
>> root 564 1 0 23:12 ? 00:00:00 /sbin/auditd
>>
>> And I have 15 lost messages ???
>> auditctl -s
>> enabled 1
>> failure 1
>> pid 564
>> rate_limit 0
>> backlog_limit 16384
>> lost 15
>> backlog 0
>> backlog_wait_time 30
>> loginuid_immutable 0 unlocked
>>
>> auditctl -l
>> -a always,exit -F arch=b64 -S execve,execveat -F key=exec
>>
>> Do I understand correctly that auiditd is indeed started by systemd before
>> other services, except 2 that is listed in auditd.service dependencuies -
>> local-fs and some temp setup of systemd ?
>
> Yes, it is started before most services. However. systemd-journal for some
> reason feels obligated to enable auditing. And sometimes people put audit=1 on
> the kernel command line. Either way, auditing is on way before auditd starts.
> The audit logs have a 64 entry buffer by default. So, as the system boots
> events pile up and eventually overflows the 64 entry limit.
>
> The fix is to add another boot command option audit_backlog_limit=8192 or some
> other suitable number. The test to check for this is to boot your system,
> login and run auditctl -s. If you have just booted and lost events during
> boot, this should fix it.
>
> -Steve
Hi Steve
Thank you for your answer.
I added backlog parameter as you advised, but it did not solve the problem
cat /proc/cmdline
BOOT_IMAGE=/vmlinuz-4.8.0-59-generic root=/dev/mapper/kubuntu--vg-root ro net.ifnames=0 biosdevname=0 audit=1 audit_backlog_limit=8192 debug splash
auditctl -s
enabled 1
failure 1
pid 672
rate_limit 0
backlog_limit 16384
lost 16
backlog 10
backlog_wait_time 30
loginuid_immutable 0 unlocked
Perhaps something else in configuration ?
Ragards,
Lev
--
Linux-audit mailing list
Linux-audit@redhat.com
https://www.redhat.com/mailman/listinfo/linux-audit
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: why I have lost messages on boot even with very big backlog while I hunting only 2 syscalls?
2017-09-28 8:51 ` Lev Olshvang
@ 2017-09-28 14:02 ` Steve Grubb
2017-09-30 12:48 ` Lev Olshvang
0 siblings, 1 reply; 7+ messages in thread
From: Steve Grubb @ 2017-09-28 14:02 UTC (permalink / raw)
To: Lev Olshvang; +Cc: linux-audit
Hello,
On Thursday, September 28, 2017 4:51:38 AM EDT Lev Olshvang wrote:
> 28.09.2017, 00:32, "Steve Grubb" <sgrubb@redhat.com>:
> > On Wednesday, September 27, 2017 4:41:29 PM EDT Lev Olshvang wrote:
> >> Hello list !
> >>
> >> A very technical question
> >> I have Ubuntu 16.10 Virtual Box , auditd 2.7.8
> >> I have audit=1 parameter in grub.cfg
> >> I see that /proc/cmdline indeed sees it
> >>
> >> I see that auditd is started with PID 564
> >>
> >> root 312 2 0 23:12 ? 00:00:00 [kauditd]
> >> root 564 1 0 23:12 ? 00:00:00 /sbin/auditd
> >>
> >> And I have 15 lost messages ???
> >> auditctl -s
> >> enabled 1
> >> failure 1
> >> pid 564
> >> rate_limit 0
> >> backlog_limit 16384
> >> lost 15
> >> backlog 0
> >> backlog_wait_time 30
> >> loginuid_immutable 0 unlocked
> >>
> >> auditctl -l
> >> -a always,exit -F arch=b64 -S execve,execveat -F key=exec
> >>
> >> Do I understand correctly that auiditd is indeed started by systemd
> >> before
> >> other services, except 2 that is listed in auditd.service dependencuies
> >> -
> >> local-fs and some temp setup of systemd ?
> >
> > Yes, it is started before most services. However. systemd-journal for some
> > reason feels obligated to enable auditing. And sometimes people put
> > audit=1 on the kernel command line. Either way, auditing is on way before
> > auditd starts. The audit logs have a 64 entry buffer by default. So, as
> > the system boots events pile up and eventually overflows the 64 entry
> > limit.
> >
> > The fix is to add another boot command option audit_backlog_limit=8192 or
> > some other suitable number. The test to check for this is to boot your
> > system, login and run auditctl -s. If you have just booted and lost
> > events during boot, this should fix it.
> >
> > -Steve
>
> Hi Steve
>
> Thank you for your answer.
> I added backlog parameter as you advised, but it did not solve the problem
>
>
> cat /proc/cmdline
> BOOT_IMAGE=/vmlinuz-4.8.0-59-generic root=/dev/mapper/kubuntu--vg-root ro
> net.ifnames=0 biosdevname=0 audit=1 audit_backlog_limit=8192 debug splash
> auditctl -s
> enabled 1
> failure 1
> pid 672
> rate_limit 0
> backlog_limit 16384
> lost 16
> backlog 10
> backlog_wait_time 30
> loginuid_immutable 0 unlocked
>
> Perhaps something else in configuration ?
You have a backlog of 10. That should normally be 0 unless the system is very
busy. What do you have for the flush and freq settings in auditd.conf?
-Steve
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: why I have lost messages on boot even with very big backlog while I hunting only 2 syscalls?
2017-09-28 14:02 ` Steve Grubb
@ 2017-09-30 12:48 ` Lev Olshvang
2017-09-30 14:03 ` Steve Grubb
0 siblings, 1 reply; 7+ messages in thread
From: Lev Olshvang @ 2017-09-30 12:48 UTC (permalink / raw)
To: Steve Grubb; +Cc: linux-audit
28.09.2017, 17:02, "Steve Grubb" <sgrubb@redhat.com>:
> Hello,
>
> On Thursday, September 28, 2017 4:51:38 AM EDT Lev Olshvang wrote:
>> 28.09.2017, 00:32, "Steve Grubb" <sgrubb@redhat.com>:
>> > On Wednesday, September 27, 2017 4:41:29 PM EDT Lev Olshvang wrote:
>> >> Hello list !
>> >>
>> >> A very technical question
>> >> I have Ubuntu 16.10 Virtual Box , auditd 2.7.8
>> >> I have audit=1 parameter in grub.cfg
>> >> I see that /proc/cmdline indeed sees it
>> >>
>> >> I see that auditd is started with PID 564
>> >>
>> >> root 312 2 0 23:12 ? 00:00:00 [kauditd]
>> >> root 564 1 0 23:12 ? 00:00:00 /sbin/auditd
>> >>
>> >> And I have 15 lost messages ???
>> >> auditctl -s
>> >> enabled 1
>> >> failure 1
>> >> pid 564
>> >> rate_limit 0
>> >> backlog_limit 16384
>> >> lost 15
>> >> backlog 0
>> >> backlog_wait_time 30
>> >> loginuid_immutable 0 unlocked
>> >>
>> >> auditctl -l
>> >> -a always,exit -F arch=b64 -S execve,execveat -F key=exec
>> >>
>> >> Do I understand correctly that auiditd is indeed started by systemd
>> >> before
>> >> other services, except 2 that is listed in auditd.service dependencuies
>> >> -
>> >> local-fs and some temp setup of systemd ?
>> >
>> > Yes, it is started before most services. However. systemd-journal for some
>> > reason feels obligated to enable auditing. And sometimes people put
>> > audit=1 on the kernel command line. Either way, auditing is on way before
>> > auditd starts. The audit logs have a 64 entry buffer by default. So, as
>> > the system boots events pile up and eventually overflows the 64 entry
>> > limit.
>> >
>> > The fix is to add another boot command option audit_backlog_limit=8192 or
>> > some other suitable number. The test to check for this is to boot your
>> > system, login and run auditctl -s. If you have just booted and lost
>> > events during boot, this should fix it.
>> >
>> > -Steve
>>
>> Hi Steve
>>
>> Thank you for your answer.
>> I added backlog parameter as you advised, but it did not solve the problem
>>
>> cat /proc/cmdline
>> BOOT_IMAGE=/vmlinuz-4.8.0-59-generic root=/dev/mapper/kubuntu--vg-root ro
>> net.ifnames=0 biosdevname=0 audit=1 audit_backlog_limit=8192 debug splash
>> auditctl -s
>> enabled 1
>> failure 1
>> pid 672
>> rate_limit 0
>> backlog_limit 16384
>> lost 16
>> backlog 10
>> backlog_wait_time 30
>> loginuid_immutable 0 unlocked
>>
>> Perhaps something else in configuration ?
>
> You have a backlog of 10. That should normally be 0 unless the system is very
> busy. What do you have for the flush and freq settings in auditd.conf?
>
> -Steve
Hi Steve,
I overloked your mail yesterday, sorry for delay.
Here the auditd.conf
local_events = yes
write_logs = yes
log_format = RAW
log_file = /var/log/audit/audit.log
log_group = root
priority_boost = 16
flush = INCREMENTAL_ASYNC
freq = 20
num_logs = 5
disp_qos = lossy
I increased priority_boost from 4 to 16 in a hope to solve lost messages problem.
I observed other values of backlog, it was sometimes 6, sometimes 7.
Today I made very big backlog, here are results
enabled 1
failure 1
pid 663
rate_limit 0
backlog_limit 32768
lost 15
backlog 0
backlog_wait_time 15000
Still 15 losts, now events in backlog
Perhaps I need to add some tracer to lost messages code in kernel to debug it.
Regards,
Lev
--
Linux-audit mailing list
Linux-audit@redhat.com
https://www.redhat.com/mailman/listinfo/linux-audit
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: why I have lost messages on boot even with very big backlog while I hunting only 2 syscalls?
2017-09-30 12:48 ` Lev Olshvang
@ 2017-09-30 14:03 ` Steve Grubb
2017-10-02 14:16 ` Paul Moore
0 siblings, 1 reply; 7+ messages in thread
From: Steve Grubb @ 2017-09-30 14:03 UTC (permalink / raw)
To: Lev Olshvang; +Cc: linux-audit
On Saturday, September 30, 2017 8:48:23 AM EDT you wrote:
> Re: why I have lost messages on boot even with very big backlog while I
> hunting only 2 syscalls?
> From: Lev Olshvang <levonshe@yandex.com>
> To: Me
> CC: "linux-audit@redhat.com" <linux-audit@redhat.com>
> Date: 9/30/17 8:48 AM
>
> 28.09.2017, 17:02, "Steve Grubb" <sgrubb@redhat.com>:
> > Hello,
> >
> > On Thursday, September 28, 2017 4:51:38 AM EDT Lev Olshvang wrote:
> >> 28.09.2017, 00:32, "Steve Grubb" <sgrubb@redhat.com>:
> >> > On Wednesday, September 27, 2017 4:41:29 PM EDT Lev Olshvang wrote:
> >> >> Hello list !
> >> >>
> >> >> A very technical question
> >> >> I have Ubuntu 16.10 Virtual Box , auditd 2.7.8
> >> >> I have audit=1 parameter in grub.cfg
> >> >> I see that /proc/cmdline indeed sees it
> >> >>
> >> >> I see that auditd is started with PID 564
> >> >>
> >> >> root 312 2 0 23:12 ? 00:00:00 [kauditd]
> >> >> root 564 1 0 23:12 ? 00:00:00 /sbin/auditd
> >> >>
> >> >> And I have 15 lost messages ???
> >> >> auditctl -s
> >> >> enabled 1
> >> >> failure 1
> >> >> pid 564
> >> >> rate_limit 0
> >> >> backlog_limit 16384
> >> >> lost 15
> >> >> backlog 0
> >> >> backlog_wait_time 30
> >> >> loginuid_immutable 0 unlocked
> >> >>
> >> >> auditctl -l
> >> >> -a always,exit -F arch=b64 -S execve,execveat -F key=exec
> >> >>
> >> >> Do I understand correctly that auiditd is indeed started by systemd
> >> >> before
> >> >> other services, except 2 that is listed in auditd.service
> >> >> dependencuies
> >> >> -
> >> >> local-fs and some temp setup of systemd ?
> >> >
> >> > Yes, it is started before most services. However. systemd-journal for
> >> > some
> >> > reason feels obligated to enable auditing. And sometimes people put
> >> > audit=1 on the kernel command line. Either way, auditing is on way
> >> > before
> >> > auditd starts. The audit logs have a 64 entry buffer by default. So,
> >> > as
> >> > the system boots events pile up and eventually overflows the 64 entry
> >> > limit.
> >> >
> >> > The fix is to add another boot command option audit_backlog_limit=8192
> >> > or
> >> > some other suitable number. The test to check for this is to boot your
> >> > system, login and run auditctl -s. If you have just booted and lost
> >> > events during boot, this should fix it.
> >> >
> >> > -Steve
> >>
> >> Hi Steve
> >>
> >> Thank you for your answer.
> >> I added backlog parameter as you advised, but it did not solve the
> >> problem
> >>
> >> cat /proc/cmdline
> >> BOOT_IMAGE=/vmlinuz-4.8.0-59-generic root=/dev/mapper/kubuntu--vg-root
> >> ro
> >> net.ifnames=0 biosdevname=0 audit=1 audit_backlog_limit=8192 debug
> >> splash
> >> auditctl -s
> >> enabled 1
> >> failure 1
> >> pid 672
> >> rate_limit 0
> >> backlog_limit 16384
> >> lost 16
> >> backlog 10
> >> backlog_wait_time 30
> >> loginuid_immutable 0 unlocked
> >>
> >> Perhaps something else in configuration ?
> >
> > You have a backlog of 10. That should normally be 0 unless the system is
> > very busy. What do you have for the flush and freq settings in
> > auditd.conf?
> >
> > -Steve
>
> Hi Steve,
>
> I overloked your mail yesterday, sorry for delay.
>
>
> Here the auditd.conf
>
> local_events = yes
> write_logs = yes
> log_format = RAW
> log_file = /var/log/audit/audit.log
> log_group = root
> priority_boost = 16
> flush = INCREMENTAL_ASYNC
> freq = 20
> num_logs = 5
> disp_qos = lossy
>
>
> I increased priority_boost from 4 to 16 in a hope to solve lost messages
> problem. I observed other values of backlog, it was sometimes 6, sometimes
> 7.
>
> Today I made very big backlog, here are results
> enabled 1
> failure 1
> pid 663
> rate_limit 0
> backlog_limit 32768
> lost 15
> backlog 0
> backlog_wait_time 15000
>
> Still 15 losts, now events in backlog
> Perhaps I need to add some tracer to lost messages code in kernel to debug
> it.
Maybe adjust your freq from 20 to maybe 50. Other than that, I don't know of
any other user space tricks to improve the flow rate. Maybe Paul or Richard
has ideas. I see you have a 4.8 kernel. I think I remember there being some
netlink comm issues prior to 4.12.
-Steve
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: why I have lost messages on boot even with very big backlog while I hunting only 2 syscalls?
2017-09-30 14:03 ` Steve Grubb
@ 2017-10-02 14:16 ` Paul Moore
0 siblings, 0 replies; 7+ messages in thread
From: Paul Moore @ 2017-10-02 14:16 UTC (permalink / raw)
To: Lev Olshvang; +Cc: linux-audit
On Sat, Sep 30, 2017 at 10:03 AM, Steve Grubb <sgrubb@redhat.com> wrote:
> Maybe adjust your freq from 20 to maybe 50. Other than that, I don't know of
> any other user space tricks to improve the flow rate. Maybe Paul or Richard
> has ideas. I see you have a 4.8 kernel. I think I remember there being some
> netlink comm issues prior to 4.12.
Sorry for the delay in responding, I was doing a bit of traveling.
I would suggest trying a newer kernel if possible. Starting with
v4.10 and continuing up through v4.13 there was substantial work done
that would affect the audit backlog and kernel/auditd connection; if
you can try a v4.13 Linux kernel I would highly recommend it.
--
paul moore
www.paul-moore.com
^ permalink raw reply [flat|nested] 7+ messages in thread
end of thread, other threads:[~2017-10-02 14:16 UTC | newest]
Thread overview: 7+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2017-09-27 20:41 why I have lost messages on boot even with very big backlog while I hunting only 2 syscalls? Lev Olshvang
2017-09-27 21:32 ` Steve Grubb
2017-09-28 8:51 ` Lev Olshvang
2017-09-28 14:02 ` Steve Grubb
2017-09-30 12:48 ` Lev Olshvang
2017-09-30 14:03 ` Steve Grubb
2017-10-02 14:16 ` Paul Moore
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.