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 for Android: free password hash cracker in your pocket

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

Date:	Fri, 15 Jul 2016 22:11:33 +0900
From:	Sergey Senozhatsky <sergey.senozhatsky@...il.com>
To:	Viresh Kumar <viresh.kumar@...aro.org>
Cc:	Sergey Senozhatsky <sergey.senozhatsky@...il.com>,
	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

Hello,

On (07/14/16 16:52), Viresh Kumar wrote:
> 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)
> > 
[..]
> - But before that it dumps the kernel-messages from last boot and the prints
>   looked like this:

kmsg_dump()? a wild guess... any chance that you kmsg dumper iterates
log_buf records under logbuf_lock long enough to cause throttling on
other CPU, because printk_kthread is simply has to spin on logbuf_lock?

something like

CPU0						CPU1

console_unlock()				kmsg_dump()
{						{
							kmsg_dump_get_buffer()
							{
								spin_lock(&logbuf_lock)

	spin_lock(&logbuf_lock)					while (....) {
							 	^^^^^^^^^^^^^^ long enough
									...
								}
								spin_unlock(&logbuf_lock)
							}
	....					}
	spin_unlock(&logbuf_lock)

	call_console_drivers()

	cond_resched()
		RT throttling
			printk_deferred("RT throttling")
}

	-ss


>   [   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
>