Hello,
kernel test robot noticed "WARNING:CPU:#PID:#at_call_timer_fn" on:
commit: 3c516f89e17e56b4738f05588e51267e295b5e63 ("x86: Add support for CONFIG_CFI_CLANG")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
[test failed on linus/master 12214540ad87ce824a8a791a3f063e6121ec5b66]
[test failed on linux-next/master d7b3af5a77e8d8da28f435f313e069aea5bcf172]
[test failed on fix commit 883bbbffa5a4ffd1915f8b42934dab81b7f87226]
in testcase: boot
compiler: clang-16
test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G
(please refer to attached dmesg/kmsg for entire log/backtrace)
the config to build this commit has below difference with the one for parent:
--- /pkg/linux/x86_64-randconfig-r034-20230729/clang-16/a4b7a12c5594fe5e6ab2a5aa514a9ae3c0b85573/.config 2023-07-31 12:32:40.547938738 +0800
+++ /pkg/linux/x86_64-randconfig-r034-20230729/clang-16/3c516f89e17e56b4738f05588e51267e295b5e63/.config 2023-07-31 12:33:11.354874788 +0800
@@ -610,6 +610,10 @@ CONFIG_HAVE_STACKPROTECTOR=y
CONFIG_ARCH_SUPPORTS_LTO_CLANG=y
CONFIG_ARCH_SUPPORTS_LTO_CLANG_THIN=y
CONFIG_LTO_NONE=y
+CONFIG_ARCH_SUPPORTS_CFI_CLANG=y
+CONFIG_ARCH_USES_CFI_TRAPS=y
+CONFIG_CFI_CLANG=y
+CONFIG_CFI_PERMISSIVE=y
CONFIG_HAVE_ARCH_WITHIN_STACK_FRAMES=y
CONFIG_HAVE_CONTEXT_TRACKING_USER=y
CONFIG_HAVE_CONTEXT_TRACKING_USER_OFFSTACK=y
we are not sure if that we can see below WARNINGs on this commit is just
expected.
we also tested on linus/master linux-next/master when this bisection done,
as well as one fix commit 883bbbffa5, we found the
dmesg.WARNING:CPU:#PID:#at_call_timer_fn (below (1)) still exists on them,
while others (below (2)(3)(4)) are gone. not sure if there are some further
fixes.
a4b7a12c5594fe5e 3c516f89e17e56b4738f05588e5
---------------- ---------------------------
fail:runs %reproduction fail:runs
| | |
:6 100% 6:6 dmesg.WARNING:CPU:#PID:#at_call_timer_fn (1)
:6 100% 6:6 dmesg.WARNING:CPU:#PID:#at_do_basic_setup (2)
:6 100% 6:6 dmesg.WARNING:CPU:#PID:#at_sha256_finup (3)
:6 100% 6:6 dmesg.WARNING:CPU:#PID:#at_sha256_update (4)
If you fix the issue in a separate patch/commit (i.e. not just a new version of
the same patch/commit), kindly add following tags
| Reported-by: kernel test robot <[email protected]>
| Closes: https://lore.kernel.org/oe-lkp/[email protected]
[ 28.182726][ C1] CFI failure at call_timer_fn+0x161/0x390 (target: dsp_cmx_send+0x0/0x212f; expected type: 0x91b4a83a)
[ 28.182792][ C1] WARNING: CPU: 1 PID: 1 at call_timer_fn+0x161/0x390
[ 28.182803][ C1] Modules linked in:
[ 28.182815][ C1] CPU: 1 PID: 1 Comm: swapper/0 Tainted: P T 6.0.0-rc4-00022-g3c516f89e17e #1
[ 28.182826][ C1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
[ 28.182832][ C1] RIP: 0010:call_timer_fn+0x161/0x390
[ 28.182842][ C1] Code: ad fa ff 85 c0 0f 84 7a 01 00 00 65 ff 0d 93 50 d4 7e 0f 84 19 02 00 00 4c 89 ff 4d 89 f3 41 ba c6 57 4b 6e 45 03 53 fc 74 02 <0f> 0b e8 2c 50 32 02 83 3d ed 12 ee 03 00 0f 8e 80 00 00 00 65 8b
[ 28.182850][ C1] RSP: 0000:ffffc90000188d90 EFLAGS: 00010213
[ 28.182861][ C1] RAX: 0000000000000001 RBX: 0000000000000101 RCX: 0000000000000000
[ 28.182868][ C1] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff869cf300
[ 28.182875][ C1] RBP: ffffc90000188de0 R08: 0000000000000000 R09: 0000000000000000
[ 28.182882][ C1] R10: 0000000012d443c2 R11: ffffffff825d599e R12: 0000000000000001
[ 28.182888][ C1] R13: ffffc90000188e60 R14: ffffffff825d599e R15: ffffffff869cf300
[ 28.182895][ C1] FS: 0000000000000000(0000) GS:ffff88839f700000(0000) knlGS:0000000000000000
[ 28.182902][ C1] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 28.182909][ C1] CR2: 0000000000000000 CR3: 0000000004616000 CR4: 00000000000406a0
[ 28.182920][ C1] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 28.182925][ C1] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 28.182932][ C1] Call Trace:
[ 28.182937][ C1] <IRQ>
[ 28.182952][ C1] ? __cfi_dsp_cmx_send+0x5/0x5
[ 28.182971][ C1] __run_timers+0x4ae/0x5f9
[ 28.183030][ C1] run_timer_softirq+0x50/0xbf
[ 28.183044][ C1] __do_softirq+0x3e0/0x852
[ 28.183088][ C1] __irq_exit_rcu+0x147/0x18e
[ 28.183104][ C1] irq_exit_rcu+0x9/0x24
[ 28.183113][ C1] sysvec_apic_timer_interrupt+0xa4/0xbb
[ 28.183125][ C1] </IRQ>
[ 28.183130][ C1] <TASK>
[ 28.183139][ C1] asm_sysvec_apic_timer_interrupt+0x1b/0x20
[ 28.183149][ C1] RIP: 0010:console_emit_next_record+0x53d/0x631
[ 28.183161][ C1] Code: 75 d7 73 26 e8 83 3b 12 00 fb eb 1e 48 8b 45 98 42 80 3c 20 00 48 8b 5d 90 74 08 48 89 df e8 67 a8 3e 00 48 ff 03 44 8a 75 d7 <44> 89 f0 48 81 c4 c0 00 00 00 5b 41 5c 41 5d 41 5e 41 5f 5d 31 c9
[ 28.183168][ C1] RSP: 0000:ffffc9000002fa70 EFLAGS: 00000246
[ 28.183179][ C1] RAX: 0000000000000000 RBX: ffffffff84dbac00 RCX: 0000000000000000
[ 28.183185][ C1] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
[ 28.183191][ C1] RBP: ffffc9000002fb58 R08: 0000000000000000 R09: 0000000000000000
[ 28.183197][ C1] R10: 0000000000000000 R11: 0000000000000000 R12: 1ffffffff09b7598
[ 28.183204][ C1] R13: 0000000000000246 R14: ffffc9000002fb01 R15: dffffc0000000000
[ 28.183291][ C1] console_unlock+0x15a/0x412
[ 28.183316][ C1] vprintk_emit+0x80/0x16f
[ 28.183325][ C1] ? __this_cpu_preempt_check+0x13/0x1e
[ 28.183359][ C1] vprintk_default+0x18/0x29
[ 28.183370][ C1] vprintk+0x58/0x5f
[ 28.183399][ C1] _printk+0x66/0x83
[ 28.183415][ C1] ? lock_is_held_type+0x101/0x154
[ 28.183444][ C1] wbsd_drv_init+0x1d/0xb0
[ 28.183457][ C1] do_one_initcall+0x201/0x530
[ 28.183467][ C1] ? sysvec_apic_timer_interrupt+0x52/0xbb
[ 28.183477][ C1] ? __cfi_wbsd_drv_init+0x5/0x5
[ 28.183558][ C1] ? rcu_read_unlock_trace_special+0x3/0x3ba
[ 28.183586][ C1] do_initcall_level+0x121/0x1bc
[ 28.183607][ C1] do_initcalls+0x4b/0x88
[ 28.183622][ C1] do_basic_setup+0x78/0x8c
[ 28.183639][ C1] kernel_init_freeable+0x140/0x1e1
[ 28.183648][ C1] ? __cfi_kernel_init+0x5/0x5
[ 28.183661][ C1] kernel_init+0x18/0x132
[ 28.183670][ C1] ? __cfi_kernel_init+0x5/0x5
[ 28.183682][ C1] ret_from_fork+0x22/0x30
[ 28.183723][ C1] </TASK>
[ 28.183728][ C1] irq event stamp: 2303362
[ 28.183734][ C1] hardirqs last enabled at (2303368): [<ffffffff81256f00>] console_trylock_spinning+0x159/0x1db
[ 28.183745][ C1] hardirqs last disabled at (2303373): [<ffffffff81256e68>] console_trylock_spinning+0xc1/0x1db
[ 28.183755][ C1] softirqs last enabled at (2299978): [<ffffffff836006fc>] __do_softirq+0x6f7/0x852
[ 28.183818][ C1] softirqs last disabled at (2302987): [<ffffffff8113c6ee>] __irq_exit_rcu+0x147/0x18e
[ 28.183826][ C1] ---[ end trace 0000000000000000 ]---
To reproduce:
# build kernel
cd linux
cp config-6.0.0-rc4-00022-g3c516f89e17e .config
make HOSTCC=clang-16 CC=clang-16 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage modules
make HOSTCC=clang-16 CC=clang-16 ARCH=x86_64 INSTALL_MOD_PATH=<mod-install-dir> modules_install
cd <mod-install-dir>
find lib/ | cpio -o -H newc --quiet | gzip > modules.cgz
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> -m modules.cgz job-script # job-script is attached in this email
# 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/wiki
On Wed, Aug 02, 2023 at 10:59:03AM +0800, kernel test robot wrote:
> Hello,
>
> kernel test robot noticed "WARNING:CPU:#PID:#at_call_timer_fn" on:
>
> commit: 3c516f89e17e56b4738f05588e51267e295b5e63 ("x86: Add support for CONFIG_CFI_CLANG")
> https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
>
> [test failed on linus/master 12214540ad87ce824a8a791a3f063e6121ec5b66]
> [test failed on linux-next/master d7b3af5a77e8d8da28f435f313e069aea5bcf172]
> [test failed on fix commit 883bbbffa5a4ffd1915f8b42934dab81b7f87226]
>
> in testcase: boot
>
> compiler: clang-16
> test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G
>
> (please refer to attached dmesg/kmsg for entire log/backtrace)
>
>
> the config to build this commit has below difference with the one for parent:
>
> --- /pkg/linux/x86_64-randconfig-r034-20230729/clang-16/a4b7a12c5594fe5e6ab2a5aa514a9ae3c0b85573/.config 2023-07-31 12:32:40.547938738 +0800
> +++ /pkg/linux/x86_64-randconfig-r034-20230729/clang-16/3c516f89e17e56b4738f05588e51267e295b5e63/.config 2023-07-31 12:33:11.354874788 +0800
> @@ -610,6 +610,10 @@ CONFIG_HAVE_STACKPROTECTOR=y
> CONFIG_ARCH_SUPPORTS_LTO_CLANG=y
> CONFIG_ARCH_SUPPORTS_LTO_CLANG_THIN=y
> CONFIG_LTO_NONE=y
> +CONFIG_ARCH_SUPPORTS_CFI_CLANG=y
> +CONFIG_ARCH_USES_CFI_TRAPS=y
> +CONFIG_CFI_CLANG=y
> +CONFIG_CFI_PERMISSIVE=y
> CONFIG_HAVE_ARCH_WITHIN_STACK_FRAMES=y
> CONFIG_HAVE_CONTEXT_TRACKING_USER=y
> CONFIG_HAVE_CONTEXT_TRACKING_USER_OFFSTACK=y
>
> we are not sure if that we can see below WARNINGs on this commit is just
> expected.
>
> we also tested on linus/master linux-next/master when this bisection done,
> as well as one fix commit 883bbbffa5, we found the
> dmesg.WARNING:CPU:#PID:#at_call_timer_fn (below (1)) still exists on them,
> while others (below (2)(3)(4)) are gone. not sure if there are some further
> fixes.
>
> a4b7a12c5594fe5e 3c516f89e17e56b4738f05588e5
> ---------------- ---------------------------
> fail:runs %reproduction fail:runs
> | | |
> :6 100% 6:6 dmesg.WARNING:CPU:#PID:#at_call_timer_fn (1)
> :6 100% 6:6 dmesg.WARNING:CPU:#PID:#at_do_basic_setup (2)
> :6 100% 6:6 dmesg.WARNING:CPU:#PID:#at_sha256_finup (3)
> :6 100% 6:6 dmesg.WARNING:CPU:#PID:#at_sha256_update (4)
>
>
>
> If you fix the issue in a separate patch/commit (i.e. not just a new version of
> the same patch/commit), kindly add following tags
> | Reported-by: kernel test robot <[email protected]>
> | Closes: https://lore.kernel.org/oe-lkp/[email protected]
>
>
>
> [ 28.182726][ C1] CFI failure at call_timer_fn+0x161/0x390 (target: dsp_cmx_send+0x0/0x212f; expected type: 0x91b4a83a)
Thanks a lot for the report, this does seem expected. I have sent a
patch:
https://lore.kernel.org/20230802-fix-dsp_cmx_send-cfi-failure-v1-1-2f2e79b0178d@kernel.org/
Cheers,
Nathan