RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 1978123 - list_del corruption triggers the BUG() upon removing the entry in the audit_tree.rules list
Summary: list_del corruption triggers the BUG() upon removing the entry in the audit_t...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 8
Classification: Red Hat
Component: kernel
Version: 8.3
Hardware: Unspecified
OS: Unspecified
medium
medium
Target Milestone: beta
: 8.6
Assignee: Richard Guy Briggs
QA Contact: Linqing Lu
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2021-07-01 07:39 UTC by Seiji Nishikawa
Modified: 2022-08-23 16:43 UTC (History)
4 users (show)

Fixed In Version: kernel-4.18.0-349.el8
Doc Type: No Doc Update
Doc Text:
Clone Of:
Environment:
Last Closed: 2022-05-10 14:59:11 UTC
Type: Bug
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Gitlab redhat/rhel/src/kernel rhel-8 merge_requests 1411 0 None None None 2021-10-15 21:54:50 UTC
Red Hat Knowledge Base (Solution) 6305751 0 None None None 2021-09-03 08:43:17 UTC
Red Hat Product Errata RHSA-2022:1988 0 None None None 2022-05-10 14:59:34 UTC

Description Seiji Nishikawa 2021-07-01 07:39:58 UTC 
Description of problem:

list_del corruption triggers the BUG() upon removing the entry in the 
audit_tree.rules list

Version-Release number of selected component (if applicable):

RHEL8.3.z kernel-4.18.0-240.10.1.el8_3

How reproducible:

Unknown at this time

Steps to Reproduce:
1. Unknown at this time
2.
3.

Actual results:

The kernel crashes due to the BUG() being hit upon removing the audit rule 
with auditctl command.

Expected results:

The kernel doesn't crash upon removing the audit rule with auditctl command.

Additional info:

Panic message logged in the kernel ring buffer:

	...
[595829.989690] hv_utils: Shutdown request received - graceful shutdown initiated
[595830.286714] list_del corruption. prev->next should be ffff968f7aac4170, but was 0000000000000000
[595830.307120] ------------[ cut here ]------------
[595830.307122] kernel BUG at lib/list_debug.c:53!
[595830.307129] invalid opcode: 0000 [#1] SMP PTI
[595830.307131] CPU: 7 PID: 2123745 Comm: auditctl Kdump: loaded Not tainted 4.18.0-240.10.1.el8_3.x86_64 #1
[595830.307132] Hardware name: Microsoft Corporation Virtual Machine/Virtual Machine, BIOS 090008  12/07/2018
[595830.307140] RIP: 0010:__list_del_entry_valid.cold.1+0x34/0x4c
[595830.307143] Code: cd 6e b4 e8 b8 44 cd ff 0f 0b 48 c7 c7 60 ce 6e b4 e8 aa 44 cd ff 0f 0b 48 89 f2 48 89 fe 48 c7 c7 20 ce 6e b4 e8 96 44 cd ff <0f> 0b 48 89 fe 48 c7 c7 e8 cd 6e b4 e8 85 44 cd ff 0f 0b 90 90 90
[595830.307144] RSP: 0018:ffffbda786703be8 EFLAGS: 00010246
[595830.307153] RAX: 0000000000000054 RBX: ffff968f7aac4020 RCX: 0000000000000000
[595830.307154] RDX: 0000000000000000 RSI: ffff968f7fdd6a08 RDI: ffff968f7fdd6a08
[595830.307155] RBP: ffff968f749de080 R08: ffff968f7cbadf00 R09: 000000000000039e
[595830.307156] R10: 000000008d8be200 R11: 00000000c12c4cc9 R12: ffff968f7aac4170
[595830.307157] R13: 0000000000000000 R14: ffff968f795a0c00 R15: ffff968c0836a810
[595830.307159] FS:  00007f8a70d4b100(0000) GS:ffff968f7fdc0000(0000) knlGS:0000000000000000
[595830.307160] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[595830.307161] CR2: 00005626ca940158 CR3: 00000008b43a2003 CR4: 00000000003606e0
[595830.307165] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[595830.307166] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[595830.307167] Call Trace:
[595830.307174]  audit_remove_tree_rule+0x39/0x160
[595830.307180]  audit_del_rule+0x8e/0x190
[595830.307182]  audit_rule_change+0x9e/0x420
[595830.307187]  ? security_capable+0x38/0x50
[595830.307190]  audit_receive_msg+0x135/0xee0
[595830.307193]  ? __check_object_size+0xa8/0x16b
[595830.307196]  ? __kmalloc_node_track_caller+0x1c3/0x290
[595830.307199]  ? __alloc_skb+0x82/0x1c0
[595830.307204]  ? __netlink_lookup+0xe6/0x150
[595830.307206]  audit_receive+0x52/0xb0
[595830.307209]  netlink_unicast+0x19e/0x260
[595830.307212]  netlink_sendmsg+0x204/0x3d0
[595830.307215]  sock_sendmsg+0x4c/0x50
[595830.307218]  __sys_sendto+0xee/0x160
[595830.307230]  ? syscall_trace_enter+0x1d3/0x2c0
[595830.307232]  ? __audit_syscall_exit+0x249/0x2a0
[595830.307234]  __x64_sys_sendto+0x24/0x30
[595830.307237]  do_syscall_64+0x5b/0x1a0
[595830.307240]  entry_SYSCALL_64_after_hwframe+0x65/0xca
[595830.307243] RIP: 0033:0x7f8a702d0d68
[595830.307245] Code: 89 02 48 c7 c0 ff ff ff ff eb b5 0f 1f 80 00 00 00 00 f3 0f 1e fa 8b 05 e6 d6 20 00 41 89 ca 85 c0 75 17 b8 2c 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 78 c3 0f 1f 80 00 00 00 00 41 57 4d 89 c7 41
[595830.307246] RSP: 002b:00007fffde324d38 EFLAGS: 00000246 ORIG_RAX: 000000000000002c
[595830.307248] RAX: ffffffffffffffda RBX: 0000000000000444 RCX: 00007f8a702d0d68
[595830.307249] RDX: 0000000000000444 RSI: 00007fffde324d70 RDI: 0000000000000003
[595830.307250] RBP: 0000000000000003 R08: 00007fffde324d5c R09: 000000000000000c
[595830.307251] R10: 0000000000000000 R11: 0000000000000246 R12: 00007fffde324d70
[595830.307251] R13: 00007fffde324d5c R14: 0000000000000014 R15: 0000000000000431
[595830.307256] Modules linked in: xsk_diag raw_diag unix_diag af_packet_diag netlink_diag udp_diag tcp_diag inet_diag nft_counter xt_owner xt_conntrack nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 nft_compat fuse ccm md4 sha512_ssse3 sha512_generic cmac nls_utf8 cifs libarc4 dns_resolver nf_tables binfmt_misc nfnetlink intel_rapl_msr intel_rapl_common sb_edac kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel intel_rapl_perf hv_balloon hv_utils hyperv_fb i2c_piix4 pcspkr joydev xfs libcrc32c auth_rpcgss sunrpc ip_tables ext4 mbcache jbd2 ata_generic sd_mod sg ata_piix hyperv_keyboard hv_storvsc hv_netvsc scsi_transport_fc hid_hyperv crc32c_intel libata serio_raw hv_vmbus dm_mirror dm_region_hash dm_log dm_mod
[595830.307891] ---[ end trace 281a8031390cd5c2 ]---
[595830.307895] RIP: 0010:__list_del_entry_valid.cold.1+0x34/0x4c
[595830.307897] Code: cd 6e b4 e8 b8 44 cd ff 0f 0b 48 c7 c7 60 ce 6e b4 e8 aa 44 cd ff 0f 0b 48 89 f2 48 89 fe 48 c7 c7 20 ce 6e b4 e8 96 44 cd ff <0f> 0b 48 89 fe 48 c7 c7 e8 cd 6e b4 e8 85 44 cd ff 0f 0b 90 90 90
[595830.307898] RSP: 0018:ffffbda786703be8 EFLAGS: 00010246
[595830.307900] RAX: 0000000000000054 RBX: ffff968f7aac4020 RCX: 0000000000000000
[595830.307900] RDX: 0000000000000000 RSI: ffff968f7fdd6a08 RDI: ffff968f7fdd6a08
[595830.307901] RBP: ffff968f749de080 R08: ffff968f7cbadf00 R09: 000000000000039e
[595830.307902] R10: 000000008d8be200 R11: 00000000c12c4cc9 R12: ffff968f7aac4170
[595830.307903] R13: 0000000000000000 R14: ffff968f795a0c00 R15: ffff968c0836a810
[595830.307905] FS:  00007f8a70d4b100(0000) GS:ffff968f7fdc0000(0000) knlGS:0000000000000000
[595830.307906] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[595830.307907] CR2: 00005626ca940158 CR3: 00000008b43a2003 CR4: 00000000003606e0
[595830.307910] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[595830.307911] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[595830.307912] Kernel panic - not syncing: Fatal exception
[595830.308088] Kernel Offset: 0x32600000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)

All of the audit rules:

[snishika@supportshell sosreport-ana1pntgnod0003-2021-06-04-fxvpuch]$ pwd
/home/nrt/snishika/02962027/0020-sosreport-ana1pntgnod0003-2021-06-04-fxvpuch.tar.xz/sosreport-ana1pntgnod0003-2021-06-04-fxvpuch

