perf/core improvements and fixes

Hi Ingo,

Please consider pulling,

- Arnaldo

The following changes since commit baa5a7bc5dd069bb37de9c8bdb5ea7f4e2e939e9:

Merge tag 'perf-core-for-mingo' of git://git.kernel.org/pub/scm/linux/kernel/git/acme/linux into perf/core (2015-03-24 17:22:44 +0100)

are available in the git repository at:

git://git.kernel.org/pub/scm/linux/kernel/git/acme/linux.git tags/perf-core-for-mingo

for you to fetch changes up to 7c27f78a297b54c3c2f5075cb15d33431b7f6333:

tools lib traceevent: Zero should not be considered "not found" in eval_flag() (2015-03-26 10:52:29 -0300)

----------------------------------------------------------------
perf/core improvements and fixes:

User visible:

- Show the first event with an invalid filter (David Ahern, Arnaldo Carvalho de Melo)

- Fix garbage output when intermixing syscalls from different threads in 'perf trace' (Arnaldo Carvalho de Melo)

- Fix 'perf timechart' SIBGUS error on sparc64 (David Ahern)

Infrastructure:

- Set JOBS based on CPU or processor, making it work on SPARC, where /proc/cpuinfo has "CPU", not "processor" (David Ahern)

- Zero should not be considered "not found" in libtraceevent's eval_flag() (Steven Rostedt)

----------------------------------------------------------------
Arnaldo Carvalho de Melo (2):
perf evlist: Return the first evsel with an invalid filter in apply_filters() perf trace: Fix syscall enter formatting bug

David Ahern (3):
perf timechart: Fix SIBGUS error on sparc64
perf: Bump max number of cpus to 1024 perf tools: Set JOBS based on CPU or processor

Steven Rostedt (1):
tools lib traceevent: Zero should not be considered "not found" in eval_flag()

 tools/lib/traceevent/event-parse.c | 10 +++++-----
 tools/perf/Makefile                |  2 +-
 tools/perf/builtin-record.c        |  5 +++--
 tools/perf/builtin-stat.c          |  5 +++--
 tools/perf/builtin-trace.c         |  2 +-
 tools/perf/perf.h                  |  2 +-
 tools/perf/util/evlist.c           |  6 ++++--
 tools/perf/util/evlist.h           |  2 +-
 tools/perf/util/evsel.c            |  2 +-
 9 files changed, 20 insertions(+), 16 deletions(-)

From: David Ahern <[email protected]>

perf timechart -T on sparc64 is terminating due to SIGBUS. Backtrace:

Program received signal SIGBUS, Bus error.
0x0000000000173d7c in perf_evsel__intval (evsel=<value optimized out>, sample=0x7feffffda28, name=0x289b28 "prev_state")

    at util/evsel.c:1918

1918 util/evsel.c: No such file or directory.
in util/evsel.c
Missing separate debuginfos, use: debuginfo-install audit-libs-2.3.7-1.0.1.el6.sparc64 bzip2-libs-1.0.5-7.el6_0.sparc64 elfutils-libelf-0.155-2.0.3.el6.sparc64 elfutils-libs-0.155-2.0.3.el6.sparc64 glibc-2.12-1.132.0.8.el6_5.sparc64 numactl-2.0.7-8.el6.sparc64 python-libs-2.6.6-52.0.2.el6.sparc64 slang-2.2.1-1.el6.sparc64 xz-libs-4.999.9-0.3.beta.20091007git.el6.sparc64 zlib-1.2.3-29.el6.sparc64 (gdb) bt
0 0x0000000000173d7c in perf_evsel__intval (evsel=<value optimized out>, sample=0x7feffffda28,

    name=0x289b28 "prev_state") at util/evsel.c:1918
1  0x0000000000123b94 in process_sample_sched_switch (tchart=0x7feffffe040, evsel=0x4ca850, sample=0x7feffffda28,
    backtrace=0xc39010 "") at builtin-timechart.c:627
2  0x0000000000122828 in process_sample_event (tool=0x7feffffe040, event=<value optimized out>, sample=0x7feffffda28,
    evsel=0x4ca850, machine=0x4c9c88) at builtin-timechart.c:569

Another extended load on unaligned pointer. As before fix by copying to a temporary variable using memcpy.

---
 tools/perf/util/evsel.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

