Is it possible to use ftrace to measure secondary CPU bootup time

Is it possible to use ftrace to measure secondary CPU bootup time

[Huang, Ying]

Hi, Steven,

We are working on parallelizing secondary CPU bootup.   So we need to
measure the bootup time of secondary CPU, that is, measure time spent in
smp_init() and its callees.  But we found that ftrace now doesn't
support measure time spent in smp_init() because it is called too early
(before core_initcall()?).  So, do you think it is possible to use
ftrace to measure secondary CPU bootup time?

Thanks,
Huang, Ying

Re: Is it possible to use ftrace to measure secondary CPU bootup time

[Steven Rostedt]

On Mon, 24 Jul 2017 13:46:07 +0800
"Huang\, Ying" <ying.huang@intel.com> wrote:

> Hi, Steven,
> 
> We are working on parallelizing secondary CPU bootup.   So we need to
> measure the bootup time of secondary CPU, that is, measure time spent in
> smp_init() and its callees.  But we found that ftrace now doesn't
> support measure time spent in smp_init() because it is called too early
> (before core_initcall()?).  So, do you think it is possible to use
> ftrace to measure secondary CPU bootup time?

One could trace with function tracing that early, but that wont give
you the timings you are looking for. The best it probably could do is
to look at the function timestamps of what is called after smp_init.
That is, trace smp_init() and sched_init_smp() and take the difference.

Function graph tracing (which is what you are probably looking for) is
much more heavy weight than function tracing. It requires some setup
that isn't ready that early. Although, I'm sure I can work to get it
there, but it's not trivial.

-- Steve

RE: Is it possible to use ftrace to measure secondary CPU bootup time

[Brandt, Todd E]

> 
> On Mon, 24 Jul 2017 13:46:07 +0800
> "Huang\, Ying" <ying.huang@intel.com> wrote:
> 
> > Hi, Steven,
> >
> > We are working on parallelizing secondary CPU bootup.   So we need to
> > measure the bootup time of secondary CPU, that is, measure time spent in
> > smp_init() and its callees.  But we found that ftrace now doesn't
> > support measure time spent in smp_init() because it is called too early
> > (before core_initcall()?).  So, do you think it is possible to use
> > ftrace to measure secondary CPU bootup time?
> 
> One could trace with function tracing that early, but that wont give
> you the timings you are looking for. The best it probably could do is
> to look at the function timestamps of what is called after smp_init.
> That is, trace smp_init() and sched_init_smp() and take the difference.
> 
> Function graph tracing (which is what you are probably looking for) is
> much more heavy weight than function tracing. It requires some setup
> that isn't ready that early. Although, I'm sure I can work to get it
> there, but it's not trivial.

Function graph tracing is indeed the target, as its the basis of the bootgraph 
tool. However, kprobes would work just as well. What's the difference in effort
between enabling kprobes for early boot vs function graph trace?

> 
> -- Steve

Re: Is it possible to use ftrace to measure secondary CPU bootup time

[Steven Rostedt]

On Mon, 24 Jul 2017 21:40:24 +0000
"Brandt, Todd E" <todd.e.brandt@intel.com> wrote:

> Function graph tracing is indeed the target, as its the basis of the bootgraph 
> tool. However, kprobes would work just as well. What's the difference in effort
> between enabling kprobes for early boot vs function graph trace?
> 

Hmm, good question. But then again, if you are only worried about
timings, tracing functions and looking at how long the next function
happens after the one you are interested in, should give you a good
idea of how long that function took.

If there is more interest, I could spend some time seeing if I can get
function graph tracing working early.

-- Steve

Re: Is it possible to use ftrace to measure secondary CPU bootup time

[Huang, Ying]

Steven Rostedt <rostedt@goodmis.org> writes:

> On Mon, 24 Jul 2017 13:46:07 +0800
> "Huang\, Ying" <ying.huang@intel.com> wrote:
>
>> Hi, Steven,
>> 
>> We are working on parallelizing secondary CPU bootup.   So we need to
>> measure the bootup time of secondary CPU, that is, measure time spent in
>> smp_init() and its callees.  But we found that ftrace now doesn't
>> support measure time spent in smp_init() because it is called too early
>> (before core_initcall()?).  So, do you think it is possible to use
>> ftrace to measure secondary CPU bootup time?
>
> One could trace with function tracing that early, but that wont give
> you the timings you are looking for. The best it probably could do is
> to look at the function timestamps of what is called after smp_init.
> That is, trace smp_init() and sched_init_smp() and take the difference.
>
> Function graph tracing (which is what you are probably looking for) is
> much more heavy weight than function tracing. It requires some setup
> that isn't ready that early. Although, I'm sure I can work to get it
> there, but it's not trivial.

Got it!  Thanks a lot!

Best Regards,
Huang, Ying

> -- Steve