Skip to content

Commit

Permalink
nohz: Use enum code for tick stop failure tracing message
Browse files Browse the repository at this point in the history
It makes nohz tracing more lightweight, standard and easier to parse.

Examples:

       user_loop-2904  [007] d..1   517.701126: tick_stop: success=1 dependency=NONE
       user_loop-2904  [007] dn.1   518.021181: tick_stop: success=0 dependency=SCHED
    posix_timers-6142  [007] d..1  1739.027400: tick_stop: success=0 dependency=POSIX_TIMER
       user_loop-5463  [007] dN.1  1185.931939: tick_stop: success=0 dependency=PERF_EVENTS

Suggested-by: Peter Zijlstra <peterz@infradead.org>
Reviewed-by: Chris Metcalf <cmetcalf@ezchip.com>
Cc: Christoph Lameter <cl@linux.com>
Cc: Chris Metcalf <cmetcalf@ezchip.com>
Cc: Ingo Molnar <mingo@kernel.org>
Cc: Luiz Capitulino <lcapitulino@redhat.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Rik van Riel <riel@redhat.com>
Cc: Thomas Gleixner <tglx@linutronix.de>
Cc: Viresh Kumar <viresh.kumar@linaro.org>
Signed-off-by: Frederic Weisbecker <fweisbec@gmail.com>
  • Loading branch information
Frederic Weisbecker committed Mar 2, 2016
1 parent d027d45 commit e6e6cc2
Show file tree
Hide file tree
Showing 3 changed files with 41 additions and 14 deletions.
1 change: 1 addition & 0 deletions include/linux/tick.h
Original file line number Diff line number Diff line change
Expand Up @@ -104,6 +104,7 @@ enum tick_dep_bits {
TICK_DEP_BIT_CLOCK_UNSTABLE = 3
};

#define TICK_DEP_MASK_NONE 0
#define TICK_DEP_MASK_POSIX_TIMER (1 << TICK_DEP_BIT_POSIX_TIMER)
#define TICK_DEP_MASK_PERF_EVENTS (1 << TICK_DEP_BIT_PERF_EVENTS)
#define TICK_DEP_MASK_SCHED (1 << TICK_DEP_BIT_SCHED)
Expand Down
36 changes: 31 additions & 5 deletions include/trace/events/timer.h
Original file line number Diff line number Diff line change
Expand Up @@ -328,23 +328,49 @@ TRACE_EVENT(itimer_expire,
);

#ifdef CONFIG_NO_HZ_COMMON

#define TICK_DEP_NAMES \
tick_dep_name(NONE) \
tick_dep_name(POSIX_TIMER) \
tick_dep_name(PERF_EVENTS) \
tick_dep_name(SCHED) \
tick_dep_name_end(CLOCK_UNSTABLE)

#undef tick_dep_name
#undef tick_dep_name_end

#define tick_dep_name(sdep) TRACE_DEFINE_ENUM(TICK_DEP_MASK_##sdep);
#define tick_dep_name_end(sdep) TRACE_DEFINE_ENUM(TICK_DEP_MASK_##sdep);

TICK_DEP_NAMES

#undef tick_dep_name
#undef tick_dep_name_end

#define tick_dep_name(sdep) { TICK_DEP_MASK_##sdep, #sdep },
#define tick_dep_name_end(sdep) { TICK_DEP_MASK_##sdep, #sdep }

#define show_tick_dep_name(val) \
__print_symbolic(val, TICK_DEP_NAMES)

TRACE_EVENT(tick_stop,

TP_PROTO(int success, char *error_msg),
TP_PROTO(int success, int dependency),

TP_ARGS(success, error_msg),
TP_ARGS(success, dependency),

TP_STRUCT__entry(
__field( int , success )
__string( msg, error_msg )
__field( int , dependency )
),

TP_fast_assign(
__entry->success = success;
__assign_str(msg, error_msg);
__entry->dependency = dependency;
),

TP_printk("success=%s msg=%s", __entry->success ? "yes" : "no", __get_str(msg))
TP_printk("success=%d dependency=%s", __entry->success, \
show_tick_dep_name(__entry->dependency))
);
#endif

Expand Down
18 changes: 9 additions & 9 deletions kernel/time/tick-sched.c
Original file line number Diff line number Diff line change
Expand Up @@ -163,22 +163,22 @@ static unsigned long tick_dep_mask;
static void trace_tick_dependency(unsigned long dep)
{
if (dep & TICK_DEP_MASK_POSIX_TIMER) {
trace_tick_stop(0, "posix timers running\n");
trace_tick_stop(0, TICK_DEP_MASK_POSIX_TIMER);
return;
}

if (dep & TICK_DEP_MASK_PERF_EVENTS) {
trace_tick_stop(0, "perf events running\n");
trace_tick_stop(0, TICK_DEP_MASK_PERF_EVENTS);
return;
}

if (dep & TICK_DEP_MASK_SCHED) {
trace_tick_stop(0, "more than 1 task in runqueue\n");
trace_tick_stop(0, TICK_DEP_MASK_SCHED);
return;
}

if (dep & TICK_DEP_MASK_CLOCK_UNSTABLE)
trace_tick_stop(0, "unstable sched clock\n");
trace_tick_stop(0, TICK_DEP_MASK_CLOCK_UNSTABLE);
}

static bool can_stop_full_tick(struct tick_sched *ts)
Expand Down Expand Up @@ -206,17 +206,17 @@ static bool can_stop_full_tick(struct tick_sched *ts)
}

if (!sched_can_stop_tick()) {
trace_tick_stop(0, "more than 1 task in runqueue\n");
trace_tick_stop(0, TICK_DEP_MASK_SCHED);
return false;
}

if (!posix_cpu_timers_can_stop_tick(current)) {
trace_tick_stop(0, "posix timers running\n");
trace_tick_stop(0, TICK_DEP_MASK_POSIX_TIMER);
return false;
}

if (!perf_event_can_stop_tick()) {
trace_tick_stop(0, "perf events running\n");
trace_tick_stop(0, TICK_DEP_MASK_PERF_EVENTS);
return false;
}

Expand All @@ -228,7 +228,7 @@ static bool can_stop_full_tick(struct tick_sched *ts)
* sched_clock_stable is set.
*/
if (!sched_clock_stable()) {
trace_tick_stop(0, "unstable sched clock\n");
trace_tick_stop(0, TICK_DEP_MASK_CLOCK_UNSTABLE);
/*
* Don't allow the user to think they can get
* full NO_HZ with this machine.
Expand Down Expand Up @@ -821,7 +821,7 @@ static ktime_t tick_nohz_stop_sched_tick(struct tick_sched *ts,

ts->last_tick = hrtimer_get_expires(&ts->sched_timer);
ts->tick_stopped = 1;
trace_tick_stop(1, " ");
trace_tick_stop(1, TICK_DEP_MASK_NONE);
}

/*
Expand Down

0 comments on commit e6e6cc2

Please sign in to comment.