[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Message-ID: <202505140917.8ee62cc6-lkp@intel.com>
Date: Wed, 14 May 2025 10:47:30 +0800
From: kernel test robot <oliver.sang@...el.com>
To: "Paul E. McKenney" <paulmck@...nel.org>
CC: <oe-lkp@...ts.linux.dev>, <lkp@...el.com>, Joel Fernandes
<joelagnelf@...dia.com>, <linux-kernel@...r.kernel.org>,
<oliver.sang@...el.com>
Subject: [linux-next:master] [rcutorture] c27d0d38f2:
WARNING:at_kernel/rcu/rcutorture.c:#rcutorture_one_extend_check[rcutorture]
hi, Paul,
for this commit we tested before, now we found it causes issues in linux-next
master branch.
=========================================================================================
tbox_group/testcase/rootfs/kconfig/compiler/runtime/test/torture_type:
vm-snb/rcutorture/debian-11.1-i386-20220923.cgz/i386-randconfig-141-20250508/clang-20/300s/cpuhotplug/srcud
c795676b5c0a4ab7 c27d0d38f2cafb70a68ca42c410
---------------- ---------------------------
fail:runs %reproduction fail:runs
| | |
:50 2% 1:50 dmesg.EIP:__kernel_text_address
:50 4% 2:50 dmesg.EIP:__srcu_check_read_flavor
:50 2% 1:50 dmesg.EIP:_raw_spin_unlock_irq
:50 14% 7:50 dmesg.EIP:_raw_spin_unlock_irqrestore
:50 30% 15:50 dmesg.EIP:console_flush_all
:50 4% 2:50 dmesg.EIP:console_trylock_spinning
:50 2% 1:50 dmesg.EIP:delay_tsc
:50 2% 1:50 dmesg.EIP:finish_lock_switch
:50 2% 1:50 dmesg.EIP:kernel_text_address
:50 2% 1:50 dmesg.EIP:lock_acquire
:50 36% 18:50 dmesg.EIP:pv_native_safe_halt
1:50 -2% :50 dmesg.EIP:rcu_torture_fwd_prog_cr
7:50 -14% :50 dmesg.EIP:rcu_torture_writer
:50 100% 50:50 dmesg.EIP:rcutorture_one_extend_check
48:50 0% 48:50 dmesg.INFO:task_blocked_for_more_than#seconds
48:50 0% 48:50 dmesg.Kernel_panic-not_syncing:hung_task:blocked_tasks
50:50 0% 50:50 dmesg.UBSAN:negation-overflow_in_lib/sort.c
1:50 -2% :50 dmesg.WARNING:at_kernel/rcu/rcutorture.c:#rcu_torture_fwd_prog_cr[rcutorture]
7:50 -14% :50 dmesg.WARNING:at_kernel/rcu/rcutorture.c:#rcu_torture_writer[rcutorture]
:50 100% 50:50 dmesg.WARNING:at_kernel/rcu/rcutorture.c:#rcutorture_one_extend_check[rcutorture] <--- (1)
7:50 -14% :50 dmesg.calltrace:__do_softirq
1:50 -2% :50 dmesg.calltrace:rcu_torture_pipe_update
though both c27d0d38f2/parent have various issues, it seems (1) is persistent
on c27d0d38f2 and clean on parent.
Hello,
kernel test robot noticed "WARNING:at_kernel/rcu/rcutorture.c:#rcutorture_one_extend_check[rcutorture]" on:
commit: c27d0d38f2cafb70a68ca42c4105e170862aaf77 ("rcutorture: Complain if an ->up_read() is delayed more than 10 seconds")
https://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git master
[test failed on linux-next/master f48887a98b78880b7711aca311fbbbcaad6c4e3b]
in testcase: rcutorture
version:
with following parameters:
runtime: 300s
test: cpuhotplug
torture_type: srcud
config: i386-randconfig-141-20250508
compiler: clang-20
test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G
(please refer to attached dmesg/kmsg for entire log/backtrace)
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 <oliver.sang@...el.com>
| Closes: https://lore.kernel.org/oe-lkp/202505140917.8ee62cc6-lkp@intel.com
The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20250514/202505140917.8ee62cc6-lkp@intel.com
[ 76.027193][ C1] ------------[ cut here ]------------
[ 76.027652][ T661] srcud-torture: rcu_torture_stats task started
[ 76.027754][ C1] rcutorture_one_extend_check before change: Current 0x80 To add 0x0 To remove 0x80 preempt_count() 0x10001
[ 76.029893][ C1] WARNING: CPU: 1 PID: 2 at kernel/rcu/rcutorture.c:1976 rcutorture_one_extend_check+0x5b/0x300 [rcutorture]
[ 76.031093][ C1] Modules linked in: rcutorture(+) torture
[ 76.031736][ C1] CPU: 1 UID: 0 PID: 2 Comm: kthreadd Tainted: G T 6.15.0-rc1-00008-gc27d0d38f2ca #1 PREEMPT(full) 4c3e2c742772c0895467dcaa42b0aab115cc2926
[ 76.033194][ C1] Tainted: [T]=RANDSTRUCT
[ 76.033728][ C1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
[ 76.034602][ C1] EIP: rcutorture_one_extend_check+0x5b/0x300 [rcutorture]
[ 76.035319][ C1] Code: 05 68 e2 69 f0 01 64 a1 0c f0 b4 c3 25 ff ff ff 7f 50 ff 75 0c 57 53 56 68 e3 c9 6a f0 68 19 b5 6a f0 e8 b8 c8 96 d0 83 c4 1c <0f> 0b f6 c3 09 75 1d eb 35 9c 8f 45 ec f7 45 ec 00 02 00 00 74 09
[ 76.037024][ C1] EAX: 0000006c EBX: 00000080 ECX: 00000027 EDX: 00000000
[ 76.037760][ C1] ESI: f06ad951 EDI: 00000000 EBP: c7f19da0 ESP: c7f19d8c
[ 76.038490][ C1] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 EFLAGS: 00010082
[ 76.039252][ C1] CR0: 80050033 CR2: b7e17eb0 CR3: 08be7000 CR4: 00040690
[ 76.039989][ C1] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[ 76.040713][ C1] DR6: fffe0ff0 DR7: 00000400
[ 76.041313][ C1] Call Trace:
[ 76.041825][ C1] rcutorture_one_extend+0x54/0x4b0 [rcutorture 4a4a34e515cdd0c53b2c18de8a71945278e82895]
[ 76.042705][ C1] ? lock_acquire+0xa8/0x1c0
[ 76.043299][ C1] rcu_torture_one_read_end+0x1b7/0x350 [rcutorture 4a4a34e515cdd0c53b2c18de8a71945278e82895]
[ 76.044196][ C1] ? local_bh_enable+0x20/0x20 [rcutorture 4a4a34e515cdd0c53b2c18de8a71945278e82895]
[ 76.045049][ C1] rcu_torture_updown_hrt+0x18/0x30 [rcutorture 4a4a34e515cdd0c53b2c18de8a71945278e82895]
[ 76.045935][ C1] __hrtimer_run_queues+0x18a/0x3b0
[ 76.046555][ C1] ? ktime_get_update_offsets_now+0x52/0x200
[ 76.047309][ C1] hrtimer_run_queues+0xf7/0x130
[ 76.048063][ C1] update_process_times+0x25/0xb0
[ 76.048680][ C1] tick_periodic+0xc4/0xe0
[ 76.049272][ C1] tick_handle_periodic+0x23/0x70
[ 76.049875][ C1] __sysvec_apic_timer_interrupt+0x73/0x190
[ 76.050528][ C1] ? sysvec_call_function_single+0x30/0x30
[ 76.051175][ C1] sysvec_apic_timer_interrupt+0x1a/0x34
[ 76.051812][ C1] handle_exception+0x150/0x150
[ 76.052405][ C1] EIP: lock_acquire+0xda/0x1c0
[ 76.052998][ C1] Code: 64 0f c1 05 8c 0e b5 c3 83 f8 01 0f 85 a5 00 00 00 9c 8f 45 d4 f7 45 d4 00 02 00 00 0f 85 a6 00 00 00 85 f6 74 01 fb 83 c4 20 <5e> 5f 5b 5d 2e e9 30 3d 3c 01 89 ce 89 55 f0 8b 55 f0 ff 75 14 ff
[ 76.054753][ C1] EAX: 00000001 EBX: c345d894 ECX: b4a771ac EDX: 00000000
[ 76.055499][ C1] ESI: 00000001 EDI: 00000000 EBP: c7f19f50 ESP: c7f19f44
[ 76.056248][ C1] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 EFLAGS: 00000286
[ 76.057032][ C1] ? try_to_wake_up+0x248/0x850
[ 76.057690][ C1] ? sysvec_call_function_single+0x30/0x30
[ 76.058377][ C1] ? try_to_wake_up+0x248/0x850
[ 76.059009][ C1] ? sysvec_call_function_single+0x30/0x30
[ 76.059693][ C1] ? lock_acquire+0xda/0x1c0
[ 76.060312][ C1] _raw_spin_lock+0x2a/0x3c
[ 76.060927][ C1] ? kthreadd+0xda/0x160
[ 76.061549][ C1] kthreadd+0xda/0x160
[ 76.062126][ C1] ? schedule_tail+0xd4/0x120
[ 76.062729][ C1] ? kthread_stop_put+0x30/0x30
[ 76.063335][ C1] ? kthread_stop_put+0x30/0x30
[ 76.063933][ C1] ret_from_fork+0x35/0x40
[ 76.064505][ C1] ret_from_fork_asm+0x12/0x1c
[ 76.065091][ C1] entry_INT80_32+0x10d/0x10d
[ 76.065693][ C1] irq event stamp: 4386
[ 76.066236][ C1] hardirqs last enabled at (4385): [<c10f858d>] finish_lock_switch+0x9d/0xe0
[ 76.067037][ C1] hardirqs last disabled at (4386): [<c24e7ab0>] sysvec_apic_timer_interrupt+0xc/0x34
[ 76.067873][ C1] softirqs last enabled at (2260): [<c10bb5d2>] handle_softirqs+0x372/0x3b0
[ 76.068659][ C1] softirqs last disabled at (2255): [<c24f627f>] __do_softirq+0xf/0x16
[ 76.069635][ C1] ---[ end trace 0000000000000000 ]---
[ 76.099825][ T636] srcud-torture: Creating torture_stutter task
[ 76.099831][ T667] srcud-torture: torture_shuffle task started
[ 76.101418][ T636] srcud-torture: Creating torture_onoff task
--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki
Powered by blists - more mailing lists