linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* perf script doesn't dump a normal call trace
@ 2018-11-02  6:36 Xin Long
  2018-11-02 10:26 ` Jiri Olsa
  0 siblings, 1 reply; 7+ messages in thread
From: Xin Long @ 2018-11-02  6:36 UTC (permalink / raw)
  To: LKML, linux-perf-users, Peter Zijlstra, Ingo Molnar,
	Arnaldo Carvalho de Melo, Alexander Shishkin, Jiri Olsa,
	Namhyung Kim

On upstream kernel(4.19) or RHEL-8 kernel(4.18.0):

# perf record -e 'skb:consume_skb' -ag
^C[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.612 MB perf.data (634 samples) ]

# perf script
swapper     0 [009] 274370.117711: skb:consume_skb: skbaddr=0xffff962c591d5b00
        ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])

kworker/9:1-eve   926 [009] 274370.117729: skb:consume_skb:
skbaddr=0xffff962c591d5b00
        ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])

kworker/9:1-eve   926 [009] 274370.117732: skb:consume_skb:
skbaddr=0xffff962c591d4900
        ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])

swapper     0 [009] 274370.145528: skb:consume_skb: skbaddr=0xffff962c591d4900
        ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])

kworker/9:1-eve   926 [009] 274370.145545: skb:consume_skb:
skbaddr=0xffff962c591d4900
        ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])

kworker/9:1-eve   926 [009] 274370.145547: skb:consume_skb:
skbaddr=0xffff962c591d5b00
        ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])

swapper     0 [009] 274370.173443: skb:consume_skb: skbaddr=0xffff962c591d5b00
        ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])


On RHEL-7 kernel(3.10.0):

# perf record -e 'skb:consume_skb' -ag
^C[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.170 MB perf.data (214 samples) ]

# perf script
swapper     0 [001] 69006.726193: skb:consume_skb: skbaddr=0xffff917db9647900
            7fffb3425a00 consume_skb ([kernel.kallsyms])
            7fffb34ba3cb arp_process ([kernel.kallsyms])
            7fffb34bad65 arp_rcv ([kernel.kallsyms])
            7fffb343b6d9 __netif_receive_skb_core ([kernel.kallsyms])
            7fffb343b9d8 __netif_receive_skb ([kernel.kallsyms])
            7fffb343ba60 netif_receive_skb_internal ([kernel.kallsyms])
            7fffb343c6e8 napi_gro_receive ([kernel.kallsyms])
            7fffc007d1f5 virtnet_poll ([kernel.kallsyms])
            7fffb343c07f net_rx_action ([kernel.kallsyms])
            7fffb2ea2f05 __do_softirq ([kernel.kallsyms])
            7fffb357a32c call_softirq ([kernel.kallsyms])
            7fffb2e30675 do_softirq ([kernel.kallsyms])
            7fffb2ea3285 irq_exit ([kernel.kallsyms])
            7fffb357b5e6 __irqentry_text_start ([kernel.kallsyms])
            7fffb356d362 ret_from_intr ([kernel.kallsyms])
            7fffb356c12e default_idle ([kernel.kallsyms])
            7fffb2e386f0 arch_cpu_idle ([kernel.kallsyms])
            7fffb2efe3ba cpu_startup_entry ([kernel.kallsyms])
            7fffb2e59db7 start_secondary ([kernel.kallsyms])
            7fffb2e020d5 start_cpu ([kernel.kallsyms])

swapper     0 [001] 69006.754090: skb:consume_skb: skbaddr=0xffff917db9647100
            7fffb3425a00 consume_skb ([kernel.kallsyms])
            7fffb34ba3cb arp_process ([kernel.kallsyms])
            7fffb34bad65 arp_rcv ([kernel.kallsyms])
            7fffb343b6d9 __netif_receive_skb_core ([kernel.kallsyms])
            7fffb343b9d8 __netif_receive_skb ([kernel.kallsyms])
            7fffb343ba60 netif_receive_skb_internal ([kernel.kallsyms])
            7fffb343c6e8 napi_gro_receive ([kernel.kallsyms])
            7fffc007d1f5 virtnet_poll ([kernel.kallsyms])
            7fffb343c07f net_rx_action ([kernel.kallsyms])
            7fffb2ea2f05 __do_softirq ([kernel.kallsyms])
            7fffb357a32c call_softirq ([kernel.kallsyms])
            7fffb2e30675 do_softirq ([kernel.kallsyms])
            7fffb2ea3285 irq_exit ([kernel.kallsyms])
            7fffb357b5e6 __irqentry_text_start ([kernel.kallsyms])
            7fffb356d362 ret_from_intr ([kernel.kallsyms])
            7fffb356c12e default_idle ([kernel.kallsyms])
            7fffb2e386f0 arch_cpu_idle ([kernel.kallsyms])
            7fffb2efe3ba cpu_startup_entry ([kernel.kallsyms])


any idea why I could get a proper call trace on the new kernel?

Thanks.

^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: perf script doesn't dump a normal call trace
  2018-11-02  6:36 perf script doesn't dump a normal call trace Xin Long
@ 2018-11-02 10:26 ` Jiri Olsa
  2018-11-03  9:36   ` Xin Long
  0 siblings, 1 reply; 7+ messages in thread
From: Jiri Olsa @ 2018-11-02 10:26 UTC (permalink / raw)
  To: Xin Long
  Cc: LKML, linux-perf-users, Peter Zijlstra, Ingo Molnar,
	Arnaldo Carvalho de Melo, Alexander Shishkin, Namhyung Kim

On Fri, Nov 02, 2018 at 03:36:13PM +0900, Xin Long wrote:
> On upstream kernel(4.19) or RHEL-8 kernel(4.18.0):
> 
> # perf record -e 'skb:consume_skb' -ag
> ^C[ perf record: Woken up 1 times to write data ]
> [ perf record: Captured and wrote 0.612 MB perf.data (634 samples) ]
> 
> # perf script
> swapper     0 [009] 274370.117711: skb:consume_skb: skbaddr=0xffff962c591d5b00
>         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> 
> kworker/9:1-eve   926 [009] 274370.117729: skb:consume_skb:
> skbaddr=0xffff962c591d5b00
>         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> 
> kworker/9:1-eve   926 [009] 274370.117732: skb:consume_skb:
> skbaddr=0xffff962c591d4900
>         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> 
> swapper     0 [009] 274370.145528: skb:consume_skb: skbaddr=0xffff962c591d4900
>         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> 
> kworker/9:1-eve   926 [009] 274370.145545: skb:consume_skb:
> skbaddr=0xffff962c591d4900
>         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> 
> kworker/9:1-eve   926 [009] 274370.145547: skb:consume_skb:
> skbaddr=0xffff962c591d5b00
>         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> 
> swapper     0 [009] 274370.173443: skb:consume_skb: skbaddr=0xffff962c591d5b00
>         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])

I can see that on upstream as well, probably something within
tracepoint entry code, because I have it working nicely when
from kprobe, like:

[root@ibm-x3650m4-02 perf]# ./perf probe 'consume_skb'
[root@ibm-x3650m4-02 perf]# ./perf record -g -e probe:consume_skb* -aR ^C

jirka

^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: perf script doesn't dump a normal call trace
  2018-11-02 10:26 ` Jiri Olsa
