Re: page_alloc.shuffle=1 + CONFIG_PROVE_LOCKING=y = arm64 hang

From: Qian Cai
Date: Thu Sep 12 2019 - 08:05:47 EST

Next message: Janosch Frank: "Re: [PATCH v2] KVM: s390: Do not leak kernel stack data in the KVM_S390_INTERRUPT ioctl"
Previous message: Geert Uytterhoeven: "Re: [PATCH] arm: dts: renesas: r8a77980: Remove r8a77970 DU compatible"
In reply to: Sergey Senozhatsky: "Re: page_alloc.shuffle=1 + CONFIG_PROVE_LOCKING=y = arm64 hang"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

On Wed, 2019-09-11 at 10:10 +0900, Sergey Senozhatsky wrote:
> Cc-ing Ted, Arnd, Greg
>
> On (09/10/19 11:22), Qian Cai wrote:
> > [ 1078.283869][T43784] -> #3 (&(&port->lock)->rlock){-.-.}:
> > [ 1078.291350][T43784]ÂÂÂÂÂÂÂÂ__lock_acquire+0x5c8/0xbb0
> > [ 1078.296394][T43784]ÂÂÂÂÂÂÂÂlock_acquire+0x154/0x428
> > [ 1078.301266][T43784]ÂÂÂÂÂÂÂÂ_raw_spin_lock_irqsave+0x80/0xa0
> > [ 1078.306831][T43784]ÂÂÂÂÂÂÂÂtty_port_tty_get+0x28/0x68
> > [ 1078.311873][T43784]ÂÂÂÂÂÂÂÂtty_port_default_wakeup+0x20/0x40
> > [ 1078.317523][T43784]ÂÂÂÂÂÂÂÂtty_port_tty_wakeup+0x38/0x48
> > [ 1078.322827][T43784]ÂÂÂÂÂÂÂÂuart_write_wakeup+0x2c/0x50
> > [ 1078.327956][T43784]ÂÂÂÂÂÂÂÂpl011_tx_chars+0x240/0x260
> > [ 1078.332999][T43784]ÂÂÂÂÂÂÂÂpl011_start_tx+0x24/0xa8
> > [ 1078.337868][T43784]ÂÂÂÂÂÂÂÂ__uart_start+0x90/0xa0
> > [ 1078.342563][T43784]ÂÂÂÂÂÂÂÂuart_write+0x15c/0x2c8
> > [ 1078.347261][T43784]ÂÂÂÂÂÂÂÂdo_output_char+0x1c8/0x2b0
> > [ 1078.352304][T43784]ÂÂÂÂÂÂÂÂn_tty_write+0x300/0x668
> > [ 1078.357087][T43784]ÂÂÂÂÂÂÂÂtty_write+0x2e8/0x430
> > [ 1078.361696][T43784]ÂÂÂÂÂÂÂÂredirected_tty_write+0xcc/0xe8
> > [ 1078.367086][T43784]ÂÂÂÂÂÂÂÂdo_iter_write+0x228/0x270
> > [ 1078.372041][T43784]ÂÂÂÂÂÂÂÂvfs_writev+0x10c/0x1c8
> > [ 1078.376735][T43784]ÂÂÂÂÂÂÂÂdo_writev+0xdc/0x180
> > [ 1078.381257][T43784]ÂÂÂÂÂÂÂÂ__arm64_sys_writev+0x50/0x60
> > [ 1078.386476][T43784]ÂÂÂÂÂÂÂÂel0_svc_handler+0x11c/0x1f0
> > [ 1078.391606][T43784]ÂÂÂÂÂÂÂÂel0_svc+0x8/0xc
> > [ 1078.395691][T43784]Â
>
> uart_port->lock -> tty_port->lock
>
> This thing along is already a bit suspicious. We re-enter tty
> here: tty -> uart -> serial -> tty
>
> And we re-enter tty under uart_port->lock.
>
> > [ 1078.395691][T43784] -> #2 (&port_lock_key){-.-.}:
> > [ 1078.402561][T43784]ÂÂÂÂÂÂÂÂ__lock_acquire+0x5c8/0xbb0
> > [ 1078.407604][T43784]ÂÂÂÂÂÂÂÂlock_acquire+0x154/0x428
> > [ 1078.412474][T43784]ÂÂÂÂÂÂÂÂ_raw_spin_lock+0x68/0x88
> > [ 1078.417343][T43784]ÂÂÂÂÂÂÂÂpl011_console_write+0x2ac/0x318
> > [ 1078.422820][T43784]ÂÂÂÂÂÂÂÂconsole_unlock+0x3c4/0x898
> > [ 1078.427863][T43784]ÂÂÂÂÂÂÂÂvprintk_emit+0x2d4/0x460
> > [ 1078.432732][T43784]ÂÂÂÂÂÂÂÂvprintk_default+0x48/0x58
> > [ 1078.437688][T43784]ÂÂÂÂÂÂÂÂvprintk_func+0x194/0x250
> > [ 1078.442557][T43784]ÂÂÂÂÂÂÂÂprintk+0xbc/0xec
> > [ 1078.446732][T43784]ÂÂÂÂÂÂÂÂregister_console+0x4a8/0x580
> > [ 1078.451947][T43784]ÂÂÂÂÂÂÂÂuart_add_one_port+0x748/0x878
> > [ 1078.457250][T43784]ÂÂÂÂÂÂÂÂpl011_register_port+0x98/0x128
> > [ 1078.462639][T43784]ÂÂÂÂÂÂÂÂsbsa_uart_probe+0x398/0x480
> > [ 1078.467772][T43784]ÂÂÂÂÂÂÂÂplatform_drv_probe+0x70/0x108
> > [ 1078.473075][T43784]ÂÂÂÂÂÂÂÂreally_probe+0x15c/0x5d8
> > [ 1078.477944][T43784]ÂÂÂÂÂÂÂÂdriver_probe_device+0x94/0x1d0
> > [ 1078.483335][T43784]ÂÂÂÂÂÂÂÂ__device_attach_driver+0x11c/0x1a8
> > [ 1078.489072][T43784]ÂÂÂÂÂÂÂÂbus_for_each_drv+0xf8/0x158
> > [ 1078.494201][T43784]ÂÂÂÂÂÂÂÂ__device_attach+0x164/0x240
> > [ 1078.499331][T43784]ÂÂÂÂÂÂÂÂdevice_initial_probe+0x24/0x30
> > [ 1078.504721][T43784]ÂÂÂÂÂÂÂÂbus_probe_device+0xf0/0x100
> > [ 1078.509850][T43784]ÂÂÂÂÂÂÂÂdevice_add+0x63c/0x960
> > [ 1078.514546][T43784]ÂÂÂÂÂÂÂÂplatform_device_add+0x1ac/0x3b8
> > [ 1078.520023][T43784]ÂÂÂÂÂÂÂÂplatform_device_register_full+0x1fc/0x290
> > [ 1078.526373][T43784]ÂÂÂÂÂÂÂÂacpi_create_platform_device.part.0+0x264/0x3a8
> > [ 1078.533152][T43784]ÂÂÂÂÂÂÂÂacpi_create_platform_device+0x68/0x80
> > [ 1078.539150][T43784]ÂÂÂÂÂÂÂÂacpi_default_enumeration+0x34/0x78
> > [ 1078.544887][T43784]ÂÂÂÂÂÂÂÂacpi_bus_attach+0x340/0x3b8
> > [ 1078.550015][T43784]ÂÂÂÂÂÂÂÂacpi_bus_attach+0xf8/0x3b8
> > [ 1078.555057][T43784]ÂÂÂÂÂÂÂÂacpi_bus_attach+0xf8/0x3b8
> > [ 1078.560099][T43784]ÂÂÂÂÂÂÂÂacpi_bus_attach+0xf8/0x3b8
> > [ 1078.565142][T43784]ÂÂÂÂÂÂÂÂacpi_bus_scan+0x9c/0x100
> > [ 1078.570015][T43784]ÂÂÂÂÂÂÂÂacpi_scan_init+0x16c/0x320
> > [ 1078.575058][T43784]ÂÂÂÂÂÂÂÂacpi_init+0x330/0x3b8
> > [ 1078.579666][T43784]ÂÂÂÂÂÂÂÂdo_one_initcall+0x158/0x7ec
> > [ 1078.584797][T43784]ÂÂÂÂÂÂÂÂkernel_init_freeable+0x9a8/0xa70
> > [ 1078.590360][T43784]ÂÂÂÂÂÂÂÂkernel_init+0x18/0x138
> > [ 1078.595055][T43784]ÂÂÂÂÂÂÂÂret_from_fork+0x10/0x1c
> >
> > [ 1078.599835][T43784] -> #1 (console_owner){-...}:
> > [ 1078.606618][T43784]ÂÂÂÂÂÂÂÂ__lock_acquire+0x5c8/0xbb0
> > [ 1078.611661][T43784]ÂÂÂÂÂÂÂÂlock_acquire+0x154/0x428
> > [ 1078.616530][T43784]ÂÂÂÂÂÂÂÂconsole_unlock+0x298/0x898
> > [ 1078.621573][T43784]ÂÂÂÂÂÂÂÂvprintk_emit+0x2d4/0x460
> > [ 1078.626442][T43784]ÂÂÂÂÂÂÂÂvprintk_default+0x48/0x58
> > [ 1078.631398][T43784]ÂÂÂÂÂÂÂÂvprintk_func+0x194/0x250
> > [ 1078.636267][T43784]ÂÂÂÂÂÂÂÂprintk+0xbc/0xec
> > [ 1078.640443][T43784]ÂÂÂÂÂÂÂÂ_warn_unseeded_randomness+0xb4/0xd0
> > [ 1078.646267][T43784]ÂÂÂÂÂÂÂÂget_random_u64+0x4c/0x100
> > [ 1078.651224][T43784]ÂÂÂÂÂÂÂÂadd_to_free_area_random+0x168/0x1a0
> > [ 1078.657047][T43784]ÂÂÂÂÂÂÂÂfree_one_page+0x3dc/0xd08
> > [ 1078.662003][T43784]ÂÂÂÂÂÂÂÂ__free_pages_ok+0x490/0xd00
> > [ 1078.667132][T43784]ÂÂÂÂÂÂÂÂ__free_pages+0xc4/0x118
> > [ 1078.671914][T43784]ÂÂÂÂÂÂÂÂ__free_pages_core+0x2e8/0x428
> > [ 1078.677219][T43784]ÂÂÂÂÂÂÂÂmemblock_free_pages+0xa4/0xec
> > [ 1078.682522][T43784]ÂÂÂÂÂÂÂÂmemblock_free_all+0x264/0x330
> > [ 1078.687825][T43784]ÂÂÂÂÂÂÂÂmem_init+0x90/0x148
> > [ 1078.692259][T43784]ÂÂÂÂÂÂÂÂstart_kernel+0x368/0x684
>
> zone->lock --> uart_port->lock
>
> Some debugging options/warnings/error print outs/etc introduce
> deadlock patterns.
>
> This adds zone->lock --> uart_port->lock, which then brings in
> uart_port->lock --> tty_port->lock, which in turn brings
> tty_port->lock --> zone->lock.
>
> > [ 1078.697126][T43784] -> #0 (&(&zone->lock)->rlock){-.-.}:
> > [ 1078.704604][T43784]ÂÂÂÂÂÂÂÂcheck_prev_add+0x120/0x1138
> > [ 1078.709733][T43784]ÂÂÂÂÂÂÂÂvalidate_chain+0x888/0x1270
> > [ 1078.714863][T43784]ÂÂÂÂÂÂÂÂ__lock_acquire+0x5c8/0xbb0
> > [ 1078.719906][T43784]ÂÂÂÂÂÂÂÂlock_acquire+0x154/0x428
> > [ 1078.724776][T43784]ÂÂÂÂÂÂÂÂ_raw_spin_lock+0x68/0x88
> > [ 1078.729645][T43784]ÂÂÂÂÂÂÂÂrmqueue_bulk.constprop.21+0xb0/0x1218
> > [ 1078.735643][T43784]ÂÂÂÂÂÂÂÂget_page_from_freelist+0x898/0x24a0
> > [ 1078.741467][T43784]ÂÂÂÂÂÂÂÂ__alloc_pages_nodemask+0x2a8/0x1d08
> > [ 1078.747291][T43784]ÂÂÂÂÂÂÂÂalloc_pages_current+0xb4/0x150
> > [ 1078.752682][T43784]ÂÂÂÂÂÂÂÂallocate_slab+0xab8/0x2350
> > [ 1078.757725][T43784]ÂÂÂÂÂÂÂÂnew_slab+0x98/0xc0
> > [ 1078.762073][T43784]ÂÂÂÂÂÂÂÂ___slab_alloc+0x66c/0xa30
> > [ 1078.767029][T43784]ÂÂÂÂÂÂÂÂ__slab_alloc+0x68/0xc8
> > [ 1078.771725][T43784]ÂÂÂÂÂÂÂÂ__kmalloc+0x3d4/0x658
> > [ 1078.776333][T43784]ÂÂÂÂÂÂÂÂ__tty_buffer_request_room+0xd4/0x220
> > [ 1078.782244][T43784]ÂÂÂÂÂÂÂÂtty_insert_flip_string_fixed_flag+0x6c/0x128
> > [ 1078.788849][T43784]ÂÂÂÂÂÂÂÂpty_write+0x98/0x100
> > [ 1078.793370][T43784]ÂÂÂÂÂÂÂÂn_tty_write+0x2a0/0x668
> > [ 1078.798152][T43784]ÂÂÂÂÂÂÂÂtty_write+0x2e8/0x430
> > [ 1078.802760][T43784]ÂÂÂÂÂÂÂÂ__vfs_write+0x5c/0xb0
> > [ 1078.807368][T43784]ÂÂÂÂÂÂÂÂvfs_write+0xf0/0x230
> > [ 1078.811890][T43784]ÂÂÂÂÂÂÂÂksys_write+0xd4/0x180
> > [ 1078.816498][T43784]ÂÂÂÂÂÂÂÂ__arm64_sys_write+0x4c/0x60
> > [ 1078.821627][T43784]ÂÂÂÂÂÂÂÂel0_svc_handler+0x11c/0x1f0
> > [ 1078.826756][T43784]ÂÂÂÂÂÂÂÂel0_svc+0x8/0xc
>
> tty_port->lock --> zone->lock
>
> > [ 1078.830842][T43784] other info that might help us debug this:
> > [ 1078.830842][T43784]Â
> > [ 1078.840918][T43784] Chain exists of:
> > [ 1078.840918][T43784]ÂÂÂ&(&zone->lock)->rlock --> &port_lock_key --> &(&port-> >lock)->rlock
> > [ 1078.840918][T43784]Â
> > [ 1078.854731][T43784]ÂÂPossible unsafe locking scenario:
> > [ 1078.854731][T43784]Â
> > [ 1078.862029][T43784]ÂÂÂÂÂÂÂÂCPU0ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂCPU1
> > [ 1078.867243][T43784]ÂÂÂÂÂÂÂÂ----ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ----
> > [ 1078.872457][T43784]ÂÂÂlock(&(&port->lock)->rlock);
> > [ 1078.877238][T43784]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂlock(&port_lock_key);
> > [ 1078.883929][T43784]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂlock(&(&port->lock)->rlock);
> > [ 1078.891228][T43784]ÂÂÂlock(&(&zone->lock)->rlock);
> > [ 1078.896010][T43784]Â
> > [ 1078.896010][T43784]ÂÂ*** DEADLOCK ***
>
> [..]
> > [ 1078.980932][T43784]ÂÂdump_backtrace+0x0/0x228
> > [ 1078.985279][T43784]ÂÂshow_stack+0x24/0x30
> > [ 1078.989282][T43784]ÂÂdump_stack+0xe8/0x13c
> > [ 1078.993370][T43784]ÂÂprint_circular_bug+0x334/0x3d8
> > [ 1078.998240][T43784]ÂÂcheck_noncircular+0x268/0x310
> > [ 1079.003022][T43784]ÂÂcheck_prev_add+0x120/0x1138
> > [ 1079.007631][T43784]ÂÂvalidate_chain+0x888/0x1270
> > [ 1079.012241][T43784]ÂÂ__lock_acquire+0x5c8/0xbb0
> > [ 1079.016763][T43784]ÂÂlock_acquire+0x154/0x428
> > [ 1079.021111][T43784]ÂÂ_raw_spin_lock+0x68/0x88
> > [ 1079.025460][T43784]ÂÂrmqueue_bulk.constprop.21+0xb0/0x1218
> > [ 1079.030937][T43784]ÂÂget_page_from_freelist+0x898/0x24a0
> > [ 1079.036240][T43784]ÂÂ__alloc_pages_nodemask+0x2a8/0x1d08
> > [ 1079.041542][T43784]ÂÂalloc_pages_current+0xb4/0x150
> > [ 1079.046412][T43784]ÂÂallocate_slab+0xab8/0x2350
> > [ 1079.050934][T43784]ÂÂnew_slab+0x98/0xc0
> > [ 1079.054761][T43784]ÂÂ___slab_alloc+0x66c/0xa30
> > [ 1079.059196][T43784]ÂÂ__slab_alloc+0x68/0xc8
> > [ 1079.063371][T43784]ÂÂ__kmalloc+0x3d4/0x658
> > [ 1079.067458][T43784]ÂÂ__tty_buffer_request_room+0xd4/0x220
> > [ 1079.072847][T43784]ÂÂtty_insert_flip_string_fixed_flag+0x6c/0x128
> > [ 1079.078932][T43784]ÂÂpty_write+0x98/0x100
> > [ 1079.082932][T43784]ÂÂn_tty_write+0x2a0/0x668
> > [ 1079.087193][T43784]ÂÂtty_write+0x2e8/0x430
> > [ 1079.091280][T43784]ÂÂ__vfs_write+0x5c/0xb0
> > [ 1079.095367][T43784]ÂÂvfs_write+0xf0/0x230
> > [ 1079.099368][T43784]ÂÂksys_write+0xd4/0x180
> > [ 1079.103455][T43784]ÂÂ__arm64_sys_write+0x4c/0x60
> > [ 1079.108064][T43784]ÂÂel0_svc_handler+0x11c/0x1f0
> > [ 1079.112672][T43784]ÂÂel0_svc+0x8/0xc
>
> tty_port->lock --> zone->lock
>
> For instance, I don't really like the re-entrant tty, at least not
> under uart_port->lock. This, maybe, can be one of the solutions.
>
> Another one, a quick and dirty one, (and so many people will blame
> me for this) would be to break zone->{printk}->uart chain...
>
> Something like this
>
> ---
>
> drivers/char/random.c | 7 ++++---
> 1 file changed, 4 insertions(+), 3 deletions(-)
>
> diff --git a/drivers/char/random.c b/drivers/char/random.c
> index 9b54cdb301d3..975015857200 100644
> --- a/drivers/char/random.c
> +++ b/drivers/char/random.c
> @@ -1687,8 +1687,9 @@ static void _warn_unseeded_randomness(const char *func_name, void *caller,
> print_once = true;
> #endif
> if (__ratelimit(&unseeded_warning))
> - pr_notice("random: %s called from %pS with crng_init=%d\n",
> - func_name, caller, crng_init);
> + printk_deferred(KERN_NOTICE "random: %s called from %pS "
> + "with crng_init=%d\n", func_name, caller,
> + crng_init);
> }
>
> /*
> @@ -2462,4 +2463,4 @@ void add_bootloader_randomness(const void *buf, unsigned int size)
> else
> add_device_randomness(buf, size);
> }
> -EXPORT_SYMBOL_GPL(add_bootloader_randomness);
> \ No newline at end of file
> +EXPORT_SYMBOL_GPL(add_bootloader_randomness);

This will also fix the hang.

Sergey, do you plan to submit this Ted?

Next message: Janosch Frank: "Re: [PATCH v2] KVM: s390: Do not leak kernel stack data in the KVM_S390_INTERRUPT ioctl"
Previous message: Geert Uytterhoeven: "Re: [PATCH] arm: dts: renesas: r8a77980: Remove r8a77970 DU compatible"
In reply to: Sergey Senozhatsky: "Re: page_alloc.shuffle=1 + CONFIG_PROVE_LOCKING=y = arm64 hang"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]