| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-ID: <CAHp75Vd8nTzmZdnhpTDChdc11zyCaSfeigbxaCpOWZ1Lv9ZBMw@mail.gmail.com>
Date: Mon, 22 Jun 2020 20:37:28 +0300
From: Andy Shevchenko <andy.shevchenko@...il.com>
To: Raul Rangel <rrangel@...gle.com>, Tony Lindgren <tony@...mide.com>,
Petr Mladek <pmladek@...e.com>,
Sergey Senozhatsky <sergey.senozhatsky.work@...il.com>
Cc: linux-kernel <linux-kernel@...r.kernel.org>,
Greg Kroah-Hartman <gregkh@...uxfoundation.org>,
Andy Shevchenko <andriy.shevchenko@...ux.intel.com>,
kurt@...utronix.de, "S, Shirish" <Shirish.S@....com>
Subject: Re: UART/TTY console deadlock
+Cc: Tony and console people
On Mon, Jun 22, 2020 at 8:32 PM Raul Rangel <rrangel@...gle.com> wrote:
>
> We are trying an S3 suspend stress test and occasionally while
> entering S3 we get a console deadlock. Is this a known issue? I'm not
> really sure why a probe would be happening while suspending.
>
> The kernel command line is `console=ttyS0` and kernel 5.4.39.
>
> Here is the log:
>
> [ 278.885831] leds mmc0::: calling led_resume+0x0/0x1c @ 3909,
> parent: 0000:02:00.0
> [ 278.885835] leds mmc0::: led_resume+0x0/0x1c returned 0 after 0 usecs
> [ 278.890230] secondary_startup_64+0xa4/0xb0
> [ 278.890236] handlers:
> [ 279.752138] [<00000000b8e5d375>] i8042_interrupt
> [ 279.756915] Disabling IRQ #1
> [ 279.759801]
> [ 279.759802] ======================================================
> [ 279.759803] WARNING: possible circular locking dependency detected
> [ 279.759803] 5.4.39 #55 Not tainted
> [ 279.759804] ------------------------------------------------------
> [ 279.759804] swapper/0/0 is trying to acquire lock:
> [ 279.759805] ffffffffab65b6c0 (console_owner){-...}, at:
> console_lock_spinning_enable+0x31/0x57
> [ 279.759806]
> [ 279.759807] but task is already holding lock:
> [ 279.759807] ffff88810a8e34c0 (&irq_desc_lock_class){-.-.}, at:
> __report_bad_irq+0x5b/0xba
> [ 279.759809]
> [ 279.759809] which lock already depends on the new lock.
> [ 279.759810]
> [ 279.759810]
> [ 279.759811] the existing dependency chain (in reverse order) is:
> [ 279.759811]
> [ 279.759811] -> #2 (&irq_desc_lock_class){-.-.}:
> [ 279.759813] _raw_spin_lock_irqsave+0x61/0x8d
> [ 279.759813] __irq_get_desc_lock+0x65/0x89
> [ 279.759814] __disable_irq_nosync+0x3b/0x93
> [ 279.759814] serial8250_do_startup+0x451/0x75c
> [ 279.759815] uart_startup+0x1b4/0x2ff
> [ 279.759815] uart_port_activate+0x73/0xa0
> [ 279.759815] tty_port_open+0xae/0x10a
> [ 279.759816] uart_open+0x1b/0x26
> [ 279.759816] tty_open+0x24d/0x3a0
> [ 279.759817] chrdev_open+0xd5/0x1cc
> [ 279.759817] do_dentry_open+0x299/0x3c8
> [ 279.759817] path_openat+0x434/0x1100
> [ 279.759818] do_filp_open+0x9b/0x10a
> [ 279.759818] do_sys_open+0x15f/0x3d7
> [ 279.759819] kernel_init_freeable+0x157/0x1dd
> [ 279.759819] kernel_init+0xe/0x105
> [ 279.759819] ret_from_fork+0x27/0x50
> [ 279.759820]
> [ 279.759820] -> #1 (&port_lock_key){-.-.}:
> [ 279.759822] _raw_spin_lock_irqsave+0x61/0x8d
> [ 279.759822] serial8250_console_write+0xa7/0x2a0
> [ 279.759823] console_unlock+0x3b7/0x528
> [ 279.759823] vprintk_emit+0x111/0x17f
> [ 279.759823] printk+0x59/0x73
> [ 279.759824] register_console+0x336/0x3a4
> [ 279.759824] uart_add_one_port+0x51b/0x5be
> [ 279.759825] serial8250_register_8250_port+0x454/0x55e
> [ 279.759825] dw8250_probe+0x4dc/0x5b9
> [ 279.759825] platform_drv_probe+0x67/0x8b
> [ 279.759826] really_probe+0x14a/0x422
> [ 279.759826] driver_probe_device+0x66/0x130
> [ 279.759827] device_driver_attach+0x42/0x5b
> [ 279.759827] __driver_attach+0xca/0x139
> [ 279.759827] bus_for_each_dev+0x97/0xc9
> [ 279.759828] bus_add_driver+0x12b/0x228
> [ 279.759828] driver_register+0x64/0xed
> [ 279.759829] do_one_initcall+0x20c/0x4a6
> [ 279.759829] do_initcall_level+0xb5/0xc5
> [ 279.759829] do_basic_setup+0x4c/0x58
> [ 279.759830] kernel_init_freeable+0x13f/0x1dd
> [ 279.759830] kernel_init+0xe/0x105
> [ 279.759831] ret_from_fork+0x27/0x50
> [ 279.759831]
> [ 279.759831] -> #0 (console_owner){-...}:
> [ 279.759833] __lock_acquire+0x118d/0x2714
> [ 279.759833] lock_acquire+0x203/0x258
> [ 279.759834] console_lock_spinning_enable+0x51/0x57
> [ 279.759834] console_unlock+0x25d/0x528
> [ 279.759834] vprintk_emit+0x111/0x17f
> [ 279.759835] printk+0x59/0x73
> [ 279.759835] __report_bad_irq+0xa3/0xba
> [ 279.759836] note_interrupt+0x19a/0x1d6
> [ 279.759836] handle_irq_event_percpu+0x57/0x79
> [ 279.759836] handle_irq_event+0x36/0x55
> [ 279.759837] handle_fasteoi_irq+0xc2/0x18a
> [ 279.759837] do_IRQ+0xb3/0x157
> [ 279.759838] ret_from_intr+0x0/0x1d
> [ 279.759838] cpuidle_enter_state+0x12f/0x1fd
> [ 279.759838] cpuidle_enter+0x2e/0x3d
> [ 279.759839] do_idle+0x1ce/0x2ce
> [ 279.759839] cpu_startup_entry+0x1d/0x1f
> [ 279.759840] start_kernel+0x406/0x46a
> [ 279.759840] secondary_startup_64+0xa4/0xb0
> [ 279.759840]
> [ 279.759841] other info that might help us debug this:
> [ 279.759841]
> [ 279.759841] Chain exists of:
> [ 279.759842] console_owner --> &port_lock_key --> &irq_desc_lock_class
> [ 279.759844]
> [ 279.759844] Possible unsafe locking scenario:
> [ 279.759845]
> [ 279.759845] CPU0 CPU1
> [ 279.759845] ---- ----
> [ 279.759846] lock(&irq_desc_lock_class);
> [ 279.759847] lock(&port_lock_key);
> [ 279.759848] lock(&irq_desc_lock_class);
> [ 279.759849] lock(console_owner);
> [ 279.759850]
> [ 279.759850] *** DEADLOCK ***
> [ 279.759850]
> [ 279.759851] 2 locks held by swapper/0/0:
> [ 279.759851] #0: ffff88810a8e34c0 (&irq_desc_lock_class){-.-.}, at:
> __report_bad_irq+0x5b/0xba
> [ 279.759853] #1: ffffffffab65b5c0 (console_lock){+.+.}, at:
> console_trylock_spinning+0x20/0x181
> [ 279.759855]
> [ 279.759855] stack backtrace:
> [ 279.759856] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.4.39 #55
> [ 279.759856] Hardware name: XXXXXX
> [ 279.759857] Call Trace:
> [ 279.759857] <IRQ>
> [ 279.759857] dump_stack+0xbf/0x133
> [ 279.759858] ? print_circular_bug+0xd6/0xe9
> [ 279.759858] check_noncircular+0x1b9/0x1c3
> [ 279.759858] __lock_acquire+0x118d/0x2714
> [ 279.759859] lock_acquire+0x203/0x258
> [ 279.759859] ? console_lock_spinning_enable+0x31/0x57
> [ 279.759860] console_lock_spinning_enable+0x51/0x57
> [ 279.759860] ? console_lock_spinning_enable+0x31/0x57
> [ 279.759861] console_unlock+0x25d/0x528
> [ 279.759861] ? console_trylock+0x18/0x4e
> [ 279.759861] vprintk_emit+0x111/0x17f
> [ 279.759862] ? lock_acquire+0x203/0x258
> [ 279.759862] printk+0x59/0x73
> [ 279.759862] __report_bad_irq+0xa3/0xba
> [ 279.759863] note_interrupt+0x19a/0x1d6
> [ 279.759863] handle_irq_event_percpu+0x57/0x79
> [ 279.759864] handle_irq_event+0x36/0x55
> [ 279.759864] handle_fasteoi_irq+0xc2/0x18a
> [ 279.759864] do_IRQ+0xb3/0x157
> [ 279.759865] common_interrupt+0xf/0xf
> [ 279.759865] </IRQ>
> [ 279.759866] RIP: 0010:cpuidle_enter_state+0x12f/0x1fd
> [ 279.759867] Code: aa aa aa aa aa aa aa 48 89 45 c8 9c 8f 45 c8 0f
> ba 65 c8 09 0f 82 cc 00 00 00 31 ff e8 57 25 76 ff e8 36 bb 7b ff fb
> 45 85 ff <78> 47 44 89 f8 48 6b d0 68 49 8b 4c 16 48 4c 2b 65 b8 4c 89
> 63 18
> [ 279.759867] RSP: 0018:ffffffffab607e20 EFLAGS: 00000202 ORIG_RAX:
> ffffffffffffffda
> [ 279.759869] RAX: 86733df5ce911a00 RBX: ffff888104709000 RCX: ffffffffa9bb229b
> [ 279.759870] RDX: 0000000000000000 RSI: 0000000000000006 RDI: ffffffffab62d780
> [ 279.759870] RBP: ffffffffab607e68 R08: dffffc0000000000 R09: fffffbfff56eb96f
> [ 279.759871] R10: fffffbfff56eb96f R11: ffffffffa9f4f800 R12: 00000040eb0f7ad6
> [ 279.759871] R13: 0000000000000000 R14: ffffffffab6caf68 R15: 0000000000000001
> [ 279.759871] ? flatten_lpi_states+0x190/0x1d7
> [ 279.759872] ? trace_irq_enable_rcuidle+0x22/0xee
> [ 279.759872] cpuidle_enter+0x2e/0x3d
> [ 279.759872] do_idle+0x1ce/0x2ce
> [ 279.759873] cpu_startup_entry+0x1d/0x1f
> [ 279.759873] start_kernel+0x406/0x46a
> [ 279.759873] secondary_startup_64+0xa4/0xb0
> [ 279.927956] i2c_designware AMD0010:00: controller timed out
> [ 280.388120] elan_i2c i2c-ELAN0000:00: reading cmd (0x0307) fail.
> [ 280.394413] elan_i2c i2c-ELAN0000:00: failed to read current power
> state: -110
> [ 280.542626] elan_i2c i2c-ELAN0000:00: elan_resume+0x0/0x5f returned
> 0 after 1607813 usecs
>
>
> Thanks,
> Raul
--
With Best Regards,
Andy Shevchenko
Powered by blists - more mailing lists