Greeting,
FYI, we noticed WARNING:at_kernel/module/internal.h:#find_module_all due to commit (built with gcc-11):
commit: 7e0c0a44cae2595beda2f4fb1af9118eb50c7526 ("module: avoid allocation if module is already present and ready")
https://git.kernel.org/cgit/linux/kernel/git/mcgrof/linux.git 20230311-module-alloc-opts
in testcase: kernel-selftests
version: kernel-selftests-x86_64-d4cf28ee-1_20230110
with following parameters:
group: sgx
test-description: The kernel contains a set of "self tests" under the tools/testing/selftests/ directory. These are intended to be small unit tests to exercise individual code paths in the kernel.
test-url: https://www.kernel.org/doc/Documentation/kselftest.txt
on test machine: 16 threads 1 sockets Intel(R) Xeon(R) E-2278G CPU @ 3.40GHz (Coffee Lake) with 32G memory
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+------------------------------------------------------+------------+------------+
| | 62f6f89a67 | 7e0c0a44ca |
+------------------------------------------------------+------------+------------+
| boot_successes | 6 | 0 |
| boot_failures | 0 | 6 |
| WARNING:at_kernel/module/internal.h:#find_module_all | 0 | 6 |
| RIP:find_module_all | 0 | 6 |
| WARNING:bad_unlock_balance_detected | 0 | 6 |
+------------------------------------------------------+------------+------------+
If you fix the issue, kindly add following tag
| Reported-by: kernel test robot <[email protected]>
| Link: https://lore.kernel.org/oe-lkp/[email protected]
[ 38.890941][ T1] ------------[ cut here ]------------
[ 38.896344][ T1] WARNING: CPU: 2 PID: 1 at kernel/module/internal.h:112 find_module_all (kernel/module/internal.h:112 kernel/module/main.c:350)
[ 38.905714][ T1] Modules linked in:
[ 38.909512][ T1] CPU: 2 PID: 1 Comm: systemd Not tainted 6.3.0-rc1-00019-g7e0c0a44cae2 #1
[ 38.918002][ T1] Hardware name: Intel Corporation Mehlow UP Server Platform/Moss Beach Server, BIOS CNLSE2R1.R00.X188.B13.1903250419 03/25/2019
[ 38.931176][ T1] RIP: 0010:find_module_all (kernel/module/internal.h:112 kernel/module/main.c:350)
[ 38.936615][ T1] Code: 45 31 e4 5b 5d 4c 89 e0 41 5c 41 5d 41 5e 41 5f c3 be ff ff ff ff 48 c7 c7 48 cf bf 84 e8 dd 2d 4c 02 85 c0 0f 85 26 ff ff ff <0f> 0b e9 1f ff ff ff e8 59 28 5a 00 e9 4e ff ff ff e8 1f 1b 5a 00
All code
========
0: 45 31 e4 xor %r12d,%r12d
3: 5b pop %rbx
4: 5d pop %rbp
5: 4c 89 e0 mov %r12,%rax
8: 41 5c pop %r12
a: 41 5d pop %r13
c: 41 5e pop %r14
e: 41 5f pop %r15
10: c3 retq
11: be ff ff ff ff mov $0xffffffff,%esi
16: 48 c7 c7 48 cf bf 84 mov $0xffffffff84bfcf48,%rdi
1d: e8 dd 2d 4c 02 callq 0x24c2dff
22: 85 c0 test %eax,%eax
24: 0f 85 26 ff ff ff jne 0xffffffffffffff50
2a:* 0f 0b ud2 <-- trapping instruction
2c: e9 1f ff ff ff jmpq 0xffffffffffffff50
31: e8 59 28 5a 00 callq 0x5a288f
36: e9 4e ff ff ff jmpq 0xffffffffffffff89
3b: e8 1f 1b 5a 00 callq 0x5a1b5f
Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: e9 1f ff ff ff jmpq 0xffffffffffffff26
7: e8 59 28 5a 00 callq 0x5a2865
c: e9 4e ff ff ff jmpq 0xffffffffffffff5f
11: e8 1f 1b 5a 00 callq 0x5a1b35
[ 38.956135][ T1] RSP: 0018:ffffc9000004fab8 EFLAGS: 00010246
[ 38.962100][ T1] RAX: 0000000000000000 RBX: 1ffff92000009f5f RCX: 0000000000000001
[ 38.969976][ T1] RDX: 0000000000000000 RSI: 00000000ffffffff RDI: ffffffff84bfcf48
[ 38.977857][ T1] RBP: 0000000000000009 R08: 0000000000000000 R09: ffffc90002309fb0
[ 38.985725][ T1] R10: dffffc0000000000 R11: 0000000000000001 R12: dffffc0000000000
[ 38.993595][ T1] R13: 0000000000000001 R14: ffffc900022d6c18 R15: ffffc900022c9000
[ 39.001464][ T1] FS: 00007f8a51fb3040(0000) GS:ffff8887ed700000(0000) knlGS:0000000000000000
[ 39.010295][ T1] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 39.016791][ T1] CR2: 00007f8a52af49f0 CR3: 00000008769e8002 CR4: 00000000003706e0
[ 39.024682][ T1] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 39.032570][ T1] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 39.040446][ T1] Call Trace:
[ 39.043629][ T1] <TASK>
[ 39.046464][ T1] module_patient_check_exists (kernel/module/main.c:2564)
[ 39.052086][ T1] ? finished_loading (kernel/module/main.c:2559)
[ 39.056834][ T1] ? get_next_modinfo (kernel/module/main.c:1058)
[ 39.061758][ T1] ? __x64_sys_sendfile (fs/read_write.c:405)
[ 39.066851][ T1] ? check_modinfo (kernel/module/main.c:1066 kernel/module/main.c:2006)
[ 39.071517][ T1] ? early_mod_check (kernel/module/main.c:2713)
[ 39.076352][ T1] load_module (kernel/module/main.c:2766)
[ 39.080761][ T1] ? post_relocation (kernel/module/main.c:2729)
[ 39.085600][ T1] ? __x64_sys_fspick (fs/kernel_read_file.c:38)
[ 39.090530][ T1] ? __do_sys_finit_module (kernel/module/main.c:2991)
[ 39.095888][ T1] __do_sys_finit_module (kernel/module/main.c:2991)
[ 39.101068][ T1] ? __ia32_sys_init_module (kernel/module/main.c:2959)
[ 39.106351][ T1] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4529)
[ 39.112845][ T1] do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80)
[ 39.117172][ T1] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:120)
[ 39.122958][ T1] RIP: 0033:0x7f8a52b195a9
[ 39.127272][ T1] Code: 08 89 e8 5b 5d c3 66 2e 0f 1f 84 00 00 00 00 00 90 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 27 08 0d 00 f7 d8 64 89 01 48
All code
========
0: 08 89 e8 5b 5d c3 or %cl,-0x3ca2a418(%rcx)
6: 66 2e 0f 1f 84 00 00 nopw %cs:0x0(%rax,%rax,1)
d: 00 00 00
10: 90 nop
11: 48 89 f8 mov %rdi,%rax
14: 48 89 f7 mov %rsi,%rdi
17: 48 89 d6 mov %rdx,%rsi
1a: 48 89 ca mov %rcx,%rdx
1d: 4d 89 c2 mov %r8,%r10
20: 4d 89 c8 mov %r9,%r8
23: 4c 8b 4c 24 08 mov 0x8(%rsp),%r9
28: 0f 05 syscall
2a:* 48 3d 01 f0 ff ff cmp $0xfffffffffffff001,%rax <-- trapping instruction
30: 73 01 jae 0x33
32: c3 retq
33: 48 8b 0d 27 08 0d 00 mov 0xd0827(%rip),%rcx # 0xd0861
3a: f7 d8 neg %eax
3c: 64 89 01 mov %eax,%fs:(%rcx)
3f: 48 rex.W
Code starting with the faulting instruction
===========================================
0: 48 3d 01 f0 ff ff cmp $0xfffffffffffff001,%rax
6: 73 01 jae 0x9
8: c3 retq
9: 48 8b 0d 27 08 0d 00 mov 0xd0827(%rip),%rcx # 0xd0837
10: f7 d8 neg %eax
12: 64 89 01 mov %eax,%fs:(%rcx)
15: 48 rex.W
[ 39.146794][ T1] RSP: 002b:00007ffc529dd768 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
[ 39.155103][ T1] RAX: ffffffffffffffda RBX: 000055fb53a182a0 RCX: 00007f8a52b195a9
[ 39.162980][ T1] RDX: 0000000000000000 RSI: 00007f8a529abefd RDI: 0000000000000004
[ 39.170860][ T1] RBP: 00007f8a529abefd R08: 0000000000000000 R09: 000055fb53a1aeb0
[ 39.178737][ T1] R10: 0000000000000004 R11: 0000000000000246 R12: 0000000000020000
[ 39.186615][ T1] R13: 0000000000000000 R14: 000055fb53a19c90 R15: 00007f8a52fc39b0
[ 39.194502][ T1] </TASK>
[ 39.197428][ T1] irq event stamp: 3344063
[ 39.201747][ T1] hardirqs last enabled at (3344075): __up_console_sem (arch/x86/include/asm/irqflags.h:42 (discriminator 1) arch/x86/include/asm/irqflags.h:77 (discriminator 1) arch/x86/include/asm/irqflags.h:135 (discriminator 1) kernel/printk/printk.c:345 (discriminator 1))
[ 39.211276][ T1] hardirqs last disabled at (3344086): __up_console_sem (kernel/printk/printk.c:343 (discriminator 1))
[ 39.220808][ T1] softirqs last enabled at (3344010): __do_softirq (arch/x86/include/asm/preempt.h:27 kernel/softirq.c:415 kernel/softirq.c:600)
[ 39.230161][ T1] softirqs last disabled at (3344107): __irq_exit_rcu (kernel/softirq.c:445 kernel/softirq.c:650)
[ 39.239695][ T1] ---[ end trace 0000000000000000 ]---
[ 39.247049][ T1] calling ip_tables_init+0x0/0x1000 [ip_tables] @ 1
[ 39.253677][ T1] initcall ip_tables_init+0x0/0x1000 [ip_tables] returned 0 after 43 usecs
[ 40.050683][ T215] calling drm_core_init+0x0/0x120 [drm] @ 215
.
Star[ 40.056380][ T217] fuse: init (API version 7.38)
[ 40.070259][ T217] initcall fuse_init+0x0/0x2d0 [fuse] returned 0 after 7799 usecs
[ 40.535901][ T239] calling init_misc_binfmt+0x0/0x1000 [binfmt_misc] @ 239
[ 40.543017][ T239] initcall init_misc_binfmt+0x0/0x1000 [binfmt_misc] returned 0 after 4 usecs
[ 43.526064][ T296] calling acpi_pad_init+0x0/0x1000 [acpi_pad] @ 296
[ 43.527853][ T309] calling acpi_power_meter_init+0x0/0xfe0 [acpi_power_meter] @ 309
[ 43.533399][ T296] initcall acpi_pad_init+0x0/0x1000 [acpi_pad] returned 0 after 765 usecs
[ 43.550142][ T275] calling acpi_tad_driver_init+0x0/0x1000 [acpi_tad] @ 275
[ 43.551753][ T316]
[ 43.552553][ T295] calling acpi_cpufreq_init+0x0/0xd80 [acpi_cpufreq] @ 295
[ 43.552563][ T295] initcall acpi_cpufreq_init+0x0/0xd80 [acpi_cpufreq] returned -17 after 0 usecs
[ 43.575694][ T316] =====================================
[ 43.579882][ T309] power_meter ACPI000D:00: Found ACPI power meter.
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
sudo bin/lkp install job.yaml # job file is attached in this email
bin/lkp split-job --compatible job.yaml # generate the yaml file for lkp run
sudo bin/lkp run generated-yaml-file
# if come across any failure that blocks the test,
# please remove ~/.lkp and /lkp dir to run from a clean state.
--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests