[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <CAABTaaDquPM1pj_dGWULV2yiFiQfsbL43TDT0bmboCZ+=pFeMw@mail.gmail.com>
Date: Thu, 23 Oct 2025 11:13:58 -0300
From: Ricardo Robaina <rrobaina@...hat.com>
To: Paul Moore <paul@...l-moore.com>
Cc: audit@...r.kernel.org, linux-kernel@...r.kernel.org, eparis@...hat.com
Subject: Re: [PATCH v2] audit: merge loops in __audit_inode_child()
On Wed, Oct 22, 2025 at 8:51 PM Paul Moore <paul@...l-moore.com> wrote:
>
> On Wed, Oct 22, 2025 at 8:36 AM Ricardo Robaina <rrobaina@...hat.com> wrote:
> >
> > Whenever there's audit context, __audit_inode_child() gets called
> > numerous times, which can lead to high latency in scenarios that
> > create too many sysfs/debugfs entries at once, for instance, upon
> > device_add_disk() invocation.
> >
> > # uname -r
> > 6.17.0-rc3+
> >
> > # auditctl -a always,exit -F path=/tmp -k foo
> > # time insmod loop max_loop=1000
> > real 0m42.753s
> > user 0m0.000s
> > sys 0m42.494s
> >
> > # perf record -a insmod loop max_loop=1000
> > # perf report --stdio |grep __audit_inode_child
> > 37.95% insmod [kernel.kallsyms] [k] __audit_inode_child
> >
> > __audit_inode_child() searches for both the parent and the child
> > in two different loops that iterate over the same list. This
> > process can be optimized by merging these into a single loop,
> > without changing the function behavior or affecting the code's
> > readability.
> >
> > This patch merges the two loops that walk through the list
> > context->names_list into a single loop. This optimization resulted
> > in around 54% performance enhancement for the benchmark.
> >
> > # uname -r
> > 6.17.0-rc3+-enhanced
> >
> > # auditctl -a always,exit -F path=/tmp -k foo
> > # time insmod loop max_loop=1000
> > real 0m19.388s
> > user 0m0.000s
> > sys 0m19.149s
>
> I couldn't help but notice that these numbers look *exactly* the same
> as the v1 patch numbers ... ;)
>
> Assuming the rest of the patch looks okay (I suspect it will), there
> is no need to re-spin the patch, but if there are different numbers
> you want me to use I can update the commit description when I merge
> the patch.
>
> > Signed-off-by: Ricardo Robaina <rrobaina@...hat.com>
> > ---
> > kernel/auditsc.c | 39 +++++++++++++++++----------------------
> > 1 file changed, 17 insertions(+), 22 deletions(-)
>
> --
> paul-moore.com
>
Hi Paul,
I did test and collected fresh data on kernel-6.18 before posting the
v2. However, I completely forgot updating the commit message, I'm
sorry for that.
Please update it as follows:
Whenever there's audit context, __audit_inode_child() gets called
numerous times, which can lead to high latency in scenarios that
create too many sysfs/debugfs entries at once, for instance, upon
device_add_disk() invocation.
# uname -r
6.18.0-rc2+
# auditctl -a always,exit -F path=/tmp -k foo
# time insmod loop max_loop=1000
real 0m46.676s
user 0m0.000s
sys 0m46.405s
# perf record -a insmod loop max_loop=1000
# perf report --stdio |grep __audit_inode_child
32.73% insmod [kernel.kallsyms] [k]
__audit_inode_child
__audit_inode_child() searches for both the parent and the child
in two different loops that iterate over the same list. This
process can be optimized by merging these into a single loop,
without changing the function behavior or affecting the code's
readability.
This patch merges the two loops that walk through the list
context->names_list into a single loop. This optimization resulted
in around 51% performance enhancement for the benchmark.
# uname -r
6.18.0-rc2-enhanced
# auditctl -a always,exit -F path=/tmp -k foo
# time insmod loop max_loop=1000
real 0m22.991s
user 0m0.000s
sys 0m22.737s
Signed-off-by: Ricardo Robaina <rrobaina@...hat.com>
Data:
root@...ora:/home/rrobaina# uname -r
6.18.0-rc2+
root@...ora:/home/rrobaina# rmmod loop
root@...ora:/home/rrobaina# time insmod /lib/modules/$(uname
-r)/kernel/drivers/block/loop.ko* max_loop=1000
real 0m45.264s
user 0m0.001s
sys 0m44.990s
root@...ora:/home/rrobaina# rmmod loop
root@...ora:/home/rrobaina# time insmod /lib/modules/$(uname
-r)/kernel/drivers/block/loop.ko* max_loop=1000
real 0m47.383s
user 0m0.000s
sys 0m47.113s
root@...ora:/home/rrobaina# auditctl -a always,exit -F path=/tmp -k foo
root@...ora:/home/rrobaina# time insmod /lib/modules/$(uname
-r)/kernel/drivers/block/loop.ko* max_loop=1000
real 0m46.984s
user 0m0.001s
sys 0m46.679s
Average:
real 0m46.676s
user 0m0.000s
sys 0m46.405s
root@...ora:/home/rrobaina# perf record -a insmod /lib/modules/$(uname
-r)/kernel/drivers/block/loop.ko* max_loop=1000
root@...ora:/home/rrobaina# perf report --stdio |grep __audit_inode_child
32.73% insmod [kernel.kallsyms] [k]
__audit_inode_child
0.00% (udev-worker) [kernel.kallsyms] [k]
__audit_inode_child
--
root@...ora:/home/rrobaina# uname -r
6.18.0-rc2-enhanced
root@...ora:/home/rrobaina# auditctl -a always,exit -F path=/tmp -k foo
root@...ora:/home/rrobaina# rmmod loop
root@...ora:/home/rrobaina# time insmod /lib/modules/$(uname
-r)/kernel/drivers/block/loop.ko* max_loop=1000
real 0m22.793s
user 0m0.000s
sys 0m22.517s
root@...ora:/home/rrobaina# rmmod loop
root@...ora:/home/rrobaina# time insmod /lib/modules/$(uname
-r)/kernel/drivers/block/loop.ko* max_loop=1000
real 0m22.763s
user 0m0.001s
sys 0m22.524s
root@...ora:/home/rrobaina# rmmod loop
root@...ora:/home/rrobaina# time insmod /lib/modules/$(uname
-r)/kernel/drivers/block/loop.ko* max_loop=1000
real 0m23.419s
user 0m0.001s
sys 0m23.172s
Average:
real 0m22.991s
user 0m0.000s
sys 0m22.737s
Performance improvement: 51%
(46.405 - 22.737) / 46.405 = 0.510
Sorry for the extra trouble!
Best regards,
-Ricardo
Powered by blists - more mailing lists