lkml.org 
[lkml]   [2014]   [Sep]   [12]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: perf top -g -U --sort=symbol --children == lalalalala?
Em Fri, Sep 12, 2014 at 10:41:33AM +0200, Mike Galbraith escreveu:
> On Fri, 2014-09-12 at 16:24 +0900, Namhyung Kim wrote:
> > Hi Arnaldo and Mike,
> >
> > On Thu, 11 Sep 2014 10:43:38 -0300, Arnaldo Carvalho de Melo wrote:
> > > Em Thu, Sep 11, 2014 at 02:43:12PM +0200, Mike Galbraith escreveu:
> > >> On Thu, 2014-09-11 at 17:09 +0900, Namhyung Kim wrote:
> > >> > On Tue, Sep 9, 2014 at 10:37 PM, Arnaldo Carvalho de Melo
> > >> > <acme@ghostprotocols.net> wrote:
> > >> > > Em Tue, Sep 09, 2014 at 01:54:01PM +0200, Mike Galbraith escreveu:
> > >> > >> Seems the now default on --children thingy doesn't like -U much.
> > >> > >
> > >> > > Namhyung, can you please take a look at this?
> > >> >
> > >> > So what is the problem here?
> > >>
> > >> Well, if you don't see anything wrong, I guess nothing at all.
> > >
> > > :-)
> > >
> > > I think that when we decide that it is so better to change defaults like
> > > we did this time, we should be required to add a big fat warning (a
> > > --tui popup, use the first lines on --stdio, etc) about why the default
> > > was changed and allow quick, easy opt out, restoring previous behaviour
> > > after the user, being warned, knows what to expect, tries it, and then
> > > is in a better position to decide if keeping the new default is what is
> > > desired.
> >
> > So the problem is that why it turned on --children option by default,
> > right? I thought you mentioned there's a problem with -U option and I
> > couldn't figure out what it is.
> >
> >
> > >
> > >> > >> Samples: 5K of event 'cycles', Event count (approx.): 2268660922
> > >> > >> Children Self Symbol
> > >> > >> + 46.42% 0.04% [k] system_call_fastpath
> > >
> > >> I'll just turn it off until I figure out what cool stuff this is telling
> > >> me. why that symbol becomes the number one hit, and why total% > 100.
> > >
> > >> To me, it looks like top smoked it's breakfast, went to lala land ;-)
> > >
> > > Yeah, its confusing, I'll let Namhyung explain it ;-)
> >
> > Now I have three persion yell at me for this change. :)
> >
> > When this change was developping, Ingo said it'd be better if it looks
> > like output of sysprof as it's more popular for most (userland?) guys.
> > You can see the discussion in the following links:
> >
> > https://lkml.org/lkml/2013/10/31/97
> > https://lkml.org/lkml/2013/11/1/85
> >
> > The children field is a cumulative total overhead (for its all
> > children/callee) so sum of them would be more than 100%. And as Ingo
> > requested it sorts the output entries using children overhead so that
> > one can easily see higher level view of performance bottle-neck.
>
> I still don't get why my #1 _KERNEL_ (-U) overhead in the below changes
> from __schedule() to system_call(). The thing that's consuming the most
> cycles remains __schedule(). It doesn't really matter much I 'spose,
> turning it off in .perfconfig works fine.
>
> (seems top wants to learn to ignore cpu_startup_entry too [see hmm
> below], and maybe grow an option to _not_ ignore idle stuff)

yeah, ideally we would have some flag from the kernel stating that it is
idle context, so that we don't have to keep this list of idle functions.

Until then we can try to get this more manageable by having a file where
people can add idle functions and as well as not just discard entries
for these functions, but instead mark them as idle.

And as well have a key in interactive tools to toggle them on/off and
somethile like -U/-K to set the initial value of this toggle from the
command line.

> --no-children
> - 6.52% [k] __schedule
> - __schedule
> - 56.95% schedule
> 99.88% pipe_wait
> pipe_read
> new_sync_read
> vfs_read
> sys_read
> system_call
> __read_nocancel
> __libc_start_main
> + 40.63% schedule_preempt_disabled
> + 1.03% __read_nocancel
> 0.78% pipe_wait
> pipe_read
> new_sync_read
> vfs_read
> sys_read
> system_call
> __read_nocancel
> __libc_start_main
> + 0.62% cpu_startup_entry <== hmm
> + 5.13% [k] native_sched_clock
> + 4.80% [k] system_call
> + 4.36% [k] resched_curr
> + 3.59% [k] _raw_spin_lock_irqsave
> + 3.34% [k] __switch_to
>
>
> --children
> + 68.49% 4.92% [k] system_call
> + 32.75% 0.42% [k] sys_write
> + 31.85% 0.86% [k] vfs_write
> + 30.20% 0.43% [k] sys_read
> + 29.34% 0.74% [k] new_sync_write
> + 29.22% 0.62% [k] vfs_read
> + 27.88% 0.70% [k] new_sync_read
> + 27.65% 1.70% [k] pipe_write
> + 26.62% 2.86% [k] cpu_startup_entry <== hmm
> + 26.23% 2.05% [k] pipe_read
> + 22.38% 0.45% [k] __wake_up_sync_key
> - 21.92% 6.61% [k] __schedule
> - __schedule
> - 62.95% schedule
> 99.88% pipe_wait
> pipe_read
> new_sync_read
> vfs_read
> sys_read
> system_call
> __read_nocancel
> + 35.27% schedule_preempt_disabled
> + 1.38% __read_nocancel
> + 20.53% 0.81% [k] __wake_up_common
> + 19.72% 0.17% [k] autoremove_wake_function
> + 19.55% 0.09% [k] default_wake_function
> + 19.01% 1.44% [k] try_to_wake_up
> + 18.65% 0.84% [k] pipe_wait
> + 15.07% 1.06% [k] schedule
>


\
 
 \ /
  Last update: 2014-09-12 14:41    [W:0.052 / U:0.576 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site