[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Message-ID: <202312121032.40bab6f5-oliver.sang@intel.com>
Date: Tue, 12 Dec 2023 13:04:54 +0800
From: kernel test robot <oliver.sang@...el.com>
To: Johannes Berg <johannes.berg@...el.com>
CC: <oe-lkp@...ts.linux.dev>, <lkp@...el.com>, Linux Memory Management List
<linux-mm@...ck.org>, Jakub Kicinski <kuba@...nel.org>, Jiri Pirko
<jiri@...dia.com>, <netdev@...r.kernel.org>, <oliver.sang@...el.com>
Subject: [linux-next:master] [net] b8dbbbc535:
INFO:rcu_sched_detected_stalls_on_CPUs/tasks
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@...el.com>
| Closes: https://lore.kernel.org/oe-lkp/202312121032.40bab6f5-oliver.sang@intel.com
[ 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@intel.com
--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki
Powered by blists - more mailing lists