Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20;
Date:   Wed, 29 Jun 2022 00:14:33 +0300
From:   Andy Shevchenko <andriy.shevchenko@linux.intel.com>
To:     Ilpo =?iso-8859-1?Q?J=E4rvinen?= <ilpo.jarvinen@linux.intel.com>
Cc:     Greg Kroah-Hartman <gregkh@linuxfoundation.org>,
        Jiri Slaby <jirislaby@kernel.org>,
        linux-serial@vger.kernel.org, linux-kernel@vger.kernel.org,
        Tony Lindgren <tony@atomide.com>
Subject: Re: [PATCH] serial: 8250: Fix PM usage_count for console handover
Message-ID: <YrtvOSrrSLGX/coS@smile.fi.intel.com>
References: <20220628165834.63044-1-ilpo.jarvinen@linux.intel.com>
MIME-Version: 1.0
Content-Type: text/plain; charset=iso-8859-1
Content-Disposition: inline
Content-Transfer-Encoding: 8bit
In-Reply-To: <20220628165834.63044-1-ilpo.jarvinen@linux.intel.com>
Organization: Intel Finland Oy - BIC 0357606-4 - Westendinkatu 7, 02160 Espoo
Precedence: bulk

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 <andriy.shevchenko@linux.intel.com>

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 <ilpo.jarvinen@linux.intel.com>
> 
> ---
>  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