Can AUDIT_LIST_RULES causes kthreadd-spam?

Can AUDIT_LIST_RULES causes kthreadd-spam?

[Rinat Gadelshin]

Hello there =)


My name is Rinat.
I'm a newbie here (at Linux kernel developer community).

My current job is to work with audit subsystem on different
versions of Linux (and different kernel versions from 3.10 to the latest)
with and without auditd.

My program works behalf of root account and uses netlink
(unicast or multicast depends of  the kernel's version)
to communicate with audit subsystem of the kernel.

If actual audit rule list has been changed
then my program should restore the configured audit rule list.

To do it the program periodically (with 60 seconds interval)
requests the actual rule list be sending AUDIT_LIST_RULES.

All rules are receiving perfectly.

But I've noticed that there are many (2K+ for 5 minutes test)
kthreadd process have been spawned after that request
(I've stubbed the poll code and compare logs).

Please, can you point me, what can I do to avoid this kthreadd-spam.


Thank you.

Best regards
Rinath

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

Re: Can AUDIT_LIST_RULES causes kthreadd-spam?

[Paul Moore]

On Wed, May 3, 2023 at 5:14 PM Rinat Gadelshin <rgadelsh@gmail.com> wrote:
> Hello there =)
>
> My name is Rinat.
> I'm a newbie here (at Linux kernel developer community).
>
> My current job is to work with audit subsystem on different
> versions of Linux (and different kernel versions from 3.10 to the latest)
> with and without auditd.
>
> My program works behalf of root account and uses netlink
> (unicast or multicast depends of  the kernel's version)
> to communicate with audit subsystem of the kernel.
>
> If actual audit rule list has been changed
> then my program should restore the configured audit rule list.
>
> To do it the program periodically (with 60 seconds interval)
> requests the actual rule list be sending AUDIT_LIST_RULES.
>
> All rules are receiving perfectly.
>
> But I've noticed that there are many (2K+ for 5 minutes test)
> kthreadd process have been spawned after that request
> (I've stubbed the poll code and compare logs).

Hi Rinat,

First, a quick note that audit discussions involving the upstream
Linux Kernel have moved to the audit@vger.kernel.org list (CC'd),
please direct future emails there.

Can you be more specific about the kernel threads you are seeing, are
you seeing multiple "kauditd" threads?

% ps -fC kauditd
UID          PID    PPID  C STIME TTY          TIME CMD
root          89       2  0 Apr28 ?        00:00:00 [kauditd]

> Please, can you point me, what can I do to avoid this kthreadd-spam.
>
> Thank you.
>
> Best regards
> Rinath

-- 
paul-moore.com

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

Re: Can AUDIT_LIST_RULES causes kthreadd-spam?

[Rinat Gadelshin]

On 04.05.2023 00:27, Paul Moore wrote:
> On Wed, May 3, 2023 at 5:14 PM Rinat Gadelshin <rgadelsh@gmail.com> wrote:
>> Hello there =)
>>
>> My name is Rinat.
>> I'm a newbie here (at Linux kernel developer community).
>>
>> My current job is to work with audit subsystem on different
>> versions of Linux (and different kernel versions from 3.10 to the latest)
>> with and without auditd.
>>
>> My program works behalf of root account and uses netlink
>> (unicast or multicast depends of  the kernel's version)
>> to communicate with audit subsystem of the kernel.
>>
>> If actual audit rule list has been changed
>> then my program should restore the configured audit rule list.
>>
>> To do it the program periodically (with 60 seconds interval)
>> requests the actual rule list be sending AUDIT_LIST_RULES.
>>
>> All rules are receiving perfectly.
>>
>> But I've noticed that there are many (2K+ for 5 minutes test)
>> kthreadd process have been spawned after that request
>> (I've stubbed the poll code and compare logs).
> Hi Rinat,
>
> First, a quick note that audit discussions involving the upstream
> Linux Kernel have moved to the audit@vger.kernel.org list (CC'd),
> please direct future emails there.
>
> Can you be more specific about the kernel threads you are seeing, are
> you seeing multiple "kauditd" threads?
>
> % ps -fC kauditd
> UID          PID    PPID  C STIME TTY          TIME CMD
> root          89       2  0 Apr28 ?        00:00:00 [kauditd]
>
>> Please, can you point me, what can I do to avoid this kthreadd-spam.
>>
>> Thank you.
>>
>> Best regards
>> Rinath
Hi Paul,

Thank you for your quick answer.
I swear to copy my future questions about audit subsystem to 
audit@vger.kernel.org =)

My logs don't provide lot of info about nature of the kthreadds.
(I hadn't written the log system).

I have something like this:

...pid: 2, uniquePid: 000082d800000002, fileName: kthreadd, lcFileName: 
kthreadd, name: kthreadd, commandLine: Skipped, lcCommandLine: Skipped, 
sessionId: 0, isRemote: 0, syscallName: fork, uid: 4294967295, gid: 
4294967295, euid: 4294967295, egid: 4294967295, logonSessionUid: -1, 
logonSessionUsername: Skipped, logonSessionRemoteHost: , exeOwnerUid: 0, 
exeOwnerGid: 0, exeMode: 0, exeInode: 0, exeCapsVersion: , 
exeCapsRootId: , exeCapsEffective: , exeCapsPermitted: , 
exeCapsInheritable: , dstPid: 106574, dstTid: 0, dstUniquePid: 
000083b10001a04e, requestId: 2684354949, startTime: 01d97d1fb24aa38e, 
hash: 00000000000000000000000000000000, cwd: , flags: 00000011, 
processState: 3, int: 0, type: 00000000..

And such events occurred 1208 times when AUDIT_LIST_RULES is sending.
The test has lasted 2 minutes.

The same test in which the request was disabled produced only 122 such 
records.

It was the only difference between the tests.

As I can see it was a fork syscall of kthreadd.

Are there any debug options for the kernel that I can set, rebuild the 
kernel, re-run the test and clarify the situation?

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

Re: Can AUDIT_LIST_RULES causes kthreadd-spam?

[Tetsuo Handa]

On 2023/05/04 7:12, Rinat Gadelshin wrote:
> On 04.05.2023 00:27, Paul Moore wrote:
>> Can you be more specific about the kernel threads you are seeing, are
>> you seeing multiple "kauditd" threads?
>>
>> % ps -fC kauditd
>> UID          PID    PPID  C STIME TTY          TIME CMD
>> root          89       2  0 Apr28 ?        00:00:00 [kauditd]

I don't think so.

kernel audit subsystem uses kthread_run() in order to run short-lived kernel threads.

  $ git grep -nF kthread_run kernel/audit*.c
  kernel/audit.c:1006:    tsk = kthread_run(audit_send_reply_thread, reply, "audit_send_reply");
  kernel/audit.c:1700:    kauditd_task = kthread_run(kauditd_thread, NULL, "kauditd");
  kernel/audit_tree.c:789:        prune_thread = kthread_run(prune_tree_thread, NULL,
  kernel/auditfilter.c:1193:      tsk = kthread_run(audit_send_list_thread, dest, "audit_send_list");

I guess that either or both of audit_send_reply_thread/audit_send_list_thread is launched
for many times.

> Are there any debug options for the kernel that I can set, rebuild the kernel,
> re-run the test and clarify the situation?

Since comm name is not available but you can afford rebuilding kernels,
counting which thread is launched could be the first step. Also, any
characteristic aspects in your usage; e.g. creating many namespaces,
crating many audit rules?

Please try something like below diff:

diff --git a/kernel/audit.c b/kernel/audit.c
index 9bc0b0301198..c28cd4ac0f30 100644
--- a/kernel/audit.c
+++ b/kernel/audit.c
@@ -911,16 +911,19 @@ int audit_send_list_thread(void *_dest)
 	struct sk_buff *skb;
 	struct sock *sk = audit_get_sk(dest->net);
 
+	pr_info("Started %s\n", __func__);
 	/* wait for parent to finish and send an ACK */
 	audit_ctl_lock();
 	audit_ctl_unlock();
 
-	while ((skb = __skb_dequeue(&dest->q)) != NULL)
+	while ((skb = __skb_dequeue(&dest->q)) != NULL) {
+		pr_info("Calling netlink_unicast\n");
 		netlink_unicast(sk, skb, dest->portid, 0);
+	}
 
 	put_net(dest->net);
 	kfree(dest);
-
+	pr_info("Finished %s\n", __func__);
 	return 0;
 }
 
@@ -963,6 +966,7 @@ static void audit_free_reply(struct audit_reply *reply)
 static int audit_send_reply_thread(void *arg)
 {
 	struct audit_reply *reply = (struct audit_reply *)arg;
+	pr_info("Started %s\n", __func__);
 
 	audit_ctl_lock();
 	audit_ctl_unlock();
@@ -972,6 +976,7 @@ static int audit_send_reply_thread(void *arg)
 	netlink_unicast(audit_get_sk(reply->net), reply->skb, reply->portid, 0);
 	reply->skb = NULL;
 	audit_free_reply(reply);
+	pr_info("Finished %s\n", __func__);
 	return 0;
 }
 


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

Re: Can AUDIT_LIST_RULES causes kthreadd-spam?

[Paul Moore]

On Wed, May 3, 2023 at 10:50 PM Tetsuo Handa
<penguin-kernel@i-love.sakura.ne.jp> wrote:
> On 2023/05/04 7:12, Rinat Gadelshin wrote:
> > On 04.05.2023 00:27, Paul Moore wrote:
> >> Can you be more specific about the kernel threads you are seeing, are
> >> you seeing multiple "kauditd" threads?
> >>
> >> % ps -fC kauditd
> >> UID          PID    PPID  C STIME TTY          TIME CMD
> >> root          89       2  0 Apr28 ?        00:00:00 [kauditd]
>
> I don't think so.
>
> kernel audit subsystem uses kthread_run() in order to run short-lived kernel threads.

Thanks Tetsuo, I agree that's far more likely.  Ever since I took over
shepherding the audit code, all of the thread issues have been around
the main audit queue thread so it's a bit reflexive to assume that is
the case :)

-- 
paul-moore.com

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

Re: Can AUDIT_LIST_RULES causes kthreadd-spam?

[Tetsuo Handa]

On 2023/05/05 3:40, Paul Moore wrote:
> On Wed, May 3, 2023 at 10:50 PM Tetsuo Handa
> <penguin-kernel@i-love.sakura.ne.jp> wrote:
>> On 2023/05/04 7:12, Rinat Gadelshin wrote:
>>> On 04.05.2023 00:27, Paul Moore wrote:
>>>> Can you be more specific about the kernel threads you are seeing, are
>>>> you seeing multiple "kauditd" threads?
>>>>
>>>> % ps -fC kauditd
>>>> UID          PID    PPID  C STIME TTY          TIME CMD
>>>> root          89       2  0 Apr28 ?        00:00:00 [kauditd]
>>
>> I don't think so.
>>
>> kernel audit subsystem uses kthread_run() in order to run short-lived kernel threads.
> 
> Thanks Tetsuo, I agree that's far more likely.  Ever since I took over
> shepherding the audit code, all of the thread issues have been around
> the main audit queue thread so it's a bit reflexive to assume that is
> the case :)
> 

Since kthread_run(audit_send_list_thread) is called by audit_receive_msg(AUDIT_LIST_RULES)
via audit_list_rules_send(), trying to audit fork request via AUDIT_LIST_RULES will cause
spams. Maybe something is going wrong with "And such events occurred 1208 times when
AUDIT_LIST_RULES is sending." part; let's wait for what printk() says.

By the way, why do we need to use kthread_run() for short-lived tasks? Can't we use
a dedicated workqueue which would significantly reduce frequency of fork request for
AUDIT_LIST_RULES request?

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

Re: Can AUDIT_LIST_RULES causes kthreadd-spam?

[Rinat Gadelshin]

On 05.05.2023 01:53, Tetsuo Handa wrote:
> On 2023/05/05 3:40, Paul Moore wrote:
>> On Wed, May 3, 2023 at 10:50 PM Tetsuo Handa
>> <penguin-kernel@i-love.sakura.ne.jp> wrote:
>>> On 2023/05/04 7:12, Rinat Gadelshin wrote:
>>>> On 04.05.2023 00:27, Paul Moore wrote:
>>>>> Can you be more specific about the kernel threads you are seeing, are
>>>>> you seeing multiple "kauditd" threads?
>>>>>
>>>>> % ps -fC kauditd
>>>>> UID          PID    PPID  C STIME TTY          TIME CMD
>>>>> root          89       2  0 Apr28 ?        00:00:00 [kauditd]
>>> I don't think so.
>>>
>>> kernel audit subsystem uses kthread_run() in order to run short-lived kernel threads.
>> Thanks Tetsuo, I agree that's far more likely.  Ever since I took over
>> shepherding the audit code, all of the thread issues have been around
>> the main audit queue thread so it's a bit reflexive to assume that is
>> the case :)
>>
> Since kthread_run(audit_send_list_thread) is called by audit_receive_msg(AUDIT_LIST_RULES)
> via audit_list_rules_send(), trying to audit fork request via AUDIT_LIST_RULES will cause
> spams. Maybe something is going wrong with "And such events occurred 1208 times when
> AUDIT_LIST_RULES is sending." part; let's wait for what printk() says.
>
> By the way, why do we need to use kthread_run() for short-lived tasks? Can't we use
> a dedicated workqueue which would significantly reduce frequency of fork request for
> AUDIT_LIST_RULES request?
>
Hello there =)
Sorry for my long absence.

I've managed to build and install the custom kernel (from Linus' branch 
with Tetsuo's patch for logging).

The following rules were dictated by my netlink (with disabled poll 
rule's logic:

-a always,exit -F arch=b32 -S fork,execve,clone,vfork,execveat
-a always,exit -F arch=b64 -S clone,fork,vfork,execve,execveat
-a never,exit -F pid=4641
-a never,exit -F ppid=4641
-a never,exit -F pid=1
-a never,exit -F ppid=1
-a always,exit -F arch=b64 -S kill,ptrace
-a always,exit -F arch=b32 -S ptrace,kill
-a always,exit -F arch=b64 -S exit,exit_group
-a always,exit -F arch=b32 -S exit,exit_group
-a always,exit -F arch=b64 -S connect,accept,accept4
-a always,exit -F arch=b32 -S connect,accept4
-a always,exit -F arch=b64 -S open,creat,openat,437
-a always,exit -F arch=b64 -S rename,renameat,renameat2
-a always,exit -F arch=b32 -S rename,renameat,renameat2
-a always,exit -F arch=b64 -S chown,fchown,lchown,fchownat
-a always,exit -F arch=b32 -S lchown,fchown,chown,fchownat
-a always,exit -F arch=b64 -S chmod,fchmod,fchmodat
-a always,exit -F arch=b32 -S chmod,fchmod,fchmodat
-a always,exit -F arch=b64 -S link,symlink,linkat,symlinkat
-a always,exit -F arch=b32 -S link,symlink,linkat,symlinkat
-a always,exit -F arch=b64 -S mount,umount2
-a always,exit -F arch=b32 -S mount,umount,umount2
-a always,exit -F arch=b64 -S 
setuid,setgid,setreuid,setregid,setresuid,setresgid
-a always,exit -F arch=b32 -S 
setuid,setgid,setreuid,setregid,setresuid,setresgid
-a always,exit -F arch=b64 -S mmap,mprotect -F a2=0x7
-a always,exit -F arch=b32 -S mmap,mprotect -F a2=0x7
-a always,exit -F arch=b64 -S unlink,unlinkat
-a always,exit -F arch=b32 -S unlink,unlinkat
-a always,exit -F arch=b64 -S ioctl -F a2=0x40086602
-a always,exit -F arch=b32 -S ioctl -F a2=0x40086602

The only one `auditctl -l` request was performed.
I see the following response in syslog for the request:

May  6 01:01:19 gadelshin-ri-nb kernel: [  110.474111] audit: Started 
audit_send_reply_thread
May  6 01:01:19 gadelshin-ri-nb kernel: [  110.474123] audit: Finished 
audit_send_reply_thread
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972014] audit: Started 
audit_send_list_thread
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972020] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972023] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972023] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972024] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972025] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972026] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972026] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972027] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972028] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972029] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972029] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972030] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972030] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972031] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972032] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972032] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972033] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972034] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972034] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972035] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972035] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972036] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972037] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972038] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972038] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972039] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972039] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972040] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972040] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972041] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972042] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972043] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972044] audit: Calling 
netlink unicast
May  6 01:01:20 gadelshin-ri-nb kernel: [  111.972045] audit: Finished 
audit_send_list_thread
May  6 01:01:21 gadelshin-ri-nb kernel: [  112.485659] audit: Started 
audit_send_reply_thread
May  6 01:01:21 gadelshin-ri-nb kernel: [  112.485689] audit: Finished 
audit_send_reply_thread
May  6 01:01:23 gadelshin-ri-nb kernel: [  114.501072] audit: Started 
audit_send_reply_thread
May  6 01:01:23 gadelshin-ri-nb kernel: [  114.501076] audit: Finished 
audit_send_reply_thread
May  6 01:01:24 gadelshin-ri-nb auditd[1210]: Audit daemon rotating log 
files
May  6 01:01:25 gadelshin-ri-nb kernel: [  116.506645] audit: Started 
audit_send_reply_thread
May  6 01:01:25 gadelshin-ri-nb kernel: [  116.506656] audit: Finished 
audit_send_reply_thread
May  6 01:01:27 gadelshin-ri-nb kernel: [  118.512282] audit: Started 
audit_send_reply_thread
May  6 01:01:27 gadelshin-ri-nb kernel: [  118.512306] audit: Finished 
audit_send_reply_thread