@ 2018-11-03  9:36   ` Xin Long
  2018-11-04 19:17     ` Jiri Olsa
  0 siblings, 1 reply; 7+ messages in thread
From: Xin Long @ 2018-11-03  9:36 UTC (permalink / raw)
  To: Jiri Olsa
  Cc: LKML, linux-perf-users, Peter Zijlstra, Ingo Molnar,
	Arnaldo Carvalho de Melo, Alexander Shishkin, Namhyung Kim

On Fri, Nov 2, 2018 at 7:26 PM Jiri Olsa <jolsa@redhat.com> wrote:
>
> On Fri, Nov 02, 2018 at 03:36:13PM +0900, Xin Long wrote:
> > On upstream kernel(4.19) or RHEL-8 kernel(4.18.0):
> >
> > # perf record -e 'skb:consume_skb' -ag
> > ^C[ perf record: Woken up 1 times to write data ]
> > [ perf record: Captured and wrote 0.612 MB perf.data (634 samples) ]
> >
> > # perf script
> > swapper     0 [009] 274370.117711: skb:consume_skb: skbaddr=0xffff962c591d5b00
> >         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> >
> > kworker/9:1-eve   926 [009] 274370.117729: skb:consume_skb:
> > skbaddr=0xffff962c591d5b00
> >         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> >
> > kworker/9:1-eve   926 [009] 274370.117732: skb:consume_skb:
> > skbaddr=0xffff962c591d4900
> >         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> >
> > swapper     0 [009] 274370.145528: skb:consume_skb: skbaddr=0xffff962c591d4900
> >         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> >
> > kworker/9:1-eve   926 [009] 274370.145545: skb:consume_skb:
> > skbaddr=0xffff962c591d4900
> >         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> >
> > kworker/9:1-eve   926 [009] 274370.145547: skb:consume_skb:
> > skbaddr=0xffff962c591d5b00
> >         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> >
> > swapper     0 [009] 274370.173443: skb:consume_skb: skbaddr=0xffff962c591d5b00
> >         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
>
> I can see that on upstream as well, probably something within
> tracepoint entry code, because I have it working nicely when
> from kprobe, like:
>
> [root@ibm-x3650m4-02 perf]# ./perf probe 'consume_skb'
> [root@ibm-x3650m4-02 perf]# ./perf record -g -e probe:consume_skb* -aR ^C
>
Thanks Jiri,

