Bug 214027

Summary:	[netconsole] WARNING: possible circular locking dependency detected
Product:	Networking	Reporter:	Erhard F. (erhard_f)
Component:	Other	Assignee:	Stephen Hemminger (stephen)
Status:	RESOLVED OBSOLETE
Severity:	normal
Priority:	P1
Hardware:	All
OS:	Linux
See Also:	https://bugzilla.kernel.org/show_bug.cgi?id=212509 https://bugzilla.kernel.org/show_bug.cgi?id=211575
Kernel Version:	5.14-rc5	Subsystem:
Regression:	No	Bisected commit-id:
Attachments:	kernel dmesg (kernel 5.14-rc5, AMD FX-8370) kernel .config (kernel 5.14-rc5, AMD FX-8370) kernel .config (kernel 5.14, AMD FX-8370) kernel dmesg (kernel 5.14, AMD FX-8370) kernel dmesg (kernel 5.15-rc1, AMD FX-8370) kernel .config (kernel 5.15-rc1, AMD FX-8370)

Description Erhard F. 2021-08-10 18:16:31 UTC

Created attachment 298261 [details]
kernel dmesg (kernel 5.14-rc5, AMD FX-8370)

Found this running a debug kernel. Not the 1st locking issue I encountered with netconsole (see bug #212509, bug #211575).

[...]
======================================================
WARNING: possible circular locking dependency detected
5.14.0-rc5-bdver2 #2 Not tainted
------------------------------------------------------
swapper/0/1 is trying to acquire lock:
ffffffffad47eb18 (once_lock){....}-{2:2}, at: __do_once_start+0x18/0xb0

but task is already holding lock:
ffffffffad54b5d8 (target_list_lock){....}-{2:2}, at: write_msg+0x85/0x210

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #2 (target_list_lock){....}-{2:2}:
       _raw_spin_lock_irqsave+0x36/0x50
       write_msg+0x85/0x210
       console_unlock+0x5a3/0x890
       register_console+0x343/0x5d0
       init_netconsole+0x644/0x931
       do_one_initcall+0xbb/0x3e0
       kernel_init_freeable+0x8ac/0x977
       kernel_init+0x14/0x120
       ret_from_fork+0x22/0x30

-> #1 (console_owner){-...}-{0:0}:
       console_unlock+0x295/0x890
       vprintk_emit+0x145/0x340
       printk+0xb2/0xe3
       alg_test.cold+0x6f/0x143
       cryptomgr_test+0x52/0x80
       kthread+0x342/0x410
       ret_from_fork+0x22/0x30

-> #0 (once_lock){....}-{2:2}:
       __lock_acquire+0x2966/0x5aa0
       lock_acquire+0x199/0x4b0
       _raw_spin_lock_irqsave+0x36/0x50
       __do_once_start+0x18/0xb0
       __skb_get_hash+0x19f/0x1f0
       netdev_pick_tx+0x751/0x850
       netdev_core_pick_tx+0x1f3/0x2a0
       netpoll_send_skb+0x342/0x7a0
       write_msg+0x185/0x210
       console_unlock+0x5a3/0x890
       register_console+0x343/0x5d0
       init_netconsole+0x644/0x931
       do_one_initcall+0xbb/0x3e0
       kernel_init_freeable+0x8ac/0x977
       kernel_init+0x14/0x120
       ret_from_fork+0x22/0x30

other info that might help us debug this:

Chain exists of:
  once_lock --> console_owner --> target_list_lock

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(target_list_lock);
                               lock(console_owner);
                               lock(target_list_lock);
  lock(once_lock);

 *** DEADLOCK ***

3 locks held by swapper/0/1:
 #0: ffffffffad2daf20 (console_lock){+.+.}-{0:0}, at: register_console+0x2a5/0x5d0
 #1: ffffffffad2a2b40 (console_owner){-...}-{0:0}, at: console_unlock+0x22c/0x890
 #2: ffffffffad54b5d8 (target_list_lock){....}-{2:2}, at: write_msg+0x85/0x210

stack backtrace:
CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.14.0-rc5-bdver2 #2
Hardware name: Gigabyte Technology Co., Ltd. To be filled by O.E.M./970-GAMING, BIOS F2 04/06/2016
Call Trace:
 dump_stack_lvl+0x57/0x7d
 check_noncircular+0x264/0x2f0
 ? print_circular_bug+0x470/0x470
 ? alloc_chain_hlocks+0x1ec/0x5b0
 __lock_acquire+0x2966/0x5aa0
 ? debug_check_no_locks_held+0xa0/0xa0
 lock_acquire+0x199/0x4b0
 ? __do_once_start+0x18/0xb0
 ? lock_release+0x6d0/0x6d0
 ? unwind_get_return_address_ptr+0xa0/0xa0
 ? __unwind_start+0x51b/0x7d0
 _raw_spin_lock_irqsave+0x36/0x50
 ? __do_once_start+0x18/0xb0
 __do_once_start+0x18/0xb0
 __skb_get_hash+0x19f/0x1f0
 ? __skb_flow_dissect+0x4d80/0x4d80
 ? __kmalloc_track_caller+0x206/0x3e0
 ? lock_downgrade+0x6e0/0x6e0
 netdev_pick_tx+0x751/0x850
 netdev_core_pick_tx+0x1f3/0x2a0
 ? __alloc_skb+0xbc/0x250
 netpoll_send_skb+0x342/0x7a0
 ? netpoll_send_udp+0x10b8/0x19f0
 ? lock_downgrade+0x6e0/0x6e0
 write_msg+0x185/0x210
 console_unlock+0x5a3/0x890
 ? devkmsg_read+0x670/0x670
 ? find_held_lock+0x2c/0x110
 ? lockdep_hardirqs_on_prepare+0x273/0x3e0
 ? _raw_spin_unlock_irqrestore+0x42/0x50
 register_console+0x343/0x5d0
 init_netconsole+0x644/0x931
 ? option_setup+0xaf/0xaf
 ? option_setup+0xaf/0xaf
 do_one_initcall+0xbb/0x3e0
 ? perf_trace_initcall_level+0x3e0/0x3e0
 ? parameq+0xd0/0xd0
 kernel_init_freeable+0x8ac/0x977
 ? rest_init+0x2e0/0x2e0
 kernel_init+0x14/0x120
 ret_from_fork+0x22/0x30
printk: console [netcon0] enabled
netconsole: network logging started
[...]


 $ inxi -bZ
System:    Kernel: 5.14.0-rc5-bdver2 x86_64 bits: 64 Desktop: MATE 1.24.1 Distro: Gentoo Base System release 2.7 
Machine:   Type: Desktop System: Gigabyte product: N/A v: N/A serial: <superuser/root required> 
           Mobo: Gigabyte model: 970-GAMING v: x.x serial: <superuser/root required> UEFI: American Megatrends v: F2 
           date: 04/06/2016 
CPU:       Info: 8-Core AMD FX-8370 [MCP] speed: 1727 MHz min/max: 1400/4000 MHz 
Graphics:  Device-1: Advanced Micro Devices [AMD/ATI] Navi 14 [Radeon RX 5500/5500M / Pro 5500M] driver: amdgpu v: kernel 
           Display: x11 server: X.Org 1.20.11 driver: amdgpu,ati unloaded: fbdev,modesetting,radeon resolution: 1920x1080~60Hz 
           OpenGL: renderer: Radeon RX 5500 XT (NAVI14 DRM 3.42.0 5.14.0-rc5-bdver2 LLVM 12.0.1) v: 4.6 Mesa 21.1.4 
Network:   Device-1: Qualcomm Atheros Killer E2400 Gigabit Ethernet driver: alx

Comment 1 Erhard F. 2021-08-10 18:19:11 UTC

Created attachment 298263 [details]
kernel .config (kernel 5.14-rc5, AMD FX-8370)

Comment 2 Erhard F. 2021-08-10 18:23:39 UTC

 $ lspci 
00:00.0 Host bridge: Advanced Micro Devices, Inc. [AMD/ATI] RD9x0/RX980 Host Bridge (rev 02)
00:00.2 IOMMU: Advanced Micro Devices, Inc. [AMD/ATI] RD890S/RD990 I/O Memory Management Unit (IOMMU)
00:02.0 PCI bridge: Advanced Micro Devices, Inc. [AMD/ATI] RD890/RD9x0/RX980 PCI to PCI bridge (PCI Express GFX port 0)
00:04.0 PCI bridge: Advanced Micro Devices, Inc. [AMD/ATI] RD890/RD9x0/RX980 PCI to PCI bridge (PCI Express GPP Port 0)
00:06.0 PCI bridge: Advanced Micro Devices, Inc. [AMD/ATI] RD890/RD9x0/RX980 PCI to PCI bridge (PCI Express GPP Port 2)
00:09.0 PCI bridge: Advanced Micro Devices, Inc. [AMD/ATI] RD890/RD9x0/RX980 PCI to PCI bridge (PCI Express GPP Port 4)
00:11.0 SATA controller: Advanced Micro Devices, Inc. [AMD/ATI] SB7x0/SB8x0/SB9x0 SATA Controller [AHCI mode] (rev 40)
00:12.0 USB controller: Advanced Micro Devices, Inc. [AMD/ATI] SB7x0/SB8x0/SB9x0 USB OHCI0 Controller
00:12.2 USB controller: Advanced Micro Devices, Inc. [AMD/ATI] SB7x0/SB8x0/SB9x0 USB EHCI Controller
00:13.0 USB controller: Advanced Micro Devices, Inc. [AMD/ATI] SB7x0/SB8x0/SB9x0 USB OHCI0 Controller
00:13.2 USB controller: Advanced Micro Devices, Inc. [AMD/ATI] SB7x0/SB8x0/SB9x0 USB EHCI Controller
00:14.0 SMBus: Advanced Micro Devices, Inc. [AMD/ATI] SBx00 SMBus Controller (rev 42)
00:14.2 Audio device: Advanced Micro Devices, Inc. [AMD/ATI] SBx00 Azalia (Intel HDA) (rev 40)
00:14.3 ISA bridge: Advanced Micro Devices, Inc. [AMD/ATI] SB7x0/SB8x0/SB9x0 LPC host controller (rev 40)
00:14.4 PCI bridge: Advanced Micro Devices, Inc. [AMD/ATI] SBx00 PCI to PCI Bridge (rev 40)
00:14.5 USB controller: Advanced Micro Devices, Inc. [AMD/ATI] SB7x0/SB8x0/SB9x0 USB OHCI2 Controller
00:15.0 PCI bridge: Advanced Micro Devices, Inc. [AMD/ATI] SB700/SB800/SB900 PCI to PCI bridge (PCIE port 0)
00:16.0 USB controller: Advanced Micro Devices, Inc. [AMD/ATI] SB7x0/SB8x0/SB9x0 USB OHCI0 Controller
00:16.2 USB controller: Advanced Micro Devices, Inc. [AMD/ATI] SB7x0/SB8x0/SB9x0 USB EHCI Controller
00:18.0 Host bridge: Advanced Micro Devices, Inc. [AMD] Family 15h Processor Function 0
00:18.1 Host bridge: Advanced Micro Devices, Inc. [AMD] Family 15h Processor Function 1
00:18.2 Host bridge: Advanced Micro Devices, Inc. [AMD] Family 15h Processor Function 2
00:18.3 Host bridge: Advanced Micro Devices, Inc. [AMD] Family 15h Processor Function 3
00:18.4 Host bridge: Advanced Micro Devices, Inc. [AMD] Family 15h Processor Function 4
00:18.5 Host bridge: Advanced Micro Devices, Inc. [AMD] Family 15h Processor Function 5
01:00.0 PCI bridge: Advanced Micro Devices, Inc. [AMD/ATI] Navi 10 XL Upstream Port of PCI Express Switch (rev c5)
02:00.0 PCI bridge: Advanced Micro Devices, Inc. [AMD/ATI] Navi 10 XL Downstream Port of PCI Express Switch
03:00.0 VGA compatible controller: Advanced Micro Devices, Inc. [AMD/ATI] Navi 14 [Radeon RX 5500/5500M / Pro 5500M] (rev c5)
03:00.1 Audio device: Advanced Micro Devices, Inc. [AMD/ATI] Navi 10 HDMI Audio
04:00.0 USB controller: Renesas Technology Corp. uPD720201 USB 3.0 Host Controller (rev 03)
05:00.0 Non-Volatile memory controller: Shenzhen Longsys Electronics Co., Ltd. Device 2263 (rev 03)
06:00.0 USB controller: ASMedia Technology Inc. ASM1143 USB 3.1 Host Controller
08:00.0 Ethernet controller: Qualcomm Atheros Killer E2400 Gigabit Ethernet Controller (rev 10)

Comment 3 Erhard F. 2021-08-30 13:52:51 UTC

Created attachment 298531 [details]
kernel .config (kernel 5.14, AMD FX-8370)

Comment 4 Erhard F. 2021-08-30 13:54:15 UTC

Created attachment 298533 [details]
kernel dmesg (kernel 5.14, AMD FX-8370)

Comment 5 Erhard F. 2021-08-30 13:55:19 UTC

[...]
stack backtrace:
CPU: 7 PID: 1 Comm: swapper/0 Not tainted 5.14.0-bdver2 #4
Hardware name: Gigabyte Technology Co., Ltd. To be filled by O.E.M./970-GAMING, BIOS F2 04/06/2016
Call Trace:
 dump_stack_lvl+0x57/0x7d
 check_noncircular+0x264/0x2f0
 ? print_circular_bug+0x470/0x470
 ? alloc_chain_hlocks+0x1ec/0x5b0
 __lock_acquire+0x2966/0x5aa0
 ? debug_check_no_locks_held+0xa0/0xa0
 lock_acquire+0x199/0x4b0
 ? __do_once_start+0x18/0xb0
 ? lock_release+0x6d0/0x6d0
 ? unwind_get_return_address_ptr+0xa0/0xa0
 ? __unwind_start+0x51b/0x7d0
 _raw_spin_lock_irqsave+0x36/0x50
 ? __do_once_start+0x18/0xb0
 __do_once_start+0x18/0xb0
 __skb_get_hash+0x19f/0x1f0
 ? __skb_flow_dissect+0x4d80/0x4d80
 ? __kmalloc_track_caller+0x206/0x3e0
 ? lock_downgrade+0x6e0/0x6e0
 netdev_pick_tx+0x751/0x850
 netdev_core_pick_tx+0x1f3/0x2a0
 ? __alloc_skb+0xbc/0x250
 netpoll_send_skb+0x342/0x7a0
 ? netpoll_send_udp+0x10b8/0x19f0
 ? lock_downgrade+0x6e0/0x6e0
 write_msg+0x185/0x210
 console_unlock+0x5a3/0x890
 ? devkmsg_read+0x670/0x670
 ? find_held_lock+0x2c/0x110
 ? lockdep_hardirqs_on_prepare+0x273/0x3e0
 ? _raw_spin_unlock_irqrestore+0x42/0x50
 register_console+0x343/0x5d0
 init_netconsole+0x645/0x931
 ? option_setup+0xaf/0xaf
 ? option_setup+0xaf/0xaf
 do_one_initcall+0xbb/0x3e0
 ? perf_trace_initcall_level+0x3e0/0x3e0
 ? parameq+0xd0/0xd0
 kernel_init_freeable+0x8b3/0x97f
 ? rest_init+0x2e0/0x2e0
 kernel_init+0x14/0x120
 ret_from_fork+0x22/0x30
printk: console [netcon0] enabled
netconsole: network logging started
[...]

Comment 6 Erhard F. 2021-09-13 19:46:26 UTC

Created attachment 298779 [details]
kernel dmesg (kernel 5.15-rc1, AMD FX-8370)

Unchanged in 5.15-rc1.

[...]
stack backtrace:
CPU: 5 PID: 1 Comm: swapper/0 Not tainted 5.15.0-rc1-bdver2 #4
Hardware name: Gigabyte Technology Co., Ltd. To be filled by O.E.M./970-GAMING, BIOS F2 04/06/2016
Call Trace:
 dump_stack_lvl+0x57/0x7d
 check_noncircular+0x264/0x2f0
 ? print_circular_bug+0x470/0x470
 ? alloc_chain_hlocks+0x1ec/0x5b0
 __lock_acquire+0x2966/0x5aa0
 ? debug_check_no_locks_held+0xa0/0xa0
 lock_acquire+0x199/0x4b0
 ? __do_once_start+0x18/0xb0
 ? lock_release+0x6d0/0x6d0
 ? unwind_get_return_address_ptr+0xa0/0xa0
 ? __unwind_start+0x51b/0x7d0
 _raw_spin_lock_irqsave+0x36/0x50
 ? __do_once_start+0x18/0xb0
 __do_once_start+0x18/0xb0
 __skb_get_hash+0x19f/0x1f0
 ? __skb_flow_dissect+0x4db0/0x4db0
 ? __kmalloc_track_caller+0x205/0x3f0
 ? lock_downgrade+0x6e0/0x6e0
 netdev_pick_tx+0x751/0x850
 netdev_core_pick_tx+0x1f3/0x2a0
 netpoll_send_skb+0x342/0x7a0
 ? netpoll_send_udp+0x10b8/0x19f0
 ? lock_downgrade+0x6e0/0x6e0
 write_msg+0x185/0x210
 console_unlock+0x55d/0x830
 ? devkmsg_read+0x670/0x670
 ? lockdep_hardirqs_on_prepare+0x273/0x3e0
 register_console+0x343/0x5c0
 init_netconsole+0x645/0x932
 ? option_setup+0xaf/0xaf
 ? debugfs_create_dir+0x2a3/0x410
 ? option_setup+0xaf/0xaf
 do_one_initcall+0xbb/0x3e0
 ? perf_trace_initcall_level+0x3e0/0x3e0
 ? parameq+0xd0/0xd0
 kernel_init_freeable+0x8ab/0x977
 ? rest_init+0x2e0/0x2e0
 kernel_init+0x14/0x120
 ret_from_fork+0x22/0x30
printk: console [netcon0] enabled
netconsole: network logging started
[...]

Comment 7 Erhard F. 2021-09-13 19:47:04 UTC

Created attachment 298781 [details]
kernel .config (kernel 5.15-rc1, AMD FX-8370)

Comment 8 Erhard F. 2022-09-14 19:49:07 UTC

Have not seen this on 5.18.x, 5.19.x nor on 6.0-rc on any of my affected systems. I think it's safe to close here.