`git describes` shows: v6.3-13027-g1a5304fecee5
Distributive is  Ubuntu 20.04 (x64)

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

Re: Can AUDIT_LIST_RULES causes kthreadd-spam?

[Tetsuo Handa]

On 2023/05/06 7:12, Rinat Gadelshin wrote:
> The only one `auditctl -l` request was performed.
> I see the following response in syslog for the request:

Thanks for rules.

I tried "auditctl -l" with these rules, and I got only

  audit: Started audit_send_list_thread
  audit: Calling netlink_unicast (repeated for 32 times)
  audit: Finished audit_send_list_thread

as output; audit_send_reply_thread is not called in my environment.

That is, for some reason (maybe some process is interfering each other)
audit_send_reply_thread is needlessly called in your environment?
In that case, fixing the cause of audit_send_reply_thread being called
could reduce the spam.

Please try to find who is calling audit_send_reply_thread for many times.

diff --git a/kernel/audit.c b/kernel/audit.c
index 9bc0b0301198..bf4fef7da692 100644
--- a/kernel/audit.c
+++ b/kernel/audit.c
@@ -1006,6 +1011,7 @@ static void audit_send_reply(struct sk_buff *request_skb, int seq, int type, int
 	tsk = kthread_run(audit_send_reply_thread, reply, "audit_send_reply");
 	if (IS_ERR(tsk))
 		goto err;
+	dump_stack();
 
 	return;
 


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

Re: Can AUDIT_LIST_RULES causes kthreadd-spam?

[Rinat Gadelshin]

On 06.05.2023 09:50, Tetsuo Handa wrote:
> On 2023/05/06 7:12, Rinat Gadelshin wrote:
>> The only one `auditctl -l` request was performed.
>> I see the following response in syslog for the request:
> Thanks for rules.
>
> I tried "auditctl -l" with these rules, and I got only
>
>    audit: Started audit_send_list_thread
>    audit: Calling netlink_unicast (repeated for 32 times)
>    audit: Finished audit_send_list_thread
>
> as output; audit_send_reply_thread is not called in my environment.
>
> That is, for some reason (maybe some process is interfering each other)
> audit_send_reply_thread is needlessly called in your environment?
> In that case, fixing the cause of audit_send_reply_thread being called
> could reduce the spam.
>
> Please try to find who is calling audit_send_reply_thread for many times.
>
> diff --git a/kernel/audit.c b/kernel/audit.c
> index 9bc0b0301198..bf4fef7da692 100644
> --- a/kernel/audit.c
> +++ b/kernel/audit.c
> @@ -1006,6 +1011,7 @@ static void audit_send_reply(struct sk_buff *request_skb, int seq, int type, int
>   	tsk = kthread_run(audit_send_reply_thread, reply, "audit_send_reply");
>   	if (IS_ERR(tsk))
>   		goto err;
> +	dump_stack();
>   
>   	return;

Hi Tetsuo,

I've rebuilt the kernel with 'dump stack()'.

I've got 7 call stacks for the same test (`auditctl -l` and the same 
audit rule list), they are all similar to:

May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025922] audit: Started 
audit_send_reply_thread
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025924] Hardware name: 
LENOVO 21AH00BPUS/21AH00BPUS, BIOS N3MET11W (1.10 ) 12/07/2022
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025926] Call Trace:
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025928]  <TASK>
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025929] 
dump_stack_lvl+0x4c/0x70
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025935] dump_stack+0x14/0x20
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025936] 
audit_send_reply.constprop.0+0xcc/0x120
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025939] 
audit_receive_msg+0x26d/0x1070
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025940]  ? 
string_nocheck+0x4f/0x60
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025942]  ? string+0x4e/0x60
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025943] 
audit_receive+0xb9/0x180
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025944]  ? 
netlink_deliver_tap+0x49/0x250
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025947] 
netlink_unicast+0x1b2/0x260
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025948] 
netlink_sendmsg+0x254/0x4d0
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025950] 
sock_sendmsg+0x9d/0xb0
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025952] 
__sys_sendto+0x122/0x1b0
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025954]  ? 
__handle_mm_fault+0xac0/0xd10
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025956]  ? 
__audit_syscall_entry+0xd2/0x140
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025958] 
__x64_sys_sendto+0x2d/0x40
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025959] 
do_syscall_64+0x5d/0x90
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025962]  ? 
exit_to_user_mode_prepare+0x3d/0x190
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025965]  ? 
do_user_addr_fault+0x1bc/0x8a0
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025967]  ? 
irqentry_exit_to_user_mode+0xd/0x20
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025969]  ? 
irqentry_exit+0x3f/0x50
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025970]  ? 
exc_page_fault+0x8e/0x190
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025971] 
entry_SYSCALL_64_after_hwframe+0x72/0xdc
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025974] RIP: 
0033:0x7fe97af368a4
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025976] Code: c2 f7 ff ff 
44 8b 4c 24 2c 4c 8b 44 24 20 89 c5 44 8b 54 24 28 48 8b 54 24 18 b8 2c 
00 00 00 48 8b 74 24 10 8b 7c 24 08 0f 05 <48> 3d 00 f0 ff ff 77 30 89 
ef 48 89 44 24 08 e8 e8 f7 ff ff 48 8b
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025977] RSP: 
002b:00007ffdfc78af50 EFLAGS: 00000293 ORIG_RAX: 000000000000002c
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025979] RAX: 
ffffffffffffffda RBX: 00007fe90900aee0 RCX: 00007fe97af368a4
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025980] RDX: 
0000000000000010 RSI: 00007fe90900aff8 RDI: 0000000000000008
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025981] RBP: 
0000000000000000 R08: 00007ffdfc78afd4 R09: 000000000000000c
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025981] R10: 
0000000000000000 R11: 0000000000000293 R12: 00007fe944461920
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025982] R13: 
00007fe905b31be0 R14: 00007fe905b31bf0 R15: 0000000000000000
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025984] </TASK>
May 10 14:51:52 gadelshin-ri-nb kernel: [ 9381.025989] audit: Finished 
audit_send_reply_thread