My debugging script is using tracepoint with some filters which I
don't think probe can support.
Any one have fixes for this tracepoint issue?

^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: perf script doesn't dump a normal call trace
  2018-11-03  9:36   ` Xin Long
@ 2018-11-04 19:17     ` Jiri Olsa
  2018-11-05  6:20       ` Xin Long
  0 siblings, 1 reply; 7+ messages in thread
From: Jiri Olsa @ 2018-11-04 19:17 UTC (permalink / raw)
  To: Xin Long
  Cc: LKML, linux-perf-users, Peter Zijlstra, Ingo Molnar,
	Arnaldo Carvalho de Melo, Alexander Shishkin, Namhyung Kim

On Sat, Nov 03, 2018 at 06:36:21PM +0900, Xin Long wrote:
> On Fri, Nov 2, 2018 at 7:26 PM Jiri Olsa <jolsa@redhat.com> wrote:
> >
> > On Fri, Nov 02, 2018 at 03:36:13PM +0900, Xin Long wrote:
> > > On upstream kernel(4.19) or RHEL-8 kernel(4.18.0):
> > >
> > > # perf record -e 'skb:consume_skb' -ag
> > > ^C[ perf record: Woken up 1 times to write data ]
> > > [ perf record: Captured and wrote 0.612 MB perf.data (634 samples) ]
> > >
> > > # perf script
> > > swapper     0 [009] 274370.117711: skb:consume_skb: skbaddr=0xffff962c591d5b00
> > >         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> > >
> > > kworker/9:1-eve   926 [009] 274370.117729: skb:consume_skb:
> > > skbaddr=0xffff962c591d5b00
> > >         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> > >
> > > kworker/9:1-eve   926 [009] 274370.117732: skb:consume_skb:
> > > skbaddr=0xffff962c591d4900
> > >         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> > >
> > > swapper     0 [009] 274370.145528: skb:consume_skb: skbaddr=0xffff962c591d4900
> > >         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> > >
> > > kworker/9:1-eve   926 [009] 274370.145545: skb:consume_skb:
> > > skbaddr=0xffff962c591d4900
> > >         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> > >
> > > kworker/9:1-eve   926 [009] 274370.145547: skb:consume_skb:
> > > skbaddr=0xffff962c591d5b00
> > >         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> > >
> > > swapper     0 [009] 274370.173443: skb:consume_skb: skbaddr=0xffff962c591d5b00
> > >         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> >
> > I can see that on upstream as well, probably something within
> > tracepoint entry code, because I have it working nicely when
> > from kprobe, like:
> >
> > [root@ibm-x3650m4-02 perf]# ./perf probe 'consume_skb'
> > [root@ibm-x3650m4-02 perf]# ./perf record -g -e probe:consume_skb* -aR ^C
> >
> Thanks Jiri,
> 
> My debugging script is using tracepoint with some filters which I
> don't think probe can support.
> Any one have fixes for this tracepoint issue?

trying to bisect that.. looks like orc code issue,
it works for me when you switch to fp unwind:
  CONFIG_UNWINDER_FRAME_POINTER

jirka

^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: perf script doesn't dump a normal call trace
  2018-11-04 19:17     ` Jiri Olsa
@ 2018-11-05  6:20       ` Xin Long
  2018-11-05  8:49         ` Jiri Olsa
  0 siblings, 1 reply; 7+ messages in thread
From: Xin Long @ 2018-11-05  6:20 UTC (permalink / raw)
  To: Jiri Olsa
  Cc: LKML, linux-perf-users, Peter Zijlstra, Ingo Molnar,
	Arnaldo Carvalho de Melo, Alexander Shishkin, Namhyung Kim

