linux-kernel - Re: [Bug #12650] Strange load average and ksoftirqd behavior with 2.6.29-rc2-git1

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:	Sun, 15 Feb 2009 20:31:02 +0100
From:	Ingo Molnar <mingo@...e.hu>
To:	Damien Wyart <damien.wyart@...e.fr>
Cc:	Peter Zijlstra <a.p.zijlstra@...llo.nl>,
	Mike Galbraith <efault@....de>,
	Frédéric Weisbecker <fweisbec@...il.com>,
	"Rafael J. Wysocki" <rjw@...k.pl>,
	Linux Kernel Mailing List <linux-kernel@...r.kernel.org>,
	Kernel Testers List <kernel-testers@...r.kernel.org>
Subject: Re: [Bug #12650] Strange load average and ksoftirqd behavior with
	2.6.29-rc2-git1


* Damien Wyart <damien.wyart@...e.fr> wrote:

> > > So I followed the tracing steps in the tutorial (with the 1 sec sleep),
> > > which gave me this:
> > > http://damien.wyart.free.fr/trace_2.6.29-rc5_ksoftirqd_prob.txt.gz
> 
> > thanks. There's definitely some weirdness visible in the trace,
> > for example:
> 
> >   0)    gpm-1879    =>   ksoftir-4   
> >   ------------------------------------------
> 
> >   0)   0.964 us    |    finish_task_switch();
> >   0) ! 1768184 us |  }
> >   0)               |  do_softirq() {
> >   0)               |    __do_softirq() {
> >   0)               |      rcu_process_callbacks() {
> 
> > the 1.7 seconds 'overhead' there must be a fluke - you'd notice it if
> > ksoftirqd _really_ took that much time to execute.
> 
> > One possibility for these symptoms would be broken scheduler timestamps.
> > Could you enable absolute timestamp printing via:
> 
> >     echo funcgraph-abstime  > trace_options
> 
> Mmm, seems I do not have this option recognized in rc5, so could not
> test. Will retry all this with tip tomorrow...

Yeah, it got renamed in -tip - in rc5 it's iter_ctrl.

> > Also, my guess is that if you boot via idle=poll, the symptoms go away.
> > This would strengthen the suspicion that it's scheduler-clock troubles.
> 
> In fact, with idle=poll, the symptoms do not go away, they are much
> stronger: without it, ksotirqd have a few % of CPU in top output; with
> it, they have 20 or 30% and the global average is not far from 1.
> 
> On my laptop (I do not have it at hand today), with rc3-gitX (did not
> retest with rc5), the load avg was ok, but I saw that after boot,
> ksoftird threads had a quite higher running time in top than with
> 2.6.28. I am surprised nobody reported this yet...
> 
> I attach to this mail config and dmesg if needed (this is rc5 without
> idle=poll).
> 
> If a trace with funcgraph-abstime is interesting for you with tip,
> I will do this tomorrow.

Yes, an abstime trace would be useful.

> checking TSC synchronization [CPU#0 -> CPU#1]: passed.
> Switched to high resolution mode on CPU 1

Lets double-check your scheduler clock first. Without being able to
trust the clock we cannot trust the task stats nor the trace output.

What does this check display:

  http://people.redhat.com/mingo/time-warp-test/time-warp-test.c

Does it find any TSC time warps?

Also, could you send the output of:

  http://people.redhat.com/mingo/cfs-scheduler/tools/cfs-debug-info.sh

Run it while you can see the ksoftirqd anomaly.

	Ingo
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/