diff --git a/cmds/tui.c b/cmds/tui.c index 7b02444ae..f2039a460 100644 --- a/cmds/tui.c +++ b/cmds/tui.c @@ -182,11 +182,12 @@ static const char *graph_field_names[NUM_GRAPH_FIELD] = { "ADDRESS", }; -#define NUM_REPORT_FIELD 12 +#define NUM_REPORT_FIELD 16 static const char *report_field_names[NUM_REPORT_FIELD] = { - "TOTAL TIME", "TOTAL AVG", "TOTAL MIN", "TOTAL MAX", "SELF TIME", "SELF AVG", - "SELF MIN", "SELF MAX", "CALL", "SIZE", "TOTAL STDV", "SELF STDV", + "TOTAL TIME", "TOTAL AVG", "TOTAL MIN", "TOTAL MAX", "SELF TIME", "SELF AVG", + "SELF MIN", "SELF MAX", "CALL", "SIZE", "TOTAL STDV", "SELF STDV", + "TOTAL MIN TS", "TOTAL MAX TS", "SELF MIN TS", "SELF MAX TS", }; static const char *field_help[] = { @@ -354,6 +355,17 @@ static void print_report_##_func(struct field_data *fd) } \ REPORT_FIELD_STRUCT(_id, _name, _func, _header, 10) +#define REPORT_FIELD_TIMESTAMP(_id, _name, _field, _func, _header) \ + static void print_report_##_func(struct field_data *fd) \ + { \ + struct uftrace_report_node *node = fd->arg; \ + uint64_t timestamp = node->_field; \ + uint64_t sec = timestamp / NSEC_PER_SEC; \ + uint64_t nsec = timestamp % NSEC_PER_SEC; \ + printw("%8lu.%09lu", sec, nsec); \ + } \ + REPORT_FIELD_STRUCT(_id, _name, _func, _header, 18) + #define REPORT_FIELD_PERCENTAGE(_id, _name, _field, _func, _header) \ static void print_report_##_func(struct field_data *fd) \ { \ @@ -375,10 +387,14 @@ REPORT_FIELD_TIME(REPORT_F_TOTAL_TIME, total, total.sum, total, "TOTAL TIME"); REPORT_FIELD_TIME(REPORT_F_TOTAL_TIME_AVG, total-avg, total.avg, total_avg, "TOTAL AVG"); REPORT_FIELD_TIME(REPORT_F_TOTAL_TIME_MIN, total-min, total.min, total_min, "TOTAL MIN"); REPORT_FIELD_TIME(REPORT_F_TOTAL_TIME_MAX, total-max, total.max, total_max, "TOTAL MAX"); +REPORT_FIELD_TIMESTAMP(REPORT_F_TOTAL_TIME_MIN_TS, total-min-ts, total.min_ts, total_min_ts, "TOTAL MIN TS"); +REPORT_FIELD_TIMESTAMP(REPORT_F_TOTAL_TIME_MAX_TS, total-max-ts, total.max_ts, total_max_ts, "TOTAL MAX TS"); REPORT_FIELD_TIME(REPORT_F_SELF_TIME, self, self.sum, self, "SELF TIME"); REPORT_FIELD_TIME(REPORT_F_SELF_TIME_AVG, self-avg, self.avg, self_avg, "SELF AVG"); REPORT_FIELD_TIME(REPORT_F_SELF_TIME_MIN, self-min, self.min, self_min, "SELF MIN"); REPORT_FIELD_TIME(REPORT_F_SELF_TIME_MAX, self-max, self.max, self_max, "SELF MAX"); +REPORT_FIELD_TIMESTAMP(REPORT_F_SELF_TIME_MIN_TS, self-min-ts, self.min_ts, self_min_ts, "SELF MIN TS"); +REPORT_FIELD_TIMESTAMP(REPORT_F_SELF_TIME_MAX_TS, self-max-ts, self.max_ts, self_max_ts, "SELF MAX TS"); REPORT_FIELD_UINT(REPORT_F_CALL, call, call, call, "CALL"); REPORT_FIELD_UINT(REPORT_F_SIZE, size, size, size, "SIZE"); REPORT_FIELD_PERCENTAGE(REPORT_F_TOTAL_TIME_STDV, total-stdv, total.stdv, total_stdv, "TOTAL STDV"); @@ -387,10 +403,12 @@ REPORT_FIELD_PERCENTAGE(REPORT_F_SELF_TIME_STDV, self-stdv, self.stdv, self_stdv /* clang-format on */ static struct display_field *report_field_table[] = { - &report_field_total, &report_field_total_avg, &report_field_total_min, - &report_field_total_max, &report_field_self, &report_field_self_avg, - &report_field_self_min, &report_field_self_max, &report_field_call, - &report_field_size, &report_field_total_stdv, &report_field_self_stdv, + &report_field_total, &report_field_total_avg, &report_field_total_min, + &report_field_total_max, &report_field_self, &report_field_self_avg, + &report_field_self_min, &report_field_self_max, &report_field_call, + &report_field_size, &report_field_total_stdv, &report_field_self_stdv, + &report_field_total_min_ts, &report_field_total_max_ts, &report_field_self_min_ts, + &report_field_self_max_ts, }; static void setup_default_graph_field(struct list_head *fields, struct uftrace_opts *opts, diff --git a/utils/debug.c b/utils/debug.c index ddd31092f..0b0d4f54a 100644 --- a/utils/debug.c +++ b/utils/debug.c @@ -384,6 +384,14 @@ void print_time_unit(uint64_t delta_nsec) __print_time_unit(delta_nsec, false); } +void print_timestamp_unit(uint64_t timestamp) +{ + uint64_t sec = timestamp / NSEC_PER_SEC; + uint64_t nsec = timestamp % NSEC_PER_SEC; + + pr_out("%8" PRIu64 ".%09" PRIu64, sec, nsec); +} + void print_diff_percent(uint64_t base_nsec, uint64_t pair_nsec) { double percent; diff --git a/utils/field.h b/utils/field.h index 4a391f1a4..89db18bb3 100644 --- a/utils/field.h +++ b/utils/field.h @@ -52,6 +52,11 @@ enum display_field_id { REPORT_F_TOTAL_TIME_STDV, REPORT_F_SELF_TIME_STDV, + REPORT_F_TOTAL_TIME_MIN_TS, + REPORT_F_TOTAL_TIME_MAX_TS, + REPORT_F_SELF_TIME_MIN_TS, + REPORT_F_SELF_TIME_MAX_TS, + REPORT_F_TASK_TOTAL_TIME = 0, REPORT_F_TASK_SELF_TIME, REPORT_F_TASK_TID, diff --git a/utils/report.c b/utils/report.c index cb6026775..1bea5c75b 100644 --- a/utils/report.c +++ b/utils/report.c @@ -14,7 +14,8 @@ static void init_time_stat(struct report_time_stat *ts) ts->min = -1ULL; } -static void update_time_stat(struct report_time_stat *ts, uint64_t time_ns, bool recursive) +static void update_time_stat(struct report_time_stat *ts, uint64_t time_ns, uint64_t timestamp, + bool recursive) { if (recursive) { ts->rec += time_ns; @@ -25,10 +26,14 @@ static void update_time_stat(struct report_time_stat *ts, uint64_t time_ns, bool ts->sum_sq += time_ns * time_ns; } - if (ts->min > time_ns) + if (ts->min > time_ns) { ts->min = time_ns; - if (ts->max < time_ns) + ts->min_ts = timestamp; + } + if (ts->max < time_ns) { ts->max = time_ns; + ts->max_ts = timestamp; + } } static void finish_time_stat(struct report_time_stat *ts, unsigned long call) @@ -98,6 +103,7 @@ void report_update_node(struct uftrace_report_node *node, struct uftrace_task_re struct uftrace_fstack *fstack; uint64_t total_time; uint64_t self_time; + uint64_t timestamp; bool recursive = false; int i; @@ -118,9 +124,10 @@ void report_update_node(struct uftrace_report_node *node, struct uftrace_task_re total_time = fstack->total_time; self_time = fstack->total_time - fstack->child_time; + timestamp = task->rstack->time - total_time; - update_time_stat(&node->total, total_time, recursive); - update_time_stat(&node->self, self_time, false); + update_time_stat(&node->total, total_time, timestamp, recursive); + update_time_stat(&node->self, self_time, timestamp, false); node->call++; node->loc = loc; if (task->func != NULL) @@ -769,6 +776,14 @@ void report_sort_tasks(struct uftrace_data *handle, struct rb_root *name_root, } \ FIELD_STRUCT(_id, _name, _func, _header, 10) +#define FIELD_TIMESTAMP(_id, _name, _field, _func, _header) \ + static void print_##_func(struct field_data *fd) \ + { \ + struct uftrace_report_node *node = fd->arg; \ + print_timestamp_unit(node->_field); \ + } \ + FIELD_STRUCT(_id, _name, _func, _header, 18) + #define FIELD_UINT(_id, _name, _field, _func, _header) \ static void print_##_func(struct field_data *fd) \ { \ @@ -869,10 +884,14 @@ FIELD_TIME(REPORT_F_TOTAL_TIME, total, total.sum, total, "Total time"); FIELD_TIME(REPORT_F_TOTAL_TIME_AVG, total-avg, total.avg, total_avg, "Total avg"); FIELD_TIME(REPORT_F_TOTAL_TIME_MIN, total-min, total.min, total_min, "Total min"); FIELD_TIME(REPORT_F_TOTAL_TIME_MAX, total-max, total.max, total_max, "Total max"); +FIELD_TIMESTAMP(REPORT_F_TOTAL_TIME_MIN_TS, total-min-ts, total.min_ts, total_min_ts, "Total min ts"); +FIELD_TIMESTAMP(REPORT_F_TOTAL_TIME_MAX_TS, total-max-ts, total.max_ts, total_max_ts, "Total max ts"); FIELD_TIME(REPORT_F_SELF_TIME, self, self.sum, self, "Self time"); FIELD_TIME(REPORT_F_SELF_TIME_AVG, self-avg, self.avg, self_avg, "Self avg"); FIELD_TIME(REPORT_F_SELF_TIME_MIN, self-min, self.min, self_min, "Self min"); FIELD_TIME(REPORT_F_SELF_TIME_MAX, self-max, self.max, self_max, "Self max"); +FIELD_TIMESTAMP(REPORT_F_SELF_TIME_MIN_TS, self-min-ts, self.min_ts, self_min_ts, "Self min ts"); +FIELD_TIMESTAMP(REPORT_F_SELF_TIME_MAX_TS, self-max-ts, self.max_ts, self_max_ts, "Self max ts"); FIELD_UINT(REPORT_F_CALL, call, call, call, "Calls"); FIELD_UINT(REPORT_F_SIZE, size, size, size, "Size"); FIELD_PERCENTAGE(REPORT_F_TOTAL_TIME_STDV, total-stdv, total.stdv, total_stdv, "Total stdv"); @@ -919,9 +938,10 @@ FIELD_UINT(REPORT_F_TASK_NR_FUNC, func, call, task_nr_func, "Num funcs"); /* index of this table should be matched to display_field_id */ static struct display_field *field_table[] = { - &field_total, &field_total_avg, &field_total_min, &field_total_max, - &field_self, &field_self_avg, &field_self_min, &field_self_max, - &field_call, &field_size, &field_total_stdv, &field_self_stdv, + &field_total, &field_total_avg, &field_total_min, &field_total_max, + &field_self, &field_self_avg, &field_self_min, &field_self_max, + &field_call, &field_size, &field_total_stdv, &field_self_stdv, + &field_total_min_ts, &field_total_max_ts, &field_self_min_ts, &field_self_max_ts, }; /* index of this table should be matched to display_field_id */ diff --git a/utils/report.h b/utils/report.h index c46acb016..c5f8ecf25 100644 --- a/utils/report.h +++ b/utils/report.h @@ -23,6 +23,8 @@ struct report_time_stat { double stdv; uint64_t min; uint64_t max; + uint64_t min_ts; + uint64_t max_ts; }; struct uftrace_report_node { diff --git a/utils/utils.h b/utils/utils.h index 20b2551cc..b526b6ef7 100644 --- a/utils/utils.h +++ b/utils/utils.h @@ -363,6 +363,7 @@ extern clockid_t clock_source; void setup_clock_id(const char *clock_str); void print_time_unit(uint64_t delta_nsec); +void print_timestamp_unit(uint64_t timestamp); void print_diff_percent(uint64_t base_nsec, uint64_t delta_nsec); void print_diff_time_unit(uint64_t base_nsec, uint64_t pair_nsec); void print_diff_count(uint64_t base, uint64_t pair);