On Mon, Nov 5, 2018 at 4:18 AM Jiri Olsa <jolsa@redhat.com> wrote:
>
> On Sat, Nov 03, 2018 at 06:36:21PM +0900, Xin Long wrote:
> > On Fri, Nov 2, 2018 at 7:26 PM Jiri Olsa <jolsa@redhat.com> wrote:
> > >
> > > On Fri, Nov 02, 2018 at 03:36:13PM +0900, Xin Long wrote:
> > > > On upstream kernel(4.19) or RHEL-8 kernel(4.18.0):
> > > >
> > > > # perf record -e 'skb:consume_skb' -ag
> > > > ^C[ perf record: Woken up 1 times to write data ]
> > > > [ perf record: Captured and wrote 0.612 MB perf.data (634 samples) ]
> > > >
> > > > # perf script
> > > > swapper     0 [009] 274370.117711: skb:consume_skb: skbaddr=0xffff962c591d5b00
> > > >         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> > > >
> > > > kworker/9:1-eve   926 [009] 274370.117729: skb:consume_skb:
> > > > skbaddr=0xffff962c591d5b00
> > > >         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> > > >
> > > > kworker/9:1-eve   926 [009] 274370.117732: skb:consume_skb:
> > > > skbaddr=0xffff962c591d4900
> > > >         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> > > >
> > > > swapper     0 [009] 274370.145528: skb:consume_skb: skbaddr=0xffff962c591d4900
> > > >         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> > > >
> > > > kworker/9:1-eve   926 [009] 274370.145545: skb:consume_skb:
> > > > skbaddr=0xffff962c591d4900
> > > >         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> > > >
> > > > kworker/9:1-eve   926 [009] 274370.145547: skb:consume_skb:
> > > > skbaddr=0xffff962c591d5b00
> > > >         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> > > >
> > > > swapper     0 [009] 274370.173443: skb:consume_skb: skbaddr=0xffff962c591d5b00
> > > >         ffffffffa4abe534 consume_skb+0x64 ([kernel.kallsyms])
> > >
> > > I can see that on upstream as well, probably something within
> > > tracepoint entry code, because I have it working nicely when
> > > from kprobe, like:
> > >
> > > [root@ibm-x3650m4-02 perf]# ./perf probe 'consume_skb'
> > > [root@ibm-x3650m4-02 perf]# ./perf record -g -e probe:consume_skb* -aR ^C
> > >
> > Thanks Jiri,
> >
> > My debugging script is using tracepoint with some filters which I
> > don't think probe can support.
> > Any one have fixes for this tracepoint issue?
>
> trying to bisect that.. looks like orc code issue,
> it works for me when you switch to fp unwind:
>   CONFIG_UNWINDER_FRAME_POINTER
>

That's a good workaround, thanks.

Another problem is when I'm using perf built manually from upstream kernel tree,
I couldn't see the function's names.
# perf --version
perf version 4.19.g26f1de

# perf report -T
# To display the perf.data header info, please use
--header/--header-only options.
#
#
# Total Lost Samples: 0
#
# Samples: 97  of event 'probe:consume_skb'
# Event count (approx.): 97
#
# Children      Self  Trace output
# ........  ........  ..................
#
   100.00%   100.00%  (ffffffff86f090f0)
            |
            |--93.81%--0xffffffff868000e6
            |          0xffffffff8684ed7f
            |          0xffffffff868e97ad
            |          0xffffffff868e953a
            |          0xffffffff87087623
            |          0xffffffff8682a06f
            |          0xffffffff870872ad
            |          |
            |          |--89.69%--0xffffffff8720098f
            |          |          0xffffffff87201b69
            |          |          0xffffffff868b9c2e


The below is with rhel7's perf
# perf --version
perf version 3.10.0-957.el7.x86_64.debug
# perf report -T
# To display the perf.data header info, please use
--header/--header-only options.
#
#
# Total Lost Samples: 0
#
# Samples: 97  of event 'probe:consume_skb'
# Event count (approx.): 97
#
# Children      Self  Trace output
# ........  ........  ..................
#
   100.00%   100.00%  (ffffffff86f090f0)
            |
            |--93.81%--0x2000e6
            |          start_secondary
            |          cpu_startup_entry
            |          do_idle
            |          default_idle_call
            |          arch_cpu_idle
            |          default_idle
            |          |
            |          |--89.69%--ret_from_intr
            |          |          do_IRQ
            |          |          irq_exit

