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 <[email protected]>
---
kernel/printk/printk.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
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;
--
2.43.0.254.ga26002b62827
On 2024-02-22, Mukesh Ojha <[email protected]> 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 <[email protected]>
Link: https://lore.kernel.org/lkml/[email protected]
Signed-off-by: John Ogness <[email protected]>
---
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
--
2.30.2
On 2/22/2024 8:23 PM, John Ogness wrote:
> On 2024-02-22, Mukesh Ojha <[email protected]> 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 <[email protected]>
> Link: https://lore.kernel.org/lkml/[email protected]
> Signed-off-by: John Ogness <[email protected]>
> ---
> 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
console_trylock_spinning() may takeover the console lock from a
schedulable context. Update @console_may_schedule to make sure it
reflects a trylock acquire.
Reported-by: Mukesh Ojha <[email protected]>
Link: https://lore.kernel.org/lkml/[email protected]
Fixes: dbdda842fe96 ("printk: Add console owner and waiter logic to load balance console writes")
Signed-off-by: John Ogness <[email protected]>
---
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 schedulable.
+ */
+ console_may_schedule = 0;
+
return 1;
}
base-commit: e7081d5a9d976b84f61f497316d7c940a4a2e67a
--
2.30.2
On 2/26/2024 5:31 PM, John Ogness wrote:
> console_trylock_spinning() may takeover the console lock from a
> schedulable context. Update @console_may_schedule to make sure it
> reflects a trylock acquire.
>
> Reported-by: Mukesh Ojha <[email protected]>
> Link: https://lore.kernel.org/lkml/[email protected]
> Fixes: dbdda842fe96 ("printk: Add console owner and waiter logic to load balance console writes")
> Signed-off-by: John Ogness <[email protected]>
Thanks for prompt response..
Yes, this looks fine..
As spinning code runs with preemption disabled context
and should reset the console_may_schedule to 0 .
what if console_trylock_spinning() gets the lock which makes
console_may_schedule =1 and it is still schedulable ?
-Mukesh
> ---
> 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 schedulable.
> + */
> + console_may_schedule = 0;
> +
> return 1;
> }
>
>
> base-commit: e7081d5a9d976b84f61f497316d7c940a4a2e67a
On 2024-02-26, Mukesh Ojha <[email protected]> wrote:
> what if console_trylock_spinning() gets the lock which makes
> console_may_schedule =1 and it is still schedulable ?
I am afraid I do not understand the question.
console_trylock_spinning() is only called from the printk caller
context. In this context, console_may_schedule is always set to 0.
Only if another context acquires the console lock per sleeping wait,
console_lock(), can console_may_schedule be set to 1.
Note that the value of console_may_schedule is only relevant for the
console lock owner when console_unlock() is called. That is why its
value is set when locking the console (or, with this patch, when
transferring console lock ownerhip).
John
On 2/26/2024 6:32 PM, John Ogness wrote:
> On 2024-02-26, Mukesh Ojha <[email protected]> wrote:
>> what if console_trylock_spinning() gets the lock which makes
>> console_may_schedule =1 and it is still schedulable ?
>
> I am afraid I do not understand the question.
>
> console_trylock_spinning() is only called from the printk caller
> context. In this context, console_may_schedule is always set to 0.
>
> Only if another context acquires the console lock per sleeping wait,
> console_lock(), can console_may_schedule be set to 1.
>
> Note that the value of console_may_schedule is only relevant for the
> console lock owner when console_unlock() is called. That is why its
> value is set when locking the console (or, with this patch, when
> transferring console lock ownerhip).
I overlooked it, thanks.
Patch LGTM.
Reviewed-by: Mukesh Ojha <[email protected]>
-Mukesh
>
> John
On Mon 2024-02-26 13:07:24, John Ogness wrote:
> console_trylock_spinning() may takeover the console lock from a
> schedulable context. Update @console_may_schedule to make sure it
> reflects a trylock acquire.
>
> Reported-by: Mukesh Ojha <[email protected]>
> Link: https://lore.kernel.org/lkml/[email protected]
> Fixes: dbdda842fe96 ("printk: Add console owner and waiter logic to load balance console writes")
> Signed-off-by: John Ogness <[email protected]>
Makes perfect sense:
Reviewed-by: Petr Mladek <[email protected]>
JFYI, the patch has been committed into printk/linux.git, for-6.9
branch.
I am going to give it a spin in for-next and get it into 6.9
either in the 2nd half of the merge window or in rc1.
Best Regards,
Petr