index bb4eff28869e..358e5954baa8 100644
@@ -1915,7 +1915,7 @@ u64 perf_evsel__intval(struct perf_evsel *evsel, struct perf_sample *sample,
 		value = *(u32 *)ptr;
 		break;
 	case 8:
-		value = *(u64 *)ptr;
+		memcpy(&value, ptr, sizeof(u64));
 		break;
 	default:
 		return 0;

1.9.3

From: Arnaldo Carvalho de Melo <[email protected]>

Use of a bad filter currently generates the message:
Error: failed to set filter with 22 (Invalid argument)

Add the event name to make it clear to which event the filter
failed to apply:
Error: Failed to set filter "foo" on event sched:sg_lb_stats: 22: Invalid argument

To test it use something like:

 # perf record -e sched:sched_switch -e sched:*fork --filter parent_pid==1 -e sched:*wait* --filter bla usleep 1
  Error: failed to set filter "bla" on event sched:sched_stat_iowait with 22 (Invalid argument)
 #

---
 tools/perf/builtin-record.c | 5 +++--
 tools/perf/builtin-stat.c   | 5 +++--
 tools/perf/util/evlist.c    | 6 ++++--
 tools/perf/util/evlist.h    | 2 +-
 4 files changed, 11 insertions(+), 7 deletions(-)

index 5a2ff510b75b..18aad239b401 100644
@@ -161,8 +161,9 @@ try_again:
 		}
 	}
 
-	if (perf_evlist__apply_filters(evlist)) {
-		error("failed to set filter with %d (%s)\n", errno,
+	if (perf_evlist__apply_filters(evlist, &pos)) {
+		error("failed to set filter \"%s\" on event %s with %d (%s)\n",
+			pos->filter, perf_evsel__name(pos), errno,
 			strerror_r(errno, msg, sizeof(msg)));
 		rc = -1;
 		goto out;

index d4d1b77da0bd..f7b8218785f6 100644
@@ -684,8 +684,9 @@ static int __run_perf_stat(int argc, const char **argv)
 			unit_width = l;
 	}
 
-	if (perf_evlist__apply_filters(evsel_list)) {
-		error("failed to set filter with %d (%s)\n", errno,
+	if (perf_evlist__apply_filters(evsel_list, &counter)) {
+		error("failed to set filter \"%s\" on event %s with %d (%s)\n",
+			counter->filter, perf_evsel__name(counter), errno,
 			strerror_r(errno, msg, sizeof(msg)));
 		return -1;
 	}

index 8d0b62361129..82bf224bbee9 100644
@@ -1050,7 +1050,7 @@ out_delete_threads:
 	return -1;
 }
 
-int perf_evlist__apply_filters(struct perf_evlist *evlist)
+int perf_evlist__apply_filters(struct perf_evlist *evlist, struct perf_evsel **err_evsel)
 {
 	struct perf_evsel *evsel;
 	int err = 0;

@@ -1062,8 +1062,10 @@ int perf_evlist__apply_filters(struct perf_evlist *evlist)
 			continue;
 
 		err = perf_evsel__set_filter(evsel, ncpus, nthreads, evsel->filter);
-		if (err)
+		if (err) {
+			*err_evsel = evsel;
 			break;
+		}
 	}
 
 	return err;

index f07c984465f0..fb19c47b8aac 100644
@@ -152,7 +152,7 @@ static inline void perf_evlist__set_maps(struct perf_evlist *evlist,
 }
 
 int perf_evlist__create_maps(struct perf_evlist *evlist, struct target *target);
-int perf_evlist__apply_filters(struct perf_evlist *evlist);
+int perf_evlist__apply_filters(struct perf_evlist *evlist, struct perf_evsel **err_evsel);
 
 void __perf_evlist__set_leader(struct list_head *list);
 void perf_evlist__set_leader(struct perf_evlist *evlist);

1.9.3

From: David Ahern <[email protected]>

SPARC based systems currently support up to 1024 cpus (e.g. T5-8). Allow perf to work on those systems.

---
 tools/perf/perf.h | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

index 1caa70a4a9e1..c38a085a5571 100644
@@ -29,7 +29,7 @@ static inline unsigned long long rdclock(void)
 	return ts.tv_sec * 1000000000ULL + ts.tv_nsec;
 }
 
-#define MAX_NR_CPUS			256
+#define MAX_NR_CPUS			1024
 
 extern const char *input_name;
 extern bool perf_host, perf_guest;

1.9.3

From: David Ahern <[email protected]>

Number of JOBS to use is set automatically to the number of processors found in /proc/cpuinfo. SPARC uses 'CPU' lines rather than 'processor'. Update the check in perf's Makefile to work for SPARC.

---
 tools/perf/Makefile | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

index d5020aeb5626..c699dc35eef9 100644
@@ -24,7 +24,7 @@ unexport MAKEFLAGS
 # (To override it, run 'make JOBS=1' and similar.)
 #
 ifeq ($(JOBS),)
-  JOBS := $(shell grep -c ^processor /proc/cpuinfo 2>/dev/null)
+  JOBS := $(shell egrep -c '^processor|^CPU' /proc/cpuinfo 2>/dev/null)
   ifeq ($(JOBS),0)
     JOBS := 1
   endif

1.9.3

From: Arnaldo Carvalho de Melo <[email protected]>

commit e596663ebb28a068f5cca57f83285b7b293a2c83
Author: Arnaldo Carvalho de Melo <[email protected]>
Date: Fri Feb 13 13:22:21 2015 -0300

perf trace: Handle multiple threads better wrt syscalls being intermixed

Introduced a bug where it considered the number of bytes output directly to the output file when formatting the syscall entry buffer that is stored to be finally printed at syscall exit, ending up leaving garbage at the start of syscalls that appeared while another syscall was being processed, in another thread. Fix it.

Example of garbage in the output before this patch:

4280.102 ( 0.000 ms): lsmd/763 ... [continued]: select()) = 0 Timeout
4280.107 (275.250 ms): tuned/852 select(tvp: 0x7f41f7ffde50 ) ...
4280.109 ( 0.002 ms): lsmd/763 Xl�� ) = -10
4639.197 ( 0.000 ms): systemd-journa/542 ... [continued]: epoll_wait()) = 1 4639.202 (359.088 ms): lsmd/763 select(n: 6, inp: 0x7ffff21daad0, tvp: 0x7ffff21daac0) ...

 4639.207 (  0.005 ms): systemd-journa/542 Hn��                      ) = 106
 4639.221 (  0.002 ms): systemd-journa/542 uname(name: 0x7ffdbaed8e00) = 0
 4639.271 (  0.008 ms): systemd-journa/542 ftruncate(fd: 11</run/log/journal/60cd52417cf440a4a80107518bbd3c20/system.journal>, length: 50331648) = 0

