Commit 3723908d authored by Andi Kleen's avatar Andi Kleen Committed by Arnaldo Carvalho de Melo

perf report: Support time sort key

Add a time sort key to perf report to display samples for different time
quantums separately. This allows easier analysis of workloads that
change over time, and also will allow looking at the context of samples.

% perf record ...
% perf report --sort time,overhead,symbol --time-quantum 1ms --stdio
...
     0.67%  277061.87300  [.] _dl_start
     0.50%  277061.87300  [.] f1
     0.50%  277061.87300  [.] f2
     0.33%  277061.87300  [.] main
     0.29%  277061.87300  [.] _dl_lookup_symbol_x
     0.29%  277061.87300  [.] dl_main
     0.29%  277061.87300  [.] do_lookup_x
     0.17%  277061.87300  [.] _dl_debug_initialize
     0.17%  277061.87300  [.] _dl_init_paths
     0.08%  277061.87300  [.] check_match
     0.04%  277061.87300  [.] _dl_count_modids
     1.33%  277061.87400  [.] f1
     1.33%  277061.87400  [.] f2
     1.33%  277061.87400  [.] main
     1.17%  277061.87500  [.] main
     1.08%  277061.87500  [.] f1
     1.08%  277061.87500  [.] f2
     1.00%  277061.87600  [.] main
     0.83%  277061.87600  [.] f1
     0.83%  277061.87600  [.] f2
     1.00%  277061.87700  [.] main

Committer notes:

Rename 'time' argument to hist_time() to htime to overcome this in older
distros:

  cc1: warnings being treated as errors
  util/hist.c: In function 'hist_time':
  util/hist.c:251: error: declaration of 'time' shadows a global declaration
  /usr/include/time.h:186: error: shadowed declaration is here
