lkml.org 
[lkml]   [2016]   [Aug]   [15]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    /
    SubjectRe: [PATCH v10 1/2] printk: Make printk() completely async
    From
    Date


    On 08/12/2016 12:44 PM, Petr Mladek wrote:
    > On Wed 2016-08-10 14:17:55, Viresh Kumar wrote:
    >> +Vladi/Greg,
    >>
    >> On Wed, Apr 6, 2016 at 1:27 AM, Jan Kara <jack@suse.cz> wrote:
    >>> On Mon 04-04-16 15:51:49, Andrew Morton wrote:
    >>>>> +static int __init init_printk_kthread(void)
    >>>>> +{
    >>>>> + struct task_struct *thread;
    >>>>> +
    >>>>> + if (printk_sync)
    >>>>> + return 0;
    >>>>> +
    >>>>> + thread = kthread_run(printk_kthread_func, NULL, "printk");
    >>>> This gets normal scheduling policy, so a spinning userspace SCHED_FIFO
    >>>> task will block printk for ever. This seems bad.
    >>> I have to research this a bit but won't the SCHED_FIFO task that has
    >>> potentially unbounded amount of work lockup the CPU even though it does
    >>> occasional cond_resched()?
    >> We are facing complete hogs because of the printk thread being a SCHED_FIFO
    >> task and have this patch to fix it up for now.
    >>
    >> Author: Vladislav Levenetz <vblagoev@mm-sol.com>
    >> Date: Wed Aug 10 13:58:00 2016 -0700
    >>
    >> SW-7786: printk: Lower the priority of printk thread
    >>
    >> Flooding the console (with a test module) in a tight loop indefinitely
    >> makes android user interface very sluggish. Opening YouTube app and the
    >> device hangs and becomes even more unresponsive to the point it
    >> completely hangs.
    >>
    >> The asynchronous printk thread is a SCHED FIFO thread with priority
    >> MAX_RT_PRIO - 1. If we create it as a simple thread (i.e. no SCHED FIFO)
    >> instead, we observe much better performance using the same printk flood
    >> test. We don't even notice any kind of sluggishness during device usage.
    >> We can play a YouTube clip smoothly and use the device normally in
    >> general. The kernel log looks fine as well, as the flood of messages
    >> continue normally.
    >>
    >> Signed-off-by: Vladislav Levenetz <vblagoev@mm-sol.com>
    >> Signed-off-by: Viresh Kumar <viresh.kumar@linaro.org>
    >> ---
    >> kernel/printk/printk.c | 4 ----
    >> 1 file changed, 4 deletions(-)
    >>
    >> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
    >> index c32872872cb6..ad5b30e5e6d9 100644
    >> --- a/kernel/printk/printk.c
    >> +++ b/kernel/printk/printk.c
    >> @@ -2856,9 +2856,6 @@ static int printk_kthread_func(void *data)
    >> static int __init_printk_kthread(void)
    >> {
    >> struct task_struct *thread;
    >> - struct sched_param param = {
    >> - .sched_priority = MAX_RT_PRIO - 1,
    >> - };
    >>
    >> if (!printk_kthread_can_run || printk_sync || printk_kthread)
    >> return 0;
    >> @@ -2870,7 +2867,6 @@ static int __init_printk_kthread(void)
    >> return PTR_ERR(thread);
    >> }
    >>
    >> - sched_setscheduler(thread, SCHED_FIFO, &param);
    >> printk_kthread = thread;
    >> return 0;
    >> }
    > IMHO, this is fine. We force the synchronous mode in critical
    > situations anyway.
    >
    > But I was curious if we could hit a printk from the wake_up_process().
    > The change above causes using the fair scheduler and there is
    > the following call chain [*]
    >
    > vprintk_emit()
    > -> wake_up_process()
    > -> try_to_wake_up()
    > -> ttwu_queue()
    > -> ttwu_do_activate()
    > -> ttwu_activate()
    > -> activate_task()
    > -> enqueue_task()
    > -> enqueue_task_fair() via p->sched_class->enqueue_task
    > -> cfs_rq_of()
    > -> task_of()
    > -> WARN_ON_ONCE(!entity_is_task(se))
    >
    > We should never trigger this because printk_kthread is a task.
    > But what if the date gets inconsistent?
    >
    > Then there is the following chain:
    >
    > vprintk_emit()
    > -> wake_up_process()
    > -> try_to_wake_up()
    > -> ttwu_queue()
    > -> ttwu_do_activate()
    > -> ttwu_activate()
    > -> activate_task()
    > -> enqueue_task()
    > -> enqueue_task_fair() via p->sched_class->enqueue_task
    > ->hrtick_update()
    > -> hrtick_start_fair()
    > -> WARN_ON(task_rq(p) != rq)
    >
    > This looks like another paranoid consistency check that might be
    > triggered when the scheduler gets messed.
    >
    > I see few possible solutions:
    >
    > 1. Replace the WARN_ONs by printk_deferred().
    >
    > This is the usual solution but it would make debugging less convenient.
    >
    >
    > 2. Force synchronous printk inside WARN()/BUG() macros.
    >
    > This would make sense even from other reasons. These are printed
    > when the system is in a strange state. There is no guarantee that
    > the printk_kthread will get scheduled.
    >
    >
    > 3. Force printk_deferred() inside WARN()/BUG() macros via the per-CPU
    > printk_func.
    >
    > It might be elegant. But we do not want this outside the scheduler
    > code. Therefore we would need special variants of WARN_*_SCHED()
    > BUG_*_SCHED() macros.
    >
    >
    > I personally prefer the 2nd solution. What do you think about it,
    > please?
    >
    >
    > Best Regards,
    > Petr

    Hi Petr,

    Sorry with for the late reply.

    Hitting a WARN()/BUG() from wake_up calls will lead to a deadlock if
    only a single CPU is running.
    We already had such a situation with system suspend. During a specific
    test on our device sometimes we hit a WARN from the time keeping core.
    (Cannot recall which one exactly. Viresh have it) from a printk wake_up
    path during system suspend and with already only one CPU running.
    So we were forced to make printing synchronous in the suspend path prior
    disabling all non-boot cpu's.

    Your solution number 2) sounds reasonable to me.

    I'm wondering if we could hit a WARN()/BUG() somewhere from the fair
    scheduler like the example you made for the RT sched?

    Thanks.

    \
     
     \ /
      Last update: 2016-09-17 09:56    [W:6.124 / U:0.104 seconds]
    ©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site