Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]


Groups > linux.kernel > #1389846 > unrolled thread

[PATCH 0/6] perf script: export sampled callchains to database

Started byChris Phlipot <cphlipot0@gmail.com>
First post2016-04-28 10:20 +0200
Last post2016-05-06 13:40 +0200
Articles 5 on this page of 25 — 5 participants

Back to article view | Back to linux.kernel


Contents

  [PATCH 0/6] perf script: export sampled callchains to database Chris Phlipot <cphlipot0@gmail.com> - 2016-04-28 10:20 +0200
    [PATCH 2/6] perf tools: refractor code to move call path handling out of thread-stack Chris Phlipot <cphlipot0@gmail.com> - 2016-04-28 10:20 +0200
      Re: [PATCH 2/6] perf tools: refractor code to move call path  handling out of thread-stack Arnaldo Carvalho de Melo <acme@kernel.org> - 2016-05-06 14:20 +0200
      [tip:perf/core] perf tools: Refactor code to move call path  handling out of thread-stack tip-bot for Chris Phlipot <tipbot@zytor.com> - 2016-05-07 07:00 +0200
    [PATCH 4/6] perf script: add call path id to exported sample in db export Chris Phlipot <cphlipot0@gmail.com> - 2016-04-28 10:30 +0200
      Re: [PATCH 4/6] perf script: add call path id to exported sample in  db export Adrian Hunter <adrian.hunter@intel.com> - 2016-05-06 13:40 +0200
        Re: [PATCH 4/6] perf script: add call path id to exported sample in  db export Arnaldo Carvalho de Melo <acme@kernel.org> - 2016-05-06 14:30 +0200
      [tip:perf/core] perf script: Add call path id to exported sample in  db export tip-bot for Chris Phlipot <tipbot@zytor.com> - 2016-05-07 07:00 +0200
    [PATCH 3/6] perf script: enable db export to output sampled callchains Chris Phlipot <cphlipot0@gmail.com> - 2016-04-28 10:30 +0200
      Re: [PATCH 3/6] perf script: enable db export to output sampled  callchains Adrian Hunter <adrian.hunter@intel.com> - 2016-05-06 13:40 +0200
        Re: [PATCH 3/6] perf script: enable db export to output sampled  callchains Arnaldo Carvalho de Melo <acme@kernel.org> - 2016-05-06 15:10 +0200
          Re: [PATCH 3/6] perf script: enable db export to output sampled  callchains Arnaldo Carvalho de Melo <acme@kernel.org> - 2016-05-06 17:40 +0200
      [tip:perf/core] perf script: Enable db export to output sampled  callchains tip-bot for Chris Phlipot <tipbot@zytor.com> - 2016-05-07 07:00 +0200
    [PATCH 5/6] perf script: expose usage of the callchain db export via the python api Chris Phlipot <cphlipot0@gmail.com> - 2016-04-28 10:30 +0200
      Re: [PATCH 5/6] perf script: expose usage of the callchain db export  via the python api Arnaldo Carvalho de Melo <acme@kernel.org> - 2016-05-06 14:30 +0200
      [tip:perf/core] perf script: Expose usage of the callchain db  export via the python api tip-bot for Chris Phlipot <tipbot@zytor.com> - 2016-05-07 07:00 +0200
    [PATCH 6/6] perf script: update export-to-postgresql to support callchain export Chris Phlipot <cphlipot0@gmail.com> - 2016-04-28 10:30 +0200
      Re: [PATCH 6/6] perf script: update export-to-postgresql to support  callchain export Arnaldo Carvalho de Melo <acme@kernel.org> - 2016-05-06 14:30 +0200
      Re: [PATCH 6/6] perf script: update export-to-postgresql to support  callchain export Arnaldo Carvalho de Melo <acme@kernel.org> - 2016-05-06 14:30 +0200
      [tip:perf/core] perf script: Update export-to-postgresql to support  callchain export tip-bot for Chris Phlipot <tipbot@zytor.com> - 2016-05-07 07:00 +0200
    [PATCH 1/6] perf tools: fix incorrect ordering of callchain entries Chris Phlipot <cphlipot0@gmail.com> - 2016-04-28 10:30 +0200
      Re: [PATCH 1/6] perf tools: fix incorrect ordering of callchain  entries Jiri Olsa <jolsa@redhat.com> - 2016-04-28 10:50 +0200
        Re: [PATCH 1/6] perf tools: fix incorrect ordering of callchain  entries Arnaldo Carvalho de Melo <acme@kernel.org> - 2016-05-06 14:20 +0200
      [tip:perf/core] perf callchain: Fix incorrect ordering of entries tip-bot for Chris Phlipot <tipbot@zytor.com> - 2016-05-07 07:00 +0200
    Re: [PATCH 0/6] perf script: export sampled callchains to database Adrian Hunter <adrian.hunter@intel.com> - 2016-05-06 13:40 +0200

