[BUG] tty: n_gsm: possible circular locking dependency detected

From: Martin HundebÃll
Date: Thu Sep 19 2019 - 09:28:16 EST


Hi,

We've come across the below lockdep report when using n_gsm multiplexing on an imx uart.

The inverted lock scenario caused by:
1) the uart tx-ready interrupt causing the tty layer to call down into n_gsm, and
2) n_gsm transmitting data, causing it to call up into the tty layer

We have about 2-3k devices running, and get the report from ~100 devices during a 1 hour span. But we haven't been able to reproduce locally.

The devices run 4.19.22 with my recent n_gsm patches backported.

Any hints on how to dig further are appreciated.

// Martin

[ 201.633281] ======================================================
[ 201.639473] WARNING: possible circular locking dependency detected
[ 201.645667] 4.19.22 #1 Not tainted
[ 201.649078] ------------------------------------------------------
[ 201.655270] kworker/u2:0/7 is trying to acquire lock:
[ 201.660337] a66ff7b8 (&(&gsm->tx_lock)->rlock){-.-.}, at: gsmld_write_wakeup+0x28/0x5c
[ 201.668309]
[ 201.668309] but task is already holding lock:
[ 201.674155] 456c79ff (&port_lock_key){-.-.}, at: imx_uart_txint+0x18/0x198
[ 201.681070]
[ 201.681070] which lock already depends on the new lock.
[ 201.681070]
[ 201.689261]
[ 201.689261] the existing dependency chain (in reverse order) is:
[ 201.696754]
[ 201.696754] -> #1 (&port_lock_key){-.-.}:
[ 201.702282] _raw_spin_lock_irqsave+0x40/0x54
[ 201.707178] uart_write_room+0x60/0xf8
[ 201.711467] tty_write_room+0x20/0x2c
[ 201.715665] gsmld_output+0x20/0x94
[ 201.719690] gsm_data_kick+0x80/0x164
[ 201.723888] __gsm_data_queue+0x188/0x1a4
[ 201.728433] gsm_control_transmit+0x78/0x8c
[ 201.733151] gsm_control_send+0x130/0x170
[ 201.737693] gsmld_ioctl+0x238/0x4f8
[ 201.741805] tty_ioctl+0x3a0/0xc44
[ 201.745744] do_vfs_ioctl+0xa8/0xa3c
[ 201.749855] ksys_ioctl+0x3c/0x68
[ 201.753703] sys_ioctl+0x10/0x14
[ 201.757468] ret_fast_syscall+0x0/0x28
[ 201.761752] 0xbecd6ab4
[ 201.764728]
[ 201.764728] -> #0 (&(&gsm->tx_lock)->rlock){-.-.}:
[ 201.771036] lock_acquire+0xd0/0x1f4
[ 201.775148] _raw_spin_lock_irqsave+0x40/0x54
[ 201.780042] gsmld_write_wakeup+0x28/0x5c
[ 201.784587] tty_wakeup+0x58/0x64
[ 201.788436] tty_port_default_wakeup+0x1c/0x28
[ 201.793412] tty_port_tty_wakeup+0x18/0x1c
[ 201.798043] uart_write_wakeup+0x1c/0x24
[ 201.802498] imx_uart_txint+0x13c/0x198
[ 201.806868] imx_uart_int+0x100/0x1a4
[ 201.811066] __handle_irq_event_percpu+0x44/0x364
[ 201.816302] handle_irq_event_percpu+0x30/0x88
[ 201.821279] handle_irq_event+0x40/0x64
[ 201.825652] handle_fasteoi_irq+0xc4/0x174
[ 201.830282] generic_handle_irq+0x28/0x3c
[ 201.834826] __handle_domain_irq+0x6c/0xe8
[ 201.839459] gic_handle_irq+0x60/0xc4
[ 201.843657] __irq_svc+0x70/0x98
[ 201.847421] _raw_spin_unlock_irq+0x30/0x34
[ 201.852141] process_one_work+0x210/0x718
[ 201.856686] worker_thread+0x2c/0x54c
[ 201.860881] kthread+0x14c/0x164
[ 201.864643] ret_from_fork+0x14/0x20
[ 201.868749] (null)
[ 201.871551]
[ 201.871551] other info that might help us debug this:
[ 201.871551]
[ 201.879568] Possible unsafe locking scenario:
[ 201.879568]
[ 201.885499] CPU0 CPU1
[ 201.890038] ---- ----
[ 201.894574] lock(&port_lock_key);
[ 201.898082] lock(&(&gsm->tx_lock)->rlock);
[ 201.904890] lock(&port_lock_key);
[ 201.910913] lock(&(&gsm->tx_lock)->rlock);
[ 201.915200]
[ 201.915200] *** DEADLOCK ***
[ 201.915200]
[ 201.921134] 2 locks held by kworker/u2:0/7:
[ 201.925326] #0: 456c79ff (&port_lock_key){-.-.}, at: imx_uart_txint+0x18/0x198
[ 201.932683] #1: e4c7457f (&tty->ldisc_sem){++++}, at: tty_ldisc_ref+0x1c/0x44
[ 201.939948]
[ 201.939948] stack backtrace:
[ 201.944326] CPU: 0 PID: 7 Comm: kworker/u2:0 Not tainted 4.19.22 #1
[ 201.950604] Hardware name: Freescale i.MX6 Ultralite (Device Tree)
[ 201.956800] Workqueue: events_unbound flush_to_ldisc
[ 201.961782] Backtrace:
[ 201.964255] [<c010ebd4>] (dump_backtrace) from [<c010ef5c>] (show_stack+0x18/0x1c)
[ 201.971840] r7:00000000 r6:60030193 r5:00000000 r4:c0d7e300
[ 201.977519] [<c010ef44>] (show_stack) from [<c0859d80>] (dump_stack+0xb4/0xec)
[ 201.984760] [<c0859ccc>] (dump_stack) from [<c017bf80>] (print_circular_bug.constprop.15+0x264/0x328)
[ 201.993996] r10:c14e4e24 r9:00000000 r8:c8094b00 r7:c8095038 r6:c1200718 r5:c11e2e38
[ 202.001836] r4:c1200718 r3:14127a92
[ 202.005430] [<c017bd1c>] (print_circular_bug.constprop.15) from [<c017edec>] (__lock_acquire+0x14a8/0x1970)
[ 202.015186] r10:00000002 r9:c1491038 r8:c8094b00 r7:c1200718 r6:c8094ff8 r5:00000001
[ 202.023027] r4:c1200718 r3:c8094ff8
[ 202.026620] [<c017d944>] (__lock_acquire) from [<c017fc04>] (lock_acquire+0xd0/0x1f4)
[ 202.034466] r10:c0d08930 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c8ccd5ec
[ 202.042303] r4:60030193
[ 202.044856] [<c017fb34>] (lock_acquire) from [<c0877fcc>] (_raw_spin_lock_irqsave+0x40/0x54)
[ 202.053310] r10:00000241 r9:00000015 r8:000000e3 r7:00030193 r6:c04d434c r5:60030193
[ 202.061148] r4:c8ccd5dc
[ 202.063704] [<c0877f8c>] (_raw_spin_lock_irqsave) from [<c04d434c>] (gsmld_write_wakeup+0x28/0x5c)
[ 202.072674] r6:00000fff r5:c8ccd5dc r4:c8ccd400
[ 202.077313] [<c04d4324>] (gsmld_write_wakeup) from [<c04c46a8>] (tty_wakeup+0x58/0x64)
[ 202.085244] r7:00030193 r6:00000fff r5:c8d759c0 r4:c8ccdc00
[ 202.090922] [<c04c4650>] (tty_wakeup) from [<c04cf0b0>] (tty_port_default_wakeup+0x1c/0x28)
[ 202.099284] r5:c82f0000 r4:c8ccdc00
[ 202.102875] [<c04cf094>] (tty_port_default_wakeup) from [<c04cec68>] (tty_port_tty_wakeup+0x18/0x1c)
[ 202.112018] r5:c82f0000 r4:c8322440
[ 202.115610] [<c04cec50>] (tty_port_tty_wakeup) from [<c04e9a88>] (uart_write_wakeup+0x1c/0x24)
[ 202.124239] [<c04e9a6c>] (uart_write_wakeup) from [<c04ee3d4>] (imx_uart_txint+0x13c/0x198)
[ 202.132605] [<c04ee298>] (imx_uart_txint) from [<c04ee530>] (imx_uart_int+0x100/0x1a4)
[ 202.140538] r9:00000015 r8:00000000 r7:00000000 r6:00000000 r5:c8322440 r4:00002040
[ 202.148299] [<c04ee430>] (imx_uart_int) from [<c018df68>] (__handle_irq_event_percpu+0x44/0x364)
[ 202.157100] r10:00000015 r9:c80b3da8 r8:00000001 r7:00000000 r6:c0d08930 r5:c8158464
[ 202.164941] r4:c8343e40 r3:c04ee430
[ 202.168534] [<c018df24>] (__handle_irq_event_percpu) from [<c018e2b8>] (handle_irq_event_percpu+0x30/0x88)
[ 202.178203] r10:c0d42038 r9:c8010400 r8:00000001 r7:00000000 r6:c8158400 r5:c8158464
[ 202.186042] r4:c0d08908
[ 202.188594] [<c018e288>] (handle_irq_event_percpu) from [<c018e350>] (handle_irq_event+0x40/0x64)
[ 202.197477] r6:c0d14f0c r5:c8158464 r4:c8158400
[ 202.202114] [<c018e310>] (handle_irq_event) from [<c019201c>] (handle_fasteoi_irq+0xc4/0x174)
[ 202.210652] r7:00000000 r6:c0d14f0c r5:c8158464 r4:c8158400
[ 202.216330] [<c0191f58>] (handle_fasteoi_irq) from [<c018d090>] (generic_handle_irq+0x28/0x3c)
[ 202.224956] r7:00000000 r6:c0d08d08 r5:00000015 r4:c0c8d128
[ 202.230633] [<c018d068>] (generic_handle_irq) from [<c018d71c>] (__handle_domain_irq+0x6c/0xe8)
[ 202.239350] [<c018d6b0>] (__handle_domain_irq) from [<c048a358>] (gic_handle_irq+0x60/0xc4)
[ 202.247717] r9:c80b3e80 r8:c0d08f34 r7:d080a000 r6:000003ff r5:000003eb r4:d080a00c
[ 202.255478] [<c048a2f8>] (gic_handle_irq) from [<c0101a30>] (__irq_svc+0x70/0x98)
[ 202.262972] Exception stack(0xc80b3e80 to 0xc80b3ec8)
[ 202.268043] 3e80: 00000001 00000001 00000000 0000b51a c8010000 c8028900 c8010000 c800f000
[ 202.276238] 3ea0: c80b3f04 c82f0418 c8010000 c80b3ee4 00000000 c80b3ed0 c017fe38 c087816c
[ 202.284425] 3ec0: 20030113 ffffffff
[ 202.287930] r10:c8010000 r9:c80b2000 r8:c80b3f04 r7:c80b3eb4 r6:ffffffff r5:20030113
[ 202.295769] r4:c087816c
[ 202.298323] [<c087813c>] (_raw_spin_unlock_irq) from [<c014728c>] (process_one_work+0x210/0x718)
[ 202.307122] r5:c8028900 r4:c82f0414
[ 202.310716] [<c014707c>] (process_one_work) from [<c01477c0>] (worker_thread+0x2c/0x54c)
[ 202.318826] r10:c8010000 r9:c0d05900 r8:00000088 r7:c8010034 r6:c8010000 r5:c8028914
[ 202.326666] r4:c8028900
[ 202.329216] [<c0147794>] (worker_thread) from [<c014e6c4>] (kthread+0x14c/0x164)
[ 202.336628] r10:c8099e40 r9:c0147794 r8:c8028900 r7:c80b2000 r6:c8037fc0 r5:c8028980
[ 202.344468] r4:00000000 r3:00000000
[ 202.348060] [<c014e578>] (kthread) from [<c01010b4>] (ret_from_fork+0x14/0x20)
[ 202.355292] Exception stack(0xc80b3fb0 to 0xc80b3ff8)
[ 202.360356] 3fa0: 00000000 00000000 00000000 00000000
[ 202.368549] 3fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[ 202.376740] 3fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[ 202.383369] r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c014e578
[ 202.391208] r4:c8037fc0