* [linux-next:master] [x86] 61aa5e5dd7: WARNING:possible_circular_locking_dependency_detected_trinity-main_is_trying_to_acquire_lock:at:__perf_event_task_sched_out_but_task_is_already_holding_lock:at:rq_lock
@ 2025-04-07 6:42 kernel test robot
0 siblings, 0 replies; only message in thread
From: kernel test robot @ 2025-04-07 6:42 UTC (permalink / raw)
To: Guenter Roeck
Cc: oe-lkp, lkp, Andrew Morton, Alessandro Carminati,
Linux Kernel Functional Testing, Dan Carpenter, Thomas Gleixner,
Ingo Molnar, Borislav Petkov, Dave Hansen, Albert Ou,
Alexander Gordeev, Arnd Bergmann, Arthur Grillo, Brendan Higgins,
Catalin Marinas, Charlie Jenkins, Daniel Diaz, Daniel Vetter,
Dave Airlie, David Gow, Heiko Carstens, Helge Deller, Huacai Chen,
Jani Nikula, John Paul Adrian Glaubitz, Kees Cook,
Maarten Lankhorst, Maíra Canal, Maxime Ripard,
Michael Ellerman, Naresh Kamboju, Palmer Dabbelt, Paul Walmsley,
Rae Moar, Rich Felker, Simon Horman, Thomas Zimemrmann,
Vasily Gorbik, Ville Syrjala, Will Deacon, Yoshinori Sato,
linux-kernel, oliver.sang
hi, Guenter Roeck and all,
this report is just FYI that we noticed a WARNING in our tests. it seems the
WARNING detail stat has changed due to this commit. in case it can supply any
hint to solve any real issues.
b6632ab0d524b989 61aa5e5dd770fab2eecb38e21f7
---------------- ---------------------------
fail:runs %reproduction fail:runs
| | |
6:6 -100% :6 dmesg.WARNING:possible_circular_locking_dependency_detected_trinity-main_is_trying_to_acquire_lock:at:__perf_event_task_sched_out_but_task_is_already_holding_lock:at:__schedule
:6 100% 6:6 dmesg.WARNING:possible_circular_locking_dependency_detected_trinity-main_is_trying_to_acquire_lock:at:__perf_event_task_sched_out_but_task_is_already_holding_lock:at:rq_lock
Hello,
kernel test robot noticed "WARNING:possible_circular_locking_dependency_detected_trinity-main_is_trying_to_acquire_lock:at:__perf_event_task_sched_out_but_task_is_already_holding_lock:at:rq_lock" on:
commit: 61aa5e5dd770fab2eecb38e21f71ca17f5b54401 ("x86: add support for suppressing warning backtraces")
https://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git master
[test failed on linux-next/master a4cda136f021ad44b8b52286aafd613030a6db5f]
in testcase: trinity
version: trinity-i386-abe9de86-1_20230429
with following parameters:
runtime: 300s
group: group-03
nr_groups: 5
config: x86_64-randconfig-102-20250402
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@intel.com>
| Closes: https://lore.kernel.org/oe-lkp/202504071333.8dfe7122-lkp@intel.com
The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20250407/202504071333.8dfe7122-lkp@intel.com
[ 165.999666][ T3622] ======================================================
[ 166.000259][ T3622] WARNING: possible circular locking dependency detected
[ 166.000873][ T3622] 6.14.0-12166-g61aa5e5dd770 #1 Not tainted
[ 166.001389][ T3622] ------------------------------------------------------
[ 166.001976][ T3622] trinity-main/3622 is trying to acquire lock:
[ 166.002468][ T3622] ffff88818f8d2018 (&ctx->lock){....}-{2:2}, at: __perf_event_task_sched_out+0x43b/0x580
[ 166.003273][ T3622]
[ 166.003273][ T3622] but task is already holding lock:
[ 166.003862][ T3622] ffff8883aee349d8 (&rq->__lock){-.-.}-{2:2}, at: rq_lock+0x130/0x2b0
[ 166.004586][ T3622]
[ 166.004586][ T3622] which lock already depends on the new lock.
[ 166.004586][ T3622]
[ 166.005480][ T3622]
[ 166.005480][ T3622] the existing dependency chain (in reverse order) is:
[ 166.006251][ T3622]
[ 166.006251][ T3622] -> #5 (&rq->__lock){-.-.}-{2:2}:
[ 166.006909][ T3622] _raw_spin_lock_nested+0x2e/0x40
[ 166.007382][ T3622] __task_rq_lock+0x1e4/0x590
[ 166.007822][ T3622] wake_up_new_task+0x544/0xb30
[ 166.008447][ T3622] kernel_clone+0x28d/0x490
[ 166.009638][ T3622] user_mode_thread+0x5f/0x80
[ 166.010918][ T3622] rest_init+0x23/0x250
[ 166.011334][ T3622] start_kernel+0x38d/0x3f0
[ 166.011782][ T3622] x86_64_start_reservations+0x2a/0x30
[ 166.012327][ T3622] x86_64_start_kernel+0x66/0x70
[ 166.012615][ T3622] common_startup_64+0x129/0x137
[ 166.012941][ T3622]
[ 166.012941][ T3622] -> #4 (&p->pi_lock){-.-.}-{2:2}:
[ 166.013317][ T3622] _raw_spin_lock_irqsave+0x51/0x70
[ 166.013614][ T3622] try_to_wake_up+0x5e/0x1140
[ 166.013869][ T3622] __wake_up_common_lock+0x13c/0x1f0
[ 166.014156][ T3622] tty_port_default_wakeup+0x8b/0xc0
[ 166.014442][ T3622] serial8250_tx_chars+0x2e2/0x8d0
[ 166.014716][ T3622] serial8250_handle_irq+0x3d7/0x850
[ 166.015000][ T3622] serial8250_interrupt+0x88/0x110
[ 166.015274][ T3622] __handle_irq_event_percpu+0x1e2/0x540
[ 166.015574][ T3622] handle_irq_event+0x8b/0x1c0
[ 166.015836][ T3622] handle_edge_irq+0x1f7/0x940
[ 166.016098][ T3622] __common_interrupt+0xbd/0x160
[ 166.016637][ T3622] common_interrupt+0x7c/0x90
[ 166.017043][ T3622] asm_common_interrupt+0x26/0x40
[ 166.017313][ T3622] default_idle+0x16/0x20
[ 166.017552][ T3622] default_idle_call+0x7b/0xc0
[ 166.017915][ T3622] do_idle+0x107/0x2e0
[ 166.018296][ T3622] cpu_startup_entry+0x49/0x70
[ 166.018728][ T3622] start_secondary+0x101/0x110
[ 166.019151][ T3622] common_startup_64+0x129/0x137
[ 166.019518][ T3622]
[ 166.019518][ T3622] -> #3 (&tty->write_wait){-.-.}-{3:3}:
[ 166.019897][ T3622] _raw_spin_lock_irqsave+0x51/0x70
[ 166.020174][ T3622] __wake_up_common_lock+0x34/0x1f0
[ 166.020486][ T3622] tty_port_default_wakeup+0x8b/0xc0
[ 166.020786][ T3622] serial8250_tx_chars+0x2e2/0x8d0
[ 166.021071][ T3622] serial8250_handle_irq+0x3d7/0x850
[ 166.021373][ T3622] serial8250_interrupt+0x88/0x110
[ 166.021648][ T3622] __handle_irq_event_percpu+0x1e2/0x540
[ 166.021950][ T3622] handle_irq_event+0x8b/0x1c0
[ 166.022207][ T3622] handle_edge_irq+0x1f7/0x940
[ 166.022469][ T3622] __common_interrupt+0xbd/0x160
[ 166.022734][ T3622] common_interrupt+0x7c/0x90
[ 166.022989][ T3622] asm_common_interrupt+0x26/0x40
[ 166.023342][ T3622] _raw_spin_unlock_irqrestore+0x3d/0x50
[ 166.023866][ T3622] uart_write+0x411/0x9c0
[ 166.024318][ T3622] do_output_char+0x44d/0x7f0
[ 166.024782][ T3622] n_tty_write+0xd6c/0x1060
[ 166.025209][ T3622] file_tty_write+0x4a9/0x860
[ 166.025654][ T3622] do_iter_readv_writev+0x378/0x520
[ 166.026136][ T3622] vfs_writev+0x23a/0x7f0
[ 166.026537][ T3622] do_writev+0xad/0x130
[ 166.026947][ T3622] __do_fast_syscall_32+0xcf/0x110
[ 166.027418][ T3622] do_fast_syscall_32+0x34/0x80
[ 166.027846][ T3622] entry_SYSENTER_compat_after_hwframe+0x83/0x8d
[ 166.028419][ T3622]
[ 166.028419][ T3622] -> #2 (&port_lock_key){-.-.}-{3:3}:
[ 166.029069][ T3622] _raw_spin_lock_irqsave+0x51/0x70
[ 166.029560][ T3622] serial8250_console_write+0xc4/0x1560
[ 166.030043][ T3622] console_flush_all+0x483/0x870
[ 166.030500][ T3622] console_unlock+0x76/0x180
[ 166.030932][ T3622] vprintk_emit+0x44f/0x670
[ 166.031337][ T3622] _printk+0x6c/0x80
[ 166.031726][ T3622] register_console+0x6b5/0xcc0
[ 166.032177][ T3622] univ8250_console_init+0x3f/0x80
[ 166.032676][ T3622] console_init+0x138/0x2c0
[ 166.033133][ T3622] start_kernel+0x25f/0x3f0
[ 166.033592][ T3622] x86_64_start_reservations+0x2a/0x30
[ 166.034131][ T3622] x86_64_start_kernel+0x66/0x70
[ 166.034629][ T3622] common_startup_64+0x129/0x137
[ 166.035118][ T3622]
[ 166.035118][ T3622] -> #1 (console_owner){-.-.}-{0:0}:
[ 166.035793][ T3622] console_flush_all+0x426/0x870
[ 166.036295][ T3622] console_unlock+0x76/0x180
[ 166.036743][ T3622] vprintk_emit+0x44f/0x670
[ 166.037179][ T3622] _printk+0x6c/0x80
[ 166.037567][ T3622] ubsan_prologue+0x24/0x50
[ 166.038003][ T3622] handle_overflow+0xcd/0x120
[ 166.038471][ T3622] visit_groups_merge+0x1719/0x1770
[ 166.038976][ T3622] __pmu_ctx_sched_in+0x91/0xb0
[ 166.039446][ T3622] ctx_sched_in+0x322/0x430
[ 166.039895][ T3622] ctx_resched+0x37f/0x630
[ 166.040337][ T3622] __perf_install_in_context+0x645/0x880
[ 166.040865][ T3622] remote_function+0xd3/0x150
[ 166.041306][ T3622] generic_exec_single+0x10e/0x2e0
[ 166.041787][ T3622] smp_call_function_single+0xdf/0x260
[ 166.042316][ T3622] perf_install_in_context+0x3c7/0x610
[ 166.042851][ T3622] __se_sys_perf_event_open+0xe3d/0x1540
[ 166.043401][ T3622] __do_fast_syscall_32+0xcf/0x110
[ 166.043883][ T3622] do_fast_syscall_32+0x34/0x80
[ 166.044374][ T3622] entry_SYSENTER_compat_after_hwframe+0x83/0x8d
[ 166.044982][ T3622]
[ 166.044982][ T3622] -> #0 (&ctx->lock){....}-{2:2}:
[ 166.045632][ T3622] __lock_acquire+0x19bb/0x3010
[ 166.046075][ T3622] lock_acquire+0xe3/0x200
[ 166.046492][ T3622] _raw_spin_lock+0x30/0x40
[ 166.046920][ T3622] __perf_event_task_sched_out+0x43b/0x580
[ 166.047448][ T3622] __schedule+0x1a09/0x4350
[ 166.047868][ T3622] schedule+0x16d/0x370
[ 166.048279][ T3622] syscall_exit_to_user_mode+0x66/0xf0
[ 166.048786][ T3622] __do_fast_syscall_32+0xdb/0x110
[ 166.049282][ T3622] do_fast_syscall_32+0x34/0x80
[ 166.049741][ T3622] entry_SYSENTER_compat_after_hwframe+0x83/0x8d
[ 166.050331][ T3622]
[ 166.050331][ T3622] other info that might help us debug this:
[ 166.050331][ T3622]
[ 166.051200][ T3622] Chain exists of:
[ 166.051200][ T3622] &ctx->lock --> &p->pi_lock --> &rq->__lock
[ 166.051200][ T3622]
[ 166.052211][ T3622] Possible unsafe locking scenario:
[ 166.052211][ T3622]
[ 166.052817][ T3622] CPU0 CPU1
[ 166.053259][ T3622] ---- ----
[ 166.053705][ T3622] lock(&rq->__lock);
[ 166.054057][ T3622] lock(&p->pi_lock);
[ 166.054587][ T3622] lock(&rq->__lock);
[ 166.055116][ T3622] lock(&ctx->lock);
[ 166.055448][ T3622]
[ 166.055448][ T3622] *** DEADLOCK ***
[ 166.055448][ T3622]
[ 166.056101][ T3622] 1 lock held by trinity-main/3622:
[ 166.056546][ T3622] #0: ffff8883aee349d8 (&rq->__lock){-.-.}-{2:2}, at: rq_lock+0x130/0x2b0
[ 166.057288][ T3622]
[ 166.057288][ T3622] stack backtrace:
[ 166.057796][ T3622] CPU: 0 UID: 65534 PID: 3622 Comm: trinity-main Not tainted 6.14.0-12166-g61aa5e5dd770 #1 PREEMPT(undef)
[ 166.057804][ T3622] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
[ 166.057808][ T3622] Call Trace:
[ 166.057813][ T3622] <TASK>
[ 166.057818][ T3622] dump_stack_lvl+0x69/0x90
[ 166.057829][ T3622] print_circular_bug+0x2ed/0x300
[ 166.057841][ T3622] check_noncircular+0x115/0x130
[ 166.057851][ T3622] __lock_acquire+0x19bb/0x3010
[ 166.057859][ T3622] ? __update_load_avg_se+0x7cb/0xcc0
[ 166.057873][ T3622] ? update_load_avg+0x54d/0x17b0
[ 166.057880][ T3622] lock_acquire+0xe3/0x200
[ 166.057886][ T3622] ? __perf_event_task_sched_out+0x43b/0x580
[ 166.057898][ T3622] _raw_spin_lock+0x30/0x40
[ 166.057906][ T3622] ? __perf_event_task_sched_out+0x43b/0x580
[ 166.057911][ T3622] __perf_event_task_sched_out+0x43b/0x580
[ 166.057919][ T3622] ? lock_is_held_type+0x8a/0x120
[ 166.057930][ T3622] __schedule+0x1a09/0x4350
[ 166.057938][ T3622] ? schedule+0x16d/0x370
[ 166.057944][ T3622] ? __se_sys_perf_event_open+0xf79/0x1540
[ 166.057956][ T3622] schedule+0x16d/0x370
[ 166.057963][ T3622] syscall_exit_to_user_mode+0x66/0xf0
[ 166.057970][ T3622] __do_fast_syscall_32+0xdb/0x110
[ 166.057976][ T3622] ? __se_sys_perf_event_open+0x4e/0x1540
[ 166.057982][ T3622] ? __do_fast_syscall_32+0xdb/0x110
[ 166.057989][ T3622] ? syscall_exit_to_user_mode+0xc1/0xf0
[ 166.057998][ T3622] ? __do_fast_syscall_32+0xdb/0x110
[ 166.058004][ T3622] ? __do_fast_syscall_32+0xdb/0x110
[ 166.058008][ T3622] ? __do_fast_syscall_32+0xdb/0x110
[ 166.058016][ T3622] do_fast_syscall_32+0x34/0x80
[ 166.058021][ T3622] entry_SYSENTER_compat_after_hwframe+0x83/0x8d
[ 166.058028][ T3622] RIP: 0023:0xf7f19539
[ 166.058035][ T3622] Code: 03 74 b4 01 10 07 03 74 b0 01 10 08 03 74 d8 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 51 52 55 89 e5 0f 34 cd 80 <5d> 5a 59 c3 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90
[ 166.058040][ T3622] RSP: 002b:00000000ffcfef6c EFLAGS: 00000206 ORIG_RAX: 0000000000000150
[ 166.058046][ T3622] RAX: 000000000000011b RBX: 0000000057146ae0 RCX: 0000000000000e26
[ 166.058050][ T3622] RDX: 00000000ffffffff RSI: 00000000ffffffff RDI: 0000000000000002
[ 166.058052][ T3622] RBP: 00000000f7d3f525 R08: 0000000000000000 R09: 0000000000000000
[ 166.058055][ T3622] R10: 0000000000000000 R11: 0000000000000206 R12: 0000000000000000
[ 166.058058][ T3622] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[ 166.058067][ T3622] </TASK>
[ 166.143279][ T3622] UDPLite: UDP-Lite is deprecated and scheduled to be removed in 2025, please contact the netdev mailing list
[ 166.157355][ T3622] UDPLite6: UDP-Lite is deprecated and scheduled to be removed in 2025, please contact the netdev mailing list
--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki
^ permalink raw reply [flat|nested] only message in thread
only message in thread, other threads:[~2025-04-07 6:42 UTC | newest]
Thread overview: (only message) (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2025-04-07 6:42 [linux-next:master] [x86] 61aa5e5dd7: WARNING:possible_circular_locking_dependency_detected_trinity-main_is_trying_to_acquire_lock:at:__perf_event_task_sched_out_but_task_is_already_holding_lock:at:rq_lock kernel test robot
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.