When console is enabled, univ8250_console_setup() calls
serial8250_console_setup() before .dev is set to uart_port. Therefore,
it will not call pm_runtime_get_sync(). Later, when the actual driver
is going to take over univ8250_console_exit() is called. As .dev is
already set, serial8250_console_exit() makes pm_runtime_put_sync() call
with usage count being zero triggering PM usage count warning
(extra debug for univ8250_console_setup(), univ8250_console_exit(), and
serial8250_register_ports()):
[ 0.068987] univ8250_console_setup ttyS0 nodev
[ 0.499670] printk: console [ttyS0] enabled
[ 0.717955] printk: console [ttyS0] printing thread started
[ 1.960163] serial8250_register_ports assigned dev for ttyS0
[ 1.976830] printk: console [ttyS0] disabled
[ 1.976888] printk: console [ttyS0] printing thread stopped
[ 1.977073] univ8250_console_exit ttyS0 usage:0
[ 1.977075] serial8250 serial8250: Runtime PM usage count underflow!
[ 1.977429] dw-apb-uart.6: ttyS0 at MMIO 0x4010006000 (irq = 33, base_baud = 115200) is a 16550A
[ 1.977812] univ8250_console_setup ttyS0 usage:2
[ 1.978167] printk: console [ttyS0] printing thread started
[ 1.978203] printk: console [ttyS0] enabled
To fix the issue, call pm_runtime_get_sync() in
serial8250_register_ports() as soon as .dev is set for an uart_port
if it has console enabled.
This problem became apparent only recently because 82586a721595 ("PM:
runtime: Avoid device usage count underflows") added the warning
printout. I confirmed this problem also occurs with v5.18 (w/o the
warning printout, obviously) so the recent printk kthreads are not the
cause for this.
Fixes: bedb404e91bb ("serial: 8250_port: Don't use power management for kernel console")
Signed-off-by: Ilpo Järvinen <[email protected]>
---
drivers/tty/serial/8250/8250_core.c | 4 ++++
drivers/tty/serial/serial_core.c | 5 -----
include/linux/serial_core.h | 5 +++++
3 files changed, 9 insertions(+), 5 deletions(-)
diff --git a/drivers/tty/serial/8250/8250_core.c b/drivers/tty/serial/8250/8250_core.c
index 57e86133af4f..2e83e7367441 100644
--- a/drivers/tty/serial/8250/8250_core.c
+++ b/drivers/tty/serial/8250/8250_core.c
@@ -23,6 +23,7 @@
#include <linux/sysrq.h>
#include <linux/delay.h>
#include <linux/platform_device.h>
+#include <linux/pm_runtime.h>
#include <linux/tty.h>
#include <linux/ratelimit.h>
#include <linux/tty_flip.h>
@@ -558,6 +559,9 @@ serial8250_register_ports(struct uart_driver *drv, struct device *dev)
up->port.dev = dev;
+ if (uart_console_enabled(&up->port))
+ pm_runtime_get_sync(up->port.dev);
+
serial8250_apply_quirks(up);
uart_add_one_port(drv, &up->port);
}
diff --git a/drivers/tty/serial/serial_core.c b/drivers/tty/serial/serial_core.c
index 85ef7ef00b82..3161445504bc 100644
--- a/drivers/tty/serial/serial_core.c
+++ b/drivers/tty/serial/serial_core.c
@@ -2024,11 +2024,6 @@ static int uart_proc_show(struct seq_file *m, void *v)
}
#endif
-static inline bool uart_console_enabled(struct uart_port *port)
-{
- return uart_console(port) && (port->cons->flags & CON_ENABLED);
-}
-
static void uart_port_spin_lock_init(struct uart_port *port)
{
spin_lock_init(&port->lock);
diff --git a/include/linux/serial_core.h b/include/linux/serial_core.h
index b7b86ee3cb12..9d8aa139b175 100644
--- a/include/linux/serial_core.h
+++ b/include/linux/serial_core.h
@@ -404,6 +404,11 @@ static const bool earlycon_acpi_spcr_enable EARLYCON_USED_OR_UNUSED;
static inline int setup_earlycon(char *buf) { return 0; }
#endif
+static inline bool uart_console_enabled(struct uart_port *port)
+{
+ return uart_console(port) && (port->cons->flags & CON_ENABLED);
+}
+
struct uart_port *uart_get_console(struct uart_port *ports, int nr,
struct console *c);
int uart_parse_earlycon(char *p, unsigned char *iotype, resource_size_t *addr,
--
tg: (f287f971e256..) fix/console-usage_count (depends on: tty-next)
On Tue, Jun 28, 2022 at 07:58:34PM +0300, Ilpo J?rvinen wrote:
> When console is enabled, univ8250_console_setup() calls
> serial8250_console_setup() before .dev is set to uart_port. Therefore,
> it will not call pm_runtime_get_sync(). Later, when the actual driver
> is going to take over univ8250_console_exit() is called. As .dev is
> already set, serial8250_console_exit() makes pm_runtime_put_sync() call
> with usage count being zero triggering PM usage count warning
> (extra debug for univ8250_console_setup(), univ8250_console_exit(), and
> serial8250_register_ports()):
>
> [ 0.068987] univ8250_console_setup ttyS0 nodev
> [ 0.499670] printk: console [ttyS0] enabled
> [ 0.717955] printk: console [ttyS0] printing thread started
> [ 1.960163] serial8250_register_ports assigned dev for ttyS0
> [ 1.976830] printk: console [ttyS0] disabled
> [ 1.976888] printk: console [ttyS0] printing thread stopped
> [ 1.977073] univ8250_console_exit ttyS0 usage:0
> [ 1.977075] serial8250 serial8250: Runtime PM usage count underflow!
> [ 1.977429] dw-apb-uart.6: ttyS0 at MMIO 0x4010006000 (irq = 33, base_baud = 115200) is a 16550A
> [ 1.977812] univ8250_console_setup ttyS0 usage:2
> [ 1.978167] printk: console [ttyS0] printing thread started
> [ 1.978203] printk: console [ttyS0] enabled
>
> To fix the issue, call pm_runtime_get_sync() in
> serial8250_register_ports() as soon as .dev is set for an uart_port
> if it has console enabled.
>
> This problem became apparent only recently because 82586a721595 ("PM:
> runtime: Avoid device usage count underflows") added the warning
> printout. I confirmed this problem also occurs with v5.18 (w/o the
> warning printout, obviously) so the recent printk kthreads are not the
> cause for this.
Since printk kthread was reverted, you may drop its mention here completely.
In any case, good catch!
Reviewed-by: Andy Shevchenko <[email protected]>
But it would be good to be tested by Tony.
> Fixes: bedb404e91bb ("serial: 8250_port: Don't use power management for kernel console")
> Signed-off-by: Ilpo J?rvinen <[email protected]>
>
> ---
> drivers/tty/serial/8250/8250_core.c | 4 ++++
> drivers/tty/serial/serial_core.c | 5 -----
> include/linux/serial_core.h | 5 +++++
> 3 files changed, 9 insertions(+), 5 deletions(-)
>
> diff --git a/drivers/tty/serial/8250/8250_core.c b/drivers/tty/serial/8250/8250_core.c
> index 57e86133af4f..2e83e7367441 100644
> --- a/drivers/tty/serial/8250/8250_core.c
> +++ b/drivers/tty/serial/8250/8250_core.c
> @@ -23,6 +23,7 @@
> #include <linux/sysrq.h>
> #include <linux/delay.h>
> #include <linux/platform_device.h>
> +#include <linux/pm_runtime.h>
> #include <linux/tty.h>
> #include <linux/ratelimit.h>
> #include <linux/tty_flip.h>
> @@ -558,6 +559,9 @@ serial8250_register_ports(struct uart_driver *drv, struct device *dev)
>
> up->port.dev = dev;
>
> + if (uart_console_enabled(&up->port))
> + pm_runtime_get_sync(up->port.dev);
> +
> serial8250_apply_quirks(up);
> uart_add_one_port(drv, &up->port);
> }
> diff --git a/drivers/tty/serial/serial_core.c b/drivers/tty/serial/serial_core.c
> index 85ef7ef00b82..3161445504bc 100644
> --- a/drivers/tty/serial/serial_core.c
> +++ b/drivers/tty/serial/serial_core.c
> @@ -2024,11 +2024,6 @@ static int uart_proc_show(struct seq_file *m, void *v)
> }
> #endif
>
> -static inline bool uart_console_enabled(struct uart_port *port)
> -{
> - return uart_console(port) && (port->cons->flags & CON_ENABLED);
> -}
> -
> static void uart_port_spin_lock_init(struct uart_port *port)
> {
> spin_lock_init(&port->lock);
> diff --git a/include/linux/serial_core.h b/include/linux/serial_core.h
> index b7b86ee3cb12..9d8aa139b175 100644
> --- a/include/linux/serial_core.h
> +++ b/include/linux/serial_core.h
> @@ -404,6 +404,11 @@ static const bool earlycon_acpi_spcr_enable EARLYCON_USED_OR_UNUSED;
> static inline int setup_earlycon(char *buf) { return 0; }
> #endif
>
> +static inline bool uart_console_enabled(struct uart_port *port)
> +{
> + return uart_console(port) && (port->cons->flags & CON_ENABLED);
> +}
> +
> struct uart_port *uart_get_console(struct uart_port *ports, int nr,
> struct console *c);
> int uart_parse_earlycon(char *p, unsigned char *iotype, resource_size_t *addr,
>
> --
> tg: (f287f971e256..) fix/console-usage_count (depends on: tty-next)
--
With Best Regards,
Andy Shevchenko
On Wed, 29 Jun 2022, Tony Lindgren wrote:
> * Andy Shevchenko <[email protected]> [220628 21:09]:
> > On Tue, Jun 28, 2022 at 07:58:34PM +0300, Ilpo Järvinen wrote:
> > > When console is enabled, univ8250_console_setup() calls
> > > serial8250_console_setup() before .dev is set to uart_port. Therefore,
> > > it will not call pm_runtime_get_sync(). Later, when the actual driver
> > > is going to take over univ8250_console_exit() is called. As .dev is
> > > already set, serial8250_console_exit() makes pm_runtime_put_sync() call
> > > with usage count being zero triggering PM usage count warning
> > > (extra debug for univ8250_console_setup(), univ8250_console_exit(), and
> > > serial8250_register_ports()):
>
> Hmm so serial8250_console_setup() calls pm_runtime_get_sync() if dev
> exists..
>
> > > diff --git a/drivers/tty/serial/8250/8250_core.c b/drivers/tty/serial/8250/8250_core.c
> > > index 57e86133af4f..2e83e7367441 100644
> > > --- a/drivers/tty/serial/8250/8250_core.c
> > > +++ b/drivers/tty/serial/8250/8250_core.c
> > > @@ -23,6 +23,7 @@
> > > #include <linux/sysrq.h>
> > > #include <linux/delay.h>
> > > #include <linux/platform_device.h>
> > > +#include <linux/pm_runtime.h>
> > > #include <linux/tty.h>
> > > #include <linux/ratelimit.h>
> > > #include <linux/tty_flip.h>
> > > @@ -558,6 +559,9 @@ serial8250_register_ports(struct uart_driver *drv, struct device *dev)
> > >
> > > up->port.dev = dev;
> > >
> > > + if (uart_console_enabled(&up->port))
> > > + pm_runtime_get_sync(up->port.dev);
> > > +
> > > serial8250_apply_quirks(up);
> > > uart_add_one_port(drv, &up->port);
> > > }
>
> ..and now we also call it here. Are there now cases where pm_runtime_get_sync()
> gets called twice potentially or does uart_console_enabled() ensure that is
> not the case already?
The code in serial8250_register_ports() right before that context block is
this:
if (up->port.dev)
continue;
If serial8250_console_setup() already saw .dev != NULL, we take that
continue and pm_runtime_get_sync() will not get called again here.
--
i.
* Andy Shevchenko <[email protected]> [220628 21:09]:
> On Tue, Jun 28, 2022 at 07:58:34PM +0300, Ilpo Järvinen wrote:
> > When console is enabled, univ8250_console_setup() calls
> > serial8250_console_setup() before .dev is set to uart_port. Therefore,
> > it will not call pm_runtime_get_sync(). Later, when the actual driver
> > is going to take over univ8250_console_exit() is called. As .dev is
> > already set, serial8250_console_exit() makes pm_runtime_put_sync() call
> > with usage count being zero triggering PM usage count warning
> > (extra debug for univ8250_console_setup(), univ8250_console_exit(), and
> > serial8250_register_ports()):
Hmm so serial8250_console_setup() calls pm_runtime_get_sync() if dev
exists..
> > diff --git a/drivers/tty/serial/8250/8250_core.c b/drivers/tty/serial/8250/8250_core.c
> > index 57e86133af4f..2e83e7367441 100644
> > --- a/drivers/tty/serial/8250/8250_core.c
> > +++ b/drivers/tty/serial/8250/8250_core.c
> > @@ -23,6 +23,7 @@
> > #include <linux/sysrq.h>
> > #include <linux/delay.h>
> > #include <linux/platform_device.h>
> > +#include <linux/pm_runtime.h>
> > #include <linux/tty.h>
> > #include <linux/ratelimit.h>
> > #include <linux/tty_flip.h>
> > @@ -558,6 +559,9 @@ serial8250_register_ports(struct uart_driver *drv, struct device *dev)
> >
> > up->port.dev = dev;
> >
> > + if (uart_console_enabled(&up->port))
> > + pm_runtime_get_sync(up->port.dev);
> > +
> > serial8250_apply_quirks(up);
> > uart_add_one_port(drv, &up->port);
> > }
..and now we also call it here. Are there now cases where pm_runtime_get_sync()
gets called twice potentially or does uart_console_enabled() ensure that is
not the case already?
Regards,
Tony
* Ilpo Järvinen <[email protected]> [220629 09:26]:
> On Wed, 29 Jun 2022, Tony Lindgren wrote:
>
> > * Andy Shevchenko <[email protected]> [220628 21:09]:
> > > On Tue, Jun 28, 2022 at 07:58:34PM +0300, Ilpo Järvinen wrote:
> > > > When console is enabled, univ8250_console_setup() calls
> > > > serial8250_console_setup() before .dev is set to uart_port. Therefore,
> > > > it will not call pm_runtime_get_sync(). Later, when the actual driver
> > > > is going to take over univ8250_console_exit() is called. As .dev is
> > > > already set, serial8250_console_exit() makes pm_runtime_put_sync() call
> > > > with usage count being zero triggering PM usage count warning
> > > > (extra debug for univ8250_console_setup(), univ8250_console_exit(), and
> > > > serial8250_register_ports()):
> >
> > Hmm so serial8250_console_setup() calls pm_runtime_get_sync() if dev
> > exists..
> >
> > > > diff --git a/drivers/tty/serial/8250/8250_core.c b/drivers/tty/serial/8250/8250_core.c
> > > > index 57e86133af4f..2e83e7367441 100644
> > > > --- a/drivers/tty/serial/8250/8250_core.c
> > > > +++ b/drivers/tty/serial/8250/8250_core.c
> > > > @@ -23,6 +23,7 @@
> > > > #include <linux/sysrq.h>
> > > > #include <linux/delay.h>
> > > > #include <linux/platform_device.h>
> > > > +#include <linux/pm_runtime.h>
> > > > #include <linux/tty.h>
> > > > #include <linux/ratelimit.h>
> > > > #include <linux/tty_flip.h>
> > > > @@ -558,6 +559,9 @@ serial8250_register_ports(struct uart_driver *drv, struct device *dev)
> > > >
> > > > up->port.dev = dev;
> > > >
> > > > + if (uart_console_enabled(&up->port))
> > > > + pm_runtime_get_sync(up->port.dev);
> > > > +
> > > > serial8250_apply_quirks(up);
> > > > uart_add_one_port(drv, &up->port);
> > > > }
> >
> > ..and now we also call it here. Are there now cases where pm_runtime_get_sync()
> > gets called twice potentially or does uart_console_enabled() ensure that is
> > not the case already?
>
> The code in serial8250_register_ports() right before that context block is
> this:
>
> if (up->port.dev)
> continue;
>
> If serial8250_console_setup() already saw .dev != NULL, we take that
> continue and pm_runtime_get_sync() will not get called again here.
OK thanks. Looks good to me:
Reviewed-by: Tony Lindgren <[email protected]>
Tested-by: Tony Lindgren <[email protected]>