Re: [PATCH v2] audit: merge loops in __audit_inode_child()

On Wed, Oct 22, 2025 at 8:51 PM Paul Moore <[email protected]> wrote:
>
> On Wed, Oct 22, 2025 at 8:36 AM Ricardo Robaina <[email protected]> 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 <[email protected]>
> > ---
> >  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 <[email protected]>


Data:

root@fedora:/home/rrobaina# uname -r
6.18.0-rc2+

root@fedora:/home/rrobaina# rmmod loop
root@fedora:/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@fedora:/home/rrobaina# rmmod loop
root@fedora:/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@fedora:/home/rrobaina# auditctl -a always,exit -F path=/tmp -k foo
root@fedora:/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@fedora:/home/rrobaina# perf record -a insmod /lib/modules/$(uname
-r)/kernel/drivers/block/loop.ko* max_loop=1000
root@fedora:/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@fedora:/home/rrobaina# uname -r
6.18.0-rc2-enhanced

root@fedora:/home/rrobaina# auditctl -a always,exit -F path=/tmp -k foo
root@fedora:/home/rrobaina# rmmod loop
root@fedora:/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@fedora:/home/rrobaina# rmmod loop
root@fedora:/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@fedora:/home/rrobaina# rmmod loop
root@fedora:/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