[<prev] [next>] [<thread-prev] [day] [month] [year] [list]
Message-ID: <20211103151855.GC30634@xsang-OptiPlex-9020>
Date: Wed, 3 Nov 2021 23:18:55 +0800
From: kernel test robot <oliver.sang@...el.com>
To: Ming Lei <ming.lei@...hat.com>
Cc: lkp@...ts.01.org, lkp@...el.com,
Josh Poimboeuf <jpoimboe@...hat.com>,
Jiri Kosina <jikos@...nel.org>,
Miroslav Benes <mbenes@...e.cz>,
Petr Mladek <pmladek@...e.com>, live-patching@...r.kernel.org,
linux-kernel@...r.kernel.org,
Greg Kroah-Hartman <gregkh@...uxfoundation.org>,
Luis Chamberlain <mcgrof@...nel.org>,
Joe Lawrence <joe.lawrence@...hat.com>,
Ming Lei <ming.lei@...hat.com>
Subject: [livepatch] 442831987f:
WARNING:at_kernel/livepatch/core.c:#klp_enable_patch.cold
Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: 442831987f34576a8739aaa6e992ae779e0dcb4b ("[PATCH V3 2/3] livepatch: free klp_patch object without holding klp_mutex")
url: https://github.com/0day-ci/linux/commits/Ming-Lei/livepatch-cleanup-kpl_patch-kobject-release/20211101-192949
base: https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git 8bb7eca972ad531c9b149c0a51ab43a417385813
patch link: https://lore.kernel.org/live-patching/20211101112548.3364086-3-ming.lei@redhat.com
in testcase: kernel-selftests
version: kernel-selftests-x86_64-c8c9111a-1_20210929
with following parameters:
group: livepatch
ucode: 0xe2
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: 4 threads Intel(R) Core(TM) i5-6500 CPU @ 3.20GHz with 32G memory
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <oliver.sang@...el.com>
[ 66.222863][ T1905] WARNING: CPU: 2 PID: 1905 at kernel/livepatch/core.c:1001 klp_enable_patch.cold (kernel/livepatch/core.c:1001 kernel/livepatch/core.c:1064 kernel/livepatch/core.c:1024)
[ 66.232960][ T1905] Modules linked in: test_klp_callbacks_demo2(K+) test_klp_callbacks_demo(K) btrfs blake2b_generic xor zstd_compress ipmi_devintf ipmi_msghandler raid6_pq libcrc32c sd_mod t10_pi sg intel_rapl_msr intel_rapl_common x86_pkg_temp_thermal intel_powerclamp i915 mei_wdt wmi_bmof coretemp crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel rapl ahci intel_cstate mei_me i2c_i801 intel_gtt intel_uncore mei libahci i2c_smbus ttm intel_pch_thermal wmi libata video acpi_pad intel_pmc_core ip_tables [last unloaded: test_klp_callbacks_demo]
[ 66.282376][ T1905] CPU: 2 PID: 1905 Comm: modprobe Tainted: G K 5.15.0-00002-g442831987f34 #1
[ 66.292321][ T1905] Hardware name: Dell Inc. OptiPlex 7040/0Y7WYT, BIOS 1.8.1 12/05/2017
[ 66.300583][ T1905] RIP: 0010:klp_enable_patch.cold (kernel/livepatch/core.c:1001 kernel/livepatch/core.c:1064 kernel/livepatch/core.c:1024)
[ 66.306519][ T1905] Code: ff ff e8 14 4f 28 ff e9 a8 35 28 ff e8 0a 54 28 ff c6 85 80 00 00 00 01 48 89 df e8 bb 4f 28 ff 48 8b 44 24 08 48 39 d8 74 02 <0f> 0b 48 c7 c7 c0 7f 6f 83 e8 a3 69 08 00 e9 12 35 28 ff 48 83 ba
All code
========
0: ff (bad)
1: ff (bad)
2: e8 14 4f 28 ff callq 0xffffffffff284f1b
7: e9 a8 35 28 ff jmpq 0xffffffffff2835b4
c: e8 0a 54 28 ff callq 0xffffffffff28541b
11: c6 85 80 00 00 00 01 movb $0x1,0x80(%rbp)
18: 48 89 df mov %rbx,%rdi
1b: e8 bb 4f 28 ff callq 0xffffffffff284fdb
20: 48 8b 44 24 08 mov 0x8(%rsp),%rax
25: 48 39 d8 cmp %rbx,%rax
28: 74 02 je 0x2c
2a:* 0f 0b ud2 <-- trapping instruction
2c: 48 c7 c7 c0 7f 6f 83 mov $0xffffffff836f7fc0,%rdi
33: e8 a3 69 08 00 callq 0x869db
38: e9 12 35 28 ff jmpq 0xffffffffff28354f
3d: 48 rex.W
3e: 83 .byte 0x83
3f: ba .byte 0xba
Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: 48 c7 c7 c0 7f 6f 83 mov $0xffffffff836f7fc0,%rdi
9: e8 a3 69 08 00 callq 0x869b1
e: e9 12 35 28 ff jmpq 0xffffffffff283525
13: 48 rex.W
14: 83 .byte 0x83
15: ba .byte 0xba
[ 66.325969][ T1905] RSP: 0018:ffffc90000c4bbd0 EFLAGS: 00010212
[ 66.331892][ T1905] RAX: ffffffffc0637080 RBX: ffffc90000c4bbd8 RCX: 0000000000000000
[ 66.339726][ T1905] RDX: ffffc90000c4bbd8 RSI: ffffc90000c4bbd8 RDI: ffffffffc0637080
[ 66.347566][ T1905] RBP: ffffffffc063c060 R08: ffffc90000c4bbd8 R09: ffffc90000c4bbd8
[ 66.355387][ T1905] R10: 0000000000000001 R11: 0000000000000000 R12: 0000000000000000
[ 66.363234][ T1905] R13: ffffffffc063c0d0 R14: ffffffffc063c090 R15: 0000000000000000
[ 66.371114][ T1905] FS: 00007f8058f95480(0000) GS:ffff8887c7500000(0000) knlGS:0000000000000000
[ 66.379926][ T1905] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 66.386380][ T1905] CR2: 00007fff2c1d0e38 CR3: 0000000812b50003 CR4: 00000000003706e0
[ 66.394223][ T1905] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 66.402062][ T1905] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 66.409915][ T1905] Call Trace:
[ 66.413096][ T1905] ? pre_patch_callback (lib/livepatch/test_klp_callbacks_demo2.c:79) test_klp_callbacks_demo2
[ 66.420349][ T1905] do_one_initcall (init/main.c:1304)
[ 66.424901][ T1905] ? do_init_module (kernel/module.c:3680)
[ 66.429537][ T1905] ? kmem_cache_alloc_trace (include/trace/events/kmem.h:46 include/trace/events/kmem.h:46 mm/slub.c:3239)
[ 66.434953][ T1905] ? lock_is_held_type (kernel/locking/lockdep.c:438 kernel/locking/lockdep.c:5669)
[ 66.439838][ T1905] do_init_module (kernel/module.c:3695)
[ 66.444314][ T1905] load_module (kernel/module.c:4096)
[ 66.448776][ T1905] ? __kernel_read (fs/read_write.c:443 (discriminator 1))
[ 66.453458][ T1905] ? __do_sys_finit_module (kernel/module.c:4187)
[ 66.458710][ T1905] __do_sys_finit_module (kernel/module.c:4187)
[ 66.463822][ T1905] do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80)
[ 66.468108][ T1905] ? do_syscall_64 (arch/x86/entry/common.c:87)
[ 66.472573][ T1905] ? lockdep_hardirqs_on (kernel/locking/lockdep.c:4344)
[ 66.477662][ T1905] ? do_syscall_64 (arch/x86/entry/common.c:87)
[ 66.482123][ T1905] ? lockdep_hardirqs_on (kernel/locking/lockdep.c:4344)
[ 66.487195][ T1905] ? do_syscall_64 (arch/x86/entry/common.c:87)
[ 66.491682][ T1905] ? do_syscall_64 (arch/x86/entry/common.c:87)
[ 66.496171][ T1905] ? asm_exc_page_fault (arch/x86/include/asm/idtentry.h:568)
[ 66.501071][ T1905] ? asm_exc_page_fault (arch/x86/include/asm/idtentry.h:568)
[ 66.505889][ T1905] ? lockdep_hardirqs_on (kernel/locking/lockdep.c:4344)
[ 66.510950][ T1905] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:113)
[ 66.516740][ T1905] RIP: 0033:0x7f80590aff59
[ 66.521028][ T1905] Code: 00 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 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 07 6f 0c 00 f7 d8 64 89 01 48
All code
========
0: 00 c3 add %al,%bl
2: 66 2e 0f 1f 84 00 00 nopw %cs:0x0(%rax,%rax,1)
9: 00 00 00
c: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
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 07 6f 0c 00 mov 0xc6f07(%rip),%rcx # 0xc6f41
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 07 6f 0c 00 mov 0xc6f07(%rip),%rcx # 0xc6f17
10: f7 d8 neg %eax
12: 64 89 01 mov %eax,%fs:(%rcx)
15: 48 rex.W
[ 66.540477][ T1905] RSP: 002b:00007fff2c1d2de8 EFLAGS: 00000246 ORIG_RAX: 0000000000000139
[ 66.548766][ T1905] RAX: ffffffffffffffda RBX: 000055c90eb76d20 RCX: 00007f80590aff59
[ 66.556608][ T1905] RDX: 0000000000000000 RSI: 000055c90eb77260 RDI: 0000000000000005
[ 66.564458][ T1905] RBP: 000055c90eb77260 R08: 0000000000000000 R09: 000055c90eb76d20
[ 66.572295][ T1905] R10: 0000000000000005 R11: 0000000000000246 R12: 0000000000000000
[ 66.580134][ T1905] R13: 000055c90eb76f90 R14: 0000000000040000 R15: 000055c90eb76d20
[ 66.587996][ T1905] irq event stamp: 10041
[ 66.592123][ T1905] hardirqs last enabled at (10051): __up_console_sem (arch/x86/include/asm/irqflags.h:45 (discriminator 1) arch/x86/include/asm/irqflags.h:80 (discriminator 1) arch/x86/include/asm/irqflags.h:140 (discriminator 1) kernel/printk/printk.c:255 (discriminator 1))
[ 66.601435][ T1905] hardirqs last disabled at (10060): __up_console_sem (kernel/printk/printk.c:253 (discriminator 1))
[ 66.610753][ T1905] softirqs last enabled at (10074): __do_softirq (arch/x86/include/asm/preempt.h:27 kernel/softirq.c:402 kernel/softirq.c:587)
[ 66.619925][ T1905] softirqs last disabled at (10087): irq_exit_rcu (kernel/softirq.c:432 kernel/softirq.c:636 kernel/softirq.c:648)
[ 66.628978][ T1905] ---[ end trace b14e7c7c69518169 ]---
[ 66.640438][ T1464] % echo 0 > /sys/kernel/livepatch/test_klp_callbacks_demo2/enabled
[ 66.648367][ T1464] livepatch: 'test_klp_callbacks_demo2': initializing unpatching transition
[ 66.656984][ T1464] test_klp_callbacks_demo2: pre_unpatch_callback: vmlinux
[ 66.663975][ T1464] livepatch: 'test_klp_callbacks_demo2': starting unpatching transition
[ 66.672436][ T1464] livepatch: 'test_klp_callbacks_demo2': completing unpatching transition
[ 66.680915][ T1464] test_klp_callbacks_demo2: post_unpatch_callback: vmlinux
[ 66.688049][ T1464] livepatch: 'test_klp_callbacks_demo2': unpatching complete
[ 66.699476][ T1464] % rmmod test_klp_callbacks_demo2
See 'systemctl status lkp-bootstrap.service' for details.
[ 131.165453][ T1464] ERROR: failed to unload module test_klp_callbacks_demo (refcnt)
[ 131.257070][ T3351] livepatch: kernel.ftrace_enabled = 1
[ 131.278180][ T3351] ===== TEST: basic shadow variable API =====
[ 131.297991][ T3351] % modprobe test_klp_shadow_vars
[ 131.310453][ T3369] test_klp_shadow_vars: klp_shadow_get(obj=PTR1, id=0x1234) = PTR0
[ 131.318185][ T3369] test_klp_shadow_vars: got expected NULL result
[ 131.324597][ T3369] test_klp_shadow_vars: shadow_ctor: PTR3 -> PTR2
[ 131.330921][ T3369] test_klp_shadow_vars: klp_shadow_get_or_alloc(obj=PTR1, id=0x1234, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR2 = PTR3
[ 131.344367][ T3369] test_klp_shadow_vars: shadow_ctor: PTR6 -> PTR5
[ 131.350626][ T3369] test_klp_shadow_vars: klp_shadow_alloc(obj=PTR1, id=0x1235, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR5 = PTR6
[ 131.363467][ T3369] test_klp_shadow_vars: shadow_ctor: PTR8 -> PTR7
[ 131.369743][ T3369] test_klp_shadow_vars: klp_shadow_alloc(obj=PTR9, id=0x1234, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR7 = PTR8
[ 131.382603][ T3369] test_klp_shadow_vars: shadow_ctor: PTR11 -> PTR10
[ 131.389098][ T3369] test_klp_shadow_vars: klp_shadow_alloc(obj=PTR9, id=0x1235, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR10 = PTR11
[ 131.402153][ T3369] test_klp_shadow_vars: shadow_ctor: PTR13 -> PTR12
[ 131.408755][ T3369] test_klp_shadow_vars: klp_shadow_get_or_alloc(obj=PTR14, id=0x1234, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR12 = PTR13
[ 131.422619][ T3369] test_klp_shadow_vars: shadow_ctor: PTR16 -> PTR15
[ 131.429059][ T3369] test_klp_shadow_vars: klp_shadow_alloc(obj=PTR14, id=0x1235, size=8, gfp_flags=GFP_KERNEL), ctor=PTR4, ctor_data=PTR15 = PTR16
[ 131.442171][ T3369] test_klp_shadow_vars: klp_shadow_get(obj=PTR1, id=0x1234) = PTR3
[ 131.449906][ T3369] test_klp_shadow_vars: got expected PTR3 -> PTR2 result
[ 131.456945][ T3369] test_klp_shadow_vars: klp_shadow_get(obj=PTR1, id=0x1235) = PTR6
[ 131.464722][ T3369] test_klp_shadow_vars: got expected PTR6 -> PTR5 result
[ 131.471774][ T3369] test_klp_shadow_vars: klp_shadow_get(obj=PTR9, id=0x1234) = PTR8
[ 131.479507][ T3369] test_klp_shadow_vars: got expected PTR8 -> PTR7 result
[ 131.486545][ T3369] test_klp_shadow_vars: klp_shadow_get(obj=PTR9, id=0x1235) = PTR11
[ 131.494365][ T3369] test_klp_shadow_vars: got expected PTR11 -> PTR10 result
[ 131.501578][ T3369] test_klp_shadow_vars: klp_shadow_get(obj=PTR14, id=0x1234) = PTR13
[ 131.509482][ T3369] test_klp_shadow_vars: got expected PTR13 -> PTR12 result
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.
---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/lkp@lists.01.org Intel Corporation
Thanks,
Oliver Sang
View attachment "config-5.15.0-00002-g442831987f34" of type "text/plain" (176414 bytes)
View attachment "job-script" of type "text/plain" (6076 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (27092 bytes)
View attachment "kernel-selftests" of type "text/plain" (2388 bytes)
View attachment "job.yaml" of type "text/plain" (4902 bytes)
View attachment "reproduce" of type "text/plain" (158 bytes)
Powered by blists - more mailing lists