printk: Add atomic context check inside console_unlock()

Message ID 20240222090538.23017-1-quic_mojha@quicinc.com
State New
Headers
Series printk: Add atomic context check inside console_unlock() |

Commit Message

Mukesh Ojha Feb. 22, 2024, 9:05 a.m. UTC
  Situation of schedule while atomic context can happen in a
scenario if CPU-Y executing a async probe of ufs and while
printing a line it is started spinning for console lock
after preemption disable on CPU-Y and later it got the handover
of console lock from CPU-X and in console_unlock() it get
schedule with preempt disable as console_may_schedule was one
and due to which do_cond_resched was one.

         CPU-X                          CPU-Y

                                      worker_thread
                                       process_one_work
                                        async_run_entry_fn
                                         ufshcd_async_scan
                                          ufshcd_device_init
really_probe+0x1c8                         ufshcd_probe_hba
 platform_probe+0xc0                        ufshcd_config_mcq
  qcom_geni_serial_probe+0x374               _dev_info
   uart_add_one_port+0x10                     __dev_printk
    serial_ctrl_register_port+0x10             dev_printk_emit
     serial_core_register_port+0x5dc            dev_vprintk_emit
      register_console+0x284                      vprintk_emit
       console_init_seq()                          preempt_disable();
	                                           console_trylock_spinning()
        console_lock();
         console_flush_all()

Hand over of console lock happen from CPU-X to CPU-Y
                                                   console_unlock()
          console_lock+0x74                         console_flush_all
	   down[jt]+0x40                             __might_resched
	    __down+0x18
             __down_common+0x68
              ___down_common+0xdc
               schedule_timeout+0x4c
                schedule+0x78
                 __schedule+0x6c0

Signed-off-by: Mukesh Ojha <quic_mojha@quicinc.com>
---
 kernel/printk/printk.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)
  

Comments

John Ogness Feb. 22, 2024, 2:53 p.m. UTC | #1
On 2024-02-22, Mukesh Ojha <quic_mojha@quicinc.com> wrote:
> Situation of schedule while atomic context can happen in a
> scenario if CPU-Y executing a async probe of ufs and while
> printing a line it is started spinning for console lock
> after preemption disable on CPU-Y and later it got the handover
> of console lock from CPU-X and in console_unlock() it get
> schedule with preempt disable as console_may_schedule was one
> and due to which do_cond_resched was one.

Nice catch. But I think the below patch is the appropriate fix:

John Ogness

-------8<--------
Subject: [PATCH] printk: Update @console_may_schedule in
 console_trylock_spinning()

console_trylock_spinning() may takeover the console lock from a
scheduable context. Update @console_may_schedule to make sure it
reflects a trylock acquire.

Reported-by: Mukesh Ojha <quic_mojha@quicinc.com>
Link: https://lore.kernel.org/lkml/20240222090538.23017-1-quic_mojha@quicinc.com
Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 kernel/printk/printk.c | 6 ++++++
 1 file changed, 6 insertions(+)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 1685a71f3f71..1612b50b2374 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2020,6 +2020,12 @@ static int console_trylock_spinning(void)
 	 */
 	mutex_acquire(&console_lock_dep_map, 0, 1, _THIS_IP_);
 
+	/*
+	 * Update @console_may_schedule for trylock because the previous
+	 * owner may have been scheduable.
+	 */
+	console_may_schedule = 0;
+
 	return 1;
 }
 

base-commit: e7081d5a9d976b84f61f497316d7c940a4a2e67a
  
Mukesh Ojha Feb. 26, 2024, 10:17 a.m. UTC | #2
On 2/22/2024 8:23 PM, John Ogness wrote:
> On 2024-02-22, Mukesh Ojha <quic_mojha@quicinc.com> wrote:
>> Situation of schedule while atomic context can happen in a
>> scenario if CPU-Y executing a async probe of ufs and while
>> printing a line it is started spinning for console lock
>> after preemption disable on CPU-Y and later it got the handover
>> of console lock from CPU-X and in console_unlock() it get
>> schedule with preempt disable as console_may_schedule was one
>> and due to which do_cond_resched was one.
> 
> Nice catch. But I think the below patch is the appropriate fix:

Thanks for the change @john, would you be sending this as proper
patch.

-Mukesh
> 
> John Ogness
> 
> -------8<--------
> Subject: [PATCH] printk: Update @console_may_schedule in
>   console_trylock_spinning()
> 
> console_trylock_spinning() may takeover the console lock from a
> scheduable context. Update @console_may_schedule to make sure it
> reflects a trylock acquire.
> 
> Reported-by: Mukesh Ojha <quic_mojha@quicinc.com>
> Link: https://lore.kernel.org/lkml/20240222090538.23017-1-quic_mojha@quicinc.com
> Signed-off-by: John Ogness <john.ogness@linutronix.de>
> ---
>   kernel/printk/printk.c | 6 ++++++
>   1 file changed, 6 insertions(+)
> 
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 1685a71f3f71..1612b50b2374 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2020,6 +2020,12 @@ static int console_trylock_spinning(void)
>   	 */
>   	mutex_acquire(&console_lock_dep_map, 0, 1, _THIS_IP_);
>   
> +	/*
> +	 * Update @console_may_schedule for trylock because the previous
> +	 * owner may have been scheduable.
> +	 */
> +	console_may_schedule = 0;
> +
>   	return 1;
>   }
>   
> 
> base-commit: e7081d5a9d976b84f61f497316d7c940a4a2e67a
  

Patch

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index f2444b581e16..8b666feff65d 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3028,7 +3028,7 @@  void console_unlock(void)
 	 * messages practically incapacitating the system. Therefore, create
 	 * a local to use for the printing loop.
 	 */
-	do_cond_resched = console_may_schedule;
+	do_cond_resched = in_atomic() || console_may_schedule;
 
 	do {
 		console_may_schedule = 0;