perf tools: Add debug prints for ordered events queue
Adding some prints for ordered events queue, to help debug issues.
Adding debug_ordered_events debug variable to be able to enable ordered
events debug messages using:
$ perf --debug ordered-events=2 report ...
Also using oe pointer in perf_session__queue_event instead of chained
session variable dereferencing.
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
Acked-by: David Ahern <dsahern@gmail.com>
Cc: Corey Ashford <cjashfor@linux.vnet.ibm.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@kernel.org>
Cc: Jean Pihet <jean.pihet@linaro.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Link: http://lkml.kernel.org/n/tip-7p3mnnopjvsp9nmk9msqcfkm@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
diff --git a/tools/perf/util/ordered-events.c b/tools/perf/util/ordered-events.c
index 381d5fe..8a8aeab 100644
--- a/tools/perf/util/ordered-events.c
+++ b/tools/perf/util/ordered-events.c
@@ -1,10 +1,16 @@
#include <linux/list.h>
+#include <linux/compiler.h>
#include "ordered-events.h"
#include "evlist.h"
#include "session.h"
#include "asm/bug.h"
#include "debug.h"
+#define pr_N(n, fmt, ...) \
+ eprintf(n, debug_ordered_events, fmt, ##__VA_ARGS__)
+
+#define pr(fmt, ...) pr_N(1, pr_fmt(fmt), ##__VA_ARGS__)
+
static void queue_event(struct ordered_events *oe, struct ordered_event *new)
{
struct ordered_event *last = oe->last;
@@ -14,6 +20,8 @@
++oe->nr_events;
oe->last = new;
+ pr_oe_time2(timestamp, "queue_event nr_events %u\n", oe->nr_events);
+
if (!last) {
list_add(&new->list, &oe->events);
oe->max_timestamp = timestamp;
@@ -69,12 +77,17 @@
if (!oe->buffer)
return NULL;
+ pr("alloc size %" PRIu64 "B (+%zu), max %" PRIu64 "B\n",
+ oe->cur_alloc_size, size, oe->max_alloc_size);
+
oe->cur_alloc_size += size;
list_add(&oe->buffer->list, &oe->to_free);
/* First entry is abused to maintain the to_free list. */
oe->buffer_idx = 2;
new = oe->buffer + 1;
+ } else {
+ pr("allocation limit reached %" PRIu64 "B\n", oe->max_alloc_size);
}
return new;
@@ -155,6 +168,11 @@
enum oe_flush how)
{
struct ordered_events *oe = &s->ordered_events;
+ static const char * const str[] = {
+ "FINAL",
+ "ROUND",
+ "HALF ",
+ };
int err;
switch (how) {
@@ -184,6 +202,10 @@
break;
};
+ pr_oe_time(oe->next_flush, "next_flush - ordered_events__flush PRE %s, nr_events %u\n",
+ str[how], oe->nr_events);
+ pr_oe_time(oe->max_timestamp, "max_timestamp\n");
+
err = __ordered_events__flush(s, tool);
if (!err) {
@@ -191,6 +213,10 @@
oe->next_flush = oe->max_timestamp;
}
+ pr_oe_time(oe->next_flush, "next_flush - ordered_events__flush POST %s, nr_events %u\n",
+ str[how], oe->nr_events);
+ pr_oe_time(oe->last_flush, "last_flush\n");
+
return err;
}