[RFC] serial: core: Use pm_runtime_get_sync() in uart_start()

Message ID 20231124122258.1050-1-xuewen.yan@unisoc.com
State New
Headers
Series [RFC] serial: core: Use pm_runtime_get_sync() in uart_start() |

Commit Message

Xuewen Yan Nov. 24, 2023, 12:22 p.m. UTC
  The commit 84a9582fd203("serial: core: Start managing serial controllers to enable runtime PM")
use the pm_runtime_get() after uart_port_lock() which would close the irq and disable preement.
At this time,  pm_runtime_get may cause the following two problems:

(1) deadlock in try_to_wake_up:

uart_write()
uart_port_lock() <<< get lock
__uart_start
__pm_runtime_resume
rpm_resume
queue_work_on
try_to_wake_up
_printk
uart_console_write
...
uart_port_lock() <<< wait forever

(2) scheduling while atomic:
uart_write()
uart_port_lock() <<< get lock
__uart_start
__pm_runtime_resume
rpm_resume
chedule() << sleep

So let us use pm_runtime_get_sync() to prevent these.

Fixes: 84a9582fd203 ("serial: core: Start managing serial controllers to enable runtime PM")
Signed-off-by: Xuewen Yan <xuewen.yan@unisoc.com>
---
 drivers/tty/serial/serial_core.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)
  

Comments

Tony Lindgren Nov. 25, 2023, 7:47 a.m. UTC | #1
* Xuewen Yan <xuewen.yan@unisoc.com> [231124 12:25]:
> The commit 84a9582fd203("serial: core: Start managing serial controllers to enable runtime PM")
> use the pm_runtime_get() after uart_port_lock() which would close the irq and disable preement.
> At this time,  pm_runtime_get may cause the following two problems:
> 
> (1) deadlock in try_to_wake_up:
> 
> uart_write()
> uart_port_lock() <<< get lock
> __uart_start
> __pm_runtime_resume
> rpm_resume
> queue_work_on
> try_to_wake_up
> _printk
> uart_console_write
> ...
> uart_port_lock() <<< wait forever
> 
> (2) scheduling while atomic:
> uart_write()
> uart_port_lock() <<< get lock
> __uart_start
> __pm_runtime_resume
> rpm_resume
> chedule() << sleep

Are these spinlock vs raw spinlock nesting warnings from lockdep? If so
can you please post the full warnings somewhere? Or if some extra steps
are needed to reproduce please describe that too.

Chances are very high that your serial port is already runtime active at
this point unless you manually idle it so that's why I'm wondering as
all that likely is happening here is a check on the runtime PM usage count.

> So let us use pm_runtime_get_sync() to prevent these.

We need to fix this some other way as we can't use pm_runtime_get_sync()
here. The sync call variants require setting pm_runtime_irq_safe() for the
device. And this is what we really want to avoid as it takes a permanent
usage count on the parent device.

What we want to do here is to get runtime PM to wake-up the device if idle
and try tx again after runtime PM resume as needed.

Just guessing at this point.. To me it sounds like the fix might be to
use a raw spinlock for uart_port_lock() and uart_port_unlock()?

Regards,

Tony


> Fixes: 84a9582fd203 ("serial: core: Start managing serial controllers to enable runtime PM")
> Signed-off-by: Xuewen Yan <xuewen.yan@unisoc.com>
> ---
>  drivers/tty/serial/serial_core.c | 4 ++--
>  1 file changed, 2 insertions(+), 2 deletions(-)
> 
> diff --git a/drivers/tty/serial/serial_core.c b/drivers/tty/serial/serial_core.c
> index f1348a509552..902f7ed35f4d 100644
> --- a/drivers/tty/serial/serial_core.c
> +++ b/drivers/tty/serial/serial_core.c
> @@ -145,7 +145,7 @@ static void __uart_start(struct uart_state *state)
>  	port_dev = port->port_dev;
>  
>  	/* Increment the runtime PM usage count for the active check below */
> -	err = pm_runtime_get(&port_dev->dev);
> +	err = pm_runtime_get_sync(&port_dev->dev);
>  	if (err < 0 && err != -EINPROGRESS) {
>  		pm_runtime_put_noidle(&port_dev->dev);
>  		return;
> @@ -159,7 +159,7 @@ static void __uart_start(struct uart_state *state)
>  	if (!pm_runtime_enabled(port->dev) || pm_runtime_active(port->dev))
>  		port->ops->start_tx(port);
>  	pm_runtime_mark_last_busy(&port_dev->dev);
> -	pm_runtime_put_autosuspend(&port_dev->dev);
> +	pm_runtime_put_sync_autosuspend(&port_dev->dev);
>  }
>  
>  static void uart_start(struct tty_struct *tty)
> -- 
> 2.25.1
>
  
