Re: Function Profiler broken on today's linux-next

From: Felipe Balbi
Date: Wed Jul 16 2014 - 14:58:16 EST


On Wed, Jul 16, 2014 at 02:54:42PM -0400, Steven Rostedt wrote:
> On Wed, 16 Jul 2014 13:41:52 -0500
> Felipe Balbi <balbi@xxxxxx> wrote:
>
> > Hi,
> >
> > On Wed, Jul 16, 2014 at 01:29:44PM -0500, Felipe Balbi wrote:
> > > On Wed, Jul 16, 2014 at 01:24:13PM -0400, Steven Rostedt wrote:
> > > > On Wed, 16 Jul 2014 11:41:42 -0500
> > > > Felipe Balbi <balbi@xxxxxx> wrote:
> > > >
> > > >
> > > > > .config attached. It's actually an ARM platform, I can help out with
> > > > > testing anything you need.
> > > >
> > > > In that case, can you see if it works under my repo?
> > > >
> > > > git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git
> > > > branch: ftrace/core
> > >
> > > works fine, thanks. FWIW
> > >
> > > Tested-by: Felipe Balbi <balbi@xxxxxx>
> >
> > Actually it seems like it's not counting time properly if I run my test
> > multiple times in a row:
> >
> > # /root/testusb -t 1 -c 100000 -s 2048 -a
> > # head -3 trace_stat/function0
> > Function Hit Time Avg s^2
> > -------- --- ---- --- ---
> > thread_interrupt 174876 166120839 us 949.935 us 3048498 us
> >
> > # /root/testusb -t 1 -c 100000 -s 2048 -a
> > # head -3 trace_stat/function0
> > Function Hit Time Avg s^2
> > -------- --- ---- --- ---
> > dwc3_thread_interrupt 286796 967267300 us 4190545199 us 3241109 us
> >
> > # /root/testusb -t 1 -c 100000 -s 2048 -a
> > # head -3 trace_stat/function0
> > Function Hit Time Avg s^2
> > -------- --- ---- --- ---
> > dwc3_thread_interrupt 401346 642632072 us 1601.192 us 1194316 us
> >
> > and so on...
> >
>
> Did it use to work? In other words, is this a regression, or just some
> another bug?

It used to work at least on v3.12... It seems like it's not always
either. After I rebooted, then it took a little effort to trigger it
again. But if I just run my test in a loop, eventually it'll start
miscalculating.

--
balbi

Attachment: signature.asc
Description: Digital signature