As far as I can see, it's the exit of `sendto` syscall.
It seems that the kernel just creates a new kthreadd for each sendto 
syscall.
But I think that I'm wrong and just missing something.

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

Re: Can AUDIT_LIST_RULES causes kthreadd-spam?

[Tetsuo Handa]

On 2023/05/10 21:12, Rinat Gadelshin wrote:
>> Please try to find who is calling audit_send_reply_thread for many times.
>>
> I've rebuilt the kernel with 'dump stack()'.

Oops, I thought dump_stack() shows pid and comm name, but
it is dump_stack_print_info() that shows pid and comm name.

> As far as I can see, it's the exit of `sendto` syscall.
> It seems that the kernel just creates a new kthreadd for each sendto syscall.
> But I think that I'm wrong and just missing something.

Yes, sendto() on netlink socket calls netlink_sendmsg().
For some reason, audit_send_reply() is called for many times.
audit_send_reply() is called by audit_receive_msg() for the following types.

  AUDIT_GET
  AUDIT_SIGNAL_INFO
  AUDIT_TTY_GET
  AUDIT_GET_FEATURE

Would you re-caputure with

-	dump_stack();
+	pr_info("%s %s:%d type=%d\n", __func__, current->comm, current->pid, type);

?

Regardless of the result of re-caputure, it seems there is no switch that can
prevent audit_send_reply() from calling kthread_run(audit_send_reply_thread).