---
 tools/perf/builtin-trace.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

index 001c6ae9a1b1..bcc98ce3e5b8 100644
@@ -1735,7 +1735,7 @@ static int trace__sys_enter(struct trace *trace, struct perf_evsel *evsel,
 	}
 
 	if (!trace->summary_only)
-		printed += trace__printf_interrupted_entry(trace, sample);
+		trace__printf_interrupted_entry(trace, sample);
 
 	ttrace->entry_time = sample->time;
 	msg = ttrace->entry_str;

1.9.3

From: Steven Rostedt <[email protected]>

Guilherme Cox found that:

There is, however, a potential bug if there is an item with code zero that is not the first one in the symbol list, since eval_flag(..) returns 0 when it doesn't find anything.

That is, if you have the following enums:

enum {
FOO_START = 0,
FOO_GO = 1,
FOO_END = 2
}

and then have:

__print_symbolic(foo, FOO_GO, "go", FOO_START, "start",

		        FOO_END, "end")

If none of the enums are known to pevent, then eval_flag() will return zero, and it will match it to the first item in the list, which would be FOO_GO, which is not zero.

Luckily, in most cases, the first element would be zero, and the parsing would match out of sheer luck.

---
 tools/lib/traceevent/event-parse.c | 10 +++++-----
 1 file changed, 5 insertions(+), 5 deletions(-)

index b6d11eea8a57..6d31b6419d37 100644
@@ -3615,7 +3615,7 @@ static const struct flag flags[] = {
 	{ "HRTIMER_RESTART", 1 },
 };
 
-static unsigned long long eval_flag(const char *flag)
+static long long eval_flag(const char *flag)
 {
 	int i;
 

@@ -3631,7 +3631,7 @@ static unsigned long long eval_flag(const char *flag)
 		if (strcmp(flags[i].name, flag) == 0)
 			return flags[i].value;
 
-	return 0;
+	return -1LL;
 }
 
 static void print_str_to_seq(struct trace_seq *s, const char *format,

@@ -3705,7 +3705,7 @@ static void print_str_arg(struct trace_seq *s, void *data, int size,
 	struct print_flag_sym *flag;
 	struct format_field *field;
 	struct printk_map *printk;
-	unsigned long long val, fval;
+	long long val, fval;
 	unsigned long addr;
 	char *str;
 	unsigned char *hex;

@@ -3764,11 +3764,11 @@ static void print_str_arg(struct trace_seq *s, void *data, int size,
 		print = 0;
 		for (flag = arg->flags.flags; flag; flag = flag->next) {
 			fval = eval_flag(flag->value);
-			if (!val && !fval) {
+			if (!val && fval < 0) {
 				print_str_to_seq(s, format, len_arg, flag->str);
 				break;
 			}
-			if (fval && (val & fval) == fval) {
+			if (fval > 0 && (val & fval) == fval) {
 				if (print && arg->flags.delim)
 					trace_seq_puts(s, arg->flags.delim);
 				print_str_to_seq(s, format, len_arg, flag->str);

1.9.3

Pulled, thanks a lot Arnaldo!

Btw., I still see:

config/Makefile:609: No libbabeltrace found, disables 'perf data' CTF format support, please install libbabeltrace-dev[el]/libbabeltrace-ctf-dev

this annoyance needs to be fixed ASAP, before I can send perf/core to Linus.

Ingo