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

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Date:	Thu, 14 Jul 2016 16:52:46 -0700
From:	Viresh Kumar <viresh.kumar@...aro.org>
To:	Sergey Senozhatsky <sergey.senozhatsky@...il.com>
Cc:	Petr Mladek <pmladek@...e.com>,
	Sergey Senozhatsky <sergey.senozhatsky.work@...il.com>,
	Jan Kara <jack@...e.cz>, Tejun Heo <tj@...nel.org>,
	Greg Kroah-Hartman <gregkh@...uxfoundation.org>,
	Linux Kernel Mailing List <linux-kernel@...r.kernel.org>,
	vlevenetz@...sol.com, vaibhav.hiremath@...aro.org,
	alex.elder@...aro.org, johan@...nel.org, akpm@...ux-foundation.org,
	rostedt@...dmis.org
Subject: Re: [Query] Preemption (hogging) of the work handler

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