[linux-next:master] [net] b8dbbbc535: INFO:rcu_sched_detected_stalls_on_CPUs/tasks

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 




Hello,

kernel test robot noticed "INFO:rcu_sched_detected_stalls_on_CPUs/tasks" on:

commit: b8dbbbc535a95acd66035cf75872cd7524c0b12f ("net: rtnetlink: remove local list in __linkwatch_run_queue()")
https://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git master

in testcase: boot

compiler: gcc-12
test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G

(please refer to attached dmesg/kmsg for entire log/backtrace)


+----------------------------------------------+------------+------------+
|                                              | 5a08d0065a | b8dbbbc535 |
+----------------------------------------------+------------+------------+
| INFO:rcu_sched_detected_stalls_on_CPUs/tasks | 0          | 6          |
| EIP:__linkwatch_run_queue                    | 0          | 6          |
| EIP:linkwatch_urgent_event                   | 0          | 6          |
+----------------------------------------------+------------+------------+


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@xxxxxxxxx>
| Closes: https://lore.kernel.org/oe-lkp/202312121032.40bab6f5-oliver.sang@xxxxxxxxx


[  310.105890][    C1] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
[  310.105890][    C1] rcu: 	0-...0: (0 ticks this GP) idle=a59c/1/0x40000000 softirq=123485/123485 fqs=12537
[  310.105890][    C1] rcu: 	         hardirqs   softirqs   csw/system
[  310.105890][    C1] rcu: 	 number:        0          0            0
[  310.105890][    C1] rcu: 	cputime:        0          0            0   ==> 52504(ms)
[  310.105890][    C1] rcu: 	(detected by 1, t=26252 jiffies, g=55465, q=13220 ncpus=2)
[  310.105890][    C1] Sending NMI from CPU 1 to CPUs 0:
[  310.062003][    C0] NMI backtrace for cpu 0
[  310.062003][    C0] CPU: 0 PID: 192 Comm: kworker/0:3 Tainted: G                 N 6.7.0-rc3-00806-gb8dbbbc535a9 #1 201d78f7550731bd41da838527871846012af2c0
[  310.062003][    C0] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
[  310.062003][    C0] Workqueue: events linkwatch_event
[ 310.062003][ C0] EIP: __linkwatch_run_queue (net/core/link_watch.c:224) 
[ 310.062003][ C0] Code: 96 81 c4 fe b8 80 73 c5 c3 e8 22 0e 34 00 a1 a4 73 c5 c3 eb 40 8d b4 26 00 00 00 00 8b 45 f0 85 c0 74 0b 89 f8 e8 7a fc ff ff <84> c0 74 5c b8 80 73 c5 c3 83 ee 01 e8 e5 0f 34 00 89 f8 e8 0e ff
All code
========
   0:	96                   	xchg   %eax,%esi
   1:	81 c4 fe b8 80 73    	add    $0x7380b8fe,%esp
   7:	c5 c3 e8             	(bad)
   a:	22 0e                	and    (%rsi),%cl
   c:	34 00                	xor    $0x0,%al
   e:	a1 a4 73 c5 c3 eb 40 	movabs 0xb48d40ebc3c573a4,%eax
  15:	8d b4 
  17:	26 00 00             	es add %al,(%rax)
  1a:	00 00                	add    %al,(%rax)
  1c:	8b 45 f0             	mov    -0x10(%rbp),%eax
  1f:	85 c0                	test   %eax,%eax
  21:	74 0b                	je     0x2e
  23:	89 f8                	mov    %edi,%eax
  25:	e8 7a fc ff ff       	call   0xfffffffffffffca4
  2a:*	84 c0                	test   %al,%al		<-- trapping instruction
  2c:	74 5c                	je     0x8a
  2e:	b8 80 73 c5 c3       	mov    $0xc3c57380,%eax
  33:	83 ee 01             	sub    $0x1,%esi
  36:	e8 e5 0f 34 00       	call   0x341020
  3b:	89 f8                	mov    %edi,%eax
  3d:	e8                   	.byte 0xe8
  3e:	0e                   	(bad)
  3f:	ff                   	.byte 0xff

