[Linux 4.2-rc8+] circular locking dependency detected: [pppd] ppp_dev_uninit() | rtnl_lock()

From: Sedat Dilek
Date: Tue Sep 01 2015 - 11:44:46 EST

Next message: Tony Lindgren: "Re: [PATCH] arm: omap2: vc: fix 'or' always true warning"
Previous message: Vitaly Kuznetsov: "Re: [PATCH] scsi_scan: move 'INQUIRY result too short' message to debug level"
Next in thread: Sedat Dilek: "Re: [Linux 4.2-rc8+] circular locking dependency detected: [pppd] ppp_dev_uninit() | rtnl_lock()"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

Hi,

I am here on Ubuntu/precise AMD64 and using
NetworkManager/ModemManager with a UMTS/HSPA modem Internet
connection.

I see and saw this especially when doing a power-off of my machine
(4.2-rc8 and 4.2 final seems to be affected)...

[ /var/log/kern.log.1 ]

Aug 31 20:56:59 fambox kernel: [ 293.301315]
Aug 31 20:56:59 fambox kernel: [ 293.301320]
======================================================
Aug 31 20:56:59 fambox kernel: [ 293.301323] [ INFO: possible
circular locking dependency detected ]
Aug 31 20:56:59 fambox kernel: [ 293.301327] 4.2.0-rc8-1-iniza-small
#1 Not tainted
Aug 31 20:56:59 fambox kernel: [ 293.301329]
-------------------------------------------------------
Aug 31 20:56:59 fambox kernel: [ 293.301331] pppd/2594 is trying to
acquire lock:
Aug 31 20:56:59 fambox kernel: [ 293.301334]
(&pn->all_ppp_mutex){+.+.+.}, at: [<ffffffff815dcb32>]
ppp_dev_uninit+0x112/0x200
Aug 31 20:56:59 fambox kernel: [ 293.301347]
Aug 31 20:56:59 fambox kernel: [ 293.301347] but task is already holding lock:
Aug 31 20:56:59 fambox kernel: [ 293.301349] (rtnl_mutex){+.+.+.},
at: [<ffffffff816d6757>] rtnl_lock+0x17/0x20
Aug 31 20:56:59 fambox kernel: [ 293.301358]
Aug 31 20:56:59 fambox kernel: [ 293.301358] which lock already
depends on the new lock.
Aug 31 20:56:59 fambox kernel: [ 293.301358]
Aug 31 20:56:59 fambox kernel: [ 293.301361]
Aug 31 20:56:59 fambox kernel: [ 293.301361] the existing dependency
chain (in reverse order) is:
Aug 31 20:56:59 fambox kernel: [ 293.301364]
Aug 31 20:56:59 fambox kernel: [ 293.301364] -> #1 (rtnl_mutex){+.+.+.}:
Aug 31 20:56:59 fambox kernel: [ 293.301369]
[<ffffffff810da50f>] lock_acquire+0xcf/0x280
Aug 31 20:56:59 fambox kernel: [ 293.301375]
[<ffffffff817d4515>] mutex_lock_nested+0x65/0x3c0
Aug 31 20:56:59 fambox kernel: [ 293.301382]
[<ffffffff816d6757>] rtnl_lock+0x17/0x20
Aug 31 20:56:59 fambox kernel: [ 293.301385]
[<ffffffff816c9fd6>] register_netdev+0x16/0x30
Aug 31 20:56:59 fambox kernel: [ 293.301391]
[<ffffffff815df4bf>] ppp_ioctl+0xfcf/0x13a0
Aug 31 20:56:59 fambox kernel: [ 293.301395]
[<ffffffff8122f601>] do_vfs_ioctl+0x301/0x560
Aug 31 20:56:59 fambox kernel: [ 293.301400]
[<ffffffff8122f8d9>] SyS_ioctl+0x79/0x90
Aug 31 20:56:59 fambox kernel: [ 293.301403]
[<ffffffff817d90f2>] entry_SYSCALL_64_fastpath+0x16/0x7a
Aug 31 20:56:59 fambox kernel: [ 293.301408]
Aug 31 20:56:59 fambox kernel: [ 293.301408] -> #0
(&pn->all_ppp_mutex){+.+.+.}:
Aug 31 20:56:59 fambox kernel: [ 293.301415]
[<ffffffff810d983d>] __lock_acquire+0x1f5d/0x21c0
Aug 31 20:56:59 fambox kernel: [ 293.301419]
[<ffffffff810da50f>] lock_acquire+0xcf/0x280
Aug 31 20:56:59 fambox kernel: [ 293.301422]
[<ffffffff817d4515>] mutex_lock_nested+0x65/0x3c0
Aug 31 20:56:59 fambox kernel: [ 293.301427]
[<ffffffff815dcb32>] ppp_dev_uninit+0x112/0x200
Aug 31 20:56:59 fambox kernel: [ 293.301431]
[<ffffffff816bf84b>] rollback_registered_many+0x18b/0x2f0
Aug 31 20:56:59 fambox kernel: [ 293.301436]
[<ffffffff816bf9dd>] rollback_registered+0x2d/0x40
Aug 31 20:56:59 fambox kernel: [ 293.301439]
[<ffffffff816c0955>] unregister_netdevice_queue+0x55/0xc0
Aug 31 20:56:59 fambox kernel: [ 293.301444]
[<ffffffff815db928>] ppp_release+0x88/0x90
Aug 31 20:56:59 fambox kernel: [ 293.301448]
[<ffffffff8121bc0f>] __fput+0xef/0x200
Aug 31 20:56:59 fambox kernel: [ 293.301452]
[<ffffffff8121bd6e>] ____fput+0xe/0x10
Aug 31 20:56:59 fambox kernel: [ 293.301455]
[<ffffffff810a32dd>] task_work_run+0x8d/0xc0
Aug 31 20:56:59 fambox kernel: [ 293.301462]
[<ffffffff8101c04c>] do_notify_resume+0x7c/0x90
Aug 31 20:56:59 fambox kernel: [ 293.301467]
[<ffffffff817d92ee>] int_signal+0x12/0x17
Aug 31 20:56:59 fambox kernel: [ 293.301471]
Aug 31 20:56:59 fambox kernel: [ 293.301471] other info that might
help us debug this:
Aug 31 20:56:59 fambox kernel: [ 293.301471]
Aug 31 20:56:59 fambox kernel: [ 293.301475] Possible unsafe locking scenario:
Aug 31 20:56:59 fambox kernel: [ 293.301475]
Aug 31 20:56:59 fambox kernel: [ 293.301477] CPU0
CPU1
Aug 31 20:56:59 fambox kernel: [ 293.301479] ----
----
Aug 31 20:56:59 fambox kernel: [ 293.301481] lock(rtnl_mutex);
Aug 31 20:56:59 fambox kernel: [ 293.301484]
lock(&pn->all_ppp_mutex);
Aug 31 20:56:59 fambox kernel: [ 293.301487]
lock(rtnl_mutex);
Aug 31 20:56:59 fambox kernel: [ 293.301491] lock(&pn->all_ppp_mutex);
Aug 31 20:56:59 fambox kernel: [ 293.301494]
Aug 31 20:56:59 fambox kernel: [ 293.301494] *** DEADLOCK ***
Aug 31 20:56:59 fambox kernel: [ 293.301494]
Aug 31 20:56:59 fambox kernel: [ 293.301498] 1 lock held by pppd/2594:
Aug 31 20:56:59 fambox kernel: [ 293.301500] #0:
(rtnl_mutex){+.+.+.}, at: [<ffffffff816d6757>] rtnl_lock+0x17/0x20
Aug 31 20:56:59 fambox kernel: [ 293.301507]
Aug 31 20:56:59 fambox kernel: [ 293.301507] stack backtrace:
Aug 31 20:56:59 fambox kernel: [ 293.301511] CPU: 0 PID: 2594 Comm:
pppd Not tainted 4.2.0-rc8-1-iniza-small #1
Aug 31 20:56:59 fambox kernel: [ 293.301514] Hardware name: SAMSUNG
ELECTRONICS CO., LTD. 530U3BI/530U4BI/530U4BH/530U3BI/530U4BI/530U4BH,
BIOS 13XK 03/28/2013
Aug 31 20:56:59 fambox kernel: [ 293.301517] ffffffff826debb0
ffff880060b57b78 ffffffff817cef33 0000000000000011
Aug 31 20:56:59 fambox kernel: [ 293.301522] ffffffff826debb0
ffff880060b57bc8 ffffffff817cc41e ffffffff826ded60
Aug 31 20:56:59 fambox kernel: [ 293.301527] ffff880060b57c38
ffff88008f034f58 0000000000000001 ffff88008f034f58
Aug 31 20:56:59 fambox kernel: [ 293.301533] Call Trace:
Aug 31 20:56:59 fambox kernel: [ 293.301538] [<ffffffff817cef33>]
dump_stack+0x4c/0x65
Aug 31 20:56:59 fambox kernel: [ 293.301543] [<ffffffff817cc41e>]
print_circular_bug+0x20b/0x21c
Aug 31 20:56:59 fambox kernel: [ 293.301547] [<ffffffff810d983d>]
__lock_acquire+0x1f5d/0x21c0
Aug 31 20:56:59 fambox kernel: [ 293.301553] [<ffffffff811fce65>] ?
__kmalloc_node_track_caller+0x35/0x40
Aug 31 20:56:59 fambox kernel: [ 293.301556] [<ffffffff810da50f>]
lock_acquire+0xcf/0x280
Aug 31 20:56:59 fambox kernel: [ 293.301560] [<ffffffff815dcb32>] ?
ppp_dev_uninit+0x112/0x200
Aug 31 20:56:59 fambox kernel: [ 293.301565] [<ffffffff817d4515>]
mutex_lock_nested+0x65/0x3c0
Aug 31 20:56:59 fambox kernel: [ 293.301569] [<ffffffff815dcb32>] ?
ppp_dev_uninit+0x112/0x200
Aug 31 20:56:59 fambox kernel: [ 293.301573] [<ffffffff810d7501>] ?
trace_hardirqs_on_caller+0x151/0x1e0
Aug 31 20:56:59 fambox kernel: [ 293.301577] [<ffffffff815dcb28>] ?
ppp_dev_uninit+0x108/0x200
Aug 31 20:56:59 fambox kernel: [ 293.301580] [<ffffffff810d759d>] ?
trace_hardirqs_on+0xd/0x10
Aug 31 20:56:59 fambox kernel: [ 293.301586] [<ffffffff81083de0>] ?
__local_bh_enable_ip+0x70/0xd0
Aug 31 20:56:59 fambox kernel: [ 293.301590] [<ffffffff815dcb32>]
ppp_dev_uninit+0x112/0x200
Aug 31 20:56:59 fambox kernel: [ 293.301594] [<ffffffff815dca44>] ?
ppp_dev_uninit+0x24/0x200
Aug 31 20:56:59 fambox kernel: [ 293.301598] [<ffffffff816bf84b>]
rollback_registered_many+0x18b/0x2f0
Aug 31 20:56:59 fambox kernel: [ 293.301602] [<ffffffff816d6757>] ?
rtnl_lock+0x17/0x20
Aug 31 20:56:59 fambox kernel: [ 293.301606] [<ffffffff816bf9dd>]
rollback_registered+0x2d/0x40
Aug 31 20:56:59 fambox kernel: [ 293.301610] [<ffffffff816c0955>]
unregister_netdevice_queue+0x55/0xc0
Aug 31 20:56:59 fambox kernel: [ 293.301614] [<ffffffff815db928>]
ppp_release+0x88/0x90
Aug 31 20:56:59 fambox kernel: [ 293.301618] [<ffffffff8121bc0f>]
__fput+0xef/0x200
Aug 31 20:56:59 fambox kernel: [ 293.301621] [<ffffffff8121bd6e>]
____fput+0xe/0x10
Aug 31 20:56:59 fambox kernel: [ 293.301626] [<ffffffff810a32dd>]
task_work_run+0x8d/0xc0
Aug 31 20:56:59 fambox kernel: [ 293.301630] [<ffffffff8101c04c>]
do_notify_resume+0x7c/0x90
Aug 31 20:56:59 fambox kernel: [ 293.301634] [<ffffffff817d92ee>]
int_signal+0x12/0x17