Signed-off-by: default avatarAndi Kleen <ak@linux.intel.com>
Acked-by: default avatarJiri Olsa <jolsa@kernel.org>
Link: http://lkml.kernel.org/r/20190311144502.15423-4-andi@firstfloor.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
parent e87e5481
...@@ -105,6 +105,8 @@ OPTIONS ...@@ -105,6 +105,8 @@ OPTIONS
guest machine guest machine
- sample: Number of sample - sample: Number of sample
- period: Raw number of event count of sample - period: Raw number of event count of sample
- time: Separate the samples by time stamp with the resolution specified by
--time-quantum (default 100ms). Specify with overhead and before it.
By default, comm, dso and symbol keys are used. By default, comm, dso and symbol keys are used.
(i.e. --sort comm,dso,symbol) (i.e. --sort comm,dso,symbol)
......
...@@ -19,6 +19,7 @@ ...@@ -19,6 +19,7 @@
#include <math.h> #include <math.h>
#include <inttypes.h> #include <inttypes.h>
#include <sys/param.h> #include <sys/param.h>
#include <linux/time64.h>
static bool hists__filter_entry_by_dso(struct hists *hists, static bool hists__filter_entry_by_dso(struct hists *hists,
struct hist_entry *he); struct hist_entry *he);
...@@ -192,6 +193,7 @@ void hists__calc_col_len(struct hists *hists, struct hist_entry *h) ...@@ -192,6 +193,7 @@ void hists__calc_col_len(struct hists *hists, struct hist_entry *h)
hists__new_col_len(hists, HISTC_MEM_LVL, 21 + 3); hists__new_col_len(hists, HISTC_MEM_LVL, 21 + 3);
hists__new_col_len(hists, HISTC_LOCAL_WEIGHT, 12); hists__new_col_len(hists, HISTC_LOCAL_WEIGHT, 12);
hists__new_col_len(hists, HISTC_GLOBAL_WEIGHT, 12); hists__new_col_len(hists, HISTC_GLOBAL_WEIGHT, 12);
hists__new_col_len(hists, HISTC_TIME, 12);
if (h->srcline) { if (h->srcline) {
len = MAX(strlen(h->srcline), strlen(sort_srcline.se_header)); len = MAX(strlen(h->srcline), strlen(sort_srcline.se_header));
...@@ -246,6 +248,14 @@ static void he_stat__add_cpumode_period(struct he_stat *he_stat, ...@@ -246,6 +248,14 @@ static void he_stat__add_cpumode_period(struct he_stat *he_stat,
} }
} }
static long hist_time(unsigned long htime)
{
unsigned long time_quantum = symbol_conf.time_quantum;
if (time_quantum)
return (htime / time_quantum) * time_quantum;
return htime;
}
static void he_stat__add_period(struct he_stat *he_stat, u64 period, static void he_stat__add_period(struct he_stat *he_stat, u64 period,
u64 weight) u64 weight)
{ {
...@@ -635,6 +645,7 @@ __hists__add_entry(struct hists *hists, ...@@ -635,6 +645,7 @@ __hists__add_entry(struct hists *hists,
.raw_data = sample->raw_data, .raw_data = sample->raw_data,
.raw_size = sample->raw_size, .raw_size = sample->raw_size,
.ops = ops, .ops = ops,
.time = hist_time(sample->time),
}, *he = hists__findnew_entry(hists, &entry, al, sample_self); }, *he = hists__findnew_entry(hists, &entry, al, sample_self);
if (!hists->has_callchains && he && he->callchain_size != 0) if (!hists->has_callchains && he && he->callchain_size != 0)
......
...@@ -31,6 +31,7 @@ enum hist_filter { ...@@ -31,6 +31,7 @@ enum hist_filter {
enum hist_column { enum hist_column {
HISTC_SYMBOL, HISTC_SYMBOL,
HISTC_TIME,
HISTC_DSO, HISTC_DSO,
HISTC_THREAD, HISTC_THREAD,
HISTC_COMM, HISTC_COMM,
......
...@@ -3,6 +3,7 @@ ...@@ -3,6 +3,7 @@
#include <inttypes.h> #include <inttypes.h>
#include <regex.h> #include <regex.h>
#include <linux/mman.h> #include <linux/mman.h>
#include <linux/time64.h>
#include "sort.h" #include "sort.h"
#include "hist.h" #include "hist.h"
#include "comm.h" #include "comm.h"
...@@ -15,6 +16,7 @@ ...@@ -15,6 +16,7 @@
#include <traceevent/event-parse.h> #include <traceevent/event-parse.h>
#include "mem-events.h" #include "mem-events.h"
#include "annotate.h" #include "annotate.h"
#include "time-utils.h"
#include <linux/kernel.h> #include <linux/kernel.h>
regex_t parent_regex; regex_t parent_regex;
...@@ -654,6 +656,42 @@ struct sort_entry sort_socket = { ...@@ -654,6 +656,42 @@ struct sort_entry sort_socket = {
.se_width_idx = HISTC_SOCKET, .se_width_idx = HISTC_SOCKET,
}; };
/* --sort time */
static int64_t
sort__time_cmp(struct hist_entry *left, struct hist_entry *right)
{
return right->time - left->time;
}
static int hist_entry__time_snprintf(struct hist_entry *he, char *bf,
size_t size, unsigned int width)
{
unsigned long secs;
unsigned long long nsecs;
char he_time[32];
nsecs = he->time;
secs = nsecs / NSEC_PER_SEC;
nsecs -= secs * NSEC_PER_SEC;
if (symbol_conf.nanosecs)
snprintf(he_time, sizeof he_time, "%5lu.%09llu: ",
secs, nsecs);
else
timestamp__scnprintf_usec(he->time, he_time,
sizeof(he_time));
return repsep_snprintf(bf, size, "%-.*s", width, he_time);
}
struct sort_entry sort_time = {
.se_header = "Time",
.se_cmp = sort__time_cmp,
.se_snprintf = hist_entry__time_snprintf,
.se_width_idx = HISTC_TIME,
};
/* --sort trace */ /* --sort trace */
static char *get_trace_output(struct hist_entry *he) static char *get_trace_output(struct hist_entry *he)
...@@ -1634,6 +1672,7 @@ static struct sort_dimension common_sort_dimensions[] = { ...@@ -1634,6 +1672,7 @@ static struct sort_dimension common_sort_dimensions[] = {
DIM(SORT_DSO_SIZE, "dso_size", sort_dso_size), DIM(SORT_DSO_SIZE, "dso_size", sort_dso_size),
DIM(SORT_CGROUP_ID, "cgroup_id", sort_cgroup_id), DIM(SORT_CGROUP_ID, "cgroup_id", sort_cgroup_id),
DIM(SORT_SYM_IPC_NULL, "ipc_null", sort_sym_ipc_null), DIM(SORT_SYM_IPC_NULL, "ipc_null", sort_sym_ipc_null),
DIM(SORT_TIME, "time", sort_time),
}; };
#undef DIM #undef DIM
......
...@@ -135,6 +135,7 @@ struct hist_entry { ...@@ -135,6 +135,7 @@ struct hist_entry {
char *srcfile; char *srcfile;
struct symbol *parent; struct symbol *parent;
struct branch_info *branch_info; struct branch_info *branch_info;
long time;
struct hists *hists; struct hists *hists;
struct mem_info *mem_info; struct mem_info *mem_info;
void *raw_data; void *raw_data;
...@@ -231,6 +232,7 @@ enum sort_type { ...@@ -231,6 +232,7 @@ enum sort_type {
SORT_DSO_SIZE, SORT_DSO_SIZE,
SORT_CGROUP_ID, SORT_CGROUP_ID,
SORT_SYM_IPC_NULL, SORT_SYM_IPC_NULL,
SORT_TIME,
/* branch stack specific sort keys */ /* branch stack specific sort keys */
__SORT_BRANCH_STACK, __SORT_BRANCH_STACK,
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment