kernel oops in aafs_create in 6.8.1-1002-realtime kernel

[Colin Ian King]

Ubuntu Noble, Real Time kernel:

cking@noble-amd64-efi:~$ uname -a
Linux noble-amd64-efi 6.8.1-1002-realtime #2-Ubuntu SMP PREEMPT_RT Tue May 21 21:13:36 UTC 2024 x86_64 x86_64 x86_64 GNU/Linux

How to reproduce issue:

git clone https://github.com/ColinIanKing/stress-ng
cd stress-ng
make clean; make -j 8

sudo ./stress-ng --apparmor 8 --vmstat 1

after a while I observed the kernel oops splat message:
[ 131.881354] AppArmor DFA next/check upper bounds error
[ 131.993510] BUG: kernel NULL pointer dereference, address: 0000000000000040
[ 131.993512] #PF: supervisor read access in kernel mode
[ 131.993513] #PF: error_code(0x0000) - not-present page
[ 131.993514] PGD 0 P4D 0
[ 131.993516] Oops: 0000 [#1] PREEMPT_RT SMP PTI
[ 131.993518] CPU: 1 PID: 2357 Comm: stress-ng-appar Not tainted 6.8.1-1002-realtime #2-Ubuntu
[ 131.993521] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 2024.02-2 03/11/2024
[ 131.993522] RIP: 0010:aafs_create.constprop.0+0x7f/0x130
[ 131.993532] Code: 4c 63 e0 48 83 c4 18 4c 89 e0 5b 41 5c 41 5d 41 5e 41 5f 5d 31 d2 31 c9 31 f6 31 ff 45 31 c0 45 31 c9 45 31 d2 c3 cc cc cc cc <4d> 8b 55 40 4d 8d ba c0 00 00 00 4c 89 55 c0 4c 89 ff e8 6a d3 af
[ 131.993533] RSP: 0018:ffffb589810efbe8 EFLAGS: 00010246
[ 131.993535] RAX: 0000000000000000 RBX: 00000000000041ed RCX: 0000000000000000
[ 131.993536] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
[ 131.993537] RBP: ffffb589810efc28 R08: 0000000000000000 R09: 0000000000000000
[ 131.993538] R10: ffff8bf44a786040 R11: 0000000000000000 R12: ffffffffa9babb88
[ 131.993539] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[ 131.993540] FS: 00007ed4e777cf40(0000) GS:ffff8bf4bba80000(0000) knlGS:0000000000000000
[ 131.993541] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 131.993542] CR2: 0000000000000040 CR3: 00000001093ba004 CR4: 0000000000370ef0
[ 131.993546] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 131.993547] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 131.993548] Call Trace:
[ 131.993549] <TASK>
[ 131.993551] ? show_regs+0x6d/0x80
[ 131.993567] ? __die+0x24/0x80
[ 131.993569] ? page_fault_oops+0x99/0x1c0
[ 131.993572] ? do_user_addr_fault+0x2ed/0x6b0
[ 131.993575] ? exc_page_fault+0x83/0x1b0
[ 131.993577] ? asm_exc_page_fault+0x27/0x30
[ 131.993582] ? aafs_create.constprop.0+0x7f/0x130
[ 131.993584] ? aafs_create.constprop.0+0x51/0x130
[ 131.993587] __aafs_profile_mkdir+0x3d6/0x480
[ 131.993589] aa_replace_profiles+0x83f/0x1270
[ 131.993606] policy_update+0xe3/0x180
[ 131.993608] profile_replace+0xbc/0x150
[ 131.993610] ? preempt_count_sub+0xc8/0x110
[ 131.993612] vfs_write+0xff/0x4a0
[ 131.993629] ? putname+0x5b/0x80
[ 131.993632] ksys_write+0x73/0x100
[ 131.993634] __x64_sys_write+0x19/0x30
[ 131.993636] x64_sys_call+0x7e/0x25c0
[ 131.993638] do_syscall_64+0x81/0x190
[ 131.993641] ? do_syscall_64+0x8e/0x190
[ 131.993643] ? debug_smp_processor_id+0x17/0x30
[ 131.993645] ? fpregs_assert_state_consistent+0x30/0x60
[ 131.993648] ? syscall_exit_to_user_mode+0x86/0x260
[ 131.993650] ? do_syscall_64+0x8e/0x190
[ 131.993652] ? do_syscall_64+0x8e/0x190
[ 131.993654] ? do_syscall_64+0x8e/0x190
[ 131.993656] ? do_syscall_64+0x8e/0x190
[ 131.993658] ? irqentry_exit+0x43/0x50
[ 131.993660] entry_SYSCALL_64_after_hwframe+0x78/0x80
[ 131.993661] RIP: 0033:0x7ed4e8041574
[ 131.993674] Code: c7 00 16 00 00 00 b8 ff ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 f3 0f 1e fa 80 3d d5 ea 0e 00 00 74 13 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 54 c3 0f 1f 00 55 48 89 e5 48 83 ec 20 48 89
[ 131.993676] RSP: 002b:00007fff57a26798 EFLAGS: 00000202 ORIG_RAX: 0000000000000001
[ 131.993677] RAX: ffffffffffffffda RBX: 0000592cb9ed38f0 RCX: 00007ed4e8041574
[ 131.993678] RDX: 000000000001916a RSI: 0000592cb9ed96d0 RDI: 0000000000000007
[ 131.993679] RBP: 00007fff57a267f0 R08: 0000592cb9eb1010 R09: 0000000000000007
[ 131.993680] R10: 0000000000000000 R11: 0000000000000202 R12: 000000000001916a
[ 131.993681] R13: 0000592cb9ed96d0 R14: 0000592cb9ed96d0 R15: 0000000000000003
[ 131.993684] </TASK>
[ 131.993685] Modules linked in: pcbc lrw chacha_generic chacha_x86_64 libchacha xxhash_generic xcbc wp512 vmac sm3_generic sm3_avx_x86_64 sm3 poly1305_generic poly1305_x86_64 nhpoly1305_avx2 nhpoly1305_sse2 nhpoly1305 libpoly1305 michael_mic md4 streebog_generic rmd160 cmac algif_rng twofish_generic twofish_avx_x86_64 twofish_x86_64_3way twofish_x86_64 twofish_common serpent_avx2 serpent_avx_x86_64 serpent_sse2_x86_64 serpent_generic fcrypt cast6_avx_x86_64 cast6_generic cast5_avx_x86_64 cast5_generic cast_common camellia_generic camellia_aesni_avx2 camellia_aesni_avx_x86_64 camellia_x86_64 blowfish_generic blowfish_x86_64 blowfish_common algif_skcipher algif_hash aria_aesni_avx2_x86_64 aria_aesni_avx_x86_64 aria_generic sm4_generic sm4_aesni_avx2_x86_64 sm4_aesni_avx_x86_64 sm4 ccm des3_ede_x86_64 des_generic libdes authenc aegis128 aegis128_aesni algif_aead af_alg qrtr cfg80211 binfmt_misc intel_rapl_msr intel_rapl_common intel_pmc_core intel_vsec pmt_telemetry pmt_class nls_iso8859_1 kvm_intel kvm irqbypass rapl
[ 131.993740] snd_hda_codec_generic snd_hda_intel snd_intel_dspcfg snd_intel_sdw_acpi i2c_i801 snd_hda_codec i2c_smbus snd_hda_core snd_hwdep snd_pcm snd_timer snd soundcore lpc_ich joydev qxl drm_ttm_helper ttm input_leds mac_hid serio_raw dm_multipath msr efi_pstore nfnetlink dmi_sysfs qemu_fw_cfg ip_tables x_tables autofs4 btrfs blake2b_generic raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 hid_generic usbhid hid crct10dif_pclmul crc32_pclmul polyval_clmulni polyval_generic ghash_clmulni_intel sha256_ssse3 ahci sha1_ssse3 libahci psmouse virtio_rng xhci_pci xhci_pci_renesas aesni_intel crypto_simd cryptd
[ 131.993785] CR2: 0000000000000040
[ 131.993787] ---[ end trace 0000000000000000 ]---