^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: perf script doesn't dump a normal call trace
  2018-11-05  6:20       ` Xin Long
@ 2018-11-05  8:49         ` Jiri Olsa
  2018-11-06  8:22           ` Xin Long
  0 siblings, 1 reply; 7+ messages in thread
From: Jiri Olsa @ 2018-11-05  8:49 UTC (permalink / raw)
  To: Xin Long
  Cc: LKML, linux-perf-users, Peter Zijlstra, Ingo Molnar,
	Arnaldo Carvalho de Melo, Alexander Shishkin, Namhyung Kim

On Mon, Nov 05, 2018 at 03:20:15PM +0900, Xin Long wrote:

SNIP

> > > > [root@ibm-x3650m4-02 perf]# ./perf probe 'consume_skb'
> > > > [root@ibm-x3650m4-02 perf]# ./perf record -g -e probe:consume_skb* -aR ^C
> > > >
> > > Thanks Jiri,
> > >
> > > My debugging script is using tracepoint with some filters which I
> > > don't think probe can support.
> > > Any one have fixes for this tracepoint issue?
> >
> > trying to bisect that.. looks like orc code issue,
> > it works for me when you switch to fp unwind:
> >   CONFIG_UNWINDER_FRAME_POINTER
> >
> 
> That's a good workaround, thanks.
> 
> Another problem is when I'm using perf built manually from upstream kernel tree,
> I couldn't see the function's names.
> # perf --version
> perf version 4.19.g26f1de
> 
> # perf report -T
> # To display the perf.data header info, please use
> --header/--header-only options.
> #
> #
> # Total Lost Samples: 0
> #
> # Samples: 97  of event 'probe:consume_skb'
> # Event count (approx.): 97
> #
> # Children      Self  Trace output
> # ........  ........  ..................
> #
>    100.00%   100.00%  (ffffffff86f090f0)
>             |
>             |--93.81%--0xffffffff868000e6
>             |          0xffffffff8684ed7f
>             |          0xffffffff868e97ad
>             |          0xffffffff868e953a
>             |          0xffffffff87087623
>             |          0xffffffff8682a06f
>             |          0xffffffff870872ad
>             |          |
>             |          |--89.69%--0xffffffff8720098f
>             |          |          0xffffffff87201b69
>             |          |          0xffffffff868b9c2e
> 
> 
> The below is with rhel7's perf
> # perf --version
> perf version 3.10.0-957.el7.x86_64.debug
> # perf report -T
> # To display the perf.data header info, please use
> --header/--header-only options.
> #
> #
> # Total Lost Samples: 0
> #
> # Samples: 97  of event 'probe:consume_skb'
> # Event count (approx.): 97
> #
> # Children      Self  Trace output
> # ........  ........  ..................
> #
>    100.00%   100.00%  (ffffffff86f090f0)
>             |
>             |--93.81%--0x2000e6
>             |          start_secondary
>             |          cpu_startup_entry
>             |          do_idle
>             |          default_idle_call
>             |          arch_cpu_idle
>             |          default_idle
>             |          |
>             |          |--89.69%--ret_from_intr
>             |          |          do_IRQ
>             |          |          irq_exit

I think that's already fixed on Arnaldo's perf/urgent branch,
  git://git.kernel.org/pub/scm/linux/kernel/git/acme/linux.git

but perhaps this post as well:
  https://lore.kernel.org/lkml/20181031091043.23465-1-adrian.hunter@intel.com/

please give it a try.. it should be merged in soon

jirka

^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: perf script doesn't dump a normal call trace
  2018-11-05  8:49         ` Jiri Olsa
