Re: [PATCH 0/2] printk/stop_machine: Defer legacy console flushes while a CPU runs a stopper callback

[John Ogness]

On 2026-08-27, Aditya Chillara <aditya.chillara@xxxxxxxxxxxxxxxx> wrote:
> A device using a legacy UART console (console=ttyMSM0,115200n8) hit a
> watchdog bark/bite about 40 seconds after boot.
>
> stop_machine() (used here for kprobe text patching) stops every CPU by
> running multi_cpu_stop() on each of them, through the per-CPU
> "migration/%u" threads. These threads run at a higher priority than the
> msm_watchdog thread. At bite time, all eight CPUs were still spinning in
> multi_cpu_stop()'s MULTI_STOP_PREPARE state, where interrupts are left
> enabled.
>
> Heavy SELinux denial logging had built up a large backlog on the
> console. One CPU took an interrupt while spinning in MULTI_STOP_PREPARE.
> Handling it eventually led to a printk(), and because the console was a
> legacy console, that printk() synchronously drained the whole backlog
> over the slow UART. While the drain was still running, the watchdog bark
> interrupt hit the same CPU, found no recent pet, and escalated to a
> bite.
>
> The captured stack for that CPU, innermost frame first:
>
>   qcom_soc_set_wdt_bite
>   qcom_wdt_bark_handler
>   __handle_irq_event_percpu
>   handle_irq_event
>   handle_fasteoi_irq
>   generic_handle_domain_irq
>   gic_handle_irq
>   do_interrupt_handler
>   el1_interrupt
>   el1h_64_irq_handler
>   el1h_64_irq
>   console_flush_all
>   console_unlock
>   vprintk_emit
>   dev_vprintk_emit
>   dev_printk_emit
>   __dev_printk
>   _dev_err
>   btspi_sleep_timeout_handler
>   call_timer_fn
>   __run_timer_base
>   run_timer_softirq
>   handle_softirqs
>   __do_softirq
>   ____do_softirq
>   call_on_irq_stack
>   do_softirq_own_stack
>   __irq_exit_rcu
>   irq_exit_rcu
>   el1_interrupt
>   el1h_64_irq_handler
>   el1h_64_irq
>   multi_cpu_stop
>   cpu_stopper_thread
>   smpboot_thread_fn
>   kthread
>   ret_from_fork
>
> Every other CPU stayed parked in the rendezvous the whole time, since
> their stopper threads outrank msm_watchdog. Nothing could pet the
> watchdog until the drain finished.
>
> This was observed through multi_cpu_stop(), but the hazard is not
> specific to it. Every cpu stopper callback runs in stop_sched_class,
> above msm_watchdog and every other thread on the CPU, so a slow flush
> from any of them (including single-CPU callbacks such as the migration
> and task-migration stoppers) can starve the watchdog just as well. The
> fix therefore covers all stopper callbacks, not only multi_cpu_stop().
>
> Fix this by having the cpu stopper mark the CPU active while a callback
> runs, and having printk use that marker to defer legacy console flushes
> until the callback returns:
>
>   1/2 stop_machine: Track when a CPU executes a stopper callback
>
>       Add a per-CPU flag, set in the stopper dispatch path around the
>       callback, and an in_cpu_stop() accessor.
>
>   2/2 printk: Defer legacy console flushes while a CPU runs a stopper callback
>
>       Route legacy console output through the offload path instead of
>       flushing it directly while a CPU is inside a stopper callback, and
>       flush it once the callback returns. Emergency and panic output is
>       unaffected.
>
> Reproduced and verified with an out-of-tree test module that triggers
> stop_machine() with a queued console backlog and a printk() inside the
> rendezvous, paired with a kprobe-based script that flags any console
> flush happening while a CPU is inside a stopper callback.

This is a fairly heavy series just to address a problem with legacy
consoles that has always existed.

How about instead a series to switch msm_serial.c/qcom_geni_serial.c
over to NBCON? That is fairly straightforward (especially with the
availability of CON_NBCON_ATOMIC_UNSAFE) and would help to move the
kernel forward rather than improving the parts we are trying to get rid
of.

I would even be willing to convert those 2 drivers if you could provide
the necessary testing for me.

John