Could this be caused by this commit...?

commit 8cb775bc0a34dc596837e7da03fd22c747be618b
"ppp: fix device unregistration upon netns deletion"

I have attached my kernel-config.
If you need more informations please let me know.

Kind regards,
- Sedat -

[1] http://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/commit/?id=8cb775bc0a34dc596837e7da03fd22c747be618b

P.S.: Used version of network-manager and modemmanager plus WWAN
mumbo-jumbo #5 and PPP settings in kernel-config.

root# dpkg -l | egrep -i 'network-manager|modemmanager'
ii modemmanager 0.5.2.0-0ubuntu2
D-Bus service for managing modems
ii network-manager 0.9.4.0-0ubuntu4.4.2
network management framework (daemon and
userspace tools)
ii network-manager-gnome 0.9.4.1-0ubuntu2.5
network management framework (GNOME
frontend)
ii network-manager-pptp 0.9.4.0-0ubuntu1
network management framework (PPTP plugin
core)
ii network-manager-pptp-gnome 0.9.4.0-0ubuntu1
network management framework (PPTP plugin
GNOME GUI)

root# dmesg | egrep -i 'cdc_ether|option|usbserial|broadband|gsm|wwan'
[ 23.267425] cdc_ether 3-1.2:1.1 wwan0: register 'cdc_ether' at
usb-0000:00:1a.0-1.2, Mobile Broadband Network Device,
02:50:f3:00:00:00
[ 23.267497] usbcore: registered new interface driver cdc_ether
[ 23.287548] usbcore: registered new interface driver usbserial
[ 23.502107] usbcore: registered new interface driver option
[ 23.504226] usbserial: USB Serial support registered for GSM modem (1-port)
[ 23.504474] option 3-1.2:1.0: GSM modem (1-port) converter detected
[ 23.505847] usb 3-1.2: GSM modem (1-port) converter now attached to ttyUSB0
[ 23.506268] option 3-1.2:1.3: GSM modem (1-port) converter detected
[ 23.506638] usb 3-1.2: GSM modem (1-port) converter now attached to ttyUSB1
[ 23.506787] option 3-1.2:1.4: GSM modem (1-port) converter detected
[ 23.508021] usb 3-1.2: GSM modem (1-port) converter now attached to ttyUSB2

root# grep PPP /boot/config-4.2.0-1-iniza-small
CONFIG_PPP=y
CONFIG_PPP_BSDCOMP=m
CONFIG_PPP_DEFLATE=m
CONFIG_PPP_FILTER=y
# CONFIG_PPP_MPPE is not set
CONFIG_PPP_MULTILINK=y
# CONFIG_PPPOE is not set
CONFIG_PPP_ASYNC=m
# CONFIG_PPP_SYNC_TTY is not set

Attachment: config-4.2.0-1-iniza-small
Description: Binary data

Next message: Tony Lindgren: "Re: [PATCH] arm: omap2: vc: fix 'or' always true warning"
Previous message: Vitaly Kuznetsov: "Re: [PATCH] scsi_scan: move 'INQUIRY result too short' message to debug level"
Next in thread: Sedat Dilek: "Re: [Linux 4.2-rc8+] circular locking dependency detected: [pppd] ppp_dev_uninit() | rtnl_lock()"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]