But since kthreadd runs with PID=2 and PPID=0, you might be able to use
PID=2 and/or PPID=0 in your rules in order to let kernel audit subsystem
ignore kthreadd. (I can't test because I haven't found how to reproduce
audit_receive_msg() in my environment...)

# cat /proc/2/status
Name:   kthreadd
Umask:  0000
State:  S (sleeping)
Tgid:   2
Ngid:   0
Pid:    2
PPid:   0

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

Re: Can AUDIT_LIST_RULES causes kthreadd-spam?

[Steve Grubb]

On Wednesday, May 10, 2023 9:30:19 AM EDT Tetsuo Handa wrote:
> On 2023/05/10 21:12, Rinat Gadelshin wrote:
> >> Please try to find who is calling audit_send_reply_thread for many
> >> times.
> > 
> > I've rebuilt the kernel with 'dump stack()'.
> 
> Oops, I thought dump_stack() shows pid and comm name, but
> it is dump_stack_print_info() that shows pid and comm name.
> 
> > As far as I can see, it's the exit of `sendto` syscall.
> > It seems that the kernel just creates a new kthreadd for each sendto
> > syscall. But I think that I'm wrong and just missing something.
> 
> Yes, sendto() on netlink socket calls netlink_sendmsg().
> For some reason, audit_send_reply() is called for many times.
> audit_send_reply() is called by audit_receive_msg() for the following
> types.
> 
>   AUDIT_GET
>   AUDIT_SIGNAL_INFO
>   AUDIT_TTY_GET
>   AUDIT_GET_FEATURE

