Messages in this thread Patch in this message | | | From | Geert Uytterhoeven <> | Date | Wed, 8 Jun 2022 17:10:27 +0200 | Subject | Re: [PATCH printk v5 1/1] printk: extend console_lock for per-console locking |
| |
Hi John,
On Mon, May 2, 2022 at 3:19 PM John Ogness <john.ogness@linutronix.de> wrote: > On 2022-05-02, Marek Szyprowski <m.szyprowski@samsung.com> wrote: > > Data written to /dev/kmsg and all kernel logs were always displayed > > correctly. Also data written directly to /dev/ttyAML0 is displayed > > properly on the console. The latter doesn't however trigger the input > > related activity. > > > > It looks that the data read from the uart is delivered only if other > > activity happens on the kernel console. If I type 'reboot' and press > > enter, nothing happens immediately. If I type 'date >/dev/ttyAML0' via > > ssh then, I only see the date printed on the console. However if I > > type 'date >/dev/kmsg', the the date is printed and reboot happens. > > I suppose if you login via ssh and check /proc/interrupts, then type > some things over serial, then check /proc/interrupts again, you will see > there have been no interrupts for the uart. But interrupts for other > devices are happening. Is this correct? > > > For comparison, here is a 't' sysrq result from the 'working' serial > > console (next-20220429), which happens usually 1 of 4 boots: > > > > https://pastebin.com/mp8zGFbW > > This still looks odd to me. We should be seeing a trace originating from > ret_from_fork+0x10/0x20 and kthread+0x118/0x11c. > > I wonder if the early creation of the thread is somehow causing > problems. Could you try the following patch to see if it makes a > difference? I would also like to see the sysrq-t output with this patch > applied:
On one board, I'm seeing a new splat during early boot, pointing to printk_activate_kthreads:
Calibrating delay loop (skipped), value calculated using timer frequency.. 48.00 BogoMIPS (lpj=96000) pid_max: default: 32768 minimum: 301 Mount-cache hash table entries: 4096 (order: 3, 32768 bytes, linear) Mountpoint-cache hash table entries: 4096 (order: 3, 32768 bytes, linear)
============================= [ BUG: Invalid wait context ] 5.19.0-rc1-ebisu-00802-g06a0dd60d6e4 #431 Not tainted ----------------------------- swapper/0/1 is trying to lock: ffffffc00910bac8 (base_crng.lock){....}-{3:3}, at: crng_make_state+0x148/0x1e4 other info that might help us debug this: context-{5:5} 2 locks held by swapper/0/1: #0: ffffffc008f8ae00 (console_lock){+.+.}-{0:0}, at: printk_activate_kthreads+0x10/0x54 #1: ffffffc009da4a28 (&meta->lock){....}-{2:2}, at: __kfence_alloc+0x378/0x5c4 stack backtrace: CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.19.0-rc1-ebisu-00802-g06a0dd60d6e4 #431 Hardware name: Renesas Ebisu-4D board based on r8a77990 (DT) Call trace: dump_backtrace.part.0+0x98/0xc0 show_stack+0x14/0x28 dump_stack_lvl+0xac/0xec dump_stack+0x14/0x2c __lock_acquire+0x388/0x10a0 lock_acquire+0x190/0x2c0 _raw_spin_lock_irqsave+0x6c/0x94 crng_make_state+0x148/0x1e4 _get_random_bytes.part.0+0x4c/0xe8 get_random_u32+0x4c/0x140 __kfence_alloc+0x460/0x5c4 kmem_cache_alloc_trace+0x194/0x1dc __kthread_create_on_node+0x5c/0x1a8 kthread_create_on_node+0x58/0x7c printk_start_kthread.part.0+0x34/0xa8 printk_activate_kthreads+0x4c/0x54 do_one_initcall+0xec/0x278 kernel_init_freeable+0x11c/0x214 kernel_init+0x24/0x124 ret_from_fork+0x10/0x20 rcu: Hierarchical SRCU implementation. printk: console [tty0] printing thread started EFI services will not be available. smp: Bringing up secondary CPUs ... Detected VIPT I-cache on CPU1 CPU1: Booted secondary processor 0x0000000001 [0x410fd034] smp: Brought up 1 node, 2 CPUs SMP: Total of 2 processors activated.
> ---------------- BEGIN PATCH --------------- > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c > index 2311a0ad584a..c4362d25de22 100644 > --- a/kernel/printk/printk.c > +++ b/kernel/printk/printk.c > @@ -3837,7 +3837,7 @@ static int __init printk_activate_kthreads(void) > > return 0; > } > -early_initcall(printk_activate_kthreads); > +late_initcall(printk_activate_kthreads); > > #if defined CONFIG_PRINTK > /* If @con is specified, only wait for that console. Otherwise wait for all. */ > ---------------- END PATCH ---------------
Doesn't seem to make much of a difference, only a slightly different backtrace, compared to the above:
Mount-cache hash table entries: 4096 (order: 3, 32768 bytes, linear) Mountpoint-cache hash table entries: 4096 (order: 3, 32768 bytes, linear) +rcu: Hierarchical SRCU implementation.
============================= [ BUG: Invalid wait context ] -5.19.0-rc1-ebisu-00802-g06a0dd60d6e4 #431 Not tainted +5.19.0-rc1-ebisu-00802-g06a0dd60d6e4-dirty #433 Not tainted ----------------------------- swapper/0/1 is trying to lock: ffffffc00910bac8 (base_crng.lock){....}-{3:3}, at: crng_make_state+0x148/0x1e4 other info that might help us debug this: context-{5:5} -2 locks held by swapper/0/1: - #0: ffffffc008f8ae00 (console_lock){+.+.}-{0:0}, at: printk_activate_kthreads+0x10/0x54 - #1: ffffffc009da4a28 (&meta->lock){....}-{2:2}, at: __kfence_alloc+0x378/0x5c4 +1 lock held by swapper/0/1: + #0: ffffffc009da4a28 (&meta->lock){....}-{2:2}, at: __kfence_alloc+0x378/0x5c4 stack backtrace: -CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.19.0-rc1-ebisu-00802-g06a0dd60d6e4 #431 +CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.19.0-rc1-ebisu-00802-g06a0dd60d6e4-dirty #433 Hardware name: Renesas Ebisu-4D board based on r8a77990 (DT) Call trace: dump_backtrace.part.0+0x98/0xc0 @@ -33,20 +32,14 @@ Call trace: kmem_cache_alloc_trace+0x194/0x1dc __kthread_create_on_node+0x5c/0x1a8 kthread_create_on_node+0x58/0x7c - printk_start_kthread.part.0+0x34/0xa8 - printk_activate_kthreads+0x4c/0x54 + rcu_spawn_gp_kthread+0x54/0x208 do_one_initcall+0xec/0x278 kernel_init_freeable+0x11c/0x214 kernel_init+0x24/0x124 ret_from_fork+0x10/0x20 -rcu: Hierarchical SRCU implementation. -printk: console [tty0] printing thread started EFI services will not be available. smp: Bringing up secondary CPUs ... Detected VIPT I-cache on CPU1 ... +printk: console [tty0] printing thread started
Gr{oetje,eeting}s,
Geert -- Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- geert@linux-m68k.org
In personal conversations with technical people, I call myself a hacker. But when I'm talking to journalists I just say "programmer" or something like that. -- Linus Torvalds
| |