[sheepdog] [PATCH v2 4/5] collie/trace: add graph stat function

[Liu Yuan]

On Mon, Aug 12, 2013 at 12:41:11PM +0900, MORITA Kazutaka wrote:
> At Mon, 12 Aug 2013 11:17:04 +0800,
> Liu Yuan wrote:
> > 
> > On Mon, Aug 12, 2013 at 05:04:12AM +0900, MORITA Kazutaka wrote:
> > > > +
> > > > +static void stat_list_print(void)
> > > > +{
> > > > +	struct graph_stat_entry *entry;
> > > > +
> > > > +	list_for_each_entry(entry, &stat_list, list) {
> > > > +		float f = (float)entry->duration / 1000000000;
> > > > +		float pf = (float)entry->duration / entry->nr_calls / 1000;
> > > > +
> > > > +		printf("%-*s| %-10"PRIu32" | %-16f| %-16f\n", TRACE_FNAME_LEN,
> > > > +		       entry->fname, entry->nr_calls, f, pf);
> > > 
> > > I prefer a right-aligned number.  In addition, the default number of
> > > digits after the decimal point looks long to me.  Then the format
> > > string is like "%-*s| %10"PRIu32" |%16.3f |%16.3f \n".
> > > 
> > > I wonder if we can use the same format as the existing tool's one?
> > > E.g. gprof output is
> > > 
> > > http://sourceware.org/binutils/docs/gprof/Flat-Profile.html#Flat-Profile
> > > 
> > > I think it'd be great if we can have the "self seconds" column to
> > > investigate a bottleneck.
> > 
> > 'Total Time' is 'self seconds'. The gprof format looks obscure and redundant.
> > I think total time, time per call, call nr, name is good enough.
> 
> I think 'Total TIme' is 'cumulative seconds'.  It includes the time
> spent by internally called functions, too.

I tried to get "cululative time", but no success because our trace buffer is not
always reliable to use self_time = item->return_time - last_item->return_time,

e.g, 
...
io 18340            |            |eventfd_xwrite() {
main                |            |worker_routine() {
main                |            |   gettid() {
main                |       1.444|   }
...

Because of eventfd_xwrite() trace is interrupted, we'll get a wrong self time
for eventfd_xwrite() later in the trace.

Probably we can later modify trace.c or graph.c to get self_time correctly. Now
let's start with total(accumulative) time only and rely on 'graph cat' to get
more accurate trace time.

Thanks
Yuan