Re: RFC: futex_wait() can DoS the tick

[Mike Galbraith]

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@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/