Re: PNP0501 serial driver takes almost 2 seconds to suspend/resume (printk issue)

[John Ogness <john.ogness@linutronix.de>]

On 2022-07-08, Todd Brandt <todd.e.brandt@linux.intel.com> wrote:
> The dmesg logs are in the html timelines themselves, just click the
> "dmesg" button in the upper right hand corner. The log button shows
> all kinds of system info as well.

Since the beginning of the kernel log is missing, I still do not see
information about which serial driver you are using. But since it is
x86, I'll assume it is an 8250.

Looking at freeze-5.19.0-rc1-bad.html, at 3431.221039 we see that
suspend_console() was called. The additional 1-second delay you are
referring to would be 3432.436187, where serial is suspended. pr_flush()
would have been satisfied when the message at 3431.221039 was
printed. So the question is, why is there still printing going on?

@Todd: I assume you actually see all the messages up to and including
3431.506391 when it suspends? But the next message does not appear on
suspend?

I wonder if the console_lock()/console_unlock() within __pr_flush() is
allowing extra printing to occur, for example if another CPU was calling
printk.

@Todd: Could you build your kernel with CONFIG_PRINTK_CALLER enabled?
Also, please provide the last line you _see_ after a suspend. And
finally, please make sure you are using the latest 5.19-rc. Thanks!

John Ogness