[snishika@supportshell sosreport-ana1pntgnod0003-2021-06-04-fxvpuch]$ cat etc/audit/audit.rules 
## This file is automatically generated from /etc/audit/rules.d
-D
-b 8192
-f 1
--backlog_wait_time 60000
-a always,exit -F arch=b32 -S adjtimex,settimeofday,stime -F key=time-change
-a always,exit -F arch=b64 -S adjtimex,settimeofday -F key=time-change
-a always,exit -F arch=b32 -S clock_settime -F a0=0x0 -F key=time-change
-a always,exit -F arch=b64 -S clock_settime -F a0=0x0 -F key=time-change
-w /etc/localtime -p wa -k time-change
-w /etc/group -p wa -k identity
-w /etc/passwd -p wa -k identity
-w /etc/gshadow -p wa -k identity
-w /etc/shadow -p wa -k identity
-w /etc/security/opasswd -p wa -k identity
-a always,exit -F arch=b32 -S sethostname,setdomainname -F key=system-locale
-a always,exit -F arch=b64 -S sethostname,setdomainname -F key=system-locale
-w /etc/issue -p wa -k system-locale
-w /etc/issuessh -p wa -k system-locale
-w /etc/issue.net -p wa -k system-locale
-w /etc/hosts -p wa -k system-locale
-w /etc/hostname -p wa -k system-locale
-a always,exit -F dir=/etc/NetworkManager/ -F perm=wa -F key=system-locale
-a always,exit -F dir=/etc/selinux/ -F perm=wa -F key=MAC-policy
-w /var/log/tallylog -p wa -k logins
-w /var/run/faillock/ -p wa -k logins
-w /var/log/lastlog -p wa -k logins
-w /var/run/utmp -p wa -k session
-w /var/log/btmp -p wa -k session
-w /var/log/wtmp -p wa -k session
-a always,exit -F arch=b32 -S chmod,fchmod,fchmodat -F auid>=1000 -F auid!=unset -F key=perm_mod
-a always,exit -F arch=b64 -S chmod,fchmod,fchmodat -F auid>=1000 -F auid!=unset -F key=perm_mod
-a always,exit -F arch=b32 -S lchown,fchown,chown,fchownat -F auid>=1000 -F auid!=unset -F key=perm_mod
-a always,exit -F arch=b64 -S chown,fchown,lchown,fchownat -F auid>=1000 -F auid!=unset -F key=perm_mod
-a always,exit -F arch=b32 -S setxattr,lsetxattr,fsetxattr,removexattr,lremovexattr,fremovexattr -F auid>=1000 -F auid!=unset -F key=perm_mod
-a always,exit -F arch=b64 -S setxattr,lsetxattr,fsetxattr,removexattr,lremovexattr,fremovexattr -F auid>=1000 -F auid!=unset -F key=perm_mod
-a always,exit -F arch=b32 -S open,creat,truncate,ftruncate,openat,open_by_handle_at -F exit=-EACCES -F auid>=1000 -F auid!=unset -F key=access
-a always,exit -F arch=b32 -S open,creat,truncate,ftruncate,openat,open_by_handle_at -F exit=-EPERM -F auid>=1000 -F auid!=unset -F key=access
-a always,exit -F arch=b64 -S open,truncate,ftruncate,creat,openat,open_by_handle_at -F exit=-EACCES -F auid>=1000 -F auid!=unset -F key=access
-a always,exit -F arch=b64 -S open,truncate,ftruncate,creat,openat,open_by_handle_at -F exit=-EPERM -F auid>=1000 -F auid!=unset -F key=access
-a always,exit -F arch=b32 -S mount -F auid>=1000 -F auid!=unset -F key=export
-a always,exit -F arch=b64 -S mount -F auid>=1000 -F auid!=unset -F key=export
-a always,exit -F arch=b32 -S unlink,unlinkat,rename,renameat -F auid>=1000 -F auid!=unset -F key=delete
-a always,exit -F arch=b64 -S unlink,unlinkat,rename,renameat -F auid>=1000 -F auid!=unset -F key=delete
-w /etc/sudoers -p wa -k actions
-w /etc/sudoers -p wa -k scope
-w /etc/sudoers.d/ -p wa -k actions
-w /etc/sudoers.d/ -p wa -k scope
find /usr/bin -type f -perm -04000 2>/dev/null | awk '{ printf "-a always,exit -F path=%s -F perm=x -F auid>=1000 -F auid!=unset -F key=privileged\n", $1 }' >> priv.rules
find /usr/sbin -type f -perm -04000 2>/dev/null | awk '{ printf "-a always,exit -F path=%s -F perm=x -F auid>=1000 -F auid!=unset -F key=privileged\n", $1 }' >> priv.rules
-a always,exit -F arch=b32 -S init_module,finit_module -F key=module-load
-a always,exit -F arch=b64 -S init_module,finit_module -F key=module-load
-a always,exit -F arch=b32 -S delete_module -F key=module-unload
-a always,exit -F arch=b64 -S delete_module -F key=module-unload
--backlog_wait_time 60000
-w /bin/kmod -p x -k auoms -k kernelmodules
-w /var/log/audit -p wxa -k audittampering -k auoms
-w /etc/audit -p wxa -k audittampering -k auoms
-w /etc/passwd -p x -k auoms -k usergroup
-w /etc/group -p x -k auoms -k usergroup
-w /etc/pam.d -p wxa -k auoms -k pam
-a always,exit -F arch=b32 -S execve,execveat -F key=auoms
-a always,exit -F arch=b64 -S execve,execveat -F key=auoms
Comment 1 Seiji Nishikawa 2021-07-01 07:54:00 UTC 
INITIAL VMCORE ANALYSIS
=======================

(Galvatron)
retrace-server-interact 912300546 crash 

      KERNEL: /cores/retrace/repos/kernel/x86_64/usr/lib/debug/lib/modules/4.18.0-240.10.1.el8_3.x86_64/vmlinux
    DUMPFILE: /cores/retrace/tasks/912300546/crash/vmcore  [PARTIAL DUMP]
     RELEASE: 4.18.0-240.10.1.el8_3.x86_64
       PANIC: "kernel BUG at lib/list_debug.c:53!"

        DMI_BIOS_VENDOR: American Megatrends Inc.
         DMI_SYS_VENDOR: Microsoft Corporation
       DMI_PRODUCT_NAME: Virtual Machine
    DMI_PRODUCT_VERSION: 7.0

PID: 2123745  TASK: ffff968bcca82f80  CPU: 7   COMMAND: "auditctl"
	...
    [exception RIP: __list_del_entry_valid.cold.1+0x34]
    RIP: ffffffffb3a4b618  RSP: ffffbda786703be8  RFLAGS: 00010246
    RAX: 0000000000000054  RBX: ffff968f7aac4020  RCX: 0000000000000000
    RDX: 0000000000000000  RSI: ffff968f7fdd6a08  RDI: ffff968f7fdd6a08
    RBP: ffff968f749de080   R8: ffff968f7cbadf00   R9: 000000000000039e
    R10: 000000008d8be200  R11: 00000000c12c4cc9  R12: ffff968f7aac4170
    R13: 0000000000000000  R14: ffff968f795a0c00  R15: ffff968c0836a810
    ORIG_RAX: ffffffffffffffff  CS: 0010  SS: 0018
 #6 [ffffbda786703be0] __list_del_entry_valid.cold.1 at ffffffffb3a4b618
 #7 [ffffbda786703be8] audit_remove_tree_rule at ffffffffb3786fd9
 #8 [ffffbda786703c18] audit_del_rule at ffffffffb377f32e
 #9 [ffffbda786703c50] audit_rule_change at ffffffffb377f4ce
#10 [ffffbda786703c98] audit_receive_msg at ffffffffb377cfc5
#11 [ffffbda786703d20] audit_receive at ffffffffb377ddc2
#12 [ffffbda786703d40] netlink_unicast at ffffffffb3daaa2e
	...

In auditctl task's context, we call audit_receive() to receive messages from
the netlink control socket, netlink_sock 0xffff9687c4590800. The message 
buffer sk_buff 0xffff968f795a0c00.

crash> sk_buff.data ffff968f795a0c00
  data = 0xffff968c0836a800 "D\004" <<------------ nlh

crash> sk_buff.len ffff968f795a0c00
  len = 1092

crash> nlmsghdr 0xffff968c0836a800
struct nlmsghdr {
  nlmsg_len = 1092, 
  nlmsg_type = 1012, <<------------ AUDIT_DEL_RULE (Delete syscall filtering rule)
  nlmsg_flags = 5, 
  nlmsg_seq = 20, 
  nlmsg_pid = 0
}