John Ogness Nov. 26, 2023, 4:17 p.m. UTC | #2
[Added printk maintainers CC.]

On 2023-11-24, Xuewen Yan <xuewen.yan@unisoc.com> wrote:
> The commit 84a9582fd203("serial: core: Start managing serial
> controllers to enable runtime PM") use the pm_runtime_get() after
> uart_port_lock() which would close the irq and disable preement.  At
> this time, pm_runtime_get may cause the following two problems:
>
> (1) deadlock in try_to_wake_up:
>
> uart_write()
> uart_port_lock() <<< get lock
> __uart_start
> __pm_runtime_resume
> rpm_resume
> queue_work_on
> try_to_wake_up
> _printk
> uart_console_write
> ...
> uart_port_lock() <<< wait forever

I suppose you got this because of the lockdep message generated by
#2. It probably would make sense to call __printk_safe_enter() inside
uart_port_lock(). This would allow printk() to automatically defer the
printing for that CPU until the port lock is released.

> (2) scheduling while atomic:
> uart_write()
> uart_port_lock() <<< get lock
> __uart_start
> __pm_runtime_resume
> rpm_resume
> schedule() << sleep

rpm_resume() is a fascinating function. It requires the caller to hold a
spin_lock (dev->power.lock) with interrupts disabled. But it seems to
believe that this is the *only* spin_lock held so that it can
temporarily spin_unlock and call might_sleep() functions. In the case of
uart_write(), it certainly is not the only spin_lock held.

I do not know enough about the internals of RPM to suggest a proper
solution. But it looks like rpm_resume() cannot assume dev->power.lock
is the only spin_lock held by the caller.

John Ogness
  
Xuewen Yan Nov. 27, 2023, 1:54 a.m. UTC | #3
Hi Tony

On Sat, Nov 25, 2023 at 3:48 PM Tony Lindgren <tony@atomide.com> wrote:
>
> * Xuewen Yan <xuewen.yan@unisoc.com> [231124 12:25]:
> > The commit 84a9582fd203("serial: core: Start managing serial controllers to enable runtime PM")
> > use the pm_runtime_get() after uart_port_lock() which would close the irq and disable preement.
> > At this time,  pm_runtime_get may cause the following two problems:
> >
> > (1) deadlock in try_to_wake_up:
> >
> > uart_write()
> > uart_port_lock() <<< get lock
> > __uart_start
> > __pm_runtime_resume
> > rpm_resume
> > queue_work_on
> > try_to_wake_up
> > _printk
> > uart_console_write
> > ...
> > uart_port_lock() <<< wait forever
> >
> > (2) scheduling while atomic:
> > uart_write()
> > uart_port_lock() <<< get lock
> > __uart_start
> > __pm_runtime_resume
> > rpm_resume
> > chedule() << sleep
>
> Are these spinlock vs raw spinlock nesting warnings from lockdep? If so
> can you please post the full warnings somewhere? Or if some extra steps
> are needed to reproduce please describe that too.

Indeed, we use pr_info in scheduler in our own kernel tree, and this
deadlock happended.
I would try to use printk_deferred and re-test.
And I also notice the warning was reported by syzbot:

https://lore.kernel.org/all/0000000000006f01f00608a16cea@google.com/
https://lore.kernel.org/all/000000000000e7765006072e9591@google.com/

These are also because the pm_runtime_put().

Thanks!

>
> Chances are very high that your serial port is already runtime active at
> this point unless you manually idle it so that's why I'm wondering as
> all that likely is happening here is a check on the runtime PM usage count.
>
> > So let us use pm_runtime_get_sync() to prevent these.
>
> We need to fix this some other way as we can't use pm_runtime_get_sync()
> here. The sync call variants require setting pm_runtime_irq_safe() for the
> device. And this is what we really want to avoid as it takes a permanent
> usage count on the parent device.
>
> What we want to do here is to get runtime PM to wake-up the device if idle
> and try tx again after runtime PM resume as needed.
>
> Just guessing at this point.. To me it sounds like the fix might be to
> use a raw spinlock for uart_port_lock() and uart_port_unlock()?
>
> Regards,
>
> Tony
>
>
> > Fixes: 84a9582fd203 ("serial: core: Start managing serial controllers to enable runtime PM")
> > Signed-off-by: Xuewen Yan <xuewen.yan@unisoc.com>
> > ---
> >  drivers/tty/serial/serial_core.c | 4 ++--
> >  1 file changed, 2 insertions(+), 2 deletions(-)
> >
> > diff --git a/drivers/tty/serial/serial_core.c b/drivers/tty/serial/serial_core.c
> > index f1348a509552..902f7ed35f4d 100644
> > --- a/drivers/tty/serial/serial_core.c
> > +++ b/drivers/tty/serial/serial_core.c
> > @@ -145,7 +145,7 @@ static void __uart_start(struct uart_state *state)
> >       port_dev = port->port_dev;
> >
> >       /* Increment the runtime PM usage count for the active check below */
> > -     err = pm_runtime_get(&port_dev->dev);
> > +     err = pm_runtime_get_sync(&port_dev->dev);
> >       if (err < 0 && err != -EINPROGRESS) {
> >               pm_runtime_put_noidle(&port_dev->dev);
> >               return;
> > @@ -159,7 +159,7 @@ static void __uart_start(struct uart_state *state)
> >       if (!pm_runtime_enabled(port->dev) || pm_runtime_active(port->dev))
> >               port->ops->start_tx(port);
> >       pm_runtime_mark_last_busy(&port_dev->dev);
> > -     pm_runtime_put_autosuspend(&port_dev->dev);
> > +     pm_runtime_put_sync_autosuspend(&port_dev->dev);
> >  }
> >
> >  static void uart_start(struct tty_struct *tty)
> > --
> > 2.25.1
> >
  
Xuewen Yan Nov. 27, 2023, 2:06 a.m. UTC | #4
Hi John

On Mon, Nov 27, 2023 at 12:17 AM John Ogness <john.ogness@linutronix.de> wrote:
>
> [Added printk maintainers CC.]
>
> On 2023-11-24, Xuewen Yan <xuewen.yan@unisoc.com> wrote:
> > The commit 84a9582fd203("serial: core: Start managing serial
> > controllers to enable runtime PM") use the pm_runtime_get() after
> > uart_port_lock() which would close the irq and disable preement.  At
> > this time, pm_runtime_get may cause the following two problems:
> >
> > (1) deadlock in try_to_wake_up:
> >
> > uart_write()
> > uart_port_lock() <<< get lock
> > __uart_start
> > __pm_runtime_resume
> > rpm_resume
> > queue_work_on
> > try_to_wake_up
> > _printk
> > uart_console_write
> > ...
> > uart_port_lock() <<< wait forever
>
> I suppose you got this because of the lockdep message generated by
> #2. It probably would make sense to call __printk_safe_enter() inside
> uart_port_lock(). This would allow printk() to automatically defer the
> printing for that CPU until the port lock is released.

Thanks for the suggestion, I would use printk_deferred in our tree to
retest the case.

And I also notice the warning was reported by syzbot:
https://lore.kernel.org/all/0000000000006f01f00608a16cea@google.com/
https://lore.kernel.org/all/000000000000e7765006072e9591@google.com/

>
> > (2) scheduling while atomic:
> > uart_write()
> > uart_port_lock() <<< get lock
> > __uart_start
> > __pm_runtime_resume
> > rpm_resume
> > schedule() << sleep
>
> rpm_resume() is a fascinating function. It requires the caller to hold a
> spin_lock (dev->power.lock) with interrupts disabled. But it seems to
> believe that this is the *only* spin_lock held so that it can
> temporarily spin_unlock and call might_sleep() functions. In the case of
> uart_write(), it certainly is not the only spin_lock held.
>
> I do not know enough about the internals of RPM to suggest a proper
> solution. But it looks like rpm_resume() cannot assume dev->power.lock
> is the only spin_lock held by the caller.

I would also be very grateful if could give us more suggestions.

Thanks!

BR
---
xuewen
>
> John Ogness
  
kernel test robot Nov. 28, 2023, 3:11 p.m. UTC | #5
Hello,

kernel test robot noticed "BUG:sleeping_function_called_from_invalid_context_at_drivers/base/power/runtime.c" on:

commit: 81a787668db066cb86873bd4f8fbf7c36ac8dd5a ("[RFC PATCH] serial: core: Use pm_runtime_get_sync() in uart_start()")
url: https://github.com/intel-lab-lkp/linux/commits/Xuewen-Yan/serial-core-Use-pm_runtime_get_sync-in-uart_start/20231124-202425
base: https://git.kernel.org/cgit/linux/kernel/git/gregkh/tty.git tty-next
patch link: https://lore.kernel.org/all/20231124122258.1050-1-xuewen.yan@unisoc.com/
patch subject: [RFC PATCH] serial: core: Use pm_runtime_get_sync() in uart_start()

in testcase: boot

compiler: gcc-12
test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G

(please refer to attached dmesg/kmsg for entire log/backtrace)



If you fix the issue in a separate patch/commit (i.e. not just a new version of
the same patch/commit), kindly add following tags
| Reported-by: kernel test robot <oliver.sang@intel.com>
| Closes: https://lore.kernel.org/oe-lkp/202311282251.b5351d99-oliver.sang@intel.com


[  678.716002][    T1] BUG: sleeping function called from invalid context at drivers/base/power/runtime.c:1163
[  678.716028][    T1]
[  678.716029][    T1] ======================================================
[  678.716030][    T1] WARNING: possible circular locking dependency detected
[  678.716031][    T1] 6.7.0-rc2-00001-g81a787668db0 #3 Tainted: G                 N
[  678.716033][    T1] ------------------------------------------------------
[  678.716033][    T1] init/1 is trying to acquire lock:
[ 678.716035][ T1] c249c82c (console_owner){-.-.}-{0:0}, at: console_flush_all (kernel/printk/printk.c:2894 kernel/printk/printk.c:2967) 
[  678.716047][    T1]
[  678.716047][    T1] but task is already holding lock:
[ 678.716048][ T1] c3356e90 (&port_lock_key){-.-.}-{2:2}, at: uart_write (drivers/tty/serial/serial_core.c:598) 
[  678.716057][    T1]
[  678.716057][    T1] which lock already depends on the new lock.
[  678.716057][    T1]
[  678.716057][    T1] the existing dependency chain (in reverse order) is:
[  678.716058][    T1]
[  678.716058][    T1] -> #1 (&port_lock_key){-.-.}-{2:2}:
[ 678.716062][ T1] __lock_acquire (kernel/locking/lockdep.c:5136) 
[ 678.716066][ T1] lock_acquire (kernel/locking/lockdep.c:467 kernel/locking/lockdep.c:5755) 
[ 678.716069][ T1] _raw_spin_lock_irqsave (include/linux/spinlock_api_smp.h:111 kernel/locking/spinlock.c:162) 
[ 678.716073][ T1] serial8250_console_write (drivers/tty/serial/8250/8250_port.c:3396) 
[ 678.716076][ T1] univ8250_console_write (drivers/tty/serial/8250/8250_core.c:601) 
[ 678.716079][ T1] console_flush_all (kernel/printk/printk.c:2905 kernel/printk/printk.c:2967) 
[ 678.716081][ T1] console_unlock (kernel/printk/printk.c:3037) 
[ 678.716084][ T1] vprintk_emit (arch/x86/include/asm/preempt.h:85 kernel/printk/printk.c:2304) 
[ 678.716086][ T1] vprintk_default (kernel/printk/printk.c:2319) 
[ 678.716089][ T1] vprintk (kernel/printk/printk_safe.c:46) 
[ 678.716091][ T1] _printk (kernel/printk/printk.c:2332) 
[ 678.716093][ T1] register_console (kernel/printk/printk.c:3543) 
[ 678.716096][ T1] univ8250_console_init (drivers/tty/serial/8250/8250_core.c:718) 
[ 678.716102][ T1] console_init (arch/x86/include/asm/atomic.h:23 include/linux/atomic/atomic-arch-fallback.h:457 include/linux/jump_label.h:260 include/linux/jump_label.h:270 include/trace/events/initcall.h:48 kernel/printk/printk.c:3689) 
[ 678.716104][ T1] start_kernel (init/main.c:1009 (discriminator 3)) 
[ 678.716108][ T1] i386_start_kernel (??:?) 
[ 678.716112][ T1] startup_32_smp (arch/x86/kernel/head_32.S:295) 
[  678.716115][    T1]
[  678.716115][    T1] -> #0 (console_owner){-.-.}-{0:0}:
[ 678.716118][ T1] check_prev_add (kernel/locking/lockdep.c:3135) 
[ 678.716121][ T1] validate_chain (kernel/locking/lockdep.c:3254 kernel/locking/lockdep.c:3868) 
[ 678.716124][ T1] __lock_acquire (kernel/locking/lockdep.c:5136) 
[ 678.716126][ T1] lock_acquire (kernel/locking/lockdep.c:467 kernel/locking/lockdep.c:5755) 
[ 678.716129][ T1] console_flush_all (kernel/printk/printk.c:2901 kernel/printk/printk.c:2967) 
[ 678.716131][ T1] console_unlock (kernel/printk/printk.c:3037) 
[ 678.716134][ T1] vprintk_emit (arch/x86/include/asm/preempt.h:85 kernel/printk/printk.c:2304) 
[ 678.716136][ T1] vprintk_default (kernel/printk/printk.c:2319) 
[ 678.716138][ T1] vprintk (kernel/printk/printk_safe.c:46) 
[ 678.716140][ T1] _printk (kernel/printk/printk.c:2332) 
[ 678.716142][ T1] __might_resched (kernel/sched/core.c:10130) 
[ 678.716145][ T1] __might_sleep (kernel/sched/core.c:10081 (discriminator 17)) 
[ 678.716147][ T1] __pm_runtime_resume (drivers/base/power/runtime.c:1163 (discriminator 5)) 
[ 678.716152][ T1] __uart_start (drivers/tty/serial/serial_core.c:149) 
[ 678.716156][ T1] uart_write (include/linux/spinlock.h:406 include/linux/serial_core.h:667 drivers/tty/serial/serial_core.c:617) 
[ 678.716159][ T1] process_output_block (drivers/tty/n_tty.c:574) 
[ 678.716163][ T1] n_tty_write (drivers/tty/n_tty.c:2380) 
[ 678.716166][ T1] iterate_tty_write (drivers/tty/tty_io.c:1022) 
[ 678.716169][ T1] file_tty_write+0x80/0x10c 
[ 678.716172][ T1] redirected_tty_write (drivers/tty/tty_io.c:1137) 
[ 678.716175][ T1] vfs_write (fs/read_write.c:492 fs/read_write.c:584) 
[ 678.716179][ T1] ksys_write (fs/read_write.c:638) 
[ 678.716180][ T1] __ia32_sys_write (fs/read_write.c:646) 
[ 678.716182][ T1] do_int80_syscall_32 (arch/x86/entry/common.c:164 arch/x86/entry/common.c:184) 
[ 678.716185][ T1] restore_all_switch_stack (arch/x86/entry/entry_32.S:947) 
[  678.716190][    T1]
[  678.716190][    T1] other info that might help us debug this:
[  678.716190][    T1]
[  678.716191][    T1]  Possible unsafe locking scenario:
[  678.716191][    T1]
[  678.716192][    T1]        CPU0                    CPU1
[  678.716193][    T1]        ----                    ----
[  678.716193][    T1]   lock(&port_lock_key);
[  678.716195][    T1]                                lock(console_owner);
[  678.716196][    T1]                                lock(&port_lock_key);
[  678.716198][    T1]   lock(console_owner);
[  678.716199][    T1]
[  678.716199][    T1]  *** DEADLOCK ***
[  678.716199][    T1]
[  678.716200][    T1] 7 locks held by init/1:
[ 678.716202][ T1] #0: c3fc5060 (&tty->ldisc_sem){++++}-{0:0}, at: ldsem_down_read (drivers/tty/tty_ldsem.c:341) 
[ 678.716211][ T1] #1: c3fc50b8 (&tty->atomic_write_lock){+.+.}-{3:3}, at: iterate_tty_write (drivers/tty/tty_io.c:954 drivers/tty/tty_io.c:973) 
[ 678.716217][ T1] #2: c3fc51c4 (&tty->termios_rwsem){++++}-{3:3}, at: n_tty_write (drivers/tty/n_tty.c:2365) 
[ 678.716223][ T1] #3: ef4112f0 (&ldata->output_lock){+.+.}-{3:3}, at: process_output_block (drivers/tty/n_tty.c:531) 
[ 678.716229][ T1] #4: c3356e90 (&port_lock_key){-.-.}-{2:2}, at: uart_write (drivers/tty/serial/serial_core.c:598) 
[ 678.716236][ T1] #5: c27bc9a8 (console_lock){+.+.}-{0:0}, at: vprintk_default (kernel/printk/printk.c:2319) 
[ 678.716241][ T1] #6: c27bca58 (console_srcu){....}-{0:0}, at: console_flush_all (include/linux/srcutiny.h:67 include/linux/srcu.h:70 include/linux/srcu.h:231 kernel/printk/printk.c:286 kernel/printk/printk.c:2959) 
[  678.716247][    T1]
[  678.716247][    T1] stack backtrace:
[  678.716248][    T1] CPU: 0 PID: 1 Comm: init Tainted: G                 N 6.7.0-rc2-00001-g81a787668db0 #3 457007a7b9fe78ab16bc9131e3cdb3e013769988
[  678.716253][    T1] Call Trace:
[ 678.716254][ T1] dump_stack_lvl (lib/dump_stack.c:108) 
[ 678.716259][ T1] dump_stack (lib/dump_stack.c:114) 
[ 678.716262][ T1] print_circular_bug (kernel/locking/lockdep.c:2061) 
[ 678.716266][ T1] check_noncircular (kernel/locking/lockdep.c:2190) 
[ 678.716271][ T1] check_prev_add (kernel/locking/lockdep.c:3135) 
[ 678.716275][ T1] validate_chain (kernel/locking/lockdep.c:3254 kernel/locking/lockdep.c:3868) 
[ 678.716279][ T1] __lock_acquire (kernel/locking/lockdep.c:5136) 
[ 678.716282][ T1] ? sched_clock_noinstr (arch/x86/kernel/tsc.c:267) 
[ 678.716285][ T1] ? local_clock_noinstr (kernel/sched/clock.c:301) 
[ 678.716290][ T1] lock_acquire (kernel/locking/lockdep.c:467 kernel/locking/lockdep.c:5755) 
[ 678.716293][ T1] ? console_flush_all (kernel/printk/printk.c:2894 kernel/printk/printk.c:2967) 
[ 678.716296][ T1] ? console_flush_all (kernel/printk/printk.c:1854 kernel/printk/printk.c:2895 kernel/printk/printk.c:2967) 
[ 678.716299][ T1] ? lock_release (kernel/locking/lockdep.c:467 kernel/locking/lockdep.c:5775) 
[ 678.716303][ T1] console_flush_all (kernel/printk/printk.c:2901 kernel/printk/printk.c:2967) 
[ 678.716306][ T1] ? console_flush_all (kernel/printk/printk.c:2894 kernel/printk/printk.c:2967) 
[ 678.716310][ T1] console_unlock (kernel/printk/printk.c:3037) 
[ 678.716313][ T1] vprintk_emit (arch/x86/include/asm/preempt.h:85 kernel/printk/printk.c:2304) 
[ 678.716316][ T1] vprintk_default (kernel/printk/printk.c:2319) 
[ 678.716319][ T1] vprintk (kernel/printk/printk_safe.c:46) 
[ 678.716322][ T1] _printk (kernel/printk/printk.c:2332) 
[ 678.716324][ T1] __might_resched (kernel/sched/core.c:10130) 
[ 678.716328][ T1] __might_sleep (kernel/sched/core.c:10081 (discriminator 17)) 
[ 678.716331][ T1] ? uart_write (drivers/tty/serial/serial_core.c:598) 
[ 678.716335][ T1] ? lock_acquired (kernel/locking/lockdep.c:467 kernel/locking/lockdep.c:6035) 
[ 678.716337][ T1] __pm_runtime_resume (drivers/base/power/runtime.c:1163 (discriminator 5)) 
[ 678.716341][ T1] ? _raw_spin_lock_irqsave (kernel/locking/spinlock.c:163) 
[ 678.716344][ T1] __uart_start (drivers/tty/serial/serial_core.c:149) 
[ 678.716348][ T1] uart_write (include/linux/spinlock.h:406 include/linux/serial_core.h:667 drivers/tty/serial/serial_core.c:617) 
[ 678.716352][ T1] ? uart_write_room (drivers/tty/serial/serial_core.c:74 drivers/tty/serial/serial_core.c:630) 
[ 678.716356][ T1] process_output_block (drivers/tty/n_tty.c:574) 
[ 678.716361][ T1] n_tty_write (drivers/tty/n_tty.c:2380) 
[ 678.716365][ T1] ? autoremove_wake_function (kernel/sched/wait.c:439) 
[ 678.716370][ T1] iterate_tty_write (drivers/tty/tty_io.c:1022) 
[ 678.716375][ T1] file_tty_write+0x80/0x10c 
[ 678.716378][ T1] ? lock_release (kernel/locking/lockdep.c:467 kernel/locking/lockdep.c:5775) 
[ 678.716382][ T1] redirected_tty_write (drivers/tty/tty_io.c:1137) 
[ 678.716385][ T1] vfs_write (fs/read_write.c:492 fs/read_write.c:584) 
[ 678.716389][ T1] ? exit_to_user_mode_prepare (kernel/entry/common.c:212 (discriminator 43)) 
[ 678.716395][ T1] ksys_write (fs/read_write.c:638) 
[ 678.716398][ T1] __ia32_sys_write (fs/read_write.c:646) 
[ 678.716400][ T1] do_int80_syscall_32 (arch/x86/entry/common.c:164 arch/x86/entry/common.c:184) 
[ 678.716403][ T1] ? syscall_exit_to_user_mode (kernel/entry/common.c:299) 
[ 678.716406][ T1] ? do_int80_syscall_32 (arch/x86/entry/common.c:188) 
[ 678.716408][ T1] ? irqentry_exit_to_user_mode (kernel/entry/common.c:312) 
[ 678.716412][ T1] ? irqentry_exit (kernel/entry/common.c:445) 
[ 678.716415][ T1] ? exc_page_fault (arch/x86/mm/fault.c:1565) 
[ 678.716417][ T1] ? rest_init (init/main.c:1433) 
[ 678.716420][ T1] entry_INT80_32 (arch/x86/entry/entry_32.S:947) 
[  678.716424][    T1] EIP: 0xb7e9b6c2
[ 678.716427][ T1] Code: 90 66 90 66 90 66 90 90 56 53 83 ec 14 8b 5c 24 20 8b 4c 24 24 8b 54 24 28 65 a1 0c 00 00 00 85 c0 75 15 b8 04 00 00 00 cd 80 <3d> 00 f0 ff ff 77 47 83 c4 14 5b 5e c3 90 89 54 24 0c 89 4c 24 08
All code
========
   0:	90                   	nop
   1:	66 90                	xchg   %ax,%ax
   3:	66 90                	xchg   %ax,%ax
   5:	66 90                	xchg   %ax,%ax
   7:	90                   	nop
   8:	56                   	push   %rsi
   9:	53                   	push   %rbx
   a:	83 ec 14             	sub    $0x14,%esp
   d:	8b 5c 24 20          	mov    0x20(%rsp),%ebx
  11:	8b 4c 24 24          	mov    0x24(%rsp),%ecx
  15:	8b 54 24 28          	mov    0x28(%rsp),%edx
  19:	65 a1 0c 00 00 00 85 	movabs %gs:0x1575c0850000000c,%eax
  20:	c0 75 15 
  23:	b8 04 00 00 00       	mov    $0x4,%eax
  28:	cd 80                	int    $0x80


The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20231128/202311282251.b5351d99-oliver.sang@intel.com
  

Patch

diff --git a/drivers/tty/serial/serial_core.c b/drivers/tty/serial/serial_core.c
index f1348a509552..902f7ed35f4d 100644
--- a/drivers/tty/serial/serial_core.c
+++ b/drivers/tty/serial/serial_core.c
@@ -145,7 +145,7 @@  static void __uart_start(struct uart_state *state)
 	port_dev = port->port_dev;
 
 	/* Increment the runtime PM usage count for the active check below */
-	err = pm_runtime_get(&port_dev->dev);
+	err = pm_runtime_get_sync(&port_dev->dev);
 	if (err < 0 && err != -EINPROGRESS) {
 		pm_runtime_put_noidle(&port_dev->dev);
 		return;
@@ -159,7 +159,7 @@  static void __uart_start(struct uart_state *state)
 	if (!pm_runtime_enabled(port->dev) || pm_runtime_active(port->dev))
 		port->ops->start_tx(port);
 	pm_runtime_mark_last_busy(&port_dev->dev);
-	pm_runtime_put_autosuspend(&port_dev->dev);
+	pm_runtime_put_sync_autosuspend(&port_dev->dev);
 }
 
 static void uart_start(struct tty_struct *tty)