Re: [Query] Preemption (hogging) of the work handler

From: Viresh Kumar
Date: Thu Jul 14 2016 - 19:53:07 EST


Sorry, but I failed to do any testing on this and answer the questions you
raise. But I saw this again today and here are some important points.

On 12-07-16, 23:03, Sergey Senozhatsky wrote:
> so, I'm looking at this thing now:
>
> : [ 12.874909] sched: RT throttling activated for rt_rq ffffffc0ac13fcd0 (cpu 0)
> : [ 12.874909] potential CPU hogs:
> : [ 12.874909] printk (292)
>
> so it's either cond_resched() does not reshed, keeping printk kthread
> active, which, however, upsets the sched and triggers throttling (umm, what);
>
> or we, somehow, have `console_may_schedule == 0' in this final console_unlock(),
> so cond_resched() never happens.
>
> I'm looking at mainline 3.10, tho.
>
> Viresh, can you verify if we can do cond_resched() from console_unlock()
> (console_may_schedule != 0) ?

I have hit this throttling issue twice and both were under the same
circumstances. Explaining in case it can help us debug it further :)

- Happens during early boot of the phone, ~10 seconds.
- Userspace noted that there are some issues with Android filesystem, like
/system/bin/sh not found and so it says:

init: cannot find '/system/bin/sh' (No such file or directory),
disabling 'console'

- Userspace noticed that something is wrong and its good to reboot phone in
another mode.
- But before that it dumps the kernel-messages from last boot and the prints
looked like this:

[ 12.805180] [ 7.919623] **Some Kernel Messages here**

Double time-stamp here, because one was already present in the last KMSG (logs
from previous boot).

After around 100 lines got printed, we had this throttling messages (without the
double timestamp), and we continue to print things after it as well.

--
viresh