linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [PATCH 1/5] perf report: Fix comparing of dynamic entries
@ 2016-02-26 18:52 Namhyung Kim
  2016-02-26 18:52 ` [PATCH 2/5] perf report: Fix indentation of dynamic entries in hierarchy Namhyung Kim
                   ` (5 more replies)
  0 siblings, 6 replies; 26+ messages in thread
From: Namhyung Kim @ 2016-02-26 18:52 UTC (permalink / raw)
  To: Arnaldo Carvalho de Melo
  Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
	Andi Kleen, Stephane Eranian, Wang Nan

When hist_entry__cmp() and hist_entry__collapse() are called, it should
check the dynamic entry is comparing matching hists only.  Otherwise it
might access different hists resulting in incorrect output.

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
 tools/perf/util/hist.c | 8 ++++++++
 1 file changed, 8 insertions(+)

diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
index 75dc41d2dca9..cc849d326211 100644
--- a/tools/perf/util/hist.c
+++ b/tools/perf/util/hist.c
@@ -1002,6 +1002,10 @@ hist_entry__cmp(struct hist_entry *left, struct hist_entry *right)
 	int64_t cmp = 0;
 
 	hists__for_each_sort_list(hists, fmt) {
+		if (perf_hpp__is_dynamic_entry(fmt) &&
+		    !perf_hpp__defined_dynamic_entry(fmt, hists))
+			continue;
+
 		cmp = fmt->cmp(fmt, left, right);
 		if (cmp)
 			break;
@@ -1018,6 +1022,10 @@ hist_entry__collapse(struct hist_entry *left, struct hist_entry *right)
 	int64_t cmp = 0;
 
 	hists__for_each_sort_list(hists, fmt) {
+		if (perf_hpp__is_dynamic_entry(fmt) &&
+		    !perf_hpp__defined_dynamic_entry(fmt, hists))
+			continue;
+
 		cmp = fmt->collapse(fmt, left, right);
 		if (cmp)
 			break;
-- 
2.7.1

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

* [PATCH 2/5] perf report: Fix indentation of dynamic entries in hierarchy
  2016-02-26 18:52 [PATCH 1/5] perf report: Fix comparing of dynamic entries Namhyung Kim
@ 2016-02-26 18:52 ` Namhyung Kim
  2016-02-27  9:43   ` [tip:perf/core] " tip-bot for Namhyung Kim
  2016-02-26 18:52 ` [PATCH 3/5] perf report: Left align " Namhyung Kim
                   ` (4 subsequent siblings)
  5 siblings, 1 reply; 26+ messages in thread
From: Namhyung Kim @ 2016-02-26 18:52 UTC (permalink / raw)
  To: Arnaldo Carvalho de Melo
  Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
	Andi Kleen, Stephane Eranian, Wang Nan

When dynamic entries are used in the hierarchy mode with multiple
events, the output might not be aligned properly.  In the hierarchy
mode, the each sort column is indented using total number of sort keys.
So it keeps track of number of sort keys when adding them.  However
a dynamic sort key can be added more than once when multiple events have
same field names.  This results in unnecessarily long indentation in the
output.

For example perf kmem records following events:

  $ perf evlist --trace-fields -i perf.data.kmem
  kmem:kmalloc: trace_fields: call_site,ptr,bytes_req,bytes_alloc,gfp_flags
  kmem:kmalloc_node: trace_fields: call_site,ptr,bytes_req,bytes_alloc,gfp_flags,node
  kmem:kfree: trace_fields: call_site,ptr
  kmem:kmem_cache_alloc: trace_fields: call_site,ptr,bytes_req,bytes_alloc,gfp_flags
  kmem:kmem_cache_alloc_node: trace_fields: call_site,ptr,bytes_req,bytes_alloc,gfp_flags,node
  kmem:kmem_cache_free: trace_fields: call_site,ptr
  kmem:mm_page_alloc: trace_fields: page,order,gfp_flags,migratetype
  kmem:mm_page_free: trace_fields: page,order

As you can see, many field names shared between kmem events.  So adding
'ptr' dynamic sort key alone will set nr_sort_keys to 6.  And this adds
many unnecessary spaces between columns.

Before:

  $ perf report -i perf.data.kmem --hierarchy -s ptr -g none --stdio
  ...
  #                Overhead                 ptr
  # .......................  ...................................
  #
      99.89%                 0xffff8803ffb79720
       0.06%                 0xffff8803d228a000
       0.03%                 0xffff8803f7678f00
       0.00%                 0xffff880401dc5280
       0.00%                 0xffff880406172380
       0.00%                 0xffff8803ffac3a00
       0.00%                 0xffff8803ffac1600

After:

  # Overhead                 ptr
  # ........  ....................
  #
      99.89%  0xffff8803ffb79720
       0.06%  0xffff8803d228a000
       0.03%  0xffff8803f7678f00
       0.00%  0xffff880401dc5280
       0.00%  0xffff880406172380
       0.00%  0xffff8803ffac3a00
       0.00%  0xffff8803ffac1600

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
 tools/perf/ui/browsers/hists.c |  6 +++---
 tools/perf/ui/stdio/hist.c     |  6 +++---
 tools/perf/util/hist.h         |  1 +
 tools/perf/util/sort.c         | 19 +++++++++++++++++++
 4 files changed, 26 insertions(+), 6 deletions(-)

diff --git a/tools/perf/ui/browsers/hists.c b/tools/perf/ui/browsers/hists.c
index 71c6d510390f..5f74c6723c53 100644
--- a/tools/perf/ui/browsers/hists.c
+++ b/tools/perf/ui/browsers/hists.c
@@ -1547,7 +1547,7 @@ static int hists_browser__scnprintf_hierarchy_headers(struct hist_browser *brows
 	struct perf_hpp_fmt *fmt;
 	size_t ret = 0;
 	int column = 0;
-	int nr_sort_keys = hists->hpp_list->nr_sort_keys;
+	int nr_sort_keys = hists->nr_sort_keys;
 	bool first = true;
 
 	ret = scnprintf(buf, size, " ");
@@ -1632,7 +1632,7 @@ static unsigned int hist_browser__refresh(struct ui_browser *browser)
 	u16 header_offset = 0;
 	struct rb_node *nd;
 	struct hist_browser *hb = container_of(browser, struct hist_browser, b);
-	int nr_sort = hb->hists->hpp_list->nr_sort_keys;
+	int nr_sort = hb->hists->nr_sort_keys;
 
 	if (hb->show_headers) {
 		hist_browser__show_headers(hb);
@@ -1969,7 +1969,7 @@ static int hist_browser__fprintf(struct hist_browser *browser, FILE *fp)
 	struct rb_node *nd = hists__filter_entries(rb_first(browser->b.entries),
 						   browser->min_pcnt);
 	int printed = 0;
-	int nr_sort = browser->hists->hpp_list->nr_sort_keys;
+	int nr_sort = browser->hists->nr_sort_keys;
 
 	while (nd) {
 		struct hist_entry *h = rb_entry(nd, struct hist_entry, rb_node);
diff --git a/tools/perf/ui/stdio/hist.c b/tools/perf/ui/stdio/hist.c
index b3bdfcb245f9..5733d6c196be 100644
--- a/tools/perf/ui/stdio/hist.c
+++ b/tools/perf/ui/stdio/hist.c
@@ -495,7 +495,7 @@ static int hist_entry__fprintf(struct hist_entry *he, size_t size,
 		size = hpp.size = bfsz;
 
 	if (symbol_conf.report_hierarchy) {
-		int nr_sort = hists->hpp_list->nr_sort_keys;
+		int nr_sort = hists->nr_sort_keys;
 
 		return hist_entry__hierarchy_fprintf(he, &hpp, nr_sort,
 						     hists, fp);
@@ -529,7 +529,7 @@ static int print_hierarchy_header(struct hists *hists, struct perf_hpp *hpp,
 	unsigned header_width = 0;
 	struct perf_hpp_fmt *fmt;
 
-	nr_sort = hists->hpp_list->nr_sort_keys;
+	nr_sort = hists->nr_sort_keys;
 
 	/* preserve max indent depth for column headers */
 	print_hierarchy_indent(sep, nr_sort, spaces, fp);
@@ -728,7 +728,7 @@ print_entries:
 		 * display "no entry >= x.xx%" message.
 		 */
 		if (!h->leaf && !hist_entry__has_hierarchy_children(h, min_pcnt)) {
-			int nr_sort = hists->hpp_list->nr_sort_keys;
+			int nr_sort = hists->nr_sort_keys;
 
 			print_hierarchy_indent(sep, nr_sort + h->depth + 1, spaces, fp);
 			fprintf(fp, "%*sno entry >= %.2f%%\n", indent, "", min_pcnt);
diff --git a/tools/perf/util/hist.h b/tools/perf/util/hist.h
index 283a3e11358c..f4ef513527ba 100644
--- a/tools/perf/util/hist.h
+++ b/tools/perf/util/hist.h
@@ -78,6 +78,7 @@ struct hists {
 	u16			col_len[HISTC_NR_COLS];
 	int			socket_filter;
 	struct perf_hpp_list	*hpp_list;
+	int			nr_sort_keys;
 };
 
 struct hist_entry_iter;
diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
index 83b218c57fe2..e948fcac0939 100644
--- a/tools/perf/util/sort.c
+++ b/tools/perf/util/sort.c
@@ -2641,6 +2641,9 @@ out:
 int setup_sorting(struct perf_evlist *evlist)
 {
 	int err;
+	struct hists *hists;
+	struct perf_evsel *evsel;
+	struct perf_hpp_fmt *fmt;
 
 	err = __setup_sorting(evlist);
 	if (err < 0)
@@ -2652,6 +2655,22 @@ int setup_sorting(struct perf_evlist *evlist)
 			return err;
 	}
 
+	evlist__for_each(evlist, evsel) {
+		hists = evsel__hists(evsel);
+		hists->nr_sort_keys = perf_hpp_list.nr_sort_keys;
+
+		/*
+		 * If dynamic entries were used, it might add multiple
+		 * entries to each evsel for a single field name.  Set
+		 * actual number of sort keys for each hists.
+		 */
+		perf_hpp_list__for_each_sort_list(&perf_hpp_list, fmt) {
+			if (perf_hpp__is_dynamic_entry(fmt) &&
+			    !perf_hpp__defined_dynamic_entry(fmt, hists))
+				hists->nr_sort_keys--;
+		}
+	}
+
 	reset_dimensions();
 
 	/*
-- 
2.7.1

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

* [PATCH 3/5] perf report: Left align dynamic entries in hierarchy
  2016-02-26 18:52 [PATCH 1/5] perf report: Fix comparing of dynamic entries Namhyung Kim
  2016-02-26 18:52 ` [PATCH 2/5] perf report: Fix indentation of dynamic entries in hierarchy Namhyung Kim
@ 2016-02-26 18:52 ` Namhyung Kim
  2016-02-27  9:43   ` [tip:perf/core] " tip-bot for Namhyung Kim
  2016-02-26 18:52 ` [PATCH 4/5] perf report: Fix dynamic entry display " Namhyung Kim
                   ` (3 subsequent siblings)
  5 siblings, 1 reply; 26+ messages in thread
From: Namhyung Kim @ 2016-02-26 18:52 UTC (permalink / raw)
  To: Arnaldo Carvalho de Melo
  Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
	Andi Kleen, Stephane Eranian, Wang Nan

The dynamic entries are right-aligned unlike other entries since it
usually has numeric value.  But for the hierarchy mode, left alignment
is more appropriate IMHO.  Also trim spaces on the left so that we can
easily identify the hierarchy.

Before:

  $ perf report --hierarchy -i perf.data.kmem -s gfp_flags,ptr,bytes_req --stdio -g none
  ...
  #
  #       Overhead                                        gfp_flags /                ptr /          bytes_req
  # ..............  .................................................................................................
  #
      91.67%                   GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
         37.50%        0xffff8803f7669400
            37.50%                       448
          8.33%        0xffff8803f766be00
             8.33%                        96
          4.17%        0xffff8800d156dc00
             4.17%                       704

After:

  #       Overhead  gfp_flags / ptr / bytes_req
  # ..............  ....................................
  #
      91.67%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
         37.50%        0xffff8803f7669400
            37.50%        448
          8.33%        0xffff8803f766be00
             8.33%        96
          4.17%        0xffff8800d156dc00
             4.17%        704

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
 tools/perf/ui/browsers/hists.c | 16 ++++++++++++++--
 tools/perf/ui/stdio/hist.c     | 28 +++++++++++++++++++---------
 2 files changed, 33 insertions(+), 11 deletions(-)

diff --git a/tools/perf/ui/browsers/hists.c b/tools/perf/ui/browsers/hists.c
index 5f74c6723c53..5ffffcb1e3c5 100644
--- a/tools/perf/ui/browsers/hists.c
+++ b/tools/perf/ui/browsers/hists.c
@@ -1400,8 +1400,13 @@ static int hist_browser__show_hierarchy_entry(struct hist_browser *browser,
 		if (fmt->color) {
 			width -= fmt->color(fmt, &hpp, entry);
 		} else {
+			int i = 0;
+
 			width -= fmt->entry(fmt, &hpp, entry);
-			ui_browser__printf(&browser->b, "%s", s);
+			ui_browser__printf(&browser->b, "%s", ltrim(s));
+
+			while (isspace(s[i++]))
+				width++;
 		}
 	}
 
@@ -1576,6 +1581,8 @@ static int hists_browser__scnprintf_hierarchy_headers(struct hist_browser *brows
 		return ret;
 
 	hists__for_each_format(hists, fmt) {
+		char *start;
+
 		if (!perf_hpp__is_sort_entry(fmt) && !perf_hpp__is_dynamic_entry(fmt))
 			continue;
 		if (perf_hpp__should_skip(fmt, hists))
@@ -1593,7 +1600,12 @@ static int hists_browser__scnprintf_hierarchy_headers(struct hist_browser *brows
 		dummy_hpp.buf[ret] = '\0';
 		rtrim(dummy_hpp.buf);
 
-		ret = strlen(dummy_hpp.buf);
+		start = ltrim(dummy_hpp.buf);
+		ret = strlen(start);
+
+		if (start != dummy_hpp.buf)
+			memmove(dummy_hpp.buf, start, ret + 1);
+
 		if (advance_hpp_check(&dummy_hpp, ret))
 			break;
 	}
diff --git a/tools/perf/ui/stdio/hist.c b/tools/perf/ui/stdio/hist.c
index 5733d6c196be..6d06fbb365b6 100644
--- a/tools/perf/ui/stdio/hist.c
+++ b/tools/perf/ui/stdio/hist.c
@@ -418,6 +418,7 @@ static int hist_entry__hierarchy_fprintf(struct hist_entry *he,
 	const char *sep = symbol_conf.field_sep;
 	struct perf_hpp_fmt *fmt;
 	char *buf = hpp->buf;
+	size_t size = hpp->size;
 	int ret, printed = 0;
 	bool first = true;
 
@@ -457,6 +458,11 @@ static int hist_entry__hierarchy_fprintf(struct hist_entry *he,
 				(nr_sort_key - 1) * HIERARCHY_INDENT + 2, "");
 	advance_hpp(hpp, ret);
 
+	printed += fprintf(fp, "%s", buf);
+
+	hpp->buf  = buf;
+	hpp->size = size;
+
 	/*
 	 * No need to call hist_entry__snprintf_alignment() since this
 	 * fmt is always the last column in the hierarchy mode.
@@ -467,7 +473,11 @@ static int hist_entry__hierarchy_fprintf(struct hist_entry *he,
 	else
 		fmt->entry(fmt, hpp, he);
 
-	printed += fprintf(fp, "%s\n", buf);
+	/*
+	 * dynamic entries are right-aligned but we want left-aligned
+	 * in the hierarchy mode
+	 */
+	printed += fprintf(fp, "%s\n", ltrim(buf));
 
 	if (symbol_conf.use_callchain && he->leaf) {
 		u64 total = hists__total_period(hists);
@@ -525,6 +535,7 @@ static int print_hierarchy_header(struct hists *hists, struct perf_hpp *hpp,
 {
 	bool first = true;
 	int nr_sort;
+	int depth;
 	unsigned width = 0;
 	unsigned header_width = 0;
 	struct perf_hpp_fmt *fmt;
@@ -558,19 +569,16 @@ static int print_hierarchy_header(struct hists *hists, struct perf_hpp *hpp,
 		if (!first)
 			header_width += fprintf(fp, " / ");
 		else {
-			header_width += fprintf(fp, "%s", sep ?: "  ");
+			fprintf(fp, "%s", sep ?: "  ");
 			first = false;
 		}
 
 		fmt->header(fmt, hpp, hists_to_evsel(hists));
 		rtrim(hpp->buf);
 
-		header_width += fprintf(fp, "%s", hpp->buf);
+		header_width += fprintf(fp, "%s", ltrim(hpp->buf));
 	}
 
-	/* preserve max indent depth for combined sort headers */
-	print_hierarchy_indent(sep, nr_sort, spaces, fp);
-
 	fprintf(fp, "\n# ");
 
 	/* preserve max indent depth for initial dots */
@@ -590,6 +598,7 @@ static int print_hierarchy_header(struct hists *hists, struct perf_hpp *hpp,
 		fprintf(fp, "%.*s", width, dots);
 	}
 
+	depth = 0;
 	hists__for_each_format(hists, fmt) {
 		if (!perf_hpp__is_sort_entry(fmt) && !perf_hpp__is_dynamic_entry(fmt))
 			continue;
@@ -597,15 +606,16 @@ static int print_hierarchy_header(struct hists *hists, struct perf_hpp *hpp,
 			continue;
 
 		width = fmt->width(fmt, hpp, hists_to_evsel(hists));
+		width += depth * HIERARCHY_INDENT;
+
 		if (width > header_width)
 			header_width = width;
+
+		depth++;
 	}
 
 	fprintf(fp, "%s%-.*s", sep ?: "  ", header_width, dots);
 
-	/* preserve max indent depth for dots under sort headers */
-	print_hierarchy_indent(sep, nr_sort, dots, fp);
-
 	fprintf(fp, "\n#\n");
 
 	return 2;
-- 
2.7.1

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

* [PATCH 4/5] perf report: Fix dynamic entry display in hierarchy
  2016-02-26 18:52 [PATCH 1/5] perf report: Fix comparing of dynamic entries Namhyung Kim
  2016-02-26 18:52 ` [PATCH 2/5] perf report: Fix indentation of dynamic entries in hierarchy Namhyung Kim
  2016-02-26 18:52 ` [PATCH 3/5] perf report: Left align " Namhyung Kim
@ 2016-02-26 18:52 ` Namhyung Kim
  2016-02-26 21:43   ` Arnaldo Carvalho de Melo
  2016-02-27  9:44   ` [tip:perf/core] perf hists: Fix dynamic entry display in hierarchy tip-bot for Namhyung Kim
  2016-02-26 18:52 ` [PATCH 5/5] perf report: Update column width of dynamic entries Namhyung Kim
                   ` (2 subsequent siblings)
  5 siblings, 2 replies; 26+ messages in thread
From: Namhyung Kim @ 2016-02-26 18:52 UTC (permalink / raw)
  To: Arnaldo Carvalho de Melo
  Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
	Andi Kleen, Stephane Eranian, Wang Nan

When dynamic sort key is used it might not show pretty printed output.
This is because the trace output was not set only for the first dynamic
sort key.  During hierarchy_insert_entry() it missed to pass the
trace_output to dynamic entries.  Also even if it did, only first entry
will have it.  Subsequent entries might set it during collapsing stage
but it's not guaranteed.

Before:

  $ perf report --hierarchy --stdio -s ptr,bytes_req,gfp_flags -g none
  #
  #       Overhead  ptr / bytes_req / gfp_flags
  # ..............  ..........................................
  #
      37.50%        0xffff8803f7669400
         37.50%        448
            37.50%        66080
      10.42%        0xffff8803f766be00
          8.33%        96
             8.33%        66080
          2.08%        512
             2.08%        67280

After:

  #
  #       Overhead  ptr / bytes_req / gfp_flags
  # ..............  ..........................................
  #
      37.50%        0xffff8803f7669400
         37.50%        448
            37.50%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
      10.42%        0xffff8803f766be00
          8.33%        96
             8.33%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
          2.08%        512
             2.08%        GFP_KERNEL|GFP_NOWARN|GFP_REPEAT|GFP

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
 tools/perf/util/hist.c | 2 +-
 tools/perf/util/sort.c | 3 +++
 2 files changed, 4 insertions(+), 1 deletion(-)

diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
index cc849d326211..9b3f582867d6 100644
--- a/tools/perf/util/hist.c
+++ b/tools/perf/util/hist.c
@@ -1125,7 +1125,7 @@ static struct hist_entry *hierarchy_insert_entry(struct hists *hists,
 	new->fmt = fmt;
 
 	/* some fields are now passed to 'new' */
-	if (perf_hpp__is_trace_entry(fmt))
+	if (perf_hpp__is_trace_entry(fmt) || perf_hpp__is_dynamic_entry(fmt))
 		he->trace_output = NULL;
 	else
 		new->trace_output = NULL;
diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
index e948fcac0939..3b1b4018f111 100644
--- a/tools/perf/util/sort.c
+++ b/tools/perf/util/sort.c
@@ -1767,6 +1767,9 @@ static int __sort__hde_entry(struct perf_hpp_fmt *fmt, struct perf_hpp *hpp,
 	if (hde->raw_trace)
 		goto raw_field;
 
+	if (!he->trace_output)
+		he->trace_output = get_trace_output(he);
+
 	field = hde->field;
 	namelen = strlen(field->name);
 	str = he->trace_output;
-- 
2.7.1

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

* [PATCH 5/5] perf report: Update column width of dynamic entries
  2016-02-26 18:52 [PATCH 1/5] perf report: Fix comparing of dynamic entries Namhyung Kim
                   ` (2 preceding siblings ...)
  2016-02-26 18:52 ` [PATCH 4/5] perf report: Fix dynamic entry display " Namhyung Kim
@ 2016-02-26 18:52 ` Namhyung Kim
  2016-02-26 22:43   ` Arnaldo Carvalho de Melo
  2016-02-27  9:44   ` [tip:perf/core] " tip-bot for Namhyung Kim
  2016-02-26 21:23 ` [PATCH 1/5] perf report: Fix comparing " Jiri Olsa
  2016-02-27  9:43 ` [tip:perf/core] perf hists: " tip-bot for Namhyung Kim
  5 siblings, 2 replies; 26+ messages in thread
From: Namhyung Kim @ 2016-02-26 18:52 UTC (permalink / raw)
  To: Arnaldo Carvalho de Melo
  Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
	Andi Kleen, Stephane Eranian, Wang Nan

The column width of dynamic entries is updated when comparing hist
entries.  However some unique entries can miss the chance to update.  So
move the update to output resort stage to make sure every entry will get
called before display.

To do that, abuse ->sort callback to update the width when the third
argument is NULL.  When resorting entries in normal path, it never be
NULL so it should be fine IMHO.

Before:

  #       Overhead  ptr / bytes_req / gfp_flags
  # ..............  ..........................................
  #
      37.50%        0xffff8803f7669400
         37.50%        448
            37.50%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
      10.42%        0xffff8803f766be00
          8.33%        96
             8.33%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
          2.08%        512
             2.08%        GFP_KERNEL|GFP_NOWARN|GFP_REPEAT|GFP   <-- here

After:

  #       Overhead  ptr / bytes_req / gfp_flags
  # ..............  .....................................................
  #
      37.50%        0xffff8803f7669400
         37.50%        448
            37.50%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
      10.42%        0xffff8803f766be00
          8.33%        96
             8.33%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
          2.08%        512
             2.08%        GFP_KERNEL|GFP_NOWARN|GFP_REPEAT|GFP_NOMEMALLOC

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
 tools/perf/util/hist.c | 11 +++++++++++
 tools/perf/util/sort.c |  8 +++++---
 2 files changed, 16 insertions(+), 3 deletions(-)

diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
index 9b3f582867d6..4b8b67bc0cd8 100644
--- a/tools/perf/util/hist.c
+++ b/tools/perf/util/hist.c
@@ -1371,6 +1371,10 @@ static void hierarchy_insert_output_entry(struct rb_root *root,
 
 	rb_link_node(&he->rb_node, parent, p);
 	rb_insert_color(&he->rb_node, root);
+
+	/* update column width of dynamic entry */
+	if (perf_hpp__is_dynamic_entry(he->fmt))
+		he->fmt->sort(he->fmt, he, NULL);
 }
 
 static void hists__hierarchy_output_resort(struct hists *hists,
@@ -1440,6 +1444,7 @@ static void __hists__insert_output_entry(struct rb_root *entries,
 	struct rb_node **p = &entries->rb_node;
 	struct rb_node *parent = NULL;
 	struct hist_entry *iter;
+	struct perf_hpp_fmt *fmt;
 
 	if (use_callchain) {
 		if (callchain_param.mode == CHAIN_GRAPH_REL) {
@@ -1466,6 +1471,12 @@ static void __hists__insert_output_entry(struct rb_root *entries,
 
 	rb_link_node(&he->rb_node, parent, p);
 	rb_insert_color(&he->rb_node, entries);
+
+	perf_hpp_list__for_each_sort_list(&perf_hpp_list, fmt) {
+		if (perf_hpp__is_dynamic_entry(fmt) &&
+		    perf_hpp__defined_dynamic_entry(fmt, he->hists))
+			fmt->sort(fmt, he, NULL);  /* update column width */
+	}
 }
 
 static void output_resort(struct hists *hists, struct ui_progress *prog,
diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
index 3b1b4018f111..1457c9d975a0 100644
--- a/tools/perf/util/sort.c
+++ b/tools/perf/util/sort.c
@@ -1819,6 +1819,11 @@ static int64_t __sort__hde_cmp(struct perf_hpp_fmt *fmt,
 
 	hde = container_of(fmt, struct hpp_dynamic_entry, hpp);
 
+	if (b == NULL) {
+		update_dynamic_len(hde, a);
+		return 0;
+	}
+
 	field = hde->field;
 	if (field->flags & FIELD_IS_DYNAMIC) {
 		unsigned long long dyn;
@@ -1833,9 +1838,6 @@ static int64_t __sort__hde_cmp(struct perf_hpp_fmt *fmt,
 	} else {
 		offset = field->offset;
 		size = field->size;
-
-		update_dynamic_len(hde, a);
-		update_dynamic_len(hde, b);
 	}
 
 	return memcmp(a->raw_data + offset, b->raw_data + offset, size);
-- 
2.7.1

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

* Re: [PATCH 1/5] perf report: Fix comparing of dynamic entries
  2016-02-26 18:52 [PATCH 1/5] perf report: Fix comparing of dynamic entries Namhyung Kim
                   ` (3 preceding siblings ...)
  2016-02-26 18:52 ` [PATCH 5/5] perf report: Update column width of dynamic entries Namhyung Kim
@ 2016-02-26 21:23 ` Jiri Olsa
  2016-02-27  9:43 ` [tip:perf/core] perf hists: " tip-bot for Namhyung Kim
  5 siblings, 0 replies; 26+ messages in thread
From: Jiri Olsa @ 2016-02-26 21:23 UTC (permalink / raw)
  To: Namhyung Kim
  Cc: Arnaldo Carvalho de Melo, Ingo Molnar, Peter Zijlstra, Jiri Olsa,
	LKML, David Ahern, Andi Kleen, Stephane Eranian, Wang Nan

On Sat, Feb 27, 2016 at 03:52:43AM +0900, Namhyung Kim wrote:
> When hist_entry__cmp() and hist_entry__collapse() are called, it should
> check the dynamic entry is comparing matching hists only.  Otherwise it
> might access different hists resulting in incorrect output.

the whole patchset looks good to me:

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

thanks,
jirka

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

* Re: [PATCH 4/5] perf report: Fix dynamic entry display in hierarchy
  2016-02-26 18:52 ` [PATCH 4/5] perf report: Fix dynamic entry display " Namhyung Kim
@ 2016-02-26 21:43   ` Arnaldo Carvalho de Melo
  2016-02-26 21:45     ` Arnaldo Carvalho de Melo
  2016-02-27  9:44   ` [tip:perf/core] perf hists: Fix dynamic entry display in hierarchy tip-bot for Namhyung Kim
  1 sibling, 1 reply; 26+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-02-26 21:43 UTC (permalink / raw)
  To: Namhyung Kim
  Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
	Andi Kleen, Stephane Eranian, Wang Nan

Em Sat, Feb 27, 2016 at 03:52:46AM +0900, Namhyung Kim escreveu:
> When dynamic sort key is used it might not show pretty printed output.
> This is because the trace output was not set only for the first dynamic
> sort key.  During hierarchy_insert_entry() it missed to pass the
> trace_output to dynamic entries.  Also even if it did, only first entry
> will have it.  Subsequent entries might set it during collapsing stage
> but it's not guaranteed.
> 
> Before:
> 
>   $ perf report --hierarchy --stdio -s ptr,bytes_req,gfp_flags -g none
>   #
>   #       Overhead  ptr / bytes_req / gfp_flags
>   # ..............  ..........................................
>   #
>       37.50%        0xffff8803f7669400
>          37.50%        448
>             37.50%        66080
>       10.42%        0xffff8803f766be00
>           8.33%        96
>              8.33%        66080
>           2.08%        512
>              2.08%        67280
> 
> After:
> 
>   #
>   #       Overhead  ptr / bytes_req / gfp_flags
>   # ..............  ..........................................
>   #
>       37.50%        0xffff8803f7669400
>          37.50%        448
>             37.50%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC

So, I'm not getting this translation, it looks just like before. So I
tried the non-hierarchy mode and got this [FAILED TO PARSE] on each
line:

Samples: 107  of event 'kmem:kmalloc', Event count (approx.): 107
Overhead  Trace output 
  33.64%  [FAILED TO PARSE] call_site=0xffffffff811a0747 ptr=0xffff880109c54000 bytes_req=4096 bytes_alloc=4096 gfp_flags=37748928                           ▒

Investigating...


>       10.42%        0xffff8803f766be00
>           8.33%        96
>              8.33%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
>           2.08%        512
>              2.08%        GFP_KERNEL|GFP_NOWARN|GFP_REPEAT|GFP
> 
> Signed-off-by: Namhyung Kim <namhyung@kernel.org>
> ---
>  tools/perf/util/hist.c | 2 +-
>  tools/perf/util/sort.c | 3 +++
>  2 files changed, 4 insertions(+), 1 deletion(-)
> 
> diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
> index cc849d326211..9b3f582867d6 100644
> --- a/tools/perf/util/hist.c
> +++ b/tools/perf/util/hist.c
> @@ -1125,7 +1125,7 @@ static struct hist_entry *hierarchy_insert_entry(struct hists *hists,
>  	new->fmt = fmt;
>  
>  	/* some fields are now passed to 'new' */
> -	if (perf_hpp__is_trace_entry(fmt))
> +	if (perf_hpp__is_trace_entry(fmt) || perf_hpp__is_dynamic_entry(fmt))
>  		he->trace_output = NULL;
>  	else
>  		new->trace_output = NULL;
> diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
> index e948fcac0939..3b1b4018f111 100644
> --- a/tools/perf/util/sort.c
> +++ b/tools/perf/util/sort.c
> @@ -1767,6 +1767,9 @@ static int __sort__hde_entry(struct perf_hpp_fmt *fmt, struct perf_hpp *hpp,
>  	if (hde->raw_trace)
>  		goto raw_field;
>  
> +	if (!he->trace_output)
> +		he->trace_output = get_trace_output(he);
> +
>  	field = hde->field;
>  	namelen = strlen(field->name);
>  	str = he->trace_output;
> -- 
> 2.7.1

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

* Re: [PATCH 4/5] perf report: Fix dynamic entry display in hierarchy
  2016-02-26 21:43   ` Arnaldo Carvalho de Melo
@ 2016-02-26 21:45     ` Arnaldo Carvalho de Melo
  2016-02-26 22:08       ` Arnaldo Carvalho de Melo
  0 siblings, 1 reply; 26+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-02-26 21:45 UTC (permalink / raw)
  To: Namhyung Kim
  Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
	Andi Kleen, Stephane Eranian, Wang Nan

Em Fri, Feb 26, 2016 at 06:43:07PM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Sat, Feb 27, 2016 at 03:52:46AM +0900, Namhyung Kim escreveu:
> >       37.50%        0xffff8803f7669400
> >          37.50%        448
> >             37.50%        66080
> >       10.42%        0xffff8803f766be00
> >           8.33%        96
> >              8.33%        66080
> >           2.08%        512
> >              2.08%        67280
> > 
> > After:
> > 
> >   #       Overhead  ptr / bytes_req / gfp_flags
> >   # ..............  ..........................................
> >       37.50%        0xffff8803f7669400
> >          37.50%        448
> >             37.50%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
> 
> So, I'm not getting this translation, it looks just like before. So I
> tried the non-hierarchy mode and got this [FAILED TO PARSE] on each
> line:
> 
> Samples: 107  of event 'kmem:kmalloc', Event count (approx.): 107
> Overhead  Trace output 
>   33.64%  [FAILED TO PARSE] call_site=0xffffffff811a0747 ptr=0xffff880109c54000 bytes_req=4096 bytes_alloc=4096 gfp_flags=37748928                           ▒
> 
> Investigating...

Further (lots of!) info:

[root@jouet ~]# cat /sys/kernel/debug/tracing/events/kmem/kmalloc/format 
name: kmalloc
ID: 424
format:
	field:unsigned short common_type;	offset:0;	size:2;	signed:0;
	field:unsigned char common_flags;	offset:2;	size:1;	signed:0;
	field:unsigned char common_preempt_count;	offset:3;	size:1;	signed:0;
	field:int common_pid;	offset:4;	size:4;	signed:1;

	field:unsigned long call_site;	offset:8;	size:8;	signed:0;
	field:const void * ptr;	offset:16;	size:8;	signed:0;
	field:size_t bytes_req;	offset:24;	size:8;	signed:0;
	field:size_t bytes_alloc;	offset:32;	size:8;	signed:0;
	field:gfp_t gfp_flags;	offset:40;	size:4;	signed:0;

print fmt: "call_site=%lx ptr=%p bytes_req=%zu bytes_alloc=%zu gfp_flags=%s", REC->call_site, REC->ptr, REC->bytes_req, REC->bytes_alloc, (REC->gfp_flags) ? __print_flags(REC->gfp_flags, "|", {(unsigned long)((((((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x20000u)) | (( gfp_t)0x02u)) | (( gfp_t)0x08u)) | (( gfp_t)0x4000u) | (( gfp_t)0x10000u) | (( gfp_t)0x1000u) | (( gfp_t)0x200u)) & ~(( gfp_t)0x2000000u)), "GFP_TRANSHUGE"}, {(unsigned long)((((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x20000u)) | (( gfp_t)0x02u)) | (( gfp_t)0x08u)), "GFP_HIGHUSER_MOVABLE"}, {(unsigned long)(((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x20000u)) | (( gfp_t)0x02u)), "GFP_HIGHUSER"}, {(unsigned long)((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x20000u)), "GFP_USER"}, {(unsigned long)((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x10u)), "GFP_TEMPORARY"}, {(unsigned long)((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u)), "GFP_KERNEL"}, {(unsigned long)((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u)), "GFP_NOFS"}, {(unsigned long)((( gfp_t)0x20u)|(( gfp_t)0x80000u)|(( gfp_t)0x2000000u)), "GFP_ATOMIC"}, {(unsigned long)((( gfp_t)(0x400000u|0x2000000u))), "GFP_NOIO"}, {(unsigned long)(( gfp_t)0x20u), "GFP_HIGH"}, {(unsigned long)(( gfp_t)0x80000u), "GFP_ATOMIC"}, {(unsigned long)(( gfp_t)0x40u), "GFP_IO"}, {(unsigned long)(( gfp_t)0x100u), "GFP_COLD"}, {(unsigned long)(( gfp_t)0x200u), "GFP_NOWARN"}, {(unsigned long)(( gfp_t)0x400u), "GFP_REPEAT"}, {(unsigned long)(( gfp_t)0x800u), "GFP_NOFAIL"}, {(unsigned long)(( gfp_t)0x1000u), "GFP_NORETRY"}, {(unsigned long)(( gfp_t)0x4000u), "GFP_COMP"}, {(unsigned long)(( gfp_t)0x8000u), "GFP_ZERO"}, {(unsigned long)(( gfp_t)0x10000u), "GFP_NOMEMALLOC"}, {(unsigned long)(( gfp_t)0x2000u), "GFP_MEMALLOC"}, {(unsigned long)(( gfp_t)0x20000u), "GFP_HARDWALL"}, {(unsigned long)(( gfp_t)0x40000u), "GFP_THISNODE"}, {(unsigned long)(( gfp_t)0x10u), "GFP_RECLAIMABLE"}, {(unsigned long)(( gfp_t)0x08u), "GFP_MOVABLE"}, {(unsigned long)(( gfp_t)0x200000u), "GFP_NOTRACK"}, {(unsigned long)(( gfp_t)0x400000u), "GFP_DIRECT_RECLAIM"}, {(unsigned long)(( gfp_t)0x2000000u), "GFP_KSWAPD_RECLAIM"}, {(unsigned long)(( gfp_t)0x800000u), "GFP_OTHER_NODE"} ) : "GFP_NOWAIT"
[root@jouet ~]# uname -a
Linux jouet 4.5.0-rc4 #1 SMP Mon Feb 22 15:53:36 BRT 2016 x86_64 x86_64 x86_64 GNU/Linux
[root@jouet ~]#

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

* Re: [PATCH 4/5] perf report: Fix dynamic entry display in hierarchy
  2016-02-26 21:45     ` Arnaldo Carvalho de Melo
@ 2016-02-26 22:08       ` Arnaldo Carvalho de Melo
  2016-02-26 22:24         ` Arnaldo Carvalho de Melo
                           ` (2 more replies)
  0 siblings, 3 replies; 26+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-02-26 22:08 UTC (permalink / raw)
  To: Steven Rostedt, Namhyung Kim
  Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
	Andi Kleen, Stephane Eranian, Wang Nan

Em Fri, Feb 26, 2016 at 06:45:06PM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Fri, Feb 26, 2016 at 06:43:07PM -0300, Arnaldo Carvalho de Melo escreveu:
> > Em Sat, Feb 27, 2016 at 03:52:46AM +0900, Namhyung Kim escreveu:
> > >       37.50%        0xffff8803f7669400
> > >          37.50%        448
> > >             37.50%        66080
> > >       10.42%        0xffff8803f766be00
> > >           8.33%        96
> > >              8.33%        66080
> > >           2.08%        512
> > >              2.08%        67280
> > > 
> > > After:
> > > 
> > >   #       Overhead  ptr / bytes_req / gfp_flags
> > >   # ..............  ..........................................
> > >       37.50%        0xffff8803f7669400
> > >          37.50%        448
> > >             37.50%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
> > 
> > So, I'm not getting this translation, it looks just like before. So I
> > tried the non-hierarchy mode and got this [FAILED TO PARSE] on each
> > line:
> > 
> > Samples: 107  of event 'kmem:kmalloc', Event count (approx.): 107
> > Overhead  Trace output 
> >   33.64%  [FAILED TO PARSE] call_site=0xffffffff811a0747 ptr=0xffff880109c54000 bytes_req=4096 bytes_alloc=4096 gfp_flags=37748928                           ▒
> > 
> > Investigating...
> 
> Further (lots of!) info:
> 
> [root@jouet ~]# cat /sys/kernel/debug/tracing/events/kmem/kmalloc/format 
> name: kmalloc
> ID: 424
> format:
> 	field:unsigned short common_type;	offset:0;	size:2;	signed:0;
> 	field:unsigned char common_flags;	offset:2;	size:1;	signed:0;
> 	field:unsigned char common_preempt_count;	offset:3;	size:1;	signed:0;
> 	field:int common_pid;	offset:4;	size:4;	signed:1;
> 
> 	field:unsigned long call_site;	offset:8;	size:8;	signed:0;
> 	field:const void * ptr;	offset:16;	size:8;	signed:0;
> 	field:size_t bytes_req;	offset:24;	size:8;	signed:0;
> 	field:size_t bytes_alloc;	offset:32;	size:8;	signed:0;
> 	field:gfp_t gfp_flags;	offset:40;	size:4;	signed:0;
> 
> print fmt: "call_site=%lx ptr=%p bytes_req=%zu bytes_alloc=%zu gfp_flags=%s", REC->call_site, REC->ptr, REC->bytes_req, REC->bytes_alloc, (REC->gfp_flags) ? __print_flags(REC->gfp_flags, "|", {(unsigned long)((((((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x20000u)) | (( gfp_t)0x02u)) | (( gfp_t)0x08u)) | (( gfp_t)0x4000u) | (( gfp_t)0x10000u) | (( gfp_t)0x1000u) | (( gfp_t)0x200u)) & ~(( gfp_t)0x2000000u)), "GFP_TRANSHUGE"}, {(unsigned long)((((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x20000u)) | (( gfp_t)0x02u)) | (( gfp_t)0x08u)), "GFP_HIGHUSER_MOVABLE"}, {(unsigned long)(((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x20000u)) | (( gfp_t)0x02u)), "GFP_HIGHUSER"}, {(unsigned long)((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x20000u)), "GFP_USER"}, {(unsigned long)((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x10u)), "GFP_TEMPORARY"}, {(unsigned long)((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u)), "GFP_KERNEL"}, {(unsigned long)((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u)), "GFP_NOFS"}, {(unsigned long)((( gfp_t)0x20u)|(( gfp_t)0x80000u)|(( gfp_t)0x2000000u)), "GFP_ATOMIC"}, {(unsigned long)((( gfp_t)(0x400000u|0x2000000u))), "GFP_NOIO"}, {(unsigned long)(( gfp_t)0x20u), "GFP_HIGH"}, {(unsigned long)(( gfp_t)0x80000u), "GFP_ATOMIC"}, {(unsigned long)(( gfp_t)0x40u), "GFP_IO"}, {(unsigned long)(( gfp_t)0x100u), "GFP_COLD"}, {(unsigned long)(( gfp_t)0x200u), "GFP_NOWARN"}, {(unsigned long)(( gfp_t)0x400u), "GFP_REPEAT"}, {(unsigned long)(( gfp_t)0x800u), "GFP_NOFAIL"}, {(unsigned long)(( gfp_t)0x1000u), "GFP_NORETRY"}, {(unsigned long)(( gfp_t)0x4000u), "GFP_COMP"}, {(unsigned long)(( gfp_t)0x8000u), "GFP_ZERO"}, {(unsigned long)(( gfp_t)0x10000u), "GFP_NOMEMALLOC"}, {(unsigned long)(( gfp_t)0x2000u), "GFP_MEMALLOC"}, {(unsigned long)(( gfp_t)0x20000u), "GFP_HARDWALL"}, {(unsigned long)(( gfp_t)0x40000u), "GFP_THISNODE"}, {(unsigned long)(( gfp_t)0x10u), "GFP_RECLAIMABLE"}, {(unsigned long)(( gfp_t)0x08u), "GFP_MOVABLE"}, {(unsigned long)(( gfp_t)0x200000u), "GFP_NOTRACK"}, {(unsigned long)(( gfp_t)0x400000u), "GFP_DIRECT_RECLAIM"}, {(unsigned long)(( gfp_t)0x2000000u), "GFP_KSWAPD_RECLAIM"}, {(unsigned long)(( gfp_t)0x800000u), "GFP_OTHER_NODE"} ) : "GFP_NOWAIT"
> [root@jouet ~]# uname -a
> Linux jouet 4.5.0-rc4 #1 SMP Mon Feb 22 15:53:36 BRT 2016 x86_64 x86_64 x86_64 GNU/Linux
> [root@jouet ~]#

It is exploding at this depth, not liking how gfp_flags is described, problem
seems to be in this function, this __print_flags() long thing.

Steven, does this look familiar?

(gdb) bt
#0  process_fields (event=0x19b95e0, list=0x19bb0d0, tok=0x7fffffffa0e8) at event-parse.c:2527
#1  0x000000000058410d in process_flags (event=0x19b95e0, arg=0x19bb0b0, tok=0x7fffffffa178) at event-parse.c:2567
#2  0x0000000000584eba in process_function (event=0x19b95e0, arg=0x19bb0b0, token=0x19bb130 "gfp_flags", tok=0x7fffffffa178) at event-parse.c:2989
#3  0x0000000000585231 in process_arg_token (event=0x19b95e0, arg=0x19bb0b0, tok=0x7fffffffa218, type=EVENT_DELIM) at event-parse.c:3060
#4  0x0000000000581f2c in process_arg (event=0x19b95e0, arg=0x19bb0b0, tok=0x7fffffffa218) at event-parse.c:1698
#5  0x000000000058208a in process_cond (event=0x19b95e0, top=0x19bafd0, tok=0x7fffffffa308) at event-parse.c:1746
#6  0x0000000000582772 in process_op (event=0x19b95e0, arg=0x19bafd0, tok=0x7fffffffa308) at event-parse.c:1941
#7  0x0000000000585573 in event_read_print_args (event=0x19b95e0, list=0x19baf70) at event-parse.c:3153
#8  0x0000000000585778 in event_read_print (event=0x19b95e0) at event-parse.c:3225
#9  0x000000000058b402 in __pevent_parse_format (eventp=0x7fffffffa458, pevent=0x19b94c0, 
    buf=0x19b96e0 "name: kmem_cache_alloc\nID: 423\nformat:\n\tfield:unsigned short common_type;\toffset:0;\tsize:2;\tsigned:0;\n\tfield:unsigned char common_flags;\toffset:2;\tsize:1;\tsigned:0;\n\tfield:unsigned char common_preempt"..., size=2983, sys=0x19b96c0 "kmem") at event-parse.c:5916
#10 0x000000000058b5bb in __pevent_parse_event (pevent=0x19b94c0, eventp=0x7fffffffa458, 
    buf=0x19b96e0 "name: kmem_cache_alloc\nID: 423\nformat:\n\tfield:unsigned short common_type;\toffset:0;\tsize:2;\tsigned:0;\n\tfield:unsigned char common_flags;\toffset:2;\tsize:1;\tsigned:0;\n\tfield:unsigned char common_preempt"..., size=2983, sys=0x19b96c0 "kmem") at event-parse.c:5970
#11 0x000000000058b68f in pevent_parse_event (pevent=0x19b94c0, 
    buf=0x19b96e0 "name: kmem_cache_alloc\nID: 423\nformat:\n\tfield:unsigned short common_type;\toffset:0;\tsize:2;\tsigned:0;\n\tfield:unsigned char common_flags;\toffset:2;\tsize:1;\tsigned:0;\n\tfield:unsigned char common_preempt"..., size=2983, sys=0x19b96c0 "kmem") at event-parse.c:6033
#12 0x00000000004f2c3c in parse_event_file (pevent=0x19b94c0, 
    buf=0x19b96e0 "name: kmem_cache_alloc\nID: 423\nformat:\n\tfield:unsigned short common_type;\toffset:0;\tsize:2;\tsigned:0;\n\tfield:unsigned char common_flags;\toffset:2;\tsize:1;\tsigned:0;\n\tfield:unsigned char common_preempt"..., size=2983, sys=0x19b96c0 "kmem") at util/trace-event-parse.c:171
#13 0x0000000000502e16 in read_event_file (pevent=0x19b94c0, sys=0x19b96c0 "kmem", size=2983) at util/trace-event-read.c:293
#14 0x0000000000502f51 in read_event_files (pevent=0x19b94c0) at util/trace-event-read.c:336
#15 0x00000000005032e2 in trace_report (fd=3, tevent=0x19b5a80, __repipe=false) at util/trace-event-read.c:417
#16 0x00000000004d6303 in process_tracing_data (section=0x19b93b0, ph=0x19b57c0, fd=3, data=0x19b5a80) at util/header.c:1595
#17 0x00000000004d8f84 in perf_file_section__process (section=0x19b93b0, ph=0x19b57c0, feat=1, fd=3, data=0x19b5a80) at util/header.c:2704
#18 0x00000000004d8878 in perf_header__process_sections (header=0x19b57c0, fd=3, data=0x19b5a80, process=0x4d8e7e <perf_file_section__process>)
    at util/header.c:2487
#19 0x00000000004d9860 in perf_session__read_header (session=0x19b57c0) at util/header.c:2922
#20 0x00000000004e8c59 in perf_session__open (session=0x19b57c0) at util/session.c:32
#21 0x00000000004e915c in perf_session__new (file=0x7fffffffc8a0, repipe=false, tool=0x7fffffffc990) at util/session.c:139
#22 0x0000000000436dfb in cmd_report (argc=0, argv=0x7fffffffe330, prefix=0x0) at builtin-report.c:878
#23 0x000000000049dbb3 in run_builtin (p=0x90d560 <commands+192>, argc=1, argv=0x7fffffffe330) at perf.c:390
#24 0x000000000049de1b in handle_internal_command (argc=1, argv=0x7fffffffe330) at perf.c:451
#25 0x000000000049df60 in run_argv (argcp=0x7fffffffe18c, argv=0x7fffffffe180) at perf.c:497
#26 0x000000000049e2f7 in main (argc=1, argv=0x7fffffffe330) at perf.c:622
(gdb)

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

* Re: [PATCH 4/5] perf report: Fix dynamic entry display in hierarchy
  2016-02-26 22:08       ` Arnaldo Carvalho de Melo
@ 2016-02-26 22:24         ` Arnaldo Carvalho de Melo
  2016-02-26 22:26         ` Steven Rostedt
  2016-02-26 23:13         ` [PATCH] tools lib traceevent: Add '~' operation within arg_num_eval() Steven Rostedt
  2 siblings, 0 replies; 26+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-02-26 22:24 UTC (permalink / raw)
  To: Steven Rostedt, Namhyung Kim
  Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
	Andi Kleen, Stephane Eranian, Wang Nan

Em Fri, Feb 26, 2016 at 07:08:19PM -0300, Arnaldo Carvalho de Melo escreveu:
> > 
> > print fmt: "call_site=%lx ptr=%p bytes_req=%zu bytes_alloc=%zu gfp_flags=%s", REC->call_site, REC->ptr, REC->bytes_req, REC->bytes_alloc, (REC->gfp_flags) ? __print_flags(REC->gfp_flags, "|", {(unsigned long)((((((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x20000u)) | (( gfp_t)0x02u)) | (( gfp_t)0x08u)) | (( gfp_t)0x4000u) | (( gfp_t)0x10000u) | (( gfp_t)0x1000u) | (( gfp_t)0x200u)) & ~(( gfp_t)0x2000000u)), "GFP_TRANSHUGE"}, {(unsigned long)((((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x20000u)) | (( gfp_t)0x02u)) | (( gfp_t)0x08u)), "GFP_HIGHUSER_MOVABLE"}, {(unsigned long)(((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x20000u)) | (( gfp_t)0x02u)), "GFP_HIGHUSER"}, {(unsigned long)((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x20000u)), "GFP_USER"}, {(unsigned long)((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x10u)), "GFP_TEMPORARY"}, {(unsigned long)((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) | (( gfp_t)0x80u)), "GFP_KERNEL"}, {(unsigned long)((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u)), "GFP_NOFS"}, {(unsigned long)((( gfp_t)0x20u)|(( gfp_t)0x80000u)|(( gfp_t)0x2000000u)), "GFP_ATOMIC"}, {(unsigned long)((( gfp_t)(0x400000u|0x2000000u))), "GFP_NOIO"}, {(unsigned long)(( gfp_t)0x20u), "GFP_HIGH"}, {(unsigned long)(( gfp_t)0x80000u), "GFP_ATOMIC"}, {(unsigned long)(( gfp_t)0x40u), "GFP_IO"}, {(unsigned long)(( gfp_t)0x100u), "GFP_COLD"}, {(unsigned long)(( gfp_t)0x200u), "GFP_NOWARN"}, {(unsigned long)(( gfp_t)0x400u), "GFP_REPEAT"}, {(unsigned long)(( gfp_t)0x800u), "GFP_NOFAIL"}, {(unsigned long)(( gfp_t)0x1000u), "GFP_NORETRY"}, {(unsigned long)(( gfp_t)0x4000u), "GFP_COMP"}, {(unsigned long)(( gfp_t)0x8000u), "GFP_ZERO"}, {(unsigned long)(( gfp_t)0x10000u), "GFP_NOMEMALLOC"}, {(unsigned long)(( gfp_t)0x2000u), "GFP_MEMALLOC"}, {(unsigned long)(( gfp_t)0x20000u), "GFP_HARDWALL"}, {(unsigned long)(( gfp_t)0x40000u), "GFP_THISNODE"}, {(unsigned long)(( gfp_t)0x10u), "GFP_RECLAIMABLE"}, {(unsigned long)(( gfp_t)0x08u), "GFP_MOVABLE"}, {(unsigned long)(( gfp_t)0x200000u), "GFP_NOTRACK"}, {(unsigned long)(( gfp_t)0x400000u), "GFP_DIRECT_RECLAIM"}, {(unsigned long)(( gfp_t)0x2000000u), "GFP_KSWAPD_RECLAIM"}, {(unsigned long)(( gfp_t)0x800000u), "GFP_OTHER_NODE"} ) : "GFP_NOWAIT"
> > [root@jouet ~]# uname -a
> > Linux jouet 4.5.0-rc4 #1 SMP Mon Feb 22 15:53:36 BRT 2016 x86_64 x86_64 x86_64 GNU/Linux
> > [root@jouet ~]#
> 
> It is exploding at this depth, not liking how gfp_flags is described, problem
> seems to be in this function, this __print_flags() long thing.
> 
> Steven, does this look familiar?

Steven, the same tool works when running on an earlier kernel, i.e.
libtraceevent manages to parse that gfp_flags function, while on 4.5-rc it doesn't, ideas?




[root@felicio ~]# cat /sys/kernel/debug/tracing/events/kmem/kmalloc/format
name: kmalloc
ID: 411
format:
	field:unsigned short common_type;	offset:0;	size:2;	signed:0;
	field:unsigned char common_flags;	offset:2;	size:1;	signed:0;
	field:unsigned char common_preempt_count;	offset:3;	size:1;	signed:0;
	field:int common_pid;	offset:4;	size:4;	signed:1;

	field:unsigned long call_site;	offset:8;	size:8;	signed:0;
	field:const void * ptr;	offset:16;	size:8;	signed:0;
	field:size_t bytes_req;	offset:24;	size:8;	signed:0;
	field:size_t bytes_alloc;	offset:32;	size:8;	signed:0;
	field:gfp_t gfp_flags;	offset:40;	size:4;	signed:0;

print fmt: "call_site=%lx ptr=%p bytes_req=%zu bytes_alloc=%zu gfp_flags=%s", REC->call_site, REC->ptr, REC->bytes_req, REC->bytes_alloc, (REC->gfp_flags) ? __print_flags(REC->gfp_flags, "|", {(unsigned long)(((( gfp_t)0x10u) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x20000u) | (( gfp_t)0x02u) | (( gfp_t)0x08u)) | (( gfp_t)0x4000u) | (( gfp_t)0x10000u) | (( gfp_t)0x1000u) | (( gfp_t)0x200u) | (( gfp_t)0x400000u)), "GFP_TRANSHUGE"}, {(unsigned long)((( gfp_t)0x10u) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x20000u) | (( gfp_t)0x02u) | (( gfp_t)0x08u)), "GFP_HIGHUSER_MOVABLE"}, {(unsigned long)((( gfp_t)0x10u) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x20000u) | (( gfp_t)0x02u)), "GFP_HIGHUSER"}, {(unsigned long)((( gfp_t)0x10u) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x20000u)), "GFP_USER"}, {(unsigned long)((( gfp_t)0x10u) | (( gfp_t)0x40u) | (( gfp_t)0x80u) | (( gfp_t)0x80000u)), "GFP_TEMPORARY"}, {(unsigned long)((( gfp_t)0x10u) | (( gfp_t)0x40u) | (( gfp_t)0x80u)), "GFP_KERNEL"}, {(unsigned long)((( gfp_t)0x10u) | (( gfp_t)0x40u)), "GFP_NOFS"}, {(unsigned long)((( gfp_t)0x20u)), "GFP_ATOMIC"}, {(unsigned long)((( gfp_t)0x10u)), "GFP_NOIO"}, {(unsigned long)(( gfp_t)0x20u), "GFP_HIGH"}, {(unsigned long)(( gfp_t)0x10u), "GFP_WAIT"}, {(unsigned long)(( gfp_t)0x40u), "GFP_IO"}, {(unsigned long)(( gfp_t)0x100u), "GFP_COLD"}, {(unsigned long)(( gfp_t)0x200u), "GFP_NOWARN"}, {(unsigned long)(( gfp_t)0x400u), "GFP_REPEAT"}, {(unsigned long)(( gfp_t)0x800u), "GFP_NOFAIL"}, {(unsigned long)(( gfp_t)0x1000u), "GFP_NORETRY"}, {(unsigned long)(( gfp_t)0x4000u), "GFP_COMP"}, {(unsigned long)(( gfp_t)0x8000u), "GFP_ZERO"}, {(unsigned long)(( gfp_t)0x10000u), "GFP_NOMEMALLOC"}, {(unsigned long)(( gfp_t)0x2000u), "GFP_MEMALLOC"}, {(unsigned long)(( gfp_t)0x20000u), "GFP_HARDWALL"}, {(unsigned long)(( gfp_t)0x40000u), "GFP_THISNODE"}, {(unsigned long)(( gfp_t)0x80000u), "GFP_RECLAIMABLE"}, {(unsigned long)(( gfp_t)0x100000u), "GFP_KMEMCG"}, {(unsigned long)(( gfp_t)0x08u), "GFP_MOVABLE"}, {(unsigned long)(( gfp_t)0x200000u), "GFP_NOTRACK"}, {(unsigned long)(( gfp_t)0x400000u), "GFP_NO_KSWAPD"}, {(unsigned long)(( gfp_t)0x800000u), "GFP_OTHER_NODE"} ) : "GFP_NOWAIT"
[root@felicio ~]# uname -r
3.10.0-350.el7perf_sync_4_4_v1.x86_64
[root@felicio ~]# perf report | head -15
# To display the perf.data header info, please use --header/--header-only options.
#
#
# Total Lost Samples: 0
#
# Samples: 128  of event 'kmem:kmalloc'
# Event count (approx.): 128
#
# Overhead  Trace output                                                                                   
# ........  ......................................................................................................................
#
    34.38%  call_site=ffffffff811655cd ptr=0xffff880233c0f000 bytes_req=4096 bytes_alloc=4096 gfp_flags=GFP_KERNEL
    14.84%  call_site=ffffffffa02e25de ptr=0xffff880231f12800 bytes_req=1025 bytes_alloc=2048 gfp_flags=GFP_KERNEL
     4.69%  call_site=ffffffff811ed957 ptr=0xffff880231765700 bytes_req=256 bytes_alloc=256 gfp_flags=GFP_KERNEL|GFP_ZERO
     4.69%  call_site=ffffffff8129461c ptr=0xffff880231563d60 bytes_req=16 bytes_alloc=16 gfp_flags=GFP_KERNEL|GFP_ZERO
[root@felicio ~]#

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

* Re: [PATCH 4/5] perf report: Fix dynamic entry display in hierarchy
  2016-02-26 22:08       ` Arnaldo Carvalho de Melo
  2016-02-26 22:24         ` Arnaldo Carvalho de Melo
@ 2016-02-26 22:26         ` Steven Rostedt
  2016-02-26 22:37           ` Arnaldo Carvalho de Melo
  2016-02-26 23:13         ` [PATCH] tools lib traceevent: Add '~' operation within arg_num_eval() Steven Rostedt
  2 siblings, 1 reply; 26+ messages in thread
From: Steven Rostedt @ 2016-02-26 22:26 UTC (permalink / raw)
  To: Arnaldo Carvalho de Melo
  Cc: Namhyung Kim, Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML,
	David Ahern, Andi Kleen, Stephane Eranian, Wang Nan

On Fri, 26 Feb 2016 19:08:19 -0300
Arnaldo Carvalho de Melo <acme@kernel.org> wrote:


> It is exploding at this depth, not liking how gfp_flags is described, problem
> seems to be in this function, this __print_flags() long thing.
> 
> Steven, does this look familiar?
> 
>

Hmm, trace-cmd has the same issue. I just having noticed.

I'll see if I can fix it.

-- Steve

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

* Re: [PATCH 4/5] perf report: Fix dynamic entry display in hierarchy
  2016-02-26 22:26         ` Steven Rostedt
@ 2016-02-26 22:37           ` Arnaldo Carvalho de Melo
  2016-02-26 23:12             ` Jiri Olsa
  0 siblings, 1 reply; 26+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-02-26 22:37 UTC (permalink / raw)
  To: Steven Rostedt
  Cc: Namhyung Kim, Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML,
	David Ahern, Andi Kleen, Stephane Eranian, Wang Nan

Em Fri, Feb 26, 2016 at 05:26:02PM -0500, Steven Rostedt escreveu:
> On Fri, 26 Feb 2016 19:08:19 -0300
> Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
> 
> 
> > It is exploding at this depth, not liking how gfp_flags is described, problem
> > seems to be in this function, this __print_flags() long thing.
> > 
> > Steven, does this look familiar?
> > 
> >
> 
> Hmm, trace-cmd has the same issue. I just having noticed.
> 
> I'll see if I can fix it.

Ok, this works well with an RHEL kernel being tested with tons of perf
backports by Jiri, its just with 4.5-rc kernels that this is exploding.

- Arnaldo

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

* Re: [PATCH 5/5] perf report: Update column width of dynamic entries
  2016-02-26 18:52 ` [PATCH 5/5] perf report: Update column width of dynamic entries Namhyung Kim
@ 2016-02-26 22:43   ` Arnaldo Carvalho de Melo
  2016-02-27  9:44   ` [tip:perf/core] " tip-bot for Namhyung Kim
  1 sibling, 0 replies; 26+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-02-26 22:43 UTC (permalink / raw)
  To: Namhyung Kim
  Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern,
	Andi Kleen, Stephane Eranian, Wang Nan

Em Sat, Feb 27, 2016 at 03:52:47AM +0900, Namhyung Kim escreveu:
> The column width of dynamic entries is updated when comparing hist
> entries.  However some unique entries can miss the chance to update.  So
> move the update to output resort stage to make sure every entry will get
> called before display.
> 
> To do that, abuse ->sort callback to update the width when the third
> argument is NULL.  When resorting entries in normal path, it never be
> NULL so it should be fine IMHO.
> 
> Before:
> 
>   #       Overhead  ptr / bytes_req / gfp_flags
>   # ..............  ..........................................
>   #
>       37.50%        0xffff8803f7669400
>          37.50%        448
>             37.50%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
>       10.42%        0xffff8803f766be00
>           8.33%        96
>              8.33%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
>           2.08%        512
>              2.08%        GFP_KERNEL|GFP_NOWARN|GFP_REPEAT|GFP   <-- here

So, I tested this with:

 perf report ... > /tmp/before

apply the patch, and then do > /tmp/after, do the diff, reproduced what
you described, slightly different output:

[root@felicio ~]# diff -u /tmp/before /tmp/after | grep ^[+-]
--- /tmp/before	2016-02-26 19:38:31.321497576 -0300
+++ /tmp/after	2016-02-26 19:39:24.043614934 -0300
-# ..............  ....................................
+# ..............  ........................................
-           0.35%        GFP_ATOMIC|GFP_ZERO|GFP_NOMEMA
+           0.35%        GFP_ATOMIC|GFP_ZERO|GFP_NOMEMALLOC
-           0.35%        GFP_ATOMIC|GFP_ZERO|GFP_NOMEMA
+           0.35%        GFP_ATOMIC|GFP_ZERO|GFP_NOMEMALLOC
-           0.35%        GFP_ATOMIC|GFP_ZERO|GFP_NOMEMA
+           0.35%        GFP_ATOMIC|GFP_ZERO|GFP_NOMEMALLOC
-           0.35%        GFP_ATOMIC|GFP_ZERO|GFP_NOMEMA
+           0.35%        GFP_ATOMIC|GFP_ZERO|GFP_NOMEMALLOC
-           0.35%        GFP_ATOMIC|GFP_ZERO|GFP_NOMEMA
+           0.35%        GFP_ATOMIC|GFP_ZERO|GFP_NOMEMALLOC
-           0.35%        GFP_ATOMIC|GFP_ZERO|GFP_NOMEMA
+           0.35%        GFP_ATOMIC|GFP_ZERO|GFP_NOMEMALLOC
-           0.35%        GFP_ATOMIC|GFP_ZERO|GFP_NOMEMA
+           0.35%        GFP_ATOMIC|GFP_ZERO|GFP_NOMEMALLOC
[root@felicio ~]# diff -u /tmp/before /tmp/after | grep ^[+-]

This is something else to add to the regression tests, output diff for
as many command line combos outputs as we can...

Anyway, good work, all applied with Jiri's acks.

- Arnaldo

> 
> After:
> 
>   #       Overhead  ptr / bytes_req / gfp_flags
>   # ..............  .....................................................
>   #
>       37.50%        0xffff8803f7669400
>          37.50%        448
>             37.50%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
>       10.42%        0xffff8803f766be00
>           8.33%        96
>              8.33%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
>           2.08%        512
>              2.08%        GFP_KERNEL|GFP_NOWARN|GFP_REPEAT|GFP_NOMEMALLOC
> 
> Signed-off-by: Namhyung Kim <namhyung@kernel.org>
> ---
>  tools/perf/util/hist.c | 11 +++++++++++
>  tools/perf/util/sort.c |  8 +++++---
>  2 files changed, 16 insertions(+), 3 deletions(-)
> 
> diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
> index 9b3f582867d6..4b8b67bc0cd8 100644
> --- a/tools/perf/util/hist.c
> +++ b/tools/perf/util/hist.c
> @@ -1371,6 +1371,10 @@ static void hierarchy_insert_output_entry(struct rb_root *root,
>  
>  	rb_link_node(&he->rb_node, parent, p);
>  	rb_insert_color(&he->rb_node, root);
> +
> +	/* update column width of dynamic entry */
> +	if (perf_hpp__is_dynamic_entry(he->fmt))
> +		he->fmt->sort(he->fmt, he, NULL);
>  }
>  
>  static void hists__hierarchy_output_resort(struct hists *hists,
> @@ -1440,6 +1444,7 @@ static void __hists__insert_output_entry(struct rb_root *entries,
>  	struct rb_node **p = &entries->rb_node;
>  	struct rb_node *parent = NULL;
>  	struct hist_entry *iter;
> +	struct perf_hpp_fmt *fmt;
>  
>  	if (use_callchain) {
>  		if (callchain_param.mode == CHAIN_GRAPH_REL) {
> @@ -1466,6 +1471,12 @@ static void __hists__insert_output_entry(struct rb_root *entries,
>  
>  	rb_link_node(&he->rb_node, parent, p);
>  	rb_insert_color(&he->rb_node, entries);
> +
> +	perf_hpp_list__for_each_sort_list(&perf_hpp_list, fmt) {
> +		if (perf_hpp__is_dynamic_entry(fmt) &&
> +		    perf_hpp__defined_dynamic_entry(fmt, he->hists))
> +			fmt->sort(fmt, he, NULL);  /* update column width */
> +	}
>  }
>  
>  static void output_resort(struct hists *hists, struct ui_progress *prog,
> diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
> index 3b1b4018f111..1457c9d975a0 100644
> --- a/tools/perf/util/sort.c
> +++ b/tools/perf/util/sort.c
> @@ -1819,6 +1819,11 @@ static int64_t __sort__hde_cmp(struct perf_hpp_fmt *fmt,
>  
>  	hde = container_of(fmt, struct hpp_dynamic_entry, hpp);
>  
> +	if (b == NULL) {
> +		update_dynamic_len(hde, a);
> +		return 0;
> +	}
> +
>  	field = hde->field;
>  	if (field->flags & FIELD_IS_DYNAMIC) {
>  		unsigned long long dyn;
> @@ -1833,9 +1838,6 @@ static int64_t __sort__hde_cmp(struct perf_hpp_fmt *fmt,
>  	} else {
>  		offset = field->offset;
>  		size = field->size;
> -
> -		update_dynamic_len(hde, a);
> -		update_dynamic_len(hde, b);
>  	}
>  
>  	return memcmp(a->raw_data + offset, b->raw_data + offset, size);
> -- 
> 2.7.1

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

* Re: [PATCH 4/5] perf report: Fix dynamic entry display in hierarchy
  2016-02-26 22:37           ` Arnaldo Carvalho de Melo
@ 2016-02-26 23:12             ` Jiri Olsa
  2016-02-26 23:13               ` Jiri Olsa
  0 siblings, 1 reply; 26+ messages in thread
From: Jiri Olsa @ 2016-02-26 23:12 UTC (permalink / raw)
  To: Arnaldo Carvalho de Melo
  Cc: Steven Rostedt, Namhyung Kim, Ingo Molnar, Peter Zijlstra,
	Jiri Olsa, LKML, David Ahern, Andi Kleen, Stephane Eranian,
	Wang Nan

On Fri, Feb 26, 2016 at 07:37:05PM -0300, Arnaldo Carvalho de Melo wrote:
> Em Fri, Feb 26, 2016 at 05:26:02PM -0500, Steven Rostedt escreveu:
> > On Fri, 26 Feb 2016 19:08:19 -0300
> > Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
> > 
> > 
> > > It is exploding at this depth, not liking how gfp_flags is described, problem
> > > seems to be in this function, this __print_flags() long thing.
> > > 
> > > Steven, does this look familiar?
> > > 
> > >
> > 
> > Hmm, trace-cmd has the same issue. I just having noticed.
> > 
> > I'll see if I can fix it.
> 
> Ok, this works well with an RHEL kernel being tested with tons of perf
> backports by Jiri, its just with 4.5-rc kernels that this is exploding.

thanks, I isolated this down to the:
  156174999dd1 perf/intel/x86: Enlarge the PEBS buffer

it's related to the FREERUNNING PEBS patchset that allows
store more than 1 event in PEBS buffer

seems like Core CPU doesn't like the default setup and
delays in msr access, which makes the watchdog scream

jirka

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

* Re: [PATCH 4/5] perf report: Fix dynamic entry display in hierarchy
  2016-02-26 23:12             ` Jiri Olsa
@ 2016-02-26 23:13               ` Jiri Olsa
  0 siblings, 0 replies; 26+ messages in thread
From: Jiri Olsa @ 2016-02-26 23:13 UTC (permalink / raw)
  To: Arnaldo Carvalho de Melo
  Cc: Steven Rostedt, Namhyung Kim, Ingo Molnar, Peter Zijlstra,
	Jiri Olsa, LKML, David Ahern, Andi Kleen, Stephane Eranian,
	Wang Nan

On Sat, Feb 27, 2016 at 12:12:08AM +0100, Jiri Olsa wrote:
> On Fri, Feb 26, 2016 at 07:37:05PM -0300, Arnaldo Carvalho de Melo wrote:
> > Em Fri, Feb 26, 2016 at 05:26:02PM -0500, Steven Rostedt escreveu:
> > > On Fri, 26 Feb 2016 19:08:19 -0300
> > > Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
> > > 
> > > 
> > > > It is exploding at this depth, not liking how gfp_flags is described, problem
> > > > seems to be in this function, this __print_flags() long thing.
> > > > 
> > > > Steven, does this look familiar?
> > > > 
> > > >
> > > 
> > > Hmm, trace-cmd has the same issue. I just having noticed.
> > > 
> > > I'll see if I can fix it.
> > 
> > Ok, this works well with an RHEL kernel being tested with tons of perf
> > backports by Jiri, its just with 4.5-rc kernels that this is exploding.
> 
> thanks, I isolated this down to the:
>   156174999dd1 perf/intel/x86: Enlarge the PEBS buffer
> 
> it's related to the FREERUNNING PEBS patchset that allows
> store more than 1 event in PEBS buffer
> 
> seems like Core CPU doesn't like the default setup and
> delays in msr access, which makes the watchdog scream

heh, wrong thread.. sry ;-)

jirka

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

* [PATCH] tools lib traceevent: Add '~' operation within arg_num_eval()
  2016-02-26 22:08       ` Arnaldo Carvalho de Melo
  2016-02-26 22:24         ` Arnaldo Carvalho de Melo
  2016-02-26 22:26         ` Steven Rostedt
@ 2016-02-26 23:13         ` Steven Rostedt
  2016-02-26 23:39           ` Arnaldo Carvalho de Melo
                             ` (2 more replies)
  2 siblings, 3 replies; 26+ messages in thread
From: Steven Rostedt @ 2016-02-26 23:13 UTC (permalink / raw)
  To: Arnaldo Carvalho de Melo
  Cc: Namhyung Kim, Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML,
	David Ahern, Andi Kleen, Stephane Eranian, Wang Nan

When evaluating values for print flags, if the value included a '~'
operator, the parsing would fail. This broke kmalloc's parsing of:

__print_flags(REC->gfp_flags, "|", {(unsigned
long)((((((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) |
(( gfp_t)0x80u) | (( gfp_t)0x20000u)) | (( gfp_t)0x02u)) |
(( gfp_t)0x08u)) | (( gfp_t)0x4000u) | (( gfp_t)0x10000u) |
(( gfp_t)0x1000u) | (( gfp_t)0x200u)) & ~(( gfp_t)0x2000000u))
                                        ^
                                        |
                                      here

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c
index c3bd294a63d1..557d8edf07f3 100644
--- a/tools/lib/traceevent/event-parse.c
+++ b/tools/lib/traceevent/event-parse.c
@@ -2397,6 +2397,12 @@ static int arg_num_eval(struct print_arg *arg, long long *val)
 				break;
 			*val = left + right;
 			break;
+		case '~':
+			ret = arg_num_eval(arg->op.right, &right);
+			if (!ret)
+				break;
+			*val = ~right;
+			break;
 		default:
 			do_warning("unknown op '%s'", arg->op.op);
 			ret = 0;

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

* Re: [PATCH] tools lib traceevent: Add '~' operation within arg_num_eval()
  2016-02-26 23:13         ` [PATCH] tools lib traceevent: Add '~' operation within arg_num_eval() Steven Rostedt
@ 2016-02-26 23:39           ` Arnaldo Carvalho de Melo
  2016-02-26 23:45           ` David Ahern
  2016-03-11  8:47           ` [tip:perf/core] " tip-bot for Steven Rostedt
  2 siblings, 0 replies; 26+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-02-26 23:39 UTC (permalink / raw)
  To: Steven Rostedt
  Cc: Namhyung Kim, Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML,
	David Ahern, Andi Kleen, Stephane Eranian, Wang Nan

Em Fri, Feb 26, 2016 at 06:13:28PM -0500, Steven Rostedt escreveu:
> When evaluating values for print flags, if the value included a '~'
> operator, the parsing would fail. This broke kmalloc's parsing of:
> 
> __print_flags(REC->gfp_flags, "|", {(unsigned
> long)((((((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) |
> (( gfp_t)0x80u) | (( gfp_t)0x20000u)) | (( gfp_t)0x02u)) |
> (( gfp_t)0x08u)) | (( gfp_t)0x4000u) | (( gfp_t)0x10000u) |
> (( gfp_t)0x1000u) | (( gfp_t)0x200u)) & ~(( gfp_t)0x2000000u))
>                                         ^
>                                         |
>                                       here

Thanks, I'll test this later.

- Arnaldo
> 
> Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
> ---
> diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c
> index c3bd294a63d1..557d8edf07f3 100644
> --- a/tools/lib/traceevent/event-parse.c
> +++ b/tools/lib/traceevent/event-parse.c
> @@ -2397,6 +2397,12 @@ static int arg_num_eval(struct print_arg *arg, long long *val)
>  				break;
>  			*val = left + right;
>  			break;
> +		case '~':
> +			ret = arg_num_eval(arg->op.right, &right);
> +			if (!ret)
> +				break;
> +			*val = ~right;
> +			break;
>  		default:
>  			do_warning("unknown op '%s'", arg->op.op);
>  			ret = 0;

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

* Re: [PATCH] tools lib traceevent: Add '~' operation within arg_num_eval()
  2016-02-26 23:13         ` [PATCH] tools lib traceevent: Add '~' operation within arg_num_eval() Steven Rostedt
  2016-02-26 23:39           ` Arnaldo Carvalho de Melo
@ 2016-02-26 23:45           ` David Ahern
  2016-03-10 16:16             ` David Ahern
  2016-03-11  8:47           ` [tip:perf/core] " tip-bot for Steven Rostedt
  2 siblings, 1 reply; 26+ messages in thread
From: David Ahern @ 2016-02-26 23:45 UTC (permalink / raw)
  To: Steven Rostedt, Arnaldo Carvalho de Melo
  Cc: Namhyung Kim, Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML,
	Andi Kleen, Stephane Eranian, Wang Nan

On 2/26/16 4:13 PM, Steven Rostedt wrote:
> When evaluating values for print flags, if the value included a '~'
> operator, the parsing would fail. This broke kmalloc's parsing of:
>
> __print_flags(REC->gfp_flags, "|", {(unsigned
> long)((((((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) |
> (( gfp_t)0x80u) | (( gfp_t)0x20000u)) | (( gfp_t)0x02u)) |
> (( gfp_t)0x08u)) | (( gfp_t)0x4000u) | (( gfp_t)0x10000u) |
> (( gfp_t)0x1000u) | (( gfp_t)0x200u)) & ~(( gfp_t)0x2000000u))
>                                          ^
>                                          |
>                                        here
>
> Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
> ---

I've been meaning to chase this down for a few weeks. Worked for me.

Tested-by: David Ahern <dsahern@gmail.com>

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

* [tip:perf/core] perf hists: Fix comparing of dynamic entries
  2016-02-26 18:52 [PATCH 1/5] perf report: Fix comparing of dynamic entries Namhyung Kim
                   ` (4 preceding siblings ...)
  2016-02-26 21:23 ` [PATCH 1/5] perf report: Fix comparing " Jiri Olsa
@ 2016-02-27  9:43 ` tip-bot for Namhyung Kim
  5 siblings, 0 replies; 26+ messages in thread
From: tip-bot for Namhyung Kim @ 2016-02-27  9:43 UTC (permalink / raw)
  To: linux-tip-commits
  Cc: eranian, tglx, hpa, dsahern, jolsa, mingo, namhyung,
	linux-kernel, andi, acme, wangnan0, peterz

Commit-ID:  84b6ee8ea36ff797afa13c297a86ed0144482bee
Gitweb:     http://git.kernel.org/tip/84b6ee8ea36ff797afa13c297a86ed0144482bee
Author:     Namhyung Kim <namhyung@kernel.org>
AuthorDate: Sat, 27 Feb 2016 03:52:43 +0900
Committer:  Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Fri, 26 Feb 2016 18:35:57 -0300

perf hists: Fix comparing of dynamic entries

When hist_entry__cmp() and hist_entry__collapse() are called, they
should check if the dynamic entry is comparing matching hists only.

Otherwise it might access different hists resulting in incorrect output.

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Acked-by: Jiri Olsa <jolsa@kernel.org>
Cc: Andi Kleen <andi@firstfloor.org>
Cc: David Ahern <dsahern@gmail.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/r/1456512767-1164-1-git-send-email-namhyung@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/util/hist.c | 8 ++++++++
 1 file changed, 8 insertions(+)

diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
index 75dc41d..cc849d3 100644
--- a/tools/perf/util/hist.c
+++ b/tools/perf/util/hist.c
@@ -1002,6 +1002,10 @@ hist_entry__cmp(struct hist_entry *left, struct hist_entry *right)
 	int64_t cmp = 0;
 
 	hists__for_each_sort_list(hists, fmt) {
+		if (perf_hpp__is_dynamic_entry(fmt) &&
+		    !perf_hpp__defined_dynamic_entry(fmt, hists))
+			continue;
+
 		cmp = fmt->cmp(fmt, left, right);
 		if (cmp)
 			break;
@@ -1018,6 +1022,10 @@ hist_entry__collapse(struct hist_entry *left, struct hist_entry *right)
 	int64_t cmp = 0;
 
 	hists__for_each_sort_list(hists, fmt) {
+		if (perf_hpp__is_dynamic_entry(fmt) &&
+		    !perf_hpp__defined_dynamic_entry(fmt, hists))
+			continue;
+
 		cmp = fmt->collapse(fmt, left, right);
 		if (cmp)
 			break;

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

* [tip:perf/core] perf report: Fix indentation of dynamic entries in hierarchy
  2016-02-26 18:52 ` [PATCH 2/5] perf report: Fix indentation of dynamic entries in hierarchy Namhyung Kim
@ 2016-02-27  9:43   ` tip-bot for Namhyung Kim
  0 siblings, 0 replies; 26+ messages in thread
From: tip-bot for Namhyung Kim @ 2016-02-27  9:43 UTC (permalink / raw)
  To: linux-tip-commits
  Cc: namhyung, andi, linux-kernel, dsahern, eranian, peterz, mingo,
	tglx, jolsa, hpa, wangnan0, acme

Commit-ID:  d3a72fd8187b7fa0014394c9dec95ba349b3301e
Gitweb:     http://git.kernel.org/tip/d3a72fd8187b7fa0014394c9dec95ba349b3301e
Author:     Namhyung Kim <namhyung@kernel.org>
AuthorDate: Sat, 27 Feb 2016 03:52:44 +0900
Committer:  Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Fri, 26 Feb 2016 18:36:11 -0300

perf report: Fix indentation of dynamic entries in hierarchy

When dynamic entries are used in the hierarchy mode with multiple
events, the output might not be aligned properly.  In the hierarchy
mode, the each sort column is indented using total number of sort keys.
So it keeps track of number of sort keys when adding them.  However
a dynamic sort key can be added more than once when multiple events have
same field names.  This results in unnecessarily long indentation in the
output.

For example perf kmem records following events:

  $ perf evlist --trace-fields -i perf.data.kmem
  kmem:kmalloc: trace_fields: call_site,ptr,bytes_req,bytes_alloc,gfp_flags
  kmem:kmalloc_node: trace_fields: call_site,ptr,bytes_req,bytes_alloc,gfp_flags,node
  kmem:kfree: trace_fields: call_site,ptr
  kmem:kmem_cache_alloc: trace_fields: call_site,ptr,bytes_req,bytes_alloc,gfp_flags
  kmem:kmem_cache_alloc_node: trace_fields: call_site,ptr,bytes_req,bytes_alloc,gfp_flags,node
  kmem:kmem_cache_free: trace_fields: call_site,ptr
  kmem:mm_page_alloc: trace_fields: page,order,gfp_flags,migratetype
  kmem:mm_page_free: trace_fields: page,order

As you can see, many field names shared between kmem events.  So adding
'ptr' dynamic sort key alone will set nr_sort_keys to 6.  And this adds
many unnecessary spaces between columns.

Before:

  $ perf report -i perf.data.kmem --hierarchy -s ptr -g none --stdio
  ...
  #                Overhead                 ptr
  # .......................  ...................................
  #
      99.89%                 0xffff8803ffb79720
       0.06%                 0xffff8803d228a000
       0.03%                 0xffff8803f7678f00
       0.00%                 0xffff880401dc5280
       0.00%                 0xffff880406172380
       0.00%                 0xffff8803ffac3a00
       0.00%                 0xffff8803ffac1600

After:

  # Overhead                 ptr
  # ........  ....................
  #
      99.89%  0xffff8803ffb79720
       0.06%  0xffff8803d228a000
       0.03%  0xffff8803f7678f00
       0.00%  0xffff880401dc5280
       0.00%  0xffff880406172380
       0.00%  0xffff8803ffac3a00
       0.00%  0xffff8803ffac1600

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Acked-by: Jiri Olsa <jolsa@kernel.org>
Cc: Andi Kleen <andi@firstfloor.org>
Cc: David Ahern <dsahern@gmail.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/r/1456512767-1164-2-git-send-email-namhyung@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/ui/browsers/hists.c |  6 +++---
 tools/perf/ui/stdio/hist.c     |  6 +++---
 tools/perf/util/hist.h         |  1 +
 tools/perf/util/sort.c         | 19 +++++++++++++++++++
 4 files changed, 26 insertions(+), 6 deletions(-)

diff --git a/tools/perf/ui/browsers/hists.c b/tools/perf/ui/browsers/hists.c
index 71c6d51..5f74c67 100644
--- a/tools/perf/ui/browsers/hists.c
+++ b/tools/perf/ui/browsers/hists.c
@@ -1547,7 +1547,7 @@ static int hists_browser__scnprintf_hierarchy_headers(struct hist_browser *brows
 	struct perf_hpp_fmt *fmt;
 	size_t ret = 0;
 	int column = 0;
-	int nr_sort_keys = hists->hpp_list->nr_sort_keys;
+	int nr_sort_keys = hists->nr_sort_keys;
 	bool first = true;
 
 	ret = scnprintf(buf, size, " ");
@@ -1632,7 +1632,7 @@ static unsigned int hist_browser__refresh(struct ui_browser *browser)
 	u16 header_offset = 0;
 	struct rb_node *nd;
 	struct hist_browser *hb = container_of(browser, struct hist_browser, b);
-	int nr_sort = hb->hists->hpp_list->nr_sort_keys;
+	int nr_sort = hb->hists->nr_sort_keys;
 
 	if (hb->show_headers) {
 		hist_browser__show_headers(hb);
@@ -1969,7 +1969,7 @@ static int hist_browser__fprintf(struct hist_browser *browser, FILE *fp)
 	struct rb_node *nd = hists__filter_entries(rb_first(browser->b.entries),
 						   browser->min_pcnt);
 	int printed = 0;
-	int nr_sort = browser->hists->hpp_list->nr_sort_keys;
+	int nr_sort = browser->hists->nr_sort_keys;
 
 	while (nd) {
 		struct hist_entry *h = rb_entry(nd, struct hist_entry, rb_node);
diff --git a/tools/perf/ui/stdio/hist.c b/tools/perf/ui/stdio/hist.c
index b3bdfcb..5733d6c 100644
--- a/tools/perf/ui/stdio/hist.c
+++ b/tools/perf/ui/stdio/hist.c
@@ -495,7 +495,7 @@ static int hist_entry__fprintf(struct hist_entry *he, size_t size,
 		size = hpp.size = bfsz;
 
 	if (symbol_conf.report_hierarchy) {
-		int nr_sort = hists->hpp_list->nr_sort_keys;
+		int nr_sort = hists->nr_sort_keys;
 
 		return hist_entry__hierarchy_fprintf(he, &hpp, nr_sort,
 						     hists, fp);
@@ -529,7 +529,7 @@ static int print_hierarchy_header(struct hists *hists, struct perf_hpp *hpp,
 	unsigned header_width = 0;
 	struct perf_hpp_fmt *fmt;
 
-	nr_sort = hists->hpp_list->nr_sort_keys;
+	nr_sort = hists->nr_sort_keys;
 
 	/* preserve max indent depth for column headers */
 	print_hierarchy_indent(sep, nr_sort, spaces, fp);
@@ -728,7 +728,7 @@ print_entries:
 		 * display "no entry >= x.xx%" message.
 		 */
 		if (!h->leaf && !hist_entry__has_hierarchy_children(h, min_pcnt)) {
-			int nr_sort = hists->hpp_list->nr_sort_keys;
+			int nr_sort = hists->nr_sort_keys;
 
 			print_hierarchy_indent(sep, nr_sort + h->depth + 1, spaces, fp);
 			fprintf(fp, "%*sno entry >= %.2f%%\n", indent, "", min_pcnt);
diff --git a/tools/perf/util/hist.h b/tools/perf/util/hist.h
index da3e7b6..da5e505 100644
--- a/tools/perf/util/hist.h
+++ b/tools/perf/util/hist.h
@@ -78,6 +78,7 @@ struct hists {
 	u16			col_len[HISTC_NR_COLS];
 	int			socket_filter;
 	struct perf_hpp_list	*hpp_list;
+	int			nr_sort_keys;
 };
 
 struct hist_entry_iter;
diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
index 6bee8bd..2beb7a6 100644
--- a/tools/perf/util/sort.c
+++ b/tools/perf/util/sort.c
@@ -2633,6 +2633,9 @@ out:
 int setup_sorting(struct perf_evlist *evlist)
 {
 	int err;
+	struct hists *hists;
+	struct perf_evsel *evsel;
+	struct perf_hpp_fmt *fmt;
 
 	err = __setup_sorting(evlist);
 	if (err < 0)
@@ -2644,6 +2647,22 @@ int setup_sorting(struct perf_evlist *evlist)
 			return err;
 	}
 
+	evlist__for_each(evlist, evsel) {
+		hists = evsel__hists(evsel);
+		hists->nr_sort_keys = perf_hpp_list.nr_sort_keys;
+
+		/*
+		 * If dynamic entries were used, it might add multiple
+		 * entries to each evsel for a single field name.  Set
+		 * actual number of sort keys for each hists.
+		 */
+		perf_hpp_list__for_each_sort_list(&perf_hpp_list, fmt) {
+			if (perf_hpp__is_dynamic_entry(fmt) &&
+			    !perf_hpp__defined_dynamic_entry(fmt, hists))
+				hists->nr_sort_keys--;
+		}
+	}
+
 	reset_dimensions();
 
 	/*

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

* [tip:perf/core] perf report: Left align dynamic entries in hierarchy
  2016-02-26 18:52 ` [PATCH 3/5] perf report: Left align " Namhyung Kim
@ 2016-02-27  9:43   ` tip-bot for Namhyung Kim
  0 siblings, 0 replies; 26+ messages in thread
From: tip-bot for Namhyung Kim @ 2016-02-27  9:43 UTC (permalink / raw)
  To: linux-tip-commits
  Cc: jolsa, tglx, wangnan0, andi, dsahern, eranian, peterz, hpa,
	linux-kernel, mingo, namhyung, acme

Commit-ID:  cb1fab917206f822d1f905cbc45971eefdef361d
Gitweb:     http://git.kernel.org/tip/cb1fab917206f822d1f905cbc45971eefdef361d
Author:     Namhyung Kim <namhyung@kernel.org>
AuthorDate: Sat, 27 Feb 2016 03:52:45 +0900
Committer:  Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Fri, 26 Feb 2016 18:37:06 -0300

perf report: Left align dynamic entries in hierarchy

The dynamic entries are right-aligned unlike other entries since it
usually has numeric value.  But for the hierarchy mode, left alignment
is more appropriate IMHO.  Also trim spaces on the left so that we can
easily identify the hierarchy.

Before:

  $ perf report --hierarchy -i perf.data.kmem -s gfp_flags,ptr,bytes_req --stdio -g none
  ...
  #
  #       Overhead                                        gfp_flags /                ptr /          bytes_req
  # ..............  .................................................................................................
  #
      91.67%                   GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
         37.50%        0xffff8803f7669400
            37.50%                       448
          8.33%        0xffff8803f766be00
             8.33%                        96
          4.17%        0xffff8800d156dc00
             4.17%                       704

After:

  #       Overhead  gfp_flags / ptr / bytes_req
  # ..............  ....................................
  #
      91.67%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
         37.50%        0xffff8803f7669400
            37.50%        448
          8.33%        0xffff8803f766be00
             8.33%        96
          4.17%        0xffff8800d156dc00
             4.17%        704

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Acked-by: Jiri Olsa <jolsa@kernel.org>
Cc: Andi Kleen <andi@firstfloor.org>
Cc: David Ahern <dsahern@gmail.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/r/1456512767-1164-3-git-send-email-namhyung@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/ui/browsers/hists.c | 16 ++++++++++++++--
 tools/perf/ui/stdio/hist.c     | 28 +++++++++++++++++++---------
 2 files changed, 33 insertions(+), 11 deletions(-)

diff --git a/tools/perf/ui/browsers/hists.c b/tools/perf/ui/browsers/hists.c
index 5f74c67..5ffffcb 100644
--- a/tools/perf/ui/browsers/hists.c
+++ b/tools/perf/ui/browsers/hists.c
@@ -1400,8 +1400,13 @@ static int hist_browser__show_hierarchy_entry(struct hist_browser *browser,
 		if (fmt->color) {
 			width -= fmt->color(fmt, &hpp, entry);
 		} else {
+			int i = 0;
+
 			width -= fmt->entry(fmt, &hpp, entry);
-			ui_browser__printf(&browser->b, "%s", s);
+			ui_browser__printf(&browser->b, "%s", ltrim(s));
+
+			while (isspace(s[i++]))
+				width++;
 		}
 	}
 
@@ -1576,6 +1581,8 @@ static int hists_browser__scnprintf_hierarchy_headers(struct hist_browser *brows
 		return ret;
 
 	hists__for_each_format(hists, fmt) {
+		char *start;
+
 		if (!perf_hpp__is_sort_entry(fmt) && !perf_hpp__is_dynamic_entry(fmt))
 			continue;
 		if (perf_hpp__should_skip(fmt, hists))
@@ -1593,7 +1600,12 @@ static int hists_browser__scnprintf_hierarchy_headers(struct hist_browser *brows
 		dummy_hpp.buf[ret] = '\0';
 		rtrim(dummy_hpp.buf);
 
-		ret = strlen(dummy_hpp.buf);
+		start = ltrim(dummy_hpp.buf);
+		ret = strlen(start);
+
+		if (start != dummy_hpp.buf)
+			memmove(dummy_hpp.buf, start, ret + 1);
+
 		if (advance_hpp_check(&dummy_hpp, ret))
 			break;
 	}
diff --git a/tools/perf/ui/stdio/hist.c b/tools/perf/ui/stdio/hist.c
index 5733d6c..6d06fbb 100644
--- a/tools/perf/ui/stdio/hist.c
+++ b/tools/perf/ui/stdio/hist.c
@@ -418,6 +418,7 @@ static int hist_entry__hierarchy_fprintf(struct hist_entry *he,
 	const char *sep = symbol_conf.field_sep;
 	struct perf_hpp_fmt *fmt;
 	char *buf = hpp->buf;
+	size_t size = hpp->size;
 	int ret, printed = 0;
 	bool first = true;
 
@@ -457,6 +458,11 @@ static int hist_entry__hierarchy_fprintf(struct hist_entry *he,
 				(nr_sort_key - 1) * HIERARCHY_INDENT + 2, "");
 	advance_hpp(hpp, ret);
 
+	printed += fprintf(fp, "%s", buf);
+
+	hpp->buf  = buf;
+	hpp->size = size;
+
 	/*
 	 * No need to call hist_entry__snprintf_alignment() since this
 	 * fmt is always the last column in the hierarchy mode.
@@ -467,7 +473,11 @@ static int hist_entry__hierarchy_fprintf(struct hist_entry *he,
 	else
 		fmt->entry(fmt, hpp, he);
 
-	printed += fprintf(fp, "%s\n", buf);
+	/*
+	 * dynamic entries are right-aligned but we want left-aligned
+	 * in the hierarchy mode
+	 */
+	printed += fprintf(fp, "%s\n", ltrim(buf));
 
 	if (symbol_conf.use_callchain && he->leaf) {
 		u64 total = hists__total_period(hists);
@@ -525,6 +535,7 @@ static int print_hierarchy_header(struct hists *hists, struct perf_hpp *hpp,
 {
 	bool first = true;
 	int nr_sort;
+	int depth;
 	unsigned width = 0;
 	unsigned header_width = 0;
 	struct perf_hpp_fmt *fmt;
@@ -558,19 +569,16 @@ static int print_hierarchy_header(struct hists *hists, struct perf_hpp *hpp,
 		if (!first)
 			header_width += fprintf(fp, " / ");
 		else {
-			header_width += fprintf(fp, "%s", sep ?: "  ");
+			fprintf(fp, "%s", sep ?: "  ");
 			first = false;
 		}
 
 		fmt->header(fmt, hpp, hists_to_evsel(hists));
 		rtrim(hpp->buf);
 
-		header_width += fprintf(fp, "%s", hpp->buf);
+		header_width += fprintf(fp, "%s", ltrim(hpp->buf));
 	}
 
-	/* preserve max indent depth for combined sort headers */
-	print_hierarchy_indent(sep, nr_sort, spaces, fp);
-
 	fprintf(fp, "\n# ");
 
 	/* preserve max indent depth for initial dots */
@@ -590,6 +598,7 @@ static int print_hierarchy_header(struct hists *hists, struct perf_hpp *hpp,
 		fprintf(fp, "%.*s", width, dots);
 	}
 
+	depth = 0;
 	hists__for_each_format(hists, fmt) {
 		if (!perf_hpp__is_sort_entry(fmt) && !perf_hpp__is_dynamic_entry(fmt))
 			continue;
@@ -597,15 +606,16 @@ static int print_hierarchy_header(struct hists *hists, struct perf_hpp *hpp,
 			continue;
 
 		width = fmt->width(fmt, hpp, hists_to_evsel(hists));
+		width += depth * HIERARCHY_INDENT;
+
 		if (width > header_width)
 			header_width = width;
+
+		depth++;
 	}
 
 	fprintf(fp, "%s%-.*s", sep ?: "  ", header_width, dots);
 
-	/* preserve max indent depth for dots under sort headers */
-	print_hierarchy_indent(sep, nr_sort, dots, fp);
-
 	fprintf(fp, "\n#\n");
 
 	return 2;

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

* [tip:perf/core] perf hists: Fix dynamic entry display in hierarchy
  2016-02-26 18:52 ` [PATCH 4/5] perf report: Fix dynamic entry display " Namhyung Kim
  2016-02-26 21:43   ` Arnaldo Carvalho de Melo
@ 2016-02-27  9:44   ` tip-bot for Namhyung Kim
  1 sibling, 0 replies; 26+ messages in thread
From: tip-bot for Namhyung Kim @ 2016-02-27  9:44 UTC (permalink / raw)
  To: linux-tip-commits
  Cc: hpa, dsahern, wangnan0, peterz, linux-kernel, namhyung, tglx,
	acme, andi, eranian, mingo, jolsa

Commit-ID:  e049d4a3fa194c8aa0d3ca29a9b11b32387ca6e3
Gitweb:     http://git.kernel.org/tip/e049d4a3fa194c8aa0d3ca29a9b11b32387ca6e3
Author:     Namhyung Kim <namhyung@kernel.org>
AuthorDate: Sat, 27 Feb 2016 03:52:46 +0900
Committer:  Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Fri, 26 Feb 2016 19:37:38 -0300

perf hists: Fix dynamic entry display in hierarchy

When dynamic sort key is used it might not show pretty printed output.
This is because the trace output was not set only for the first dynamic
sort key.  During hierarchy_insert_entry() it missed to pass the
trace_output to dynamic entries.  Also even if it did, only first entry
will have it.  Subsequent entries might set it during collapsing stage
but it's not guaranteed.

Before:

  $ perf report --hierarchy --stdio -s ptr,bytes_req,gfp_flags -g none
  #
  #       Overhead  ptr / bytes_req / gfp_flags
  # ..............  ..........................................
  #
      37.50%        0xffff8803f7669400
         37.50%        448
            37.50%        66080
      10.42%        0xffff8803f766be00
          8.33%        96
             8.33%        66080
          2.08%        512
             2.08%        67280

After:

  #
  #       Overhead  ptr / bytes_req / gfp_flags
  # ..............  ..........................................
  #
      37.50%        0xffff8803f7669400
         37.50%        448
            37.50%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
      10.42%        0xffff8803f766be00
          8.33%        96
             8.33%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
          2.08%        512
             2.08%        GFP_KERNEL|GFP_NOWARN|GFP_REPEAT|GFP

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Acked-by: Jiri Olsa <jolsa@kernel.org>
Cc: Andi Kleen <andi@firstfloor.org>
Cc: David Ahern <dsahern@gmail.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/r/1456512767-1164-4-git-send-email-namhyung@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/util/hist.c | 2 +-
 tools/perf/util/sort.c | 3 +++
 2 files changed, 4 insertions(+), 1 deletion(-)

diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
index cc849d3..9b3f582 100644
--- a/tools/perf/util/hist.c
+++ b/tools/perf/util/hist.c
@@ -1125,7 +1125,7 @@ static struct hist_entry *hierarchy_insert_entry(struct hists *hists,
 	new->fmt = fmt;
 
 	/* some fields are now passed to 'new' */
-	if (perf_hpp__is_trace_entry(fmt))
+	if (perf_hpp__is_trace_entry(fmt) || perf_hpp__is_dynamic_entry(fmt))
 		he->trace_output = NULL;
 	else
 		new->trace_output = NULL;
diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
index 2beb7a6..d26c6b9 100644
--- a/tools/perf/util/sort.c
+++ b/tools/perf/util/sort.c
@@ -1764,6 +1764,9 @@ static int __sort__hde_entry(struct perf_hpp_fmt *fmt, struct perf_hpp *hpp,
 	if (hde->raw_trace)
 		goto raw_field;
 
+	if (!he->trace_output)
+		he->trace_output = get_trace_output(he);
+
 	field = hde->field;
 	namelen = strlen(field->name);
 	str = he->trace_output;

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

* [tip:perf/core] perf report: Update column width of dynamic entries
  2016-02-26 18:52 ` [PATCH 5/5] perf report: Update column width of dynamic entries Namhyung Kim
  2016-02-26 22:43   ` Arnaldo Carvalho de Melo
@ 2016-02-27  9:44   ` tip-bot for Namhyung Kim
  1 sibling, 0 replies; 26+ messages in thread
From: tip-bot for Namhyung Kim @ 2016-02-27  9:44 UTC (permalink / raw)
  To: linux-tip-commits
  Cc: dsahern, hpa, jolsa, mingo, eranian, peterz, andi, tglx,
	wangnan0, namhyung, acme, linux-kernel

Commit-ID:  abab5e7fcec16e526968f8a5448cd81c635705ce
Gitweb:     http://git.kernel.org/tip/abab5e7fcec16e526968f8a5448cd81c635705ce
Author:     Namhyung Kim <namhyung@kernel.org>
AuthorDate: Sat, 27 Feb 2016 03:52:47 +0900
Committer:  Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Fri, 26 Feb 2016 19:38:48 -0300

perf report: Update column width of dynamic entries

The column width of dynamic entries is updated when comparing hist
entries.  However some unique entries can miss the chance to update.  So
move the update to output resort stage to make sure every entry will get
called before display.

To do that, abuse ->sort callback to update the width when the third
argument is NULL.  When resorting entries in normal path, it never be
NULL so it should be fine IMHO.

Before:

  #       Overhead  ptr / bytes_req / gfp_flags
  # ..............  ..........................................
  #
      37.50%        0xffff8803f7669400
         37.50%        448
            37.50%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
      10.42%        0xffff8803f766be00
          8.33%        96
             8.33%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
          2.08%        512
             2.08%        GFP_KERNEL|GFP_NOWARN|GFP_REPEAT|GFP   <-- here

After:

  #       Overhead  ptr / bytes_req / gfp_flags
  # ..............  .....................................................
  #
      37.50%        0xffff8803f7669400
         37.50%        448
            37.50%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
      10.42%        0xffff8803f766be00
          8.33%        96
             8.33%        GFP_ATOMIC|GFP_NOWARN|GFP_NOMEMALLOC
          2.08%        512
             2.08%        GFP_KERNEL|GFP_NOWARN|GFP_REPEAT|GFP_NOMEMALLOC

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Acked-by: Jiri Olsa <jolsa@kernel.org>
Cc: Andi Kleen <andi@firstfloor.org>
Cc: David Ahern <dsahern@gmail.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/r/1456512767-1164-5-git-send-email-namhyung@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/util/hist.c | 11 +++++++++++
 tools/perf/util/sort.c |  8 +++++---
 2 files changed, 16 insertions(+), 3 deletions(-)

diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
index 9b3f582..4b8b67b 100644
--- a/tools/perf/util/hist.c
+++ b/tools/perf/util/hist.c
@@ -1371,6 +1371,10 @@ static void hierarchy_insert_output_entry(struct rb_root *root,
 
 	rb_link_node(&he->rb_node, parent, p);
 	rb_insert_color(&he->rb_node, root);
+
+	/* update column width of dynamic entry */
+	if (perf_hpp__is_dynamic_entry(he->fmt))
+		he->fmt->sort(he->fmt, he, NULL);
 }
 
 static void hists__hierarchy_output_resort(struct hists *hists,
@@ -1440,6 +1444,7 @@ static void __hists__insert_output_entry(struct rb_root *entries,
 	struct rb_node **p = &entries->rb_node;
 	struct rb_node *parent = NULL;
 	struct hist_entry *iter;
+	struct perf_hpp_fmt *fmt;
 
 	if (use_callchain) {
 		if (callchain_param.mode == CHAIN_GRAPH_REL) {
@@ -1466,6 +1471,12 @@ static void __hists__insert_output_entry(struct rb_root *entries,
 
 	rb_link_node(&he->rb_node, parent, p);
 	rb_insert_color(&he->rb_node, entries);
+
+	perf_hpp_list__for_each_sort_list(&perf_hpp_list, fmt) {
+		if (perf_hpp__is_dynamic_entry(fmt) &&
+		    perf_hpp__defined_dynamic_entry(fmt, he->hists))
+			fmt->sort(fmt, he, NULL);  /* update column width */
+	}
 }
 
 static void output_resort(struct hists *hists, struct ui_progress *prog,
diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
index d26c6b9..5888bfe 100644
--- a/tools/perf/util/sort.c
+++ b/tools/perf/util/sort.c
@@ -1816,6 +1816,11 @@ static int64_t __sort__hde_cmp(struct perf_hpp_fmt *fmt,
 
 	hde = container_of(fmt, struct hpp_dynamic_entry, hpp);
 
+	if (b == NULL) {
+		update_dynamic_len(hde, a);
+		return 0;
+	}
+
 	field = hde->field;
 	if (field->flags & FIELD_IS_DYNAMIC) {
 		unsigned long long dyn;
@@ -1830,9 +1835,6 @@ static int64_t __sort__hde_cmp(struct perf_hpp_fmt *fmt,
 	} else {
 		offset = field->offset;
 		size = field->size;
-
-		update_dynamic_len(hde, a);
-		update_dynamic_len(hde, b);
 	}
 
 	return memcmp(a->raw_data + offset, b->raw_data + offset, size);

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

* Re: [PATCH] tools lib traceevent: Add '~' operation within arg_num_eval()
  2016-02-26 23:45           ` David Ahern
@ 2016-03-10 16:16             ` David Ahern
  2016-03-10 19:28               ` Arnaldo Carvalho de Melo
  0 siblings, 1 reply; 26+ messages in thread
From: David Ahern @ 2016-03-10 16:16 UTC (permalink / raw)
  To: Steven Rostedt, Arnaldo Carvalho de Melo
  Cc: Namhyung Kim, Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML,
	Andi Kleen, Stephane Eranian, Wang Nan

On 2/26/16 4:45 PM, David Ahern wrote:
> On 2/26/16 4:13 PM, Steven Rostedt wrote:
>> When evaluating values for print flags, if the value included a '~'
>> operator, the parsing would fail. This broke kmalloc's parsing of:
>>
>> __print_flags(REC->gfp_flags, "|", {(unsigned
>> long)((((((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) |
>> (( gfp_t)0x80u) | (( gfp_t)0x20000u)) | (( gfp_t)0x02u)) |
>> (( gfp_t)0x08u)) | (( gfp_t)0x4000u) | (( gfp_t)0x10000u) |
>> (( gfp_t)0x1000u) | (( gfp_t)0x200u)) & ~(( gfp_t)0x2000000u))
>>                                          ^
>>                                          |
>>                                        here
>>
>> Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
>> ---
>
> I've been meaning to chase this down for a few weeks. Worked for me.
>
> Tested-by: David Ahern <dsahern@gmail.com>

Arnaldo: have not seen this one hit your tree. Did it fall through the 
cracks?

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

* Re: [PATCH] tools lib traceevent: Add '~' operation within arg_num_eval()
  2016-03-10 16:16             ` David Ahern
@ 2016-03-10 19:28               ` Arnaldo Carvalho de Melo
  0 siblings, 0 replies; 26+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-03-10 19:28 UTC (permalink / raw)
  To: David Ahern
  Cc: Steven Rostedt, Namhyung Kim, Ingo Molnar, Peter Zijlstra,
	Jiri Olsa, LKML, Andi Kleen, Stephane Eranian, Wang Nan

Em Thu, Mar 10, 2016 at 09:16:41AM -0700, David Ahern escreveu:
> >>(( gfp_t)0x1000u) | (( gfp_t)0x200u)) & ~(( gfp_t)0x2000000u))
> >>                                         ^
> >>                                         |
> >>                                       here
> >>Signed-off-by: Steven Rostedt <rostedt@goodmis.org>

> >I've been meaning to chase this down for a few weeks. Worked for me.

> >Tested-by: David Ahern <dsahern@gmail.com>

> Arnaldo: have not seen this one hit your tree. Did it fall through the
> cracks?

Yeap, thanks for the reminder, applied.

- Arnaldo

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

* [tip:perf/core] tools lib traceevent: Add '~' operation within arg_num_eval()
  2016-02-26 23:13         ` [PATCH] tools lib traceevent: Add '~' operation within arg_num_eval() Steven Rostedt
  2016-02-26 23:39           ` Arnaldo Carvalho de Melo
  2016-02-26 23:45           ` David Ahern
@ 2016-03-11  8:47           ` tip-bot for Steven Rostedt
  2 siblings, 0 replies; 26+ messages in thread
From: tip-bot for Steven Rostedt @ 2016-03-11  8:47 UTC (permalink / raw)
  To: linux-tip-commits
  Cc: namhyung, eranian, tglx, hpa, wangnan0, andi, peterz, rostedt,
	jolsa, dsahern, mingo, linux-kernel, acme

Commit-ID:  9eb42dee2b11635174c74a7996934b6ca18f2179
Gitweb:     http://git.kernel.org/tip/9eb42dee2b11635174c74a7996934b6ca18f2179
Author:     Steven Rostedt <rostedt@goodmis.org>
AuthorDate: Fri, 26 Feb 2016 18:13:28 -0500
Committer:  Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Thu, 10 Mar 2016 16:27:41 -0300

tools lib traceevent: Add '~' operation within arg_num_eval()

When evaluating values for print flags, if the value included a '~'
operator, the parsing would fail. This broke kmalloc's parsing of:

__print_flags(REC->gfp_flags, "|", {(unsigned
long)((((((( gfp_t)(0x400000u|0x2000000u)) | (( gfp_t)0x40u) |
(( gfp_t)0x80u) | (( gfp_t)0x20000u)) | (( gfp_t)0x02u)) |
(( gfp_t)0x08u)) | (( gfp_t)0x4000u) | (( gfp_t)0x10000u) |
(( gfp_t)0x1000u) | (( gfp_t)0x200u)) & ~(( gfp_t)0x2000000u))
                                        ^
                                        |
                                      here

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
Reported-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Tested-by: David Ahern <dsahern@gmail.com>
Cc: Andi Kleen <andi@firstfloor.org>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/r/20160226181328.22f47129@gandalf.local.home
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/lib/traceevent/event-parse.c | 6 ++++++
 1 file changed, 6 insertions(+)

diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c
index 865dea5..190cc88 100644
--- a/tools/lib/traceevent/event-parse.c
+++ b/tools/lib/traceevent/event-parse.c
@@ -2398,6 +2398,12 @@ static int arg_num_eval(struct print_arg *arg, long long *val)
 				break;
 			*val = left + right;
 			break;
+		case '~':
+			ret = arg_num_eval(arg->op.right, &right);
+			if (!ret)
+				break;
+			*val = ~right;
+			break;
 		default:
 			do_warning("unknown op '%s'", arg->op.op);
 			ret = 0;

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

end of thread, other threads:[~2016-03-11  8:48 UTC | newest]

Thread overview: 26+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2016-02-26 18:52 [PATCH 1/5] perf report: Fix comparing of dynamic entries Namhyung Kim
2016-02-26 18:52 ` [PATCH 2/5] perf report: Fix indentation of dynamic entries in hierarchy Namhyung Kim
2016-02-27  9:43   ` [tip:perf/core] " tip-bot for Namhyung Kim
2016-02-26 18:52 ` [PATCH 3/5] perf report: Left align " Namhyung Kim
2016-02-27  9:43   ` [tip:perf/core] " tip-bot for Namhyung Kim
2016-02-26 18:52 ` [PATCH 4/5] perf report: Fix dynamic entry display " Namhyung Kim
2016-02-26 21:43   ` Arnaldo Carvalho de Melo
2016-02-26 21:45     ` Arnaldo Carvalho de Melo
2016-02-26 22:08       ` Arnaldo Carvalho de Melo
2016-02-26 22:24         ` Arnaldo Carvalho de Melo
2016-02-26 22:26         ` Steven Rostedt
2016-02-26 22:37           ` Arnaldo Carvalho de Melo
2016-02-26 23:12             ` Jiri Olsa
2016-02-26 23:13               ` Jiri Olsa
2016-02-26 23:13         ` [PATCH] tools lib traceevent: Add '~' operation within arg_num_eval() Steven Rostedt
2016-02-26 23:39           ` Arnaldo Carvalho de Melo
2016-02-26 23:45           ` David Ahern
2016-03-10 16:16             ` David Ahern
2016-03-10 19:28               ` Arnaldo Carvalho de Melo
2016-03-11  8:47           ` [tip:perf/core] " tip-bot for Steven Rostedt
2016-02-27  9:44   ` [tip:perf/core] perf hists: Fix dynamic entry display in hierarchy tip-bot for Namhyung Kim
2016-02-26 18:52 ` [PATCH 5/5] perf report: Update column width of dynamic entries Namhyung Kim
2016-02-26 22:43   ` Arnaldo Carvalho de Melo
2016-02-27  9:44   ` [tip:perf/core] " tip-bot for Namhyung Kim
2016-02-26 21:23 ` [PATCH 1/5] perf report: Fix comparing " Jiri Olsa
2016-02-27  9:43 ` [tip:perf/core] perf hists: " tip-bot for Namhyung Kim

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).