[<prev] [next>] [day] [month] [year] [list]
Message-ID: <202504071333.8dfe7122-lkp@intel.com>
Date: Mon, 7 Apr 2025 14:42:10 +0800
From: kernel test robot <oliver.sang@...el.com>
To: Guenter Roeck <linux@...ck-us.net>
CC: <oe-lkp@...ts.linux.dev>, <lkp@...el.com>, Andrew Morton
<akpm@...ux-foundation.org>, Alessandro Carminati <acarmina@...hat.com>,
Linux Kernel Functional Testing <lkft@...aro.org>, Dan Carpenter
<dan.carpenter@...aro.org>, Thomas Gleixner <tglx@...utronix.de>, Ingo Molnar
<mingo@...hat.com>, Borislav Petkov <bp@...en8.de>, Dave Hansen
<dave.hansen@...ux.intel.com>, Albert Ou <aou@...s.berkeley.edu>, "Alexander
Gordeev" <agordeev@...ux.ibm.com>, Arnd Bergmann <arnd@...db.de>, "Arthur
Grillo" <arthurgrillo@...eup.net>, Brendan Higgins
<brendan.higgins@...ux.dev>, Catalin Marinas <catalin.marinas@....com>,
Charlie Jenkins <charlie@...osinc.com>, Daniel Diaz <daniel.diaz@...aro.org>,
Daniel Vetter <daniel@...ll.ch>, Dave Airlie <airlied@...il.com>, David Gow
<davidgow@...gle.com>, Heiko Carstens <hca@...ux.ibm.com>, Helge Deller
<deller@....de>, Huacai Chen <chenhuacai@...nel.org>, Jani Nikula
<jani.nikula@...el.com>, John Paul Adrian Glaubitz
<glaubitz@...sik.fu-berlin.de>, Kees Cook <keescook@...omium.org>, "Maarten
Lankhorst" <maarten.lankhorst@...ux.intel.com>, MaĆra
Canal <mcanal@...lia.com>, Maxime Ripard <mripard@...nel.org>, Michael
Ellerman <mpe@...erman.id.au>, Naresh Kamboju <naresh.kamboju@...aro.org>,
"Palmer Dabbelt" <palmer@...belt.com>, Paul Walmsley
<paul.walmsley@...ive.com>, "Rae Moar" <rmoar@...gle.com>, Rich Felker
<dalias@...c.org>, Simon Horman <horms@...nel.org>, Thomas Zimemrmann
<tzimmermann@...e.de>, Vasily Gorbik <gor@...ux.ibm.com>, Ville Syrjala
<ville.syrjala@...ux.intel.com>, "Will Deacon" <will@...nel.org>, Yoshinori
Sato <ysato@...rs.sourceforge.jp>, <linux-kernel@...r.kernel.org>,
<oliver.sang@...el.com>
Subject: [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
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@...el.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
Powered by blists - more mailing lists