[Colin Ian King (colin-king)]

Same issue on ARM64 with 6.8.1-1002-realtime too:

stress-ng: error: [4568] klog-check: alert: [445.413206] 'Unable to handle kernel access to user memory outside uaccess routines at virtual address 0000000000000040'
stress-ng: error: [4568] klog-check: alert: [445.413235] 'Mem abort info:'
stress-ng: error: [4568] klog-check: alert: [445.413239] ' ESR = 0x0000000096000004'
stress-ng: error: [4568] klog-check: alert: [445.413244] ' EC = 0x25: DABT (current EL), IL = 32 bits'
stress-ng: error: [4568] klog-check: alert: [445.413251] ' SET = 0, FnV = 0'
stress-ng: error: [4568] klog-check: alert: [445.413256] ' EA = 0, S1PTW = 0'
stress-ng: error: [4568] klog-check: alert: [445.413260] ' FSC = 0x04: level 0 translation fault'
stress-ng: error: [4568] klog-check: alert: [445.413265] 'Data abort info:'
stress-ng: error: [4568] klog-check: alert: [445.413268] ' ISV = 0, ISS = 0x00000004, ISS2 = 0x00000000'
stress-ng: error: [4568] klog-check: alert: [445.413273] ' CM = 0, WnR = 0, TnD = 0, TagAccess = 0'
stress-ng: error: [4568] klog-check: alert: [445.413279] ' GCS = 0, Overlay = 0, DirtyBit = 0, Xs = 0'
stress-ng: error: [4568] klog-check: alert: [445.413286] 'user pgtable: 4k pages, 48-bit VAs, pgdp=0000000128037000'
stress-ng: error: [4568] klog-check: alert: [445.413295] '[0000000000000040] pgd=0000000000000000, p4d=0000000000000000'
stress-ng: error: [4568] klog-check: emergency: [445.413316] 'Internal error: Oops: 0000000096000004 [#1] PREEMPT_RT SMP'
stress-ng: info: [4568] klog-check: warning: [445.413385] 'Modules linked in: nhpoly1305_neon nhpoly1305 libpoly1305 michael_mic md4 streebog_generic rmd160 crc32_generic cmac algif_rng twofish_generic twofish_common serpent_generic fcrypt cast6_generic cast5_generic cast_common camellia_generic blowfish_generic blowfish_common aes_arm64 algif_skcipher algif_hash aria_generic sm4_generic sm4_neon ccm aes_ce_ccm des_generic libdes authenc aegis128 algif_aead af_alg tls qrtr cfg80211 binfmt_misc nls_iso8859_1 dm_multipath efi_pstore nfnetlink dmi_sysfs qemu_fw_cfg ip_tables x_tables autofs4 btrfs blake2b_generic raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor xor_neon raid6_pq libcrc32c raid1 raid0 crct10dif_ce polyval_ce polyval_generic ghash_ce sm4 sha2_ce sha256_arm64 sha1_ce arm_smccc_trng virtio_rng xhci_pci xhci_pci_renesas aes_neon_bs aes_neon_blk aes_ce_blk aes_ce_cipher'
stress-ng: info: [4568] klog-check: warning: [445.413741] 'CPU: 18 PID: 8888 Comm: stress-ng-appar Not tainted 6.8.1-1002-realtime #2-Ubuntu'
stress-ng: info: [4568] klog-check: warning: [445.413759] 'Hardware name: QEMU KVM Virtual Machine, BIOS 2023.05-2ubuntu0.1 02/12/2024'
stress-ng: info: [4568] klog-check: warning: [445.413767] 'pstate: 60400005 (nZCv daif +PAN -UAO -TCO -DIT -SSBS BTYPE=--)'
stress-ng: info: [4568] klog-check: warning: [445.413778] 'pc : aafs_create.constprop.0+0xc0/0x170'
stress-ng: info: [4568] klog-check: warning: [445.413802] 'lr : aafs_create.constprop.0+0x70/0x170'
stress-ng: info: [4568] klog-check: warning: [445.413811] 'sp : ffff800085513b10'
stress-ng: info: [4568] klog-check: warning: [445.413815] 'x29: ffff800085513b10 x28: ffff14ec8bf7967c...