@ 2018-11-06  8:22           ` Xin Long
  0 siblings, 0 replies; 7+ messages in thread
From: Xin Long @ 2018-11-06  8:22 UTC (permalink / raw)
  To: Jiri Olsa
  Cc: LKML, linux-perf-users, Peter Zijlstra, Ingo Molnar,
	Arnaldo Carvalho de Melo, Alexander Shishkin, Namhyung Kim

On Mon, Nov 5, 2018 at 5:49 PM Jiri Olsa <jolsa@redhat.com> wrote:
>
> On Mon, Nov 05, 2018 at 03:20:15PM +0900, Xin Long wrote:
>
> SNIP
>
> > > > > [root@ibm-x3650m4-02 perf]# ./perf probe 'consume_skb'
> > > > > [root@ibm-x3650m4-02 perf]# ./perf record -g -e probe:consume_skb* -aR ^C
> > > > >
> > > > Thanks Jiri,
> > > >
> > > > My debugging script is using tracepoint with some filters which I
> > > > don't think probe can support.
> > > > Any one have fixes for this tracepoint issue?
> > >
> > > trying to bisect that.. looks like orc code issue,
> > > it works for me when you switch to fp unwind:
> > >   CONFIG_UNWINDER_FRAME_POINTER
> > >
> >
> > That's a good workaround, thanks.
> >
> > Another problem is when I'm using perf built manually from upstream kernel tree,
> > I couldn't see the function's names.
> > # perf --version
> > perf version 4.19.g26f1de
> >
> > # perf report -T
> > # To display the perf.data header info, please use
> > --header/--header-only options.
> > #
> > #
> > # Total Lost Samples: 0
> > #
> > # Samples: 97  of event 'probe:consume_skb'
> > # Event count (approx.): 97
> > #
> > # Children      Self  Trace output
> > # ........  ........  ..................
> > #
> >    100.00%   100.00%  (ffffffff86f090f0)
> >             |
> >             |--93.81%--0xffffffff868000e6
> >             |          0xffffffff8684ed7f
> >             |          0xffffffff868e97ad
> >             |          0xffffffff868e953a
> >             |          0xffffffff87087623
> >             |          0xffffffff8682a06f
> >             |          0xffffffff870872ad
> >             |          |
> >             |          |--89.69%--0xffffffff8720098f
> >             |          |          0xffffffff87201b69
> >             |          |          0xffffffff868b9c2e
> >
> >
> > The below is with rhel7's perf
> > # perf --version
> > perf version 3.10.0-957.el7.x86_64.debug
> > # perf report -T
> > # To display the perf.data header info, please use
> > --header/--header-only options.
> > #
> > #
> > # Total Lost Samples: 0
> > #
> > # Samples: 97  of event 'probe:consume_skb'
> > # Event count (approx.): 97
> > #
> > # Children      Self  Trace output
> > # ........  ........  ..................
> > #
> >    100.00%   100.00%  (ffffffff86f090f0)
> >             |
> >             |--93.81%--0x2000e6
> >             |          start_secondary
> >             |          cpu_startup_entry
> >             |          do_idle
> >             |          default_idle_call
> >             |          arch_cpu_idle
> >             |          default_idle
> >             |          |
> >             |          |--89.69%--ret_from_intr
> >             |          |          do_IRQ
> >             |          |          irq_exit
>
> I think that's already fixed on Arnaldo's perf/urgent branch,
>   git://git.kernel.org/pub/scm/linux/kernel/git/acme/linux.git
>
> but perhaps this post as well:
>   https://lore.kernel.org/lkml/20181031091043.23465-1-adrian.hunter@intel.com/
>
> please give it a try.. it should be merged in soon
I will try it later, I have another question?
# perf report -T

# Samples: 97  of event 'probe:consume_skb'
# Event count (approx.): 97
#
# Children      Self  Trace output
# ........  ........  ..................
#
   100.00%   100.00%  (ffffffff86f090f0)
            |
            |--93.81%--0x2000e6
            |          start_secondary
            |          cpu_startup_entry
            |          do_idle
            |          default_idle_call
            |          arch_cpu_idle
          [...]
            |          |                     |
            |          |                      --2.06%--arp_process
            |          |                                neigh_update
            |          |                                __neigh_notify
            |          |                                rtnl_notify
            |          |                                nlmsg_notify
            |          |                                consume_skb  <-----[1]


This command can show a nice tree, and it has the total samples number 97.
But I couldn't see how many of them are from [1]?
Do you know how to count each path's numbers?
Is there an option for "perf report" to do these statistics?
Thanks.

^ permalink raw reply	[flat|nested] 7+ messages in thread

end of thread, other threads:[~2018-11-06  8:22 UTC | newest]

Thread overview: 7+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2018-11-02  6:36 perf script doesn't dump a normal call trace Xin Long
2018-11-02 10:26 ` Jiri Olsa
2018-11-03  9:36   ` Xin Long
2018-11-04 19:17     ` Jiri Olsa
2018-11-05  6:20       ` Xin Long
2018-11-05  8:49         ` Jiri Olsa
2018-11-06  8:22           ` Xin Long

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).