Page 2 of 2 — ← Prev page 1 [2]


#1389870 — [PATCH 1/6] perf tools: fix incorrect ordering of callchain entries

FromChris Phlipot <cphlipot0@gmail.com>
Date2016-04-28 10:30 +0200
Subject[PATCH 1/6] perf tools: fix incorrect ordering of callchain entries
Message-ID<rsPuG-4Y-33@gated-at.bofh.it>
In reply to#1389846
The existing implementation of thread__resolve_callchain, under certain
circumstances, can assemble callchain entries in the incorrect order.

The callchain entries are resolved incorrectly for a sample when all
of the following conditions are met:

1. callchain_param.order is set to ORDER_CALLER

2. thread__resolve_callchain_sample is able to resolve callchain entries
   for the sample.

3. unwind__get_entries is also able to resolve callchain entries for the
   sample.

The fix is accomplished by reversing the order in which
thread__resolve_callchain_sample and unwind__get_entries are called
when callchain_param.order is set to ORDER_CALLER.

Unwind specific code from thread__resolve_callchain is also moved into a
new static function to improve readability of the fix.

How to Reproduce the Existing Bug:

Modifying perf script to print call trees in the opposite order or
applying the remaining patches from this series and comparing the
results output from export-to-postgtresql.py are the easiest ways
to see the bug, however it can still be seen in current builds
using perf report.

Here is how i can reproduce the bug using perf report:
$ ./perf record --call-graph=dwarf stress -c 1 -t 5

when i run this command:
$./perf report --call-graph=flat,0,0,callee

This callchain is contained in the output, which looks correct
(callee order):

                gen8_irq_handler
                handle_irq_event_percpu
                handle_irq_event
                handle_edge_irq
                handle_irq
                do_IRQ
                ret_from_intr
                __random
                rand
                0x558f2a04dded
                0x558f2a04c774
                __libc_start_main
                0x558f2a04dcd9

Now run this command using caller order:
$./perf report --call-graph=flat,0,0,caller

It is expected to see the exact reverse of the above when using caller
order (with "0x558f2a04dcd9" at the top and "gen8_irq_handler" at the
bottom) in the output, but it is nowhere to be found.

instead you see this:

                ret_from_intr
                do_IRQ
                handle_irq
                handle_edge_irq
                handle_irq_event
                handle_irq_event_percpu
                gen8_irq_handler
                0x558f2a04dcd9
                __libc_start_main
                0x558f2a04c774
                0x558f2a04dded
                rand
                __random

Notice how internally the kernel symbols are reversed and the user space
symbols are reversed, but the kernel symbols still appear above the user
space symbols.

if this patch is applied and perf script is re-run, you will see the 
expected output (with "0x558f2a04dcd9" at the top and "gen8_irq_handler"
at the bottom):

                0x558f2a04dcd9
                __libc_start_main
                0x558f2a04c774
                0x558f2a04dded
                rand
                __random
                ret_from_intr
                do_IRQ
                handle_irq
                handle_edge_irq
                handle_irq_event
                handle_irq_event_percpu
                gen8_irq_handler

