Re: [PATCH 2/2] tracing/function-graph-tracer: improve duration output

[Ingo Molnar <mingo@elte.hu>]

* Frederic Weisbecker <fweisbec@gmail.com> wrote:

> Frederic Weisbecker wrote:
> > Impact: better output of duration for long calls
> > 
> > The old duration output didn't exceeded 9999.999 us to fit the column
> > and the nanosecs were always 3 numbers. As Ingo suggested, it's better
> > to have the whole microseconds elapsed time and shift the nanosecs precision
> > if needed to fit the maximum 7 numbers. And usec need more number, the case
> > should be rare and important enough to break a bit the column alignment to
> > show it.
> > 
> > So, depending of the duration value, we now have these patterns:
> > 
> > u.nnn
> > uu.nnn
> > uuu.nnn
> > uuuu.nnn
> > uuuuu.nn
> > uuuuuu.n
> > uuuuuuuu.....

applied, thanks!

> An example of a trace after these two patches (with funcgraph-proc enabled):
> 
>  0)    cat-2796    |               |            put_prev_task_fair() {
>  0)    cat-2796    |   0.609 us    |              update_curr();
>  0)    cat-2796    |   1.842 us    |            }
>  0)    cat-2796    |               |            pick_next_task_fair() {
>  0)    cat-2796    |   0.526 us    |              wakeup_preempt_entity();
>  0)    cat-2796    |   0.797 us    |              set_next_entity();
>  0)    cat-2796    |   0.541 us    |              hrtick_start_fair();
>  0)    cat-2796    |   4.195 us    |            }
>  0)    cat-2796    |   1.263 us    |            _spin_trylock();
>  0)    cat-2796    |   0.624 us    |            _spin_unlock();
>  0)    cat-2796    |   0.789 us    |            _spin_trylock();
>  0)    cat-2796    |   0.617 us    |            _spin_unlock();
>  0)    cat-2796    |   0.579 us    |            native_load_sp0();
>  0)    cat-2796    |   0.722 us    |            native_load_tls();
>
>  ------------------------------------------
>  | 0)    cat-2796    =>   events/-9   
>  ------------------------------------------

small detail: i'd suggest to remove the newline before the context-switch 
box. That makes it appear visually to attach logically with the 
switch-out place, not the switch-in place:

>  0)    cat-2796    |   0.579 us    |            native_load_sp0();
>  0)    cat-2796    |   0.722 us    |            native_load_tls();
>  ------------------------------------------
>  | 0)    cat-2796    =>   events/-9   
>  ------------------------------------------
> 
>  0)   events/-9    |               |    finish_task_switch() {
>  0)   events/-9    |   0.789 us    |      _spin_unlock_irq();
>  0)   events/-9    |   2.309 us    |    }
>  0)   events/-9    | ! 269848.5 us |  }

which is what we want to express.

	Ingo