1193 static int audit_receive_msg(struct sk_buff *skb, struct nlmsghdr *nlh)
1194 {
1195         u32                     seq;
1196         void                    *data;
1197         int                     data_len;
1198         int                     err;
1199         struct audit_buffer     *ab;
1200         u16                     msg_type = nlh->nlmsg_type;
1201         struct audit_sig_info   *sig_data;
1202         char                    *ctx = NULL;
1203         u32                     len;
....
1209         seq  = nlh->nlmsg_seq;
1210         data = nlmsg_data(nlh);
1211         data_len = nlmsg_len(nlh);
....
1381         case AUDIT_DEL_RULE:
....
1394                 err = audit_rule_change(msg_type, seq, data, data_len);
....

nlmsg_data(nlh) returns 0xffff968c0836a810 at line number 1210.

crash> px 0xffff968c0836a800+0x10
$31 = 0xffff968c0836a810 <<------------ data (head of message payload)

nlmsg_len(hlh) returns 1076 at line number 1211.

crash> pd 1092-0x10
$33 = 1076 <<------------ length of message payload

1140 int audit_rule_change(int type, int seq, void *data, size_t datasz)
1141 {
....
1145         switch (type) {
....
1153         case AUDIT_DEL_RULE:
1154                 entry = audit_data_to_entry(data, datasz);
1155                 if (IS_ERR(entry))
1156                         return PTR_ERR(entry);
1157                 err = audit_del_rule(entry);
....

audit_data_to_entry() returns the audit_entry 0xffff968bd35bb200 at line 
number 1154.

crash> kmem ffff968bd35bb200
CACHE             OBJSIZE  ALLOCATED     TOTAL  SLABS  SSIZE  NAME
ffff9687c7c06c00      512       4213      4960    155    16k  kmalloc-512
  SLAB              MEMORY            NODE  TOTAL  ALLOCATED  FREE
  fffff1e7d44d6e00  ffff968bd35b8000     0     32         16    16
  FREE / [ALLOCATED]
  [ffff968bd35bb200]

      PAGE        PHYSICAL      MAPPING       INDEX CNT FLAGS
fffff1e7d44d6ec0 5135bb000 dead000000000400        0  0 17ffffc0000000

The audit_entry that is passed to audit_del_rule() is:

crash> audit_entry ffff968bd35bb200
struct audit_entry {
  list = {
    next = 0x0, 
    prev = 0x0
  }, 
  rcu = {
    next = 0x0, 
    func = 0x0
  }, 
  rule = {
    pflags = 0, 
    flags = 0, 
    listnr = 4, <<------------ AUDIT_FILTER_EXIT (Apply rule at syscall exit)
    action = 2, <<------------ AUDIT_ALWAYS (Generate audit record if rule matches)
    mask = {4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 4294967295, 65535}, 
    buflen = 33, 
    field_count = 3, 
    filterkey = 0xffff968f39e2bde0 "system-locale", 
    fields = 0xffff968eeabe1d80, 
    arch_f = 0x0, 
    inode_f = 0x0, 
    watch = 0x0, 
    tree = 0xffff968bd3552e80, 
    exe = 0x0, 
    rlist = {
      next = 0x0, 
      prev = 0x0
    }, 
    list = {
      next = 0x0, 
      prev = 0x0
    }, 
    prio = 0
  }
}

1029 /* Remove an existing rule from filterlist. */
1030 int audit_del_rule(struct audit_entry *entry)
1031 {
1032         struct audit_entry  *e;
1033         struct audit_tree *tree = entry->rule.tree;
1034         struct list_head *list;
1035         int ret = 0;
1036 #ifdef CONFIG_AUDITSYSCALL
1037         int dont_count = 0;
1038 
1039         /* If any of these, don't count towards total */
1040         switch(entry->rule.listnr) {
1041         case AUDIT_FILTER_USER:
1042         case AUDIT_FILTER_EXCLUDE:
1043         case AUDIT_FILTER_FS:
1044                 dont_count = 1;
1045         }
1046 #endif
1047 
1048         mutex_lock(&audit_filter_mutex);
1049         e = audit_find_rule(entry, &list);
....
	 906 /* Find an existing audit rule.
	 907  * Caller must hold audit_filter_mutex to prevent stale rule data. */
	 908 static struct audit_entry *audit_find_rule(struct audit_entry *entry,
	 909                                            struct list_head **p)
	 910 {
	 911         struct audit_entry *e, *found = NULL;
	 912         struct list_head *list;
	 913         int h;
	 914 
	 915         if (entry->rule.inode_f) { <<------------ Skip this branch.
     ...
	 918         } else if (entry->rule.watch) { <<------------ Skip this branch.
     ...
	 929         } else { <<------------ Take this branch.
	 930                 *p = list = &audit_filter_list[entry->rule.listnr];
	 931         }
	 932 
	 933         list_for_each_entry(e, list, list)
	 934                 if (!audit_compare_rule(&entry->rule, &e->rule)) {
	 935                         found = e;
	 936                         goto out;
	 937                 }
	 938 
	 939 out:
	 940         return found;
	 941 }
....
1050         if (!e) {
1051                 ret = -ENOENT;
1052                 goto out;
1053         }
1054 
1055         if (e->rule.watch)
1056                 audit_remove_watch_rule(&e->rule);
1057 
1058         if (e->rule.tree)
1059                 audit_remove_tree_rule(&e->rule);
....

crash> audit_entry.rule.tree,rule.inode_f,rule.watch,rule.listnr ffff968bd35bb200
  rule.tree = 0xffff968bd3552e80, <<------------ The watched tree associated with this audit_krule.
  rule.inode_f = 0x0, <<------------ No quick access to an inode field.
  rule.watch = 0x0, <<------------ No associated watch.
  rule.listnr = 0x4, <<------------ AUDIT_FILTER_EXIT (Apply rule at syscall exit)

crash> px &audit_filter_list[4]
$46 = (struct list_head *) 0xffffffffb48b3180

crash> list -o audit_entry.list  -H 0xffffffffb48b3180 | wc -l
28

crash> list -o audit_entry.list  -H 0xffffffffb48b3180
ffff968f7aac4000 <<------------ found
ffff968f7426fe00
ffff968f7baa1e00
ffff968f7e6eea00
ffff968f7e6ee600
ffff968f74d9f800
ffff968f74d9d600
ffff968f74d9c200
ffff968f74d9e200
ffff968f74d9ec00
ffff968f74d9c800
ffff968f74d9e000
ffff968f74aef000
ffff968f7d0dec00
ffff968f7d0dc200
ffff968f7d0dea00
ffff968f7d0dda00
ffff968f7d0dca00
ffff968f7d0dc000
ffff968f74e33000
ffff968f74e31000
ffff968f74e30000
ffff968f74e30800
ffff968f74e31c00
ffff968f74e30c00
ffff968f74e32200
ffff968f74e30200
ffff968f74e33a00

We call audit_find_rule() and then find the below audit_entry in the 
audit_filter_list:

crash> audit_entry ffff968f7aac4000
struct audit_entry {
  list = {
    next = 0xffff968f7426fe00, 
    prev = 0xffffffffb48b3180
  }, 
  rcu = {
    next = 0x0, 
    func = 0x0
  }, 
  rule = {
    pflags = 0x0, 
    flags = 0x0, 
    listnr = 0x4, 
    action = 0x2, 
    mask = {0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffffffff, 0xffff}, 
    buflen = 0x21, 
    field_count = 0x3, 
    filterkey = 0xffff968f74f4cf30 "system-locale", 
    fields = 0xffff968f71613e40, 
    arch_f = 0x0, 
    inode_f = 0x0, 
    watch = 0x0, 
    tree = 0xffff968f749de080, 
    exe = 0x0, 
    rlist = {
      next = 0xffff968f749de0a0, 
      prev = 0xffff968f749de0a0
    }, 
    list = {
      next = 0xffff968f7426ff80, 
      prev = 0xffffffffb48b3100
    }, 
    prio = 0x7fffffffffffffed
  }
}


crash> audit_entry.rule.watch,rule.tree,rule.exe ffff968f7aac4000
  rule.watch = 0x0, <<------------ No watch associated.
  rule.tree = 0xffff968f749de080, <<------------ The watched tree (audit_tree) is associated.
  rule.exe = 0x0, <<------------ No fsnotify_mark associated.

The audit_tree, that is associated with the entry's audit_krule, is, however,
a free object in kmalloc-128 slab cache. It's not an allocated object (strange).


crash> kmem 0xffff968f749de080
CACHE             OBJSIZE  ALLOCATED     TOTAL  SLABS  SSIZE  NAME
ffff9687c7c07200      128       2334      3328    104     4k  kmalloc-128
  SLAB              MEMORY            NODE  TOTAL  ALLOCATED  FREE
  fffff1e7e2d27780  ffff968f749de000     0     32         24     8
  FREE / [ALLOCATED]
   ffff968f749de080  

      PAGE        PHYSICAL      MAPPING       INDEX CNT FLAGS
fffff1e7e2d27780 8b49de000 ffff9687c7c07200 ffff968f749de680  1 17ffffc0000100 slab


crash> audit_tree 0xffff968f749de080
struct audit_tree {
  count = {
    refs = {
      counter = 1956506880
    }
  }, 
  goner = -26993, 
  root = 0x0, 
  chunks = {
    next = 0x0, 
    prev = 0xffffffffffffffff
  }, 
  rules = {
    next = 0x0, 
    prev = 0x0
  }, 
  list = {
    next = 0xffffffffffffffff, 
    prev = 0x0
  }, 
  same_root = {
    next = 0x0, 
    prev = 0x0
  }, 
  head = {
    next = 0xffff968f7978db38, 
    func = 0x2
  }, 
  pathname = 0xffff968f749de0e0 "/etc/NetworkManager/"
}

[snishika@supportshell sosreport-ana1pntgnod0003-2021-06-04-fxvpuch]$ cat etc/audit/audit.rules  | grep system-locale
-a always,exit -F arch=b32 -S sethostname,setdomainname -F key=system-locale
-a always,exit -F arch=b64 -S sethostname,setdomainname -F key=system-locale
-w /etc/issue -p wa -k system-locale
-w /etc/issuessh -p wa -k system-locale
-w /etc/issue.net -p wa -k system-locale
-w /etc/hosts -p wa -k system-locale
-w /etc/hostname -p wa -k system-locale
-a always,exit -F dir=/etc/NetworkManager/ -F perm=wa -F key=system-locale <<------------ The rule is this one.


Anyways, since the audit_entry, that was obtained from the audit_filter_list,
has the audit_krule being associated the watched tree (audit_tree), we call 
audit_remove_tree_rule() to remove the entries in the rlist, initialize the 
rlist, and also initialize the watched tree.

 648 /* called with audit_filter_mutex */
 649 int audit_remove_tree_rule(struct audit_krule *rule)
 650 {
 651         struct audit_tree *tree;
 652         tree = rule->tree;
 653         if (tree) {
 654                 spin_lock(&hash_lock);
 655                 list_del_init(&rule->rlist);
 656                 if (list_empty(&tree->rules) && !tree->goner) {
 657                         tree->root = NULL;
 658                         list_del_init(&tree->same_root);
 659                         tree->goner = 1;
 660                         list_move(&tree->list, &prune_list);
 661                         rule->tree = NULL;
 662                         spin_unlock(&hash_lock);
 663                         audit_schedule_prune();
 664                         return 1;
 665                 }
 666                 rule->tree = NULL;
 667                 spin_unlock(&hash_lock);
 668                 return 1;
 669         }
 670         return 0;
 671 }

At this time, the watched tree is not an allocated object but free object in 
kmalloc-128 slab cache as mentioned above.


crash> px ((struct audit_krule *) 0xffff968f7aac4020)->tree
$53 = (struct audit_tree *) 0xffff968f749de080

crash> kmem 0xffff968f749de080
CACHE             OBJSIZE  ALLOCATED     TOTAL  SLABS  SSIZE  NAME
ffff9687c7c07200      128       2334      3328    104     4k  kmalloc-128
  SLAB              MEMORY            NODE  TOTAL  ALLOCATED  FREE
  fffff1e7e2d27780  ffff968f749de000     0     32         24     8
  FREE / [ALLOCATED]
   ffff968f749de080  

      PAGE        PHYSICAL      MAPPING       INDEX CNT FLAGS
fffff1e7e2d27780 8b49de000 ffff9687c7c07200 ffff968f749de680  1 17ffffc0000100 slab


The audit_tree is not an allocated object but a free object in kmalloc-128 
slab. compound_head() doesn't return the slab head page. 

crash> page.compound_head fffff1e7e2d27780
      compound_head = 0xfffff1e7dff05d08

crash> px (0xfffff1e7dff05d08 & 1)
$56 = 0x0

crash> kmem 0xfffff1e7dff05d08
      PAGE        PHYSICAL      MAPPING       INDEX CNT FLAGS
fffff1e7e2b64140 8ad905000                0        c  2 17ffffc0001800 reserved,private


And then, finally check_data_corruption() is called in subsequent __list_del_entry()
upon comparing prev->next with the rlist, 0xffff968f7aac4170, because prev->next
is not equal to the rlist but NULL.


crash> px &((struct audit_krule *) 0xffff968f7aac4020)->rlist
$60 = (struct list_head *) 0xffff968f7aac4170

crash> px ((struct audit_krule *) 0xffff968f7aac4020)->rlist
$69 = {
  next = 0xffff968f749de0a0, 
  prev = 0xffff968f749de0a0
}

crash> list_head 0xffff968f749de0a0
struct list_head {
  next = 0x0, 
  prev = 0x0
}

crash> log | grep corruption
[595830.286714] list_del corruption. prev->next should be ffff968f7aac4170, but was 0000000000000000

188 static inline void list_del_init(struct list_head *entry)
189 {
190         __list_del_entry(entry);
...

crash> dis -lr ffffffffb3a4b618
/usr/src/debug/kernel-4.18.0-240.10.1.el8_3/linux-4.18.0-240.10.1.el8_3.x86_64/lib/list_debug.c: 45
0xffffffffb3a4b5e4 <__list_del_entry_valid.cold.1>:	mov    %rdi,%rsi
0xffffffffb3a4b5e7 <__list_del_entry_valid.cold.1+0x3>:	mov    %rax,%rdx
0xffffffffb3a4b5ea <__list_del_entry_valid.cold.1+0x6>:	mov    $0xffffffffb46ecdb0,%rdi
0xffffffffb3a4b5f1 <__list_del_entry_valid.cold.1+0xd>:	callq  0xffffffffb371faae <printk>
0xffffffffb3a4b5f6 <__list_del_entry_valid.cold.1+0x12>:	ud2    
/usr/src/debug/kernel-4.18.0-240.10.1.el8_3/linux-4.18.0-240.10.1.el8_3.x86_64/lib/list_debug.c: 54
0xffffffffb3a4b5f8 <__list_del_entry_valid.cold.1+0x14>:	mov    $0xffffffffb46ece60,%rdi
0xffffffffb3a4b5ff <__list_del_entry_valid.cold.1+0x1b>:	callq  0xffffffffb371faae <printk>
0xffffffffb3a4b604 <__list_del_entry_valid.cold.1+0x20>:	ud2    
0xffffffffb3a4b606 <__list_del_entry_valid.cold.1+0x22>:	mov    %rsi,%rdx
0xffffffffb3a4b609 <__list_del_entry_valid.cold.1+0x25>:	mov    %rdi,%rsi
0xffffffffb3a4b60c <__list_del_entry_valid.cold.1+0x28>:	mov    $0xffffffffb46ece20,%rdi
0xffffffffb3a4b613 <__list_del_entry_valid.cold.1+0x2f>:	callq  0xffffffffb371faae <printk>
/usr/src/debug/kernel-4.18.0-240.10.1.el8_3/linux-4.18.0-240.10.1.el8_3.x86_64/lib/list_debug.c: 51
0xffffffffb3a4b618 <__list_del_entry_valid.cold.1+0x34>:	ud2    

 38 bool __list_del_entry_valid(struct list_head *entry)
 39 {
 ..
 42         prev = entry->prev;
 43         next = entry->next;
 44 
 45         if (CHECK_DATA_CORRUPTION(next == LIST_POISON1,
 ..
 51             CHECK_DATA_CORRUPTION(prev->next != entry,
 52                         "list_del corruption. prev->next should be %px, but was %px\n",
 53                         entry, prev->next) ||
 ..

The current running kernel is not so very old one here. It may be possible 
that we still have some race or use-after-free bug around the audit code 
that hasn't yet been fixed as of the latest rhel8.4.z:

$ git log --oneline kernel-4.18.0-240.11.1.el8_3..kernel-4.18.0-305.8.el8 kernel/audit*
9763ea8f934f [kernel] audit: do not set FS_EVENT_ON_CHILD in audit marks mask
bfcdfc68eeca [kernel] audit: fix macros warnings
ee1d4ff404b7 [kernel] audit: trigger accompanying records when no rules present
1189e7ed993c [kernel] audit: fix a kernel-doc markup
584ab576d267 [kernel] audit: Remove redundant null check
7dd4e9a56fe0 [kernel] audit: uninitialize variable audit_sig_sid
fa776e3eeb92 [kernel] audit: change unnecessary globals into statics
dcf7f86a1218 [kernel] audit: report audit wait metric in audit status reply
9c0ebe52fbe5 [security] audit: purge audit_log_string from the intra-kernel audit API
d2a2ff151ee3 [kernel] audit: issue CWD record to accompany LSM_AUDIT_DATA_* records
5b97d1864ae1 [net] audit: add gfp parameter to audit_log_nfcfg
ef31631db38c [kernel] audit: log nftables configuration change events
8ba14d3c8a7b [kernel] audit: Use struct_size() helper in alloc_chunk
6714fb6a17c1 [kernel] revert: 1320a4052ea1 ("audit: trigger accompanying records when no rules present")
Comment 2 Seiji Nishikawa 2021-07-01 09:29:12 UTC 
Looks like the issue has got reproduced in my lab.

[root@localhost ~]# uname -r
4.18.0-240.10.1.el8_3.x86_64+debug

[root@localhost ~]# cat /proc/cmdline 
BOOT_IMAGE=(hd0,msdos1)/vmlinuz-4.18.0-240.10.1.el8_3.x86_64+debug root=/dev/mapper/rhel-root ro crashkernel=auto resume=/dev/mapper/rhel-swap rd.lvm.lv=rhel/root rd.lvm.lv=rhel/swap modprobe.blacklist=nouveau kasan_multi_shot log_buf_len=10M


[   48.993884] ==================================================================
[   48.995545] BUG: KASAN: use-after-free in audit_add_tree_rule+0x7cf/0x9b0
[   48.997023] Read of size 8 at addr ffff888035074130 by task auditctl/823

[   48.999936] CPU: 0 PID: 823 Comm: auditctl Tainted: G                 ---------r-  - 4.18.0-240.10.1.el8_3.x86_64+debug #1
[   49.002907] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 04/05/2016
[   49.005958] Call Trace:
[   49.007455]  dump_stack+0x9a/0xf0
[   49.008938]  print_address_description.cold.3+0x9/0x23b
[   49.010452]  kasan_report.cold.4+0x65/0x95
[   49.011945]  ? audit_add_tree_rule+0x7cf/0x9b0
[   49.013446]  audit_add_tree_rule+0x7cf/0x9b0
[   49.014925]  ? audit_put_tree+0x30/0x30
[   49.016421]  audit_rule_change+0x412/0xd20
[   49.017895]  ? audit_del_rule+0x530/0x530
[   49.019374]  ? security_capable+0x58/0x90
[   49.020831]  audit_receive_msg+0x2b0/0x1eb0
[   49.022274]  ? lock_contended+0xd90/0xd90
[   49.023724]  ? audit_log_feature_change.part.8+0x1d0/0x1d0
[   49.025176]  ? __mutex_lock+0xe26/0x13d0
[   49.026616]  ? sched_clock+0x5/0x10
[   49.028033]  ? audit_receive+0x78/0x200
[   49.029444]  ? mutex_lock_io_nested+0x12a0/0x12a0
[   49.030842]  ? sched_clock+0x5/0x10
[   49.032214]  ? sched_clock_cpu+0x18/0x1e0
[   49.033677]  ? find_held_lock+0x3a/0x1c0
[   49.035063]  ? netlink_deliver_tap+0x107/0xad0
[   49.036433]  ? lock_downgrade+0x6f0/0x6f0
[   49.037791]  ? rcu_is_watching+0x2c/0x80
[   49.039167]  audit_receive+0xe9/0x200
[   49.040535]  netlink_unicast+0x40f/0x5d0
[   49.041873]  ? netlink_attachskb+0x680/0x680
[   49.043233]  netlink_sendmsg+0x73e/0xb60
[   49.044587]  ? netlink_unicast+0x5d0/0x5d0
[   49.045918]  ? netlink_unicast+0x5d0/0x5d0
[   49.047213]  sock_sendmsg+0xde/0x110
[   49.048451]  __sys_sendto+0x1de/0x2c0
[   49.049667]  ? __ia32_sys_getpeername+0xb0/0xb0
[   49.050873]  ? lock_downgrade+0x6f0/0x6f0
[   49.052044]  ? lock_acquire+0x14f/0x3b0
[   49.053172]  ? syscall_trace_enter+0x5b2/0xe00
[   49.054281]  ? syscall_trace_enter+0x5b2/0xe00
[   49.055296]  ? kfree+0x246/0x2d0
[   49.056304]  ? syscall_slow_exit_work+0x480/0x480
[   49.057349]  __x64_sys_sendto+0xdd/0x1b0
[   49.058371]  do_syscall_64+0xa5/0x4d0
[   49.059383]  entry_SYSCALL_64_after_hwframe+0x6a/0xdf
[   49.060405] RIP: 0033:0x7f346440cd78
[   49.061414] Code: 89 02 48 c7 c0 ff ff ff ff eb b5 0f 1f 80 00 00 00 00 f3 0f 1e fa 8b 05 d6 d6 20 00 41 89 ca 85 c0 75 17 b8 2c 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 78 c3 0f 1f 80 00 00 00 00 41 57 4d 89 c7 41
[   49.064793] RSP: 002b:00007ffe9f1dbfe8 EFLAGS: 00000246 ORIG_RAX: 000000000000002c
[   49.066026] RAX: ffffffffffffffda RBX: 0000000000000444 RCX: 00007f346440cd78
[   49.067282] RDX: 0000000000000444 RSI: 00007ffe9f1dc020 RDI: 0000000000000003
[   49.068547] RBP: 0000000000000003 R08: 00007ffe9f1dc00c R09: 000000000000000c
[   49.069802] R10: 0000000000000000 R11: 0000000000000246 R12: 00007ffe9f1dc020
[   49.071044] R13: 00007ffe9f1dc00c R14: 000000000000003e R15: 0000000000000432

[   49.073545] Allocated by task 823:
[   49.074775]  kasan_kmalloc+0xbf/0xe0
[   49.076000]  __kmalloc+0x157/0x320
[   49.077236]  audit_make_tree+0x126/0x440
[   49.078471]  audit_data_to_entry+0xb32/0x2400
[   49.079716]  audit_rule_change+0xbd/0xd20
[   49.080947]  audit_receive_msg+0x2b0/0x1eb0
[   49.082177]  audit_receive+0xe9/0x200
[   49.083407]  netlink_unicast+0x40f/0x5d0
[   49.084625]  netlink_sendmsg+0x73e/0xb60
[   49.085831]  sock_sendmsg+0xde/0x110
[   49.087038]  __sys_sendto+0x1de/0x2c0
[   49.088234]  __x64_sys_sendto+0xdd/0x1b0
[   49.089458]  do_syscall_64+0xa5/0x4d0
[   49.090673]  entry_SYSCALL_64_after_hwframe+0x6a/0xdf
[   49.091916]  0xffffffffffffffff

[   49.094344] Freed by task 0:
[   49.095549]  __kasan_slab_free+0x125/0x170
[   49.096777]  slab_free_freelist_hook+0x5e/0x140
[   49.098026]  kfree+0xd6/0x2d0
[   49.099260]  rcu_core+0xba7/0x1110
[   49.100496]  __do_softirq+0x23d/0xacd

[   49.102921] The buggy address belongs to the object at ffff888035074100
                which belongs to the cache kmalloc-128 of size 128
[   49.105467] The buggy address is located 48 bytes inside of
                128-byte region [ffff888035074100, ffff888035074180)
[   49.107914] The buggy address belongs to the page:
[   49.109084] page:ffffea0000d41d00 refcount:1 mapcount:0 mapping:ffff88810700ea00 index:0x0
[   49.110301] flags: 0xfffffc0000100(slab)
[   49.111470] raw: 000fffffc0000100 ffffea0002b50cc0 0000000200000002 ffff88810700ea00
[   49.112706] raw: 0000000000000000 0000000000100010 00000001ffffffff 0000000000000000
[   49.113960] page dumped because: kasan: bad access detected

[   49.116419] Memory state around the buggy address:
[   49.117646]  ffff888035074000: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[   49.118935]  ffff888035074080: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
[   49.120238] >ffff888035074100: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[   49.121543]                                      ^
[   49.122857]  ffff888035074180: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
[   49.124230]  ffff888035074200: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
Comment 3 Seiji Nishikawa 2021-07-01 13:27:03 UTC 
How reproducible:

 Always. 100% reproducible in our Lab.

Steps to reproduce:

 1. Install kernel-debug-4.18.0-240.10.1.el8_3 with kasan_multi_shot being 
    enabled.

 2. Add "kernel.panic_on_warn=1" in /etc/sysctl.conf but the change is not 
    yet applied at runtime (It will be enabled on the next boot).

 3. Reboot

 4. Then the kernel crashes on boot.

 The kernel ring buffer messages that can be seen in the serial console at
 this point in time:

~~~
	...
[   46.938455] XFS (sda1): Mounting V5 Filesystem
[   47.052552] XFS (sda1): Ending clean mount
[  OK  ] Mounted /boot.
[  OK  ] Reached target Local File Systems.
         Starting Restore /run/initramfs on shutdown...
         Starting Tell Plymouth To Write Out Runtime Data...
         Starting Import network configuration from initramfs...
[  OK  ] Started Restore /run/initramfs on shutdown.
[  OK  ] Started Tell Plymouth To Write Out Runtime Data.
[  OK  ] Started Import network configuration from initramfs.
         Starting Create Volatile Files and Directories...
[  OK  ] Started Create Volatile Files and Directories.
         Starting Security Auditing Service...
         Mounting RPC Pipe File System...
         Starting RPC Bind...
[   48.362945] RPC: Registered named UNIX socket transport module.
[   48.364185] RPC: Registered udp transport module.
[   48.365151] RPC: Registered tcp transport module.
[   48.366075] RPC: Registered tcp NFSv4.1 backchannel transport module.
[  OK  ] Mounted RPC Pipe File System.
[  OK  ] Reached target rpc_pipefs.target.
[  OK  ] Started RPC Bind.
[   48.567767] mktemp (813) used greatest stack depth: 21872 bytes left
[   49.021229] ==================================================================
[   49.022662] BUG: KASAN: use-after-free in audit_add_tree_rule+0x7cf/0x9b0
[   49.023933] Read of size 8 at addr ffff8880bf878b30 by task auditctl/822
[   49.025178] 
[   49.025485] CPU: 0 PID: 822 Comm: auditctl Tainted: G                 ---------r-  - 4.18.0-240.10.1.el8_3.x86_64+debug #1
[   49.027519] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 04/05/2016
[   49.029490] Call Trace:
[   49.029976]  dump_stack+0x9a/0xf0
[   49.030624]  print_address_description.cold.3+0x9/0x23b
[   49.031617]  kasan_report.cold.4+0x65/0x95
[   49.032408]  ? audit_add_tree_rule+0x7cf/0x9b0
[   49.033261]  audit_add_tree_rule+0x7cf/0x9b0
[   49.034082]  ? audit_put_tree+0x30/0x30
[   49.034835]  audit_rule_change+0x412/0xd20
[   49.035625]  ? audit_del_rule+0x530/0x530
[   49.036398]  ? security_capable+0x58/0x90
[   49.037175]  audit_receive_msg+0x2b0/0x1eb0
[   49.037975]  ? lock_contended+0xd90/0xd90
[   49.038748]  ? audit_log_feature_change.part.8+0x1d0/0x1d0
[   49.039790]  ? __mutex_lock+0xe26/0x13d0
[   49.040542]  ? sched_clock+0x5/0x10
[   49.041232]  ? audit_receive+0x78/0x200
[   49.041972]  ? mutex_lock_io_nested+0x12a0/0x12a0
[   49.042867]  ? sched_clock+0x5/0x10
[   49.043534]  ? sched_clock_cpu+0x18/0x1e0
[   49.044296]  ? find_held_lock+0x3a/0x1c0
[   49.045055]  ? netlink_deliver_tap+0x107/0xad0
[   49.045903]  ? lock_downgrade+0x6f0/0x6f0
[   49.046678]  ? rcu_is_watching+0x2c/0x80
[   49.047437]  audit_receive+0xe9/0x200
[   49.048144]  netlink_unicast+0x40f/0x5d0
[   49.048902]  ? netlink_attachskb+0x680/0x680
[   49.049731]  netlink_sendmsg+0x73e/0xb60
[   49.050488]  ? netlink_unicast+0x5d0/0x5d0
[   49.051285]  ? netlink_unicast+0x5d0/0x5d0
[   49.052069]  sock_sendmsg+0xde/0x110
[   49.052762]  __sys_sendto+0x1de/0x2c0
[   49.053466]  ? __ia32_sys_getpeername+0xb0/0xb0
[   49.054334]  ? lock_downgrade+0x6f0/0x6f0
[   49.055107]  ? lock_acquire+0x14f/0x3b0
[   49.055844]  ? syscall_trace_enter+0x5b2/0xe00
[   49.056709]  ? syscall_trace_enter+0x5b2/0xe00
[   49.057557]  ? kfree+0x246/0x2d0
[   49.058184]  ? syscall_slow_exit_work+0x480/0x480
[   49.059093]  __x64_sys_sendto+0xdd/0x1b0
[   49.059849]  do_syscall_64+0xa5/0x4d0
[   49.060556]  entry_SYSCALL_64_after_hwframe+0x6a/0xdf
[   49.061513] RIP: 0033:0x7fef79940d78
[   49.062199] Code: 89 02 48 c7 c0 ff ff ff ff eb b5 0f 1f 80 00 00 00 00 f3 0f 1e fa 8b 05 d6 d6 20 00 41 89 ca 85 c0 75 17 b8 2c 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 78 c3 0f 1f 80 00 00 00 00 41 57 4d 89 c7 41
[   49.065643] RSP: 002b:00007ffd73b25fe8 EFLAGS: 00000246 ORIG_RAX: 000000000000002c
[   49.067060] RAX: ffffffffffffffda RBX: 0000000000000444 RCX: 00007fef79940d78
[   49.068391] RDX: 0000000000000444 RSI: 00007ffd73b26020 RDI: 0000000000000003
[   49.069719] RBP: 0000000000000003 R08: 00007ffd73b2600c R09: 000000000000000c
[   49.071048] R10: 0000000000000000 R11: 0000000000000246 R12: 00007ffd73b26020
[   49.072378] R13: 00007ffd73b2600c R14: 000000000000003e R15: 0000000000000432
[   49.073727] 
[   49.074032] Allocated by task 822:
[   49.074685]  kasan_kmalloc+0xbf/0xe0
[   49.075367]  __kmalloc+0x157/0x320
[   49.076017]  audit_make_tree+0x126/0x440
[   49.076763]  audit_data_to_entry+0xb32/0x2400
[   49.077585]  audit_rule_change+0xbd/0xd20
[   49.078344]  audit_receive_msg+0x2b0/0x1eb0
[   49.079134]  audit_receive+0xe9/0x200
[   49.079831]  netlink_unicast+0x40f/0x5d0
[   49.080574]  netlink_sendmsg+0x73e/0xb60
[   49.081319]  sock_sendmsg+0xde/0x110
[   49.082001]  __sys_sendto+0x1de/0x2c0
[   49.082701]  __x64_sys_sendto+0xdd/0x1b0
[   49.083444]  do_syscall_64+0xa5/0x4d0
[   49.084143]  entry_SYSCALL_64_after_hwframe+0x6a/0xdf
[   49.085091]  0xffffffffffffffff
[   49.085694] 
[   49.085998] Freed by task 0:
[   49.086555]  __kasan_slab_free+0x125/0x170
[   49.087334]  slab_free_freelist_hook+0x5e/0x140
[   49.088193]  kfree+0xd6/0x2d0
[   49.088767]  rcu_core+0xba7/0x1110
[   49.089420]  __do_softirq+0x23d/0xacd
[   49.090117] 
[   49.090422] The buggy address belongs to the object at ffff8880bf878b00
[   49.090422]  which belongs to the cache kmalloc-128 of size 128
[   49.092726] The buggy address is located 48 bytes inside of
[   49.092726]  128-byte region [ffff8880bf878b00, ffff8880bf878b80)
[   49.094860] The buggy address belongs to the page:
[   49.095760] page:ffffea0002fe1e00 refcount:1 mapcount:0 mapping:ffff888107c0ea00 index:0x0
[   49.097289] flags: 0xfffffc0000100(slab)
[   49.098035] raw: 000fffffc0000100 dead000000000100 dead000000000200 ffff888107c0ea00
[   49.099479] raw: 0000000000000000 0000000000100010 00000001ffffffff 0000000000000000
[   49.100924] page dumped because: kasan: bad access detected
[   49.101969] 
[   49.102273] Memory state around the buggy address:
[   49.103179]  ffff8880bf878a00: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[   49.104530]  ffff8880bf878a80: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
[   49.105878] >ffff8880bf878b00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[   49.107226]                                      ^
[   49.108131]  ffff8880bf878b80: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
[   49.109480]  ffff8880bf878c00: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[   49.110825] ==================================================================
[   49.112170] Disabling lock debugging due to kernel taint
[   49.113224] Kernel panic - not syncing: panic_on_warn set ...
[   49.113224] 
[   49.114583] CPU: 0 PID: 822 Comm: auditctl Tainted: G    B            ---------r-  - 4.18.0-240.10.1.el8_3.x86_64+debug #1
[   49.116629] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 04/05/2016
[   49.118602] Call Trace:
[   49.119083]  dump_stack+0x9a/0xf0
[   49.119722]  panic+0x1bc/0x3e3
[   49.120311]  ? __warn_printk+0xdb/0xdb
[   49.121031]  ? do_raw_spin_unlock+0x54/0x230
[   49.121846]  kasan_end_report+0x48/0x4e
[   49.122577]  kasan_report.cold.4+0x85/0x95
[   49.123356]  ? audit_add_tree_rule+0x7cf/0x9b0
[   49.124195]  audit_add_tree_rule+0x7cf/0x9b0
[   49.125003]  ? audit_put_tree+0x30/0x30
[   49.125740]  audit_rule_change+0x412/0xd20
[   49.126520]  ? audit_del_rule+0x530/0x530
[   49.127284]  ? security_capable+0x58/0x90
[   49.128051]  audit_receive_msg+0x2b0/0x1eb0
[   49.128845]  ? lock_contended+0xd90/0xd90
[   49.129610]  ? audit_log_feature_change.part.8+0x1d0/0x1d0
[   49.130644]  ? __mutex_lock+0xe26/0x13d0
[   49.131391]  ? sched_clock+0x5/0x10
[   49.132059]  ? audit_receive+0x78/0x200
[   49.132794]  ? mutex_lock_io_nested+0x12a0/0x12a0
[   49.133682]  ? sched_clock+0x5/0x10
[   49.134347]  ? sched_clock_cpu+0x18/0x1e0
[   49.135110]  ? find_held_lock+0x3a/0x1c0
[   49.135860]  ? netlink_deliver_tap+0x107/0xad0
[   49.136703]  ? lock_downgrade+0x6f0/0x6f0
[   49.137463]  ? rcu_is_watching+0x2c/0x80
[   49.138213]  audit_receive+0xe9/0x200
[   49.138912]  netlink_unicast+0x40f/0x5d0
[   49.139659]  ? netlink_attachskb+0x680/0x680
[   49.140471]  netlink_sendmsg+0x73e/0xb60
[   49.141216]  ? netlink_unicast+0x5d0/0x5d0
[   49.141996]  ? netlink_unicast+0x5d0/0x5d0
[   49.142776]  sock_sendmsg+0xde/0x110
[   49.143457]  __sys_sendto+0x1de/0x2c0
[   49.144155]  ? __ia32_sys_getpeername+0xb0/0xb0
[   49.145014]  ? lock_downgrade+0x6f0/0x6f0
[   49.145777]  ? lock_acquire+0x14f/0x3b0
[   49.146506]  ? syscall_trace_enter+0x5b2/0xe00
[   49.147355]  ? syscall_trace_enter+0x5b2/0xe00
[   49.148198]  ? kfree+0x246/0x2d0
[   49.148818]  ? syscall_slow_exit_work+0x480/0x480
[   49.149713]  __x64_sys_sendto+0xdd/0x1b0
[   49.150460]  do_syscall_64+0xa5/0x4d0
[   49.151160]  entry_SYSCALL_64_after_hwframe+0x6a/0xdf
[   49.152109] RIP: 0033:0x7fef79940d78
[   49.152792] Code: 89 02 48 c7 c0 ff ff ff ff eb b5 0f 1f 80 00 00 00 00 f3 0f 1e fa 8b 05 d6 d6 20 00 41 89 ca 85 c0 75 17 b8 2c 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 78 c3 0f 1f 80 00 00 00 00 41 57 4d 89 c7 41
[   49.156212] RSP: 002b:00007ffd73b25fe8 EFLAGS: 00000246 ORIG_RAX: 000000000000002c
[   49.157612] RAX: ffffffffffffffda RBX: 0000000000000444 RCX: 00007fef79940d78
[   49.158932] RDX: 0000000000000444 RSI: 00007ffd73b26020 RDI: 0000000000000003
[   49.160252] RBP: 0000000000000003 R08: 00007ffd73b2600c R09: 000000000000000c
[   49.161568] R10: 0000000000000000 R11: 0000000000000246 R12: 00007ffd73b26020
[   49.162890] R13: 00007ffd73b2600c R14: 000000000000003e R15: 0000000000000432
[   49.164293] Kernel Offset: 0x18c00000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)
[   49.166264] ---[ end Kernel panic - not syncing: panic_on_warn set ...
[   49.166264]  ]---
~~~

5. Now that the kernel has got halted, suspend the VM and get the snapshot
   from the datastore for vmcore analysis.


The vmcore can be visited on Galvatron:

[snishika@galvatron 002]$ uname -a
Linux galvatron.cee.redhat.com 4.18.0-240.22.1.el8_3.x86_64 #1 SMP Thu Mar 25 14:36:04 EDT 2021 x86_64 x86_64 x86_64 GNU/Linux

[snishika@galvatron 002]$ ip a
	...
2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UP group default qlen 1000
    link/ether fa:16:3e:cd:7a:a2 brd ff:ff:ff:ff:ff:ff
    inet 10.0.79.114/23 brd 10.0.79.255 scope global dynamic noprefixroute eth0
       valid_lft 37019sec preferred_lft 37019sec
    inet6 2620:52:0:4e:f816:3eff:fecd:7aa2/64 scope global dynamic mngtmpaddr 
       valid_lft 2591664sec preferred_lft 604464sec
    inet6 fe80::f816:3eff:fecd:7aa2/64 scope link 
       valid_lft forever preferred_lft forever

[snishika@galvatron 002]$ pwd
/cores/exceptions/02962027/002

[snishika@galvatron 002]$ crash vmlinux rhel8_2-0829d2ea.vmss
	...
crash> sys
      KERNEL: vmlinux
    DUMPFILE: rhel8_2-0829d2ea.vmss
        CPUS: 2 [OFFLINE: 1]
        DATE: Thu Jul  1 08:30:23 2021
      UPTIME: 00:00:49
LOAD AVERAGE: 2.84, 0.70, 0.23
       TASKS: 135
    NODENAME: localhost.localdomain
     RELEASE: 4.18.0-240.10.1.el8_3.x86_64+debug
     VERSION: #1 SMP Wed Dec 16 03:04:46 EST 2020
     MACHINE: x86_64  (2393 Mhz)
      MEMORY: 4 GB
       PANIC: "Kernel panic - not syncing: panic_on_warn set ..."

crash> bt
PID: 822    TASK: ffff8880a5c60000  CPU: 0   COMMAND: "auditctl"
 #0 [ffff8880a8247640] do_raw_spin_unlock at ffffffff99f5faf4
 #1 [ffff8880a8247680] kasan_end_report at ffffffff9a4aa915
 #2 [ffff8880a8247690] kasan_report.cold.4 at ffffffff9a4aa9a0
 #3 [ffff8880a82476f8] audit_add_tree_rule at ffffffff9a0e306f
 #4 [ffff8880a82477b0] audit_rule_change at ffffffff9a0c4972
 #5 [ffff8880a8247868] audit_receive_msg at ffffffff9a0bcab0
 #6 [ffff8880a8247a98] audit_receive at ffffffff9a0be799
 #7 [ffff8880a8247ac8] netlink_unicast at ffffffff9b607bcf
 #8 [ffff8880a8247b88] netlink_sendmsg at ffffffff9b6084ce
 #9 [ffff8880a8247c78] sock_sendmsg at ffffffff9b3df79e
#10 [ffff8880a8247ca0] __sys_sendto at ffffffff9b3e3aee
#11 [ffff8880a8247ef0] __x64_sys_sendto at ffffffff9b3e3cad
#12 [ffff8880a8247f28] do_syscall_64 at ffffffff99c09875
#13 [ffff8880a8247f50] entry_SYSCALL_64_after_hwframe at ffffffff9bc000b2
    RIP: 00007fef79940d78  RSP: 00007ffd73b25fe8  RFLAGS: 00000246
    RAX: ffffffffffffffda  RBX: 0000000000000444  RCX: 00007fef79940d78
    RDX: 0000000000000444  RSI: 00007ffd73b26020  RDI: 0000000000000003
    RBP: 0000000000000003   R8: 00007ffd73b2600c   R9: 000000000000000c
    R10: 0000000000000000  R11: 0000000000000246  R12: 00007ffd73b26020
    R13: 00007ffd73b2600c  R14: 000000000000003e  R15: 0000000000000432
    ORIG_RAX: 000000000000002c  CS: 0033  SS: 002b



The buggy address ffff8880bf878b30 is within the range of the below object
in kmalloc-128 slab:

crash> kmem ffff8880bf878b30
CACHE             OBJSIZE  ALLOCATED     TOTAL  SLABS  SSIZE  NAME
ffff888107c0ea00      128      67524     67728   4233     4k  kmalloc-128
  SLAB              MEMORY            NODE  TOTAL  ALLOCATED  FREE
  ffffea0002fe1e00  ffff8880bf878000     0     16         16     0
  FREE / [ALLOCATED]
  [ffff8880bf878b00]

      PAGE       PHYSICAL      MAPPING       INDEX CNT FLAGS
ffffea0002fe1e00 bf878000 ffff888107c0ea00        0  1 fffffc0000100 slab

crash> rd ffff8880bf878b00 16 -SS
ffff8880bf878b00:  [ffff88810c402700:kmalloc-128] [ffff888106b9d100:kmalloc-128] 
ffff8880bf878b10:  [ffff888106b9d150:kmalloc-128] [ffff888106b9d150:kmalloc-128] 
ffff8880bf878b20:  [ffff8880adfa7570:kmalloc-512] [ffff8880adfa5570:kmalloc-512] 
ffff8880bf878b30:  [ffff88810c402730:kmalloc-128] tree_list        
                    ^^^^^^^^^^^^^^^^
ffff8880bf878b40:  [ffff888106b9d120:kmalloc-128] [ffff888106b9d120:kmalloc-128] 
ffff8880bf878b50:  ffff8880a8247638 0000000000000050 
ffff8880bf878b60:  6475732f6374652f 0000642e7372656f 
ffff8880bf878b70:  0000000000000000 0000000100000008 

crash> kmem ffff88810c402730
CACHE             OBJSIZE  ALLOCATED     TOTAL  SLABS  SSIZE  NAME
ffff888107c0ea00      128      67524     67728   4233     4k  kmalloc-128
  SLAB              MEMORY            NODE  TOTAL  ALLOCATED  FREE
  ffffea0004310080  ffff88810c402000     0     16         16     0
  FREE / [ALLOCATED]
  [ffff88810c402700]

      PAGE       PHYSICAL      MAPPING       INDEX CNT FLAGS
ffffea0004310080 10c402000 ffff888107c0ea00        0  1 17ffffc0000100 slab

crash> kmem ffffea0004310080
CACHE             OBJSIZE  ALLOCATED     TOTAL  SLABS  SSIZE  NAME
ffff888107c0ea00      128      67524     67728   4233     4k  kmalloc-128
  SLAB              MEMORY            NODE  TOTAL  ALLOCATED  FREE
  ffffea0004310080  ffff88810c402000     0     16         16     0
  FREE / [ALLOCATED]
  [ffff88810c402000]
  [ffff88810c402100]
  [ffff88810c402200]
  [ffff88810c402300]
  [ffff88810c402400]
  [ffff88810c402500]
  [ffff88810c402600]
  [ffff88810c402700]
  [ffff88810c402800]
  [ffff88810c402900]
  [ffff88810c402a00]
  [ffff88810c402b00]
  [ffff88810c402c00]
  [ffff88810c402d00]
  [ffff88810c402e00]
  [ffff88810c402f00]

      PAGE       PHYSICAL      MAPPING       INDEX CNT FLAGS
ffffea0004310080 10c402000 ffff888107c0ea00        0  1 17ffffc0000100 slab
Comment 4 Seiji Nishikawa 2021-07-01 14:44:52 UTC 
According to the KASAN use-after-free report, the entry->rule->tree is
kmalloc()ed in alloc_tree() at line number 97, and kfree()ed in the 
softirq context invoked somewhere between [1] and [2], and then use-
after-free upon the list_for_each_entry() operation with the tree at [2].

audit_receive_msg()
	|
	+----> audit_rule_change()
			|
			+----> audit_data_to_entry()
			|			|
			|			+----> audit_make_tree()
			|						|
			|						+----> alloc_tree()
			|						....
			|						  93 static struct audit_tree *alloc_tree(const char *s)
			|						  94 {
			|						  95         struct audit_tree *tree;
			|						  96 
			|						  97         tree = kmalloc(sizeof(struct audit_tree) + strlen(s) + 1, GFP_KERNEL); <<------------[1]
			|						  98         if (tree) {
			|						  99                 refcount_set(&tree->count, 1);
			|						 100                 tree->goner = 0;
			|						 101                 INIT_LIST_HEAD(&tree->chunks);
			|						 102                 INIT_LIST_HEAD(&tree->rules);
			|						 103                 INIT_LIST_HEAD(&tree->list);
			|						 104                 INIT_LIST_HEAD(&tree->same_root);
			|						 105                 tree->root = NULL;
			|						 106                 strcpy(tree->pathname, s);
			|						 107         }
			|						 108         return tree;
			|						 109 }
			|						....
			+-----> audit_add_rule()
						|
						+----> audit_add_tree_rule()
						....
						 801 /* called with audit_filter_mutex */
						 802 int audit_add_tree_rule(struct audit_krule *rule)
						 803 {
						 804         struct audit_tree *seed = rule->tree, *tree;
						 805         struct path path;
						 806         struct vfsmount *mnt;
						 807         int err;
						 808 
						 809         rule->tree = NULL;
						 810         list_for_each_entry(tree, &tree_list, list) { <<------------[2]
						 811                 if (!strcmp(seed->pathname, tree->pathname)) {
						 812                         put_tree(seed);
						 813                         rule->tree = tree;
						 814                         list_add(&rule->rlist, &tree->rules);
						 815                         return 0;
						 816                 }
						 817         }
						....
Comment 5 Seiji Nishikawa 2021-07-07 10:14:44 UTC 
I found that the issue resolved and never came back after commenting out these
2 lines in audit.rules:

~~~
#find /usr/bin -type f -perm -04000 2>/dev/null | awk '{ printf "-a always,exit -F path=%s -F perm=x -F auid>=1000 -F auid!=unset -F key=privileged\n", $1 }' >> priv.rules
#find /usr/sbin -type f -perm -04000 2>/dev/null | awk '{ printf "-a always,exit -F path=%s -F perm=x -F auid>=1000 -F auid!=unset -F key=privileged\n", $1 }' >> priv.rules
~~~
Comment 6 Linqing Lu 2021-07-13 02:05:15 UTC 
Hi Seiji,

Could you check if it's reproducible on ystream (RHEL8.5) kernel in your lab?

I tried kernel-debug-4.18.0-320.el8 with params described in c#3 on a KVM VM but didn't hit the issue:
    [root@ci-vm-10-0-138-226 ~]# cat /proc/cmdline
    BOOT_IMAGE=(hd0,msdos1)/boot/vmlinuz-4.18.0-320.el8.x86_64+debug root=UUID=d2758fbe-27bf-4317-bdd1-7bd1eaeb9c9a ro console=tty0 console=ttyS0,115200 crashkernel=auto net.ifnames=0 rhgb quiet kasan_multi_shot
    [root@ci-vm-10-0-138-226 ~]# sysctl -n kernel.panic_on_warn
    1

Thanks!
Comment 7 Seiji Nishikawa 2021-07-13 03:20:50 UTC 
(In reply to Linqing Lu from comment #6)
> Hi Seiji,
> 
> Could you check if it's reproducible on ystream (RHEL8.5) kernel in your lab?
> 
> I tried kernel-debug-4.18.0-320.el8 with params described in c#3 on a KVM VM
> but didn't hit the issue:
>     [root@ci-vm-10-0-138-226 ~]# cat /proc/cmdline
>     BOOT_IMAGE=(hd0,msdos1)/boot/vmlinuz-4.18.0-320.el8.x86_64+debug
> root=UUID=d2758fbe-27bf-4317-bdd1-7bd1eaeb9c9a ro console=tty0
> console=ttyS0,115200 crashkernel=auto net.ifnames=0 rhgb quiet
> kasan_multi_shot
>     [root@ci-vm-10-0-138-226 ~]# sysctl -n kernel.panic_on_warn
>     1
> 
> Thanks!

Hi Linqing,

Thanks for letting me know that.

I don't have rhel8.5 rpm. I cannot rh-brew-build rhel8.5 rpm either because
4.18.0-320.el8 is not available in the cloned rhel8 git in my Lab.

Can you please provide rhel8.5 rpms?
- source rpm
- kernel-debug
- kernel-debug-modules
- kernel-debug-core
- kernel-debug-debuginfo
- kernel-debug-debuginfo-common

Thanks,
Seiji
Comment 13 Seiji Nishikawa 2021-07-26 08:32:36 UTC 
Looks like the things are getting worse as the kernel version becomes newer.

Opened bz#1985909 and bz#1985904.
Comment 14 Linqing Lu 2021-07-26 17:55:00 UTC 
(In reply to Seiji Nishikawa from comment #12)
> (In reply to Linqing Lu from comment #11)
> > (In reply to Seiji Nishikawa from comment #9)
> > 
> > Hi Seiji,
> > 
> > Thanks for confirming!
> > I still got no luck on my side with KVM VM. Either I missed something or
> > it's somehow related to Microsoft/VMware VMs.
> > 
> > Either I'll provide qa_ack here since you are able to reproduce that
> > reliably. And I'll let you know once there is a fixed build to verify
> > against.
> 
> Linquing,
> 
> Thanks for the help.
> 
> Don’t you at least see the KASAN use-after-free messages logged in dmesg 
> on boot even though the kernel-debug doesn’t crash with panic_on_warn being
> disabled?

Hi Seiji,

I tried a few rounds but they didn't have any KASAN-related warning/message (except KASAN initialization):

# dmesg | grep -i KASAN
[    0.000000] Command line: BOOT_IMAGE=(hd0,msdos1)/boot/vmlinuz-4.18.0-321.el8.x86_64+debug root=UUID=b56cf5df-0638-47d0-86c5-9cc4ff00c558 ro console=tty0 console=ttyS0,115200 crashkernel=auto net.ifnames=0 rhgb quiet kasan_multi_shot
[    0.000000] kasan: KernelAddressSanitizer initialized
[    0.000000] Kernel command line: BOOT_IMAGE=(hd0,msdos1)/boot/vmlinuz-4.18.0-321.el8.x86_64+debug root=UUID=b56cf5df-0638-47d0-86c5-9cc4ff00c558 ro console=tty0 console=ttyS0,115200 crashkernel=auto net.ifnames=0 rhgb quiet kasan_multi_shot

> 
> By the way, the customer let us know that they haven’t experienced this sort
> Of crash On rhel7 with the same audit rules.
> 
> Thanks,
> Seiji
Comment 16 Richard Guy Briggs 2021-07-26 21:56:38 UTC 
(In reply to Seiji Nishikawa from comment #5)
> I found that the issue resolved and never came back after commenting out these 2 lines in audit.rules:
> ~~~
> #find /usr/bin -type f -perm -04000 2>/dev/null | awk '{ printf "-a always,exit -F path=%s -F perm=x -F auid>=1000 -F auid!=unset -F key=privileged\n", $1 }' >> priv.rules
> #find /usr/sbin -type f -perm -04000 2>/dev/null | awk '{ printf "-a always,exit -F path=%s -F perm=x -F auid>=1000 -F auid!=unset -F key=privileged\n", $1 }' >> priv.rules
> ~~~

So this generates a list of rules?  I've never seen this construct in a .rules file.  Is that legal?  Will auditctl even let it get to the kernel?  What happens if those shell commands are expanded and the results inserted into the .rules file?  What do those generated rules have to do with system-locale?  My first reaction is "Don't do that, then.", but either that is a legal construct and auditctl pre-processes it, or it isn't and auditctl should reject it as a misformed rule.  What happens if those rules are expanded and added to the .rules file?  This looks like one bug with many symptoms so bz1985904 and bzJ1985909 should be marked as duplicates or clones of this.
Comment 17 Steve Grubb 2021-07-26 22:06:34 UTC 
That rule is not legal. In 31-privileged.rules it says to run that command to generate a rules file. That said, it looks like there are 2 or more issues. The kernel should be able to handle garbage input. And auditctl should detect garbage input and emit a warning. Both should be fixed separately.
Comment 18 Richard Guy Briggs 2021-07-29 19:57:50 UTC 
(In reply to Richard Guy Briggs from comment #16)
> (In reply to Seiji Nishikawa from comment #5)
> > I found that the issue resolved and never came back after commenting out these 2 lines in audit.rules:
> > ~~~
> > #find /usr/bin -type f -perm -04000 2>/dev/null | awk '{ printf "-a always,exit -F path=%s -F perm=x -F auid>=1000 -F auid!=unset -F key=privileged\n", $1 }' >> priv.rules
> > #find /usr/sbin -type f -perm -04000 2>/dev/null | awk '{ printf "-a always,exit -F path=%s -F perm=x -F auid>=1000 -F auid!=unset -F key=privileged\n", $1 }' >> priv.rules
> > ~~~
> 
> So this generates a list of rules?  I've never seen this construct in a .rules file.  Is that legal?  Will auditctl even let it get to the kernel?  What happens if those shell commands are expanded and the results inserted into the .rules file?  What do those generated rules have to do with system-locale?  My first reaction is "Don't do that, then.", but either that is a legal construct and auditctl pre-processes it, or it isn't and auditctl should reject it as a misformed rule.  What happens if those rules are expanded and added to the .rules file?  This looks like one bug with many symptoms so bz1985904 and bzJ1985909 should be marked as duplicates or clones of this.

It turns out auditctl ignores everything else on those two lines and parses this as "-t" and sends the AUDIT_TRIM command to the kernel twice, and the AUDIT_TRIM command appears to be broken in the kernel.
Comment 19 Richard Guy Briggs 2021-08-24 16:18:20 UTC 
2021-08-23 fix posted upstream
https://lkml.org/lkml/2021/8/23/1115
https://listman.redhat.com/archives/linux-audit/2021-August/msg00061.html
Comment 21 Seiji Nishikawa 2021-10-11 11:04:45 UTC 
Hi Richard,

I just wanted to update you to let you know that the customer on 
sfdc case 02962027 confirmed that the test kernel containing your
patch worked to avoid the issue completely on their server.

> 1. Re-enabled the audit rules which caused the issue and rebooted the machine. Result: Kernel panic.
> 2. Did a hard reboot of the machine..
> 3. Installed the kernel packages and changed the default kernel. Successfully rebooted the machine post installation.
> 
> # uname -r
> 4.18.0-240.10.1.el8_3.case_02962027.x86_64

Thanks,
Seiji
Comment 25 Linqing Lu 2021-10-15 23:44:06 UTC 
(In reply to Seiji Nishikawa from comment #21)
> Hi Richard,
> 
> I just wanted to update you to let you know that the customer on 
> sfdc case 02962027 confirmed that the test kernel containing your
> patch worked to avoid the issue completely on their server.
> 
> > 1. Re-enabled the audit rules which caused the issue and rebooted the machine. Result: Kernel panic.
> > 2. Did a hard reboot of the machine..
> > 3. Installed the kernel packages and changed the default kernel. Successfully rebooted the machine post installation.
> > 
> > # uname -r
> > 4.18.0-240.10.1.el8_3.case_02962027.x86_64
> 
> Thanks,
> Seiji

Considering pre-verification passed per customer test result. Will propose double check once it's merged in official kernel.
Comment 27 Bruno Meneguele 2021-11-18 15:21:32 UTC 
List of commits available on kernel-4.18.0-349.el8 (1/1):
Related commit: b33e67360e9e ("Merge: audit: move put_tree() to avoid trim_trees refcount underflow and UAF")
Related commit: f666bde85657 ("audit: move put_tree() to avoid trim_trees refcount underflow and UAF")
Comment 28 errata-xmlrpc 2021-11-18 15:51:02 UTC 
This bug has been added to advisory RHSA-2021:82037 by Bruno de Oliveira Meneguele (brdeoliv)
Comment 30 errata-xmlrpc 2021-11-18 15:51:35 UTC 
This bug has been added to advisory RHSA-2021:82037 by Bruno de Oliveira Meneguele (brdeoliv)
Comment 35 errata-xmlrpc 2022-05-10 14:59:11 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (Important: kernel security, bug fix, and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHSA-2022:1988
Note You need to log in before you can comment on or make changes to this bug.