Signed-off-by: Chris Phlipot <cphlipot0@gmail.com>
---
 tools/perf/util/machine.c | 56 ++++++++++++++++++++++++++++++++++-------------
 1 file changed, 41 insertions(+), 15 deletions(-)

diff --git a/tools/perf/util/machine.c b/tools/perf/util/machine.c
index 2cb95bb..baec208 100644
--- a/tools/perf/util/machine.c
+++ b/tools/perf/util/machine.c
@@ -1812,8 +1812,6 @@ static int thread__resolve_callchain_sample(struct thread *thread,
 	int skip_idx = -1;
 	int first_call = 0;
 
-	callchain_cursor_reset(cursor);
-
 	if (perf_evsel__has_branch_callstack(evsel)) {
 		err = resolve_lbr_callchain_sample(thread, cursor, sample, parent,
 						   root_al, max_stack);
@@ -1924,20 +1922,12 @@ static int unwind_entry(struct unwind_entry *entry, void *arg)
 				       entry->map, entry->sym);
 }
 
-int thread__resolve_callchain(struct thread *thread,
-			      struct callchain_cursor *cursor,
-			      struct perf_evsel *evsel,
-			      struct perf_sample *sample,
-			      struct symbol **parent,
-			      struct addr_location *root_al,
-			      int max_stack)
+static int thread__resolve_callchain_unwind(struct thread *thread,
+					    struct callchain_cursor *cursor,
+					    struct perf_evsel *evsel,
+					    struct perf_sample *sample,
+					    int max_stack)
 {
-	int ret = thread__resolve_callchain_sample(thread, cursor, evsel,
-						   sample, parent,
-						   root_al, max_stack);
-	if (ret)
-		return ret;
-
 	/* Can we do dwarf post unwind? */
 	if (!((evsel->attr.sample_type & PERF_SAMPLE_REGS_USER) &&
 	      (evsel->attr.sample_type & PERF_SAMPLE_STACK_USER)))
@@ -1950,7 +1940,43 @@ int thread__resolve_callchain(struct thread *thread,
 
 	return unwind__get_entries(unwind_entry, cursor,
 				   thread, sample, max_stack);
+}
 
+int thread__resolve_callchain(struct thread *thread,
+			      struct callchain_cursor *cursor,
+			      struct perf_evsel *evsel,
+			      struct perf_sample *sample,
+			      struct symbol **parent,
+			      struct addr_location *root_al,
+			      int max_stack)
+{
+	int ret = 0;
+
+	callchain_cursor_reset(&callchain_cursor);
+
+	if (callchain_param.order == ORDER_CALLEE) {
+		ret = thread__resolve_callchain_sample(thread, cursor,
+						       evsel, sample,
+						       parent, root_al,
+						       max_stack);
+		if (ret)
+			return ret;
+		ret = thread__resolve_callchain_unwind(thread, cursor,
+						       evsel, sample,
+						       max_stack);
+	} else {
+		ret = thread__resolve_callchain_unwind(thread, cursor,
+						       evsel, sample,
+						       max_stack);
+		if (ret)
+			return ret;
+		ret = thread__resolve_callchain_sample(thread, cursor,
+						       evsel, sample,
+						       parent, root_al,
+						       max_stack);
+	}
+
+	return ret;
 }
 
 int machine__for_each_thread(struct machine *machine,
-- 
2.7.4

[toc] | [prev] | [next] | [standalone]


#1389894 — Re: [PATCH 1/6] perf tools: fix incorrect ordering of callchain entries

FromJiri Olsa <jolsa@redhat.com>
Date2016-04-28 10:50 +0200
SubjectRe: [PATCH 1/6] perf tools: fix incorrect ordering of callchain entries
Message-ID<rsPO2-e7-7@gated-at.bofh.it>
In reply to#1389870
On Thu, Apr 28, 2016 at 01:19:06AM -0700, Chris Phlipot wrote:
> The existing implementation of thread__resolve_callchain, under certain
> circumstances, can assemble callchain entries in the incorrect order.

SNIP

>                 0x558f2a04c774
>                 0x558f2a04dded
>                 rand
>                 __random
>                 ret_from_intr
>                 do_IRQ
>                 handle_irq
>                 handle_edge_irq
>                 handle_irq_event
>                 handle_irq_event_percpu
>                 gen8_irq_handler
> 
> Signed-off-by: Chris Phlipot <cphlipot0@gmail.com>

for this patch

Acked-by: Jiri Olsa <jolsa@kernel.org>

can't really ack the rest of the patchset, but it looks good to me

thanks,
jirka

[toc] | [prev] | [next] | [standalone]


#1395817 — Re: [PATCH 1/6] perf tools: fix incorrect ordering of callchain entries

FromArnaldo Carvalho de Melo <acme@kernel.org>
Date2016-05-06 14:20 +0200
SubjectRe: [PATCH 1/6] perf tools: fix incorrect ordering of callchain entries
Message-ID<rvMTD-4RE-3@gated-at.bofh.it>
In reply to#1389894
Em Thu, Apr 28, 2016 at 10:49:03AM +0200, Jiri Olsa escreveu:
> On Thu, Apr 28, 2016 at 01:19:06AM -0700, Chris Phlipot wrote:
> > The existing implementation of thread__resolve_callchain, under certain
> > circumstances, can assemble callchain entries in the incorrect order.
> 
> SNIP
> 
> >                 0x558f2a04c774
> >                 0x558f2a04dded
> >                 rand
> >                 __random
> >                 ret_from_intr
> >                 do_IRQ
> >                 handle_irq
> >                 handle_edge_irq
> >                 handle_irq_event
> >                 handle_irq_event_percpu
> >                 gen8_irq_handler
> > 
> > Signed-off-by: Chris Phlipot <cphlipot0@gmail.com>
> 
> for this patch
> 
> Acked-by: Jiri Olsa <jolsa@kernel.org>

Tested, nice catch and fix, applied.

A good thing would be to be able to reverse the callchain order
dynamicly, in the TUI, shouldn't be hard, right?

- Arnaldo
 
> can't really ack the rest of the patchset, but it looks good to me
> 
> thanks,
> jirka

[toc] | [prev] | [next] | [standalone]


#1396233 — [tip:perf/core] perf callchain: Fix incorrect ordering of entries

Fromtip-bot for Chris Phlipot <tipbot@zytor.com>
Date2016-05-07 07:00 +0200
Subject[tip:perf/core] perf callchain: Fix incorrect ordering of entries
Message-ID<rw2vn-36E-1@gated-at.bofh.it>
In reply to#1389870
Commit-ID:  9919a65ec532799544dfdfd6df6f994b74c12b42
Gitweb:     http://git.kernel.org/tip/9919a65ec532799544dfdfd6df6f994b74c12b42
Author:     Chris Phlipot <cphlipot0@gmail.com>
AuthorDate: Thu, 28 Apr 2016 01:19:06 -0700
Committer:  Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Fri, 6 May 2016 08:59:47 -0300

perf callchain: Fix incorrect ordering of entries

The existing implementation of thread__resolve_callchain, under certain
circumstances, can assemble callchain entries in the incorrect order.

The callchain entries are resolved incorrectly for a sample when all of
the following conditions are met:

1. callchain_param.order is set to ORDER_CALLER

2. thread__resolve_callchain_sample is able to resolve callchain entries
   for the sample.

3. unwind__get_entries is also able to resolve callchain entries for the
   sample.

The fix is accomplished by reversing the order in which
thread__resolve_callchain_sample and unwind__get_entries are called when
callchain_param.order is set to ORDER_CALLER.

Unwind specific code from thread__resolve_callchain is also moved into a
new static function to improve readability of the fix.

How to Reproduce the Existing Bug:

Modifying perf script to print call trees in the opposite order or
applying the remaining patches from this series and comparing the
results output from export-to-postgtresql.py are the easiest ways to see
the bug, however it can still be seen in current builds using perf
report.

Here is how i can reproduce the bug using perf report:

  # perf record --call-graph=dwarf stress -c 1 -t 5

when i run this command:

  # perf report --call-graph=flat,0,0,callee

This callchain, containing kernel (handle_irq_event, etc) and userspace
samples (__libc_start_main, etc) is contained in the output, which looks
correct (callee order):

                gen8_irq_handler
                handle_irq_event_percpu
                handle_irq_event
                handle_edge_irq
                handle_irq
                do_IRQ
                ret_from_intr
                __random
                rand
                0x558f2a04dded
                0x558f2a04c774
                __libc_start_main
                0x558f2a04dcd9

Now run this command using caller order:

  # perf report --call-graph=flat,0,0,caller

It is expected to see the exact reverse of the above when using caller
order (with "0x558f2a04dcd9" at the top and "gen8_irq_handler" at the
bottom) in the output, but it is nowhere to be found.

instead you see this:

                ret_from_intr
                do_IRQ
                handle_irq
                handle_edge_irq
                handle_irq_event
                handle_irq_event_percpu
                gen8_irq_handler
                0x558f2a04dcd9
                __libc_start_main
                0x558f2a04c774
                0x558f2a04dded
                rand
                __random

Notice how internally the kernel symbols are reversed and the user space
symbols are reversed, but the kernel symbols still appear above the user
space symbols.

if this patch is applied and perf script is re-run, you will see the
expected output (with "0x558f2a04dcd9" at the top and "gen8_irq_handler"
at the bottom):

                0x558f2a04dcd9
                __libc_start_main
                0x558f2a04c774
                0x558f2a04dded
                rand
                __random
                ret_from_intr
                do_IRQ
                handle_irq
                handle_edge_irq
                handle_irq_event
                handle_irq_event_percpu
                gen8_irq_handler

Signed-off-by: Chris Phlipot <cphlipot0@gmail.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Acked-by: Jiri Olsa <jolsa@kernel.org>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lkml.kernel.org/r/1461831551-12213-2-git-send-email-cphlipot0@gmail.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/util/machine.c | 56 ++++++++++++++++++++++++++++++++++-------------
 1 file changed, 41 insertions(+), 15 deletions(-)

diff --git a/tools/perf/util/machine.c b/tools/perf/util/machine.c
index 8c7bf4d..639a290 100644
--- a/tools/perf/util/machine.c
+++ b/tools/perf/util/machine.c
@@ -1817,8 +1817,6 @@ static int thread__resolve_callchain_sample(struct thread *thread,
 	int skip_idx = -1;
 	int first_call = 0;
 
-	callchain_cursor_reset(cursor);
-
 	if (perf_evsel__has_branch_callstack(evsel)) {
 		err = resolve_lbr_callchain_sample(thread, cursor, sample, parent,
 						   root_al, max_stack);
@@ -1929,20 +1927,12 @@ static int unwind_entry(struct unwind_entry *entry, void *arg)
 				       entry->map, entry->sym);
 }
 
-int thread__resolve_callchain(struct thread *thread,
-			      struct callchain_cursor *cursor,
-			      struct perf_evsel *evsel,
-			      struct perf_sample *sample,
-			      struct symbol **parent,
-			      struct addr_location *root_al,
-			      int max_stack)
+static int thread__resolve_callchain_unwind(struct thread *thread,
+					    struct callchain_cursor *cursor,
+					    struct perf_evsel *evsel,
+					    struct perf_sample *sample,
+					    int max_stack)
 {
-	int ret = thread__resolve_callchain_sample(thread, cursor, evsel,
-						   sample, parent,
-						   root_al, max_stack);
-	if (ret)
-		return ret;
-
 	/* Can we do dwarf post unwind? */
 	if (!((evsel->attr.sample_type & PERF_SAMPLE_REGS_USER) &&
 	      (evsel->attr.sample_type & PERF_SAMPLE_STACK_USER)))
@@ -1955,7 +1945,43 @@ int thread__resolve_callchain(struct thread *thread,
 
 	return unwind__get_entries(unwind_entry, cursor,
 				   thread, sample, max_stack);
+}
 
+int thread__resolve_callchain(struct thread *thread,
+			      struct callchain_cursor *cursor,
+			      struct perf_evsel *evsel,
+			      struct perf_sample *sample,
+			      struct symbol **parent,
+			      struct addr_location *root_al,
+			      int max_stack)
+{
+	int ret = 0;
+
+	callchain_cursor_reset(&callchain_cursor);
+
+	if (callchain_param.order == ORDER_CALLEE) {
+		ret = thread__resolve_callchain_sample(thread, cursor,
+						       evsel, sample,
+						       parent, root_al,
+						       max_stack);
+		if (ret)
+			return ret;
+		ret = thread__resolve_callchain_unwind(thread, cursor,
+						       evsel, sample,
+						       max_stack);
+	} else {
+		ret = thread__resolve_callchain_unwind(thread, cursor,
+						       evsel, sample,
+						       max_stack);
+		if (ret)
+			return ret;
+		ret = thread__resolve_callchain_sample(thread, cursor,
+						       evsel, sample,
+						       parent, root_al,
+						       max_stack);
+	}
+
+	return ret;
 }
 
 int machine__for_each_thread(struct machine *machine,

[toc] | [prev] | [next] | [standalone]


#1395793

FromAdrian Hunter <adrian.hunter@intel.com>
Date2016-05-06 13:40 +0200
Message-ID<rvMgW-466-21@gated-at.bofh.it>
In reply to#1389846
On 28/04/16 11:19, Chris Phlipot wrote:
> This patch set contains a set of changes to allow the export of sampled
> callchains, and to associate them with samples, via the Python db export
> API and export-to-postgresql.py script.
> 
> Call path information is currently only available in the database when
> call/return info is available, but not when doing normal sampling. These
> changes make this information available for normal sampling runs as well.
> 
> Patches 2-6 are required to make this information available in the
> database.
> 
> Patch 1 is needed to fix an existing issue where callchains are
> processed incorrectly which can cause the other patches to export
> incorrect call paths for a small percentage of samples 
> (depending on the workload).
> 
> Chris Phlipot (6):
>   perf tools: fix incorrect ordering of callchain entries
>   perf tools: refractor code to move call path handling out of
>     thread-stack
>   perf script: enable db export to output sampled callchains
>   perf script: add call path id to exported sample in db export
>   perf script: expose usage of the callchain db export via the python
>     api
>   perf script: update export-to-postgresql to support callchain export
> 
>  tools/perf/scripts/python/export-to-postgresql.py  |  47 ++++---
>  tools/perf/util/Build                              |   1 +
>  tools/perf/util/call-path.c                        | 122 ++++++++++++++++++
>  tools/perf/util/call-path.h                        |  77 ++++++++++++
>  tools/perf/util/db-export.c                        |  89 +++++++++++++
>  tools/perf/util/db-export.h                        |   3 +
>  tools/perf/util/machine.c                          |  56 ++++++---
>  .../util/scripting-engines/trace-event-python.c    |  36 +++++-
>  tools/perf/util/thread-stack.c                     | 139 +--------------------
>  tools/perf/util/thread-stack.h                     |  31 ++---
>  10 files changed, 408 insertions(+), 193 deletions(-)
>  create mode 100644 tools/perf/util/call-path.c
>  create mode 100644 tools/perf/util/call-path.h
> 

You should have put the version number (V2 in this case) in the email
subject and briefly documented what had changed from version to version.
e.g. like here http://marc.info/?l=linux-kernel&m=146172371214423

Nevertheless:

Jiri Acked patch 1 and I have Acked patches 2 - 5 although some minor
changes are needed to patch 3.

[toc] | [prev] | [standalone]


Page 2 of 2 — ← Prev page 1 [2]

Back to top | Article view | linux.kernel


csiph-web