4:14 p.m.
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
4:27 p.m.
On Wed, May 3, 2023 at 5:14 PM Rinat Gadelshin <rgadelsh(a)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(a)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
5:12 p.m.
On 04.05.2023 00:27, Paul Moore wrote:
On Wed, May 3, 2023 at 5:14 PM Rinat Gadelshin
<rgadelsh(a)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(a)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(a)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?
9:50 p.m.
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;
}
1:40 p.m.
On Wed, May 3, 2023 at 10:50 PM Tetsuo Handa
<penguin-kernel(a)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
5:53 p.m.
On 2023/05/05 3:40, Paul Moore wrote:
On Wed, May 3, 2023 at 10:50 PM Tetsuo Handa
<penguin-kernel(a)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?
5:12 p.m.
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(a)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)
1:50 a.m.
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;
7:12 a.m.
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.
8:30 a.m.
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
8:48 a.m.
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(a)redhat.com
https://listman.redhat.com/mailman/listinfo/linux-audit
5:38 a.m.
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
5:48 a.m.
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.
577
days inactive
598
days old
linux-audit@lists.linux-audit.osci.io
12 comments
4 participants
participants (4)
-
Paul Moore -
Rinat Gadelshin -
Steve Grubb -
Tetsuo Handa