[Kevin Becker (kevinbecker)]

Thanks for the report, Colin. I'll work on reproducing this. Do you have any other info on the system configurations that may be useful? Have you seen this issue with any other kernels?

[Colin Ian King (colin-king)]

These were running on QEMU KVM installations using virt-manager and were bog-standard server ISO installs using the RT kernel.

[Kevin Becker (kevinbecker)]

Hi Colin, I've been able to reproduce this issue in QEMU VMs on amd64 consistently and I got it to happen once in arm64, however, I haven't been able to reproduce the kernel oops again. I can't get it to happen on bare metal or in an LXD VM (multipass). I've also found that this doesn't just happen on realtime, at least on amd64. I was able to reliably reproduce it in QEMU on amd64 without realtime. I'll add that to this bug ticket and let the relevant people know. We'll continue investigating this.

[Kevin Becker (kevinbecker)]

To be clear, so far I've only been able to get the following hardware configurations to fail reliably:

- QEMU VM amd64, linux-realtime 6.8.1-1002-realtime
- QEMU VM amd64, linux (generic) 6.8.0-35-generic

I once got each of the following to fail, but haven't been able to reproduce it consistently:

- QEMU arm64, linux-realtime 6.8.1-1002-realtime
- QEMU arm64, linux (generic) 6.8.0-35-generic

I haven't been able to get these combinations to fail:

- bare metal amd64, linux-realtime 6.8.1-1002-realtime
- LXD VM (multipass) amd64, linux-realtime 6.8.1-1002-realtime

[Colin Ian King (colin-king)]

I disassembled the offending code, the error is in the following code:

r13 is zero so the mov 0x40 is accessing data from the NULL ptr in r13

ffffffff8172898f: 4d 8b 55 40 mov 0x40(%r13),%r10 <---- here
ffffffff81728993: 4d 8d ba c0 00 00 00 lea 0xc0(%r10),%r15
ffffffff8172899a: 4c 89 55 c0 mov %r10,-0x40(%rbp)
ffffffff8172899e: 4c 89 ff mov %r15,%rdi
ffffffff817289a1: e8 6a d3 af 00 call 0xffffffff82225d10 <--- down_write()

So looking at aafs_create() in security/apparmor/apparmorfs.c I'm presuming the dir from d_inode(parent) is null and this is tripping this issue.

Would be good to get John the apparmor maintainer to look at this.

Normally I'd help debug this further, but I don't know how to get access to the RT kernel source.

[Colin Ian King (colin-king)]

Given it's a case of adding debug into the calling paths of aafs_create() and into aafs_create to see why the ptr is null I don't think finding reproducers is necessary the fast path to solving this. I suspect this is a race condition hence it's not easily reproducible in some configurations.