Code starting with the faulting instruction
===========================================
   0:	84 c0                	test   %al,%al
   2:	74 5c                	je     0x60
   4:	b8 80 73 c5 c3       	mov    $0xc3c57380,%eax
   9:	83 ee 01             	sub    $0x1,%esi
   c:	e8 e5 0f 34 00       	call   0x340ff6
  11:	89 f8                	mov    %edi,%eax
  13:	e8                   	.byte 0xe8
  14:	0e                   	(bad)
  15:	ff                   	.byte 0xff
[  310.062003][    C0] EAX: 00000000 EBX: c6de2380 ECX: 00000001 EDX: c3c573a4
[  310.062003][    C0] ESI: 000000c8 EDI: c6de2000 EBP: c8619f04 ESP: c8619ef4
[  310.062003][    C0] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 EFLAGS: 00000092
[  310.062003][    C0] CR0: 80050033 CR2: ffd39000 CR3: 03e7d000 CR4: 000406d0
[  310.062003][    C0] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[  310.062003][    C0] DR6: fffe0ff0 DR7: 00000400
[  310.062003][    C0] Call Trace:
[ 310.062003][ C0] ? show_regs (arch/x86/kernel/dumpstack.c:479 arch/x86/kernel/dumpstack.c:465) 
[ 310.062003][ C0] ? nmi_cpu_backtrace (lib/nmi_backtrace.c:115) 
[ 310.062003][ C0] ? nmi_cpu_backtrace_handler (arch/x86/kernel/apic/hw_nmi.c:51) 
[ 310.062003][ C0] ? nmi_handle (arch/x86/kernel/nmi.c:151 (discriminator 7)) 
[ 310.062003][ C0] ? lock_acquire (kernel/locking/lockdep.c:467 kernel/locking/lockdep.c:5756 kernel/locking/lockdep.c:5719) 
[ 310.062003][ C0] ? default_do_nmi (arch/x86/kernel/nmi.c:351 (discriminator 19)) 
[ 310.062003][ C0] ? exc_nmi (arch/x86/kernel/nmi.c:544) 
[ 310.062003][ C0] ? asm_exc_nmi (arch/x86/entry/entry_32.S:1149) 
[ 310.062003][ C0] ? __linkwatch_run_queue (net/core/link_watch.c:224) 
[ 310.062003][ C0] linkwatch_event (net/core/link_watch.c:274) 
[ 310.062003][ C0] process_one_work (include/linux/jump_label.h:207 include/linux/jump_label.h:207 include/trace/events/workqueue.h:108 kernel/workqueue.c:2635) 
[ 310.062003][ C0] worker_thread (kernel/workqueue.c:2697 kernel/workqueue.c:2784) 
[ 310.062003][ C0] ? process_one_work (kernel/workqueue.c:2730) 
[ 310.062003][ C0] kthread (kernel/kthread.c:388) 
[ 310.062003][ C0] ? process_one_work (kernel/workqueue.c:2730) 
[ 310.062003][ C0] ? kthread_complete_and_exit (kernel/kthread.c:341) 
[ 310.062003][ C0] ret_from_fork (arch/x86/kernel/process.c:153) 
[ 310.062003][ C0] ? kthread_complete_and_exit (kernel/kthread.c:341) 
[ 310.062003][ C0] ret_from_fork_asm (arch/x86/entry/entry_32.S:741) 
[ 310.062003][ C0] entry_INT80_32 (arch/x86/entry/entry_32.S:947) 
[  315.849979][   T61] rcu-torture: rtc: (ptrval) ver: 5490 tfle: 0 rta: 5491 rtaf: 0 rtf: 5481 rtmbe: 0 rtmbkf: 0/0 rtbe: 0 rtbke: 0 rtbf: 0 rtb: 0 nt: 30811 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 read-exits: 224 nocb-toggles: 0:0
[  315.852036][   T61] rcu-torture: Reader Pipe:  50990989 932 0 0 0 0 0 0 0 0 0
[  315.852728][   T61] rcu-torture: Reader Batch:  50985846 6075 0 0 0 0 0 0 0 0 0
[  315.853487][   T61] rcu-torture: Free-Block Circulation:  5490 5489 5488 5487 5486 5485 5484 5483 5482 5481 0
[  315.854460][   T61] ??? Writer stall state RTWS_POLL_WAIT(17) g55465 f0x0 ->state 0x402 cpu 1
[  315.855292][   T61] task:rcu_torture_wri state:I stack:0     pid:55    tgid:55    ppid:2      flags:0x00004000
[  315.856251][   T61] Call Trace:
[ 315.856601][ T61] __schedule (kernel/sched/core.c:5379 kernel/sched/core.c:6688) 
[ 315.857054][ T61] schedule (arch/x86/include/asm/preempt.h:85 kernel/sched/core.c:6764 kernel/sched/core.c:6778) 
[ 315.857474][ T61] schedule_hrtimeout_range_clock (kernel/time/hrtimer.c:2308) 
[ 315.858071][ T61] ? __hrtimer_init (kernel/time/hrtimer.c:1938) 
[ 315.858559][ T61] schedule_hrtimeout (kernel/time/hrtimer.c:2390) 
[ 315.859032][ T61] torture_hrtimeout_ns (kernel/torture.c:99 (discriminator 4)) 
[ 315.859522][ T61] torture_hrtimeout_jiffies (kernel/torture.c:141) 
[ 315.860053][ T61] rcu_torture_writer (kernel/rcu/rcutorture.c:1502 (discriminator 3)) 
[ 315.860563][ T61] ? rcu_torture_pipe_update (kernel/rcu/rcutorture.c:1354) 
[ 315.861116][ T61] kthread (kernel/kthread.c:388) 
[ 315.861517][ T61] ? rcu_torture_pipe_update (kernel/rcu/rcutorture.c:1354) 
[ 315.862074][ T61] ? kthread_complete_and_exit (kernel/kthread.c:341) 
[ 315.862619][ T61] ret_from_fork (arch/x86/kernel/process.c:153) 
[ 315.863065][ T61] ? kthread_complete_and_exit (kernel/kthread.c:341) 
[ 315.863604][ T61] ret_from_fork_asm (arch/x86/entry/entry_32.S:741) 
[ 315.864075][ T61] entry_INT80_32 (arch/x86/entry/entry_32.S:947) 
[  315.864532][   T61] rcu: rcu_sched: wait state: RCU_GP_WAIT_FQS(5) ->state: 0x0 ->rt_priority 0 delta ->gp_start 27691 ->gp_activity 3 ->gp_req_activity 27691 ->gp_wake_time 1439 ->gp_wake_seq 55465 ->gp_seq 55465 ->gp_seq_needed 55472 ->gp_max 3132 ->gp_flags 0x0
[  315.866693][   T61] rcu: 	rcu_node 0:1 ->gp_seq 55465 ->gp_seq_needed 55472 ->qsmask 0x1 .... ->n_boosts 0
[  315.867624][   T61] rcu: 	cpu 0 ->gp_seq_needed 55472
[  315.868131][   T61] rcu: 	cpu 1 ->gp_seq_needed 55468
[  315.868644][   T61] rcu: RCU callbacks invoked since boot: 8906368
[  315.869246][   T61] rcu_tasks: RTGS_WAIT_CBS(11) since 78426 g:8 i:0/0 k.u. l:63
[  315.870003][   T61] rcu_tasks_rude: RTGS_WAIT_CBS(11) since 78454 g:8 i:0/3 k.u. l:63
[  315.870798][   T61] rcu_tasks_trace: RTGS_WAIT_CBS(11) since 78577 g:8 i:0/0 k.u. l:63 N0 h:0/0/0
[  315.871659][   T61] Dumping ftrace buffer:
[  315.872108][   T61]    (ftrace buffer empty)


The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20231212/202312121032.40bab6f5-oliver.sang@xxxxxxxxx



-- 
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki





[Index of Archives]     [Linux ARM Kernel]     [Linux ARM]     [Linux Omap]     [Fedora ARM]     [IETF Annouce]     [Bugtraq]     [Linux OMAP]     [Linux MIPS]     [eCos]     [Asterisk Internet PBX]     [Linux API]

  Powered by Linux