[<prev] [next>] [<thread-prev] [day] [month] [year] [list]
Message-ID: <1572535333.5937.114.camel@lca.pw>
Date: Thu, 31 Oct 2019 11:22:13 -0400
From: Qian Cai <cai@....pw>
To: DaeRyong Jeong <threeearcat@...il.com>
Cc: Peter Zijlstra <peterz@...radead.org>,
Greg Kroah-Hartman <gregkh@...uxfoundation.org>,
Jiri Slaby <jslaby@...e.com>, linux-kernel@...r.kernel.org
Subject: Re: "Fix data race in tty_insert_flip_string_fixed_flag" triggers a
lockdep warning
On Wed, 2019-10-30 at 17:40 -0400, Qian Cai wrote:
> The commit b6da31b2c07c ("tty: Fix data race in
> tty_insert_flip_string_fixed_flag") creates a locking order,
>
> &(&port->lock)->rlock --> &(&zone->lock)->rlock
>
> which will trigger a lockdep warning below.
>
> [ 489.312784] WARNING: possible circular locking dependency detected
> [ 489.319655] 5.4.0-rc5-next-20191030+ #2 Tainted: G W L
> [ 489.326610] ------------------------------------------------------
> [ 489.333479] sshd/5541 is trying to acquire lock:
> [ 489.338785] ffff008b7cff9290 (&(&zone->lock)->rlock){..-.}, at:
> rmqueue+0xfe8/0x2274
> [ 489.347230]
> but task is already holding lock:
> [ 489.354444] 1cff0009e39c0540 (&(&port->lock)->rlock){-.-.}, at:
> pty_write+0x60/0xd0
> [ 489.362799]
> which lock already depends on the new lock.
>
> [ 489.373052]
> the existing dependency chain (in reverse order) is:
> [ 489.381916]
> -> #3 (&(&port->lock)->rlock){-.-.}:
> [ 489.389403] lock_acquire+0x320/0x360
> [ 489.394279] _raw_spin_lock_irqsave+0x7c/0x9c
> [ 489.399849] tty_port_tty_get+0x24/0x60
> [ 489.404896] tty_port_default_wakeup+0x1c/0x3c
> [ 489.410551] tty_port_tty_wakeup+0x34/0x40
> [ 489.415859] uart_write_wakeup+0x28/0x44
> [ 489.420993] pl011_tx_chars+0x1b8/0x270
> [ 489.426040] pl011_start_tx+0x24/0x70
> [ 489.430913] __uart_start+0x5c/0x68
> [ 489.435612] uart_write+0x164/0x1c8
> [ 489.440312] do_output_char+0x33c/0x348
> [ 489.445358] n_tty_write+0x4bc/0x60c
> [ 489.450143] tty_write+0x338/0x474
> [ 489.454755] redirected_tty_write+0xc0/0xdc
> [ 489.460150] do_loop_readv_writev+0x140/0x180
> [ 489.465718] do_iter_write+0xe0/0x10c
> [ 489.470590] vfs_writev+0x134/0x1cc
> [ 489.475289] do_writev+0xbc/0x130
> [ 489.479815] __arm64_sys_writev+0x58/0x8c
> [ 489.485038] el0_svc_handler+0x170/0x240
> [ 489.490173] el0_sync_handler+0x150/0x250
> [ 489.495393] el0_sync+0x164/0x180
> [ 489.499915]
> -> #2 (&port_lock_key){-.-.}:
> [ 489.506793] lock_acquire+0x320/0x360
> [ 489.511666] _raw_spin_lock+0x64/0x80
> [ 489.516540] pl011_console_write+0xec/0x2cc
> [ 489.521934] console_unlock+0x794/0x96c
> [ 489.526981] vprintk_emit+0x260/0x31c
> [ 489.531854] vprintk_default+0x54/0x7c
> [ 489.536813] vprintk_func+0x218/0x254
> [ 489.541687] printk+0x7c/0xa4
>
> -> #1 (console_owner){-...}:
> [ 489.703613] lock_acquire+0x320/0x360
> [ 489.708486] console_lock_spinning_enable+0x6c/0x7c
> [ 489.714575] console_unlock+0x4f8/0x96c
> [ 489.719622] vprintk_emit+0x260/0x31c
> [ 489.724495] vprintk_default+0x54/0x7c
> [ 489.729454] vprintk_func+0x218/0x254
> [ 489.734327] printk+0x7c/0xa4
> [ 489.810371]
Correction -- the call traces of the locking order from,
&(&zone->lock)->rlock --> console_owner:
-> #1 (console_owner){-...}:
[ 489.703613] lock_acquire+0x320/0x360
[ 489.708486] console_lock_spinning_enable+0x6c/0x7c
[ 489.714575] console_unlock+0x4f8/0x96c
[ 489.719622] vprintk_emit+0x260/0x31c
[ 489.724495] vprintk_default+0x54/0x7c
[ 489.729454] vprintk_func+0x218/0x254
[ 489.734327] printk+0x7c/0xa4
[ 489.738506] get_random_u64+0x1c4/0x1dc
[ 489.743552] add_to_free_area_random+0x50/0x16c
[ 489.749292] __free_one_page+0x374/0x6a0
[ 489.754425] free_one_page+0x6c/0x11c
[ 489.810371]
Should b6da31b2c07c ("tty: Fix data race in tty_insert_flip_string_fixed_flag")
be reverted first while taking time to rework?
> -> #0 (&(&zone->lock)->rlock){..-.}:
> [ 489.817854] validate_chain+0xf6c/0x2e2c
> [ 489.822988] __lock_acquire+0x868/0xc2c
> [ 489.828035] lock_acquire+0x320/0x360
> [ 489.832909] _raw_spin_lock_irqsave+0x7c/0x9c
> [ 489.838475] rmqueue+0xfe8/0x2274
> [ 489.843002] get_page_from_freelist+0x474/0x688
> [ 489.848743] __alloc_pages_nodemask+0x3b8/0x1928
> [ 489.854573] alloc_pages_current+0xd0/0xe0
> [ 489.859882] stack_depot_save+0x300/0x440
> [ 489.865103] __kasan_kmalloc+0x198/0x1e0
> [ 489.870236] kasan_slab_alloc+0x18/0x20
> [ 489.875284] slab_post_alloc_hook+0x48/0x9c
> [ 489.880677] kmem_cache_alloc+0x2e8/0x588
> [ 489.885898] create_object+0x60/0x698
> [ 489.890771] kmemleak_alloc+0x78/0xb8
> [ 489.895644] slab_post_alloc_hook+0x64/0x9c
> [ 489.901038] __kmalloc+0x328/0x490
> [ 489.905652] __tty_buffer_request_room+0x118/0x1f8
> [ 489.911654] tty_insert_flip_string_fixed_flag+0x6c/0x144
> [ 489.918263] pty_write+0x80/0xd0
> [ 489.922701] n_tty_write+0x450/0x60c
> [ 489.927486] tty_write+0x338/0x474
> [ 489.932098] __vfs_write+0x88/0x214
> [ 489.936796] vfs_write+0x12c/0x1a4
> [ 489.941411] ksys_write+0xb0/0x120
> [ 489.946027] __arm64_sys_write+0x54/0x88
> [ 489.951161] el0_svc_handler+0x170/0x240
> [ 489.956294] el0_sync_handler+0x150/0x250
> [ 489.961514] el0_sync+0x164/0x180
> [ 489.966038]
> other info that might help us debug this:
>
> [ 489.976117] Chain exists of:
> &(&zone->lock)->rlock --> &port_lock_key --> &(&port->lock)-
> > rlock
>
> [ 489.989937] Possible unsafe locking scenario:
>
> [ 489.997239] CPU0 CPU1
> [ 490.002456] ---- ----
> [ 490.007673] lock(&(&port->lock)->rlock);
> [ 490.012459] lock(&port_lock_key);
> [ 490.019155] lock(&(&port->lock)->rlock);
> [ 490.026458] lock(&(&zone->lock)->rlock);
> [ 490.031244]
> *** DEADLOCK ***
>
> [ 490.039241] 5 locks held by sshd/5541:
> [ 490.043677] #0: 12ff0009eb0c6890 (&tty->ldisc_sem){++++}, at:
> ldsem_down_read+0x3c/0x48
> [ 490.052465] #1: 12ff0009eb0c6918 (&tty->atomic_write_lock){+.+.}, at:
> tty_write+0x12c/0x474
> [ 490.061599] #2: 12ff0009eb0c6aa0 (&o_tty->termios_rwsem/1){++++}, at:
> n_tty_write+0x10c/0x60c
> [ 490.070908] #3: ffff90001f852360 (&ldata->output_lock){+.+.}, at:
> n_tty_write+0x278/0x60c
> [ 490.079868] #4: 1cff0009e39c0540 (&(&port->lock)->rlock){-.-.}, at:
> pty_write+0x60/0xd0
> [ 490.088654]
> stack backtrace:
> [ 490.094398] CPU: 31 PID: 5541 Comm: sshd Tainted: G W L 5.4.0-
> rc5-next-20191030+ #2
> [ 490.103871] Hardware name: HPE Apollo 70 /C01_APACHE_MB ,
> BIOS L50_5.13_1.11 06/18/2019
> [ 490.114300] Call trace:
> [ 490.117438] dump_backtrace+0x0/0x248
> [ 490.121791] show_stack+0x20/0x2c
> [ 490.125798] dump_stack+0xc8/0x130
> [ 490.129890] print_circular_bug+0x368/0x380
> [ 490.134764] check_noncircular+0x28c/0x294
> [ 490.139550] validate_chain+0xf6c/0x2e2c
> [ 490.144164] __lock_acquire+0x868/0xc2c
> [ 490.148691] lock_acquire+0x320/0x360
> [ 490.153044] _raw_spin_lock_irqsave+0x7c/0x9c
> [ 490.158090] rmqueue+0xfe8/0x2274
> [ 490.162097] get_page_from_freelist+0x474/0x688
> [ 490.167317] __alloc_pages_nodemask+0x3b8/0x1928
> [ 490.172625] alloc_pages_current+0xd0/0xe0
> [ 490.177412] stack_depot_save+0x300/0x440
> [ 490.182112] __kasan_kmalloc+0x198/0x1e0
> [ 490.186723] kasan_slab_alloc+0x18/0x20
> [ 490.191249] slab_post_alloc_hook+0x48/0x9c
> [ 490.196121] kmem_cache_alloc+0x2e8/0x588
> [ 490.200820] create_object+0x60/0x698
> [ 490.205173] kmemleak_alloc+0x78/0xb8
> [ 490.209525] slab_post_alloc_hook+0x64/0x9c
> [ 490.214398] __kmalloc+0x328/0x490
> [ 490.218491] __tty_buffer_request_room+0x118/0x1f8
> [ 490.223972] tty_insert_flip_string_fixed_flag+0x6c/0x144
> [ 490.230059] pty_write+0x80/0xd0
> [ 490.233977] n_tty_write+0x450/0x60c
> [ 490.238241] tty_write+0x338/0x474
> [ 490.242333] __vfs_write+0x88/0x214
> [ 490.246511] vfs_write+0x12c/0x1a4
> [ 490.250601] ksys_write+0xb0/0x120
> [ 490.254693] __arm64_sys_write+0x54/0x88
> [ 490.259305] el0_svc_handler+0x170/0x240
> [ 490.263918] el0_sync_handler+0x150/0x250
> [ 490.268617] el0_sync+0x164/0x180
Powered by blists - more mailing lists