The audit userspace always adds NLM_F_ACK to any netlink communication to 
make sure it did not get discarded before it arrived. It has done this since 
before I started working on audit code.

-Steve

> Would you re-caputure with
> 
> -	dump_stack();
> +	pr_info("%s %s:%d type=%d\n", __func__, current->comm, current->pid,
> type);
> 
> ?
> 
> Regardless of the result of re-caputure, it seems there is no switch that
> can prevent audit_send_reply() from calling
> kthread_run(audit_send_reply_thread).
> 
> But since kthreadd runs with PID=2 and PPID=0, you might be able to use
> PID=2 and/or PPID=0 in your rules in order to let kernel audit subsystem
> ignore kthreadd. (I can't test because I haven't found how to reproduce
> audit_receive_msg() in my environment...)
> 
> # cat /proc/2/status
> Name:   kthreadd
> Umask:  0000
> State:  S (sleeping)
> Tgid:   2
> Ngid:   0
> Pid:    2
> PPid:   0
> 
> --
> Linux-audit mailing list
> Linux-audit@redhat.com
> https://listman.redhat.com/mailman/listinfo/linux-audit




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

Re: Can AUDIT_LIST_RULES causes kthreadd-spam?

[Rinat Gadelshin]

Hi Tetsuo.

Sorry for my log absence.
The kthread-spam problem has gone when I've switched to using 
unicast-netlink connection (like auditd does).

