[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <1433989634.3411.15.camel@gmail.com>
Date: Thu, 11 Jun 2015 04:27:14 +0200
From: Mike Galbraith <umgwanakikbuti@...il.com>
To: Thomas Gleixner <tglx@...utronix.de>
Cc: LKML <linux-kernel@...r.kernel.org>,
Peter Zijlstra <peterz@...radead.org>,
Ingo Molnar <mingo@...e.hu>,
Steven Rostedt <rostedt@...dmis.org>
Subject: Re: RFC: futex_wait() can DoS the tick
On Wed, 2015-06-10 at 20:59 +0200, Thomas Gleixner wrote:
> On Wed, 10 Jun 2015, Mike Galbraith wrote:
>
> > On Wed, 2015-06-10 at 17:12 +0200, Thomas Gleixner wrote:
> >
> > > Some more information about your symptoms in form of configuration,
> > > extra patches, kernel traces etc. would be appreciated.
> >
> > homer:~/tmp # perf record -C 3 -eirq:*,irq_vectors:local* -- sleep 10
> > [ perf record: Woken up 2 times to write data ]
> > [ perf record: Captured and wrote 1380.507 MB perf.data (19530595 samples) ]
> > homer:~/tmp # perf script | grep irq_vectors:local_timer
> > ksoftirqd/3 19 [003] 5586.564238: irq_vectors:local_timer_entry: vector=239
> > ksoftirqd/3 19 [003] 5586.564239: irq_vectors:local_timer_exit: vector=239
> > ksoftirqd/3 19 [003] 5586.568238: irq_vectors:local_timer_entry: vector=239
> > ksoftirqd/3 19 [003] 5586.568239: irq_vectors:local_timer_exit: vector=239
> > ksoftirqd/3 19 [003] 5586.632218: irq_vectors:local_timer_entry: vector=239
>
> That gap is odd. Can you fire up the function tracer please?
Well, trying to do that like so...
trace-cmd record -M 8 -p function -e irq:* -e irq_vectors:local* -e timer:hrtimer* -- sleep 1
..capture takes much more than a second...
LOC: 248161 226536 42091 38892 Local timer interrupts
LOC: 248381 226783 42092 38901 Local timer interrupts
LOC: 248668 227038 42092 38903 Local timer interrupts
LOC: 248963 227277 42092 38904 Local timer interrupts
LOC: 249214 227515 42092 38905 Local timer interrupts
LOC: 249486 227732 42092 38905 Local timer interrupts
LOC: 249720 227961 42092 38905 Local timer interrupts
LOC: 249996 228200 42092 38906 Local timer interrupts
LOC: 250215 228450 42092 38906 Local timer interrupts
LOC: 250489 228704 42092 38906 Local timer interrupts
LOC: 250729 228952 42099 38964 Local timer interrupts
LOC: 250951 229141 42100 39215 Local timer interrupts
LOC: 251168 229374 42119 39468 Local timer interrupts
LOC: 251426 229641 42131 39719 Local timer interrupts
LOC: 251652 229868 42131 39970 Local timer interrupts
LOC: 251881 230141 42132 40220 Local timer interrupts
LOC: 252131 230371 42132 40471 Local timer interrupts
LOC: 252361 230646 42133 40721 Local timer interrupts
LOC: 252611 230875 42133 40972 Local timer interrupts
LOC: 252866 231149 42137 41222 Local timer interrupts
LOC: 253103 231386 42153 41450 Local timer interrupts
...but more importantly, when it gets cranked up..
homer:~/tmp # trace-cmd report > report
homer:~/tmp # grep local_timer_entry report|wc -l
252
...it scares the problem away.
(4 cpus because I fired up cpuset shield, isolates 2-3, takes 4-7 down)
-Mike
--
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/
Powered by blists - more mailing lists