Do we need to make another test with the additional pr_info() ?

On 10.05.2023 16:30, Tetsuo Handa wrote:
> On 2023/05/10 21:12, Rinat Gadelshin wrote:
>>> Please try to find who is calling audit_send_reply_thread for many times.
>>>
>> I've rebuilt the kernel with 'dump stack()'.
> Oops, I thought dump_stack() shows pid and comm name, but
> it is dump_stack_print_info() that shows pid and comm name.
>
>> As far as I can see, it's the exit of `sendto` syscall.
>> It seems that the kernel just creates a new kthreadd for each sendto syscall.
>> But I think that I'm wrong and just missing something.
> Yes, sendto() on netlink socket calls netlink_sendmsg().
> For some reason, audit_send_reply() is called for many times.
> audit_send_reply() is called by audit_receive_msg() for the following types.
>
>    AUDIT_GET
>    AUDIT_SIGNAL_INFO
>    AUDIT_TTY_GET
>    AUDIT_GET_FEATURE
>
> Would you re-caputure with
>
> -	dump_stack();
> +	pr_info("%s %s:%d type=%d\n", __func__, current->comm, current->pid, type);
>
> ?
>
> Regardless of the result of re-caputure, it seems there is no switch that can
> prevent audit_send_reply() from calling kthread_run(audit_send_reply_thread).
>
> But since kthreadd runs with PID=2 and PPID=0, you might be able to use
> PID=2 and/or PPID=0 in your rules in order to let kernel audit subsystem
> ignore kthreadd. (I can't test because I haven't found how to reproduce
> audit_receive_msg() in my environment...)
>
> # cat /proc/2/status
> Name:   kthreadd
> Umask:  0000
> State:  S (sleeping)
> Tgid:   2
> Ngid:   0
> Pid:    2
> PPid:   0
>

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

Re: Can AUDIT_LIST_RULES causes kthreadd-spam?

[Tetsuo Handa]

On 2023/05/24 19:38, Rinat Gadelshin wrote:
> Hi Tetsuo.
> 
> Sorry for my log absence.
> The kthread-spam problem has gone when I've switched to using unicast-netlink connection (like auditd does).

Glad to hear that.

> 
> Do we need to make another test with the additional pr_info() ?
> 

No need to test.

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