Skip to content

Commit e6e6cc2

Browse files
fweisbecfweisbec
committed
nohz: Use enum code for tick stop failure tracing message
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>
1 parent d027d45 commit e6e6cc2

File tree

3 files changed

+41
-14
lines changed

3 files changed

+41
-14
lines changed

‎include/linux/tick.h

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -104,6 +104,7 @@ enum tick_dep_bits {
104104
TICK_DEP_BIT_CLOCK_UNSTABLE = 3
105105
};
106106

107+
#define TICK_DEP_MASK_NONE 0
107108
#define TICK_DEP_MASK_POSIX_TIMER (1 << TICK_DEP_BIT_POSIX_TIMER)
108109
#define TICK_DEP_MASK_PERF_EVENTS (1 << TICK_DEP_BIT_PERF_EVENTS)
109110
#define TICK_DEP_MASK_SCHED (1 << TICK_DEP_BIT_SCHED)

‎include/trace/events/timer.h

Lines changed: 31 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -328,23 +328,49 @@ TRACE_EVENT(itimer_expire,
328328
);
329329

330330
#ifdef CONFIG_NO_HZ_COMMON
331+
332+
#define TICK_DEP_NAMES \
333+
tick_dep_name(NONE) \
334+
tick_dep_name(POSIX_TIMER) \
335+
tick_dep_name(PERF_EVENTS) \
336+
tick_dep_name(SCHED) \
337+
tick_dep_name_end(CLOCK_UNSTABLE)
338+
339+
#undef tick_dep_name
340+
#undef tick_dep_name_end
341+
342+
#define tick_dep_name(sdep) TRACE_DEFINE_ENUM(TICK_DEP_MASK_##sdep);
343+
#define tick_dep_name_end(sdep) TRACE_DEFINE_ENUM(TICK_DEP_MASK_##sdep);
344+
345+
TICK_DEP_NAMES
346+
347+
#undef tick_dep_name
348+
#undef tick_dep_name_end
349+
350+
#define tick_dep_name(sdep) { TICK_DEP_MASK_##sdep, #sdep },
351+
#define tick_dep_name_end(sdep) { TICK_DEP_MASK_##sdep, #sdep }
352+
353+
#define show_tick_dep_name(val) \
354+
__print_symbolic(val, TICK_DEP_NAMES)
355+
331356
TRACE_EVENT(tick_stop,
332357

333-
TP_PROTO(int success, char *error_msg),
358+
TP_PROTO(int success, int dependency),
334359

335-
TP_ARGS(success, error_msg),
360+
TP_ARGS(success, dependency),
336361

337362
TP_STRUCT__entry(
338363
__field( int , success )
339-
__string( msg, error_msg )
364+
__field( int , dependency )
340365
),
341366

342367
TP_fast_assign(
343368
__entry->success = success;
344-
__assign_str(msg, error_msg);
369+
__entry->dependency = dependency;
345370
),
346371

347-
TP_printk("success=%s msg=%s", __entry->success ? "yes" : "no", __get_str(msg))
372+
TP_printk("success=%d dependency=%s", __entry->success, \
373+
show_tick_dep_name(__entry->dependency))
348374
);
349375
#endif
350376

‎kernel/time/tick-sched.c

Lines changed: 9 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -163,22 +163,22 @@ static unsigned long tick_dep_mask;
163163
static void trace_tick_dependency(unsigned long dep)
164164
{
165165
if (dep & TICK_DEP_MASK_POSIX_TIMER) {
166-
trace_tick_stop(0, "posix timers running\n");
166+
trace_tick_stop(0, TICK_DEP_MASK_POSIX_TIMER);
167167
return;
168168
}
169169

170170
if (dep & TICK_DEP_MASK_PERF_EVENTS) {
171-
trace_tick_stop(0, "perf events running\n");
171+
trace_tick_stop(0, TICK_DEP_MASK_PERF_EVENTS);
172172
return;
173173
}
174174

175175
if (dep & TICK_DEP_MASK_SCHED) {
176-
trace_tick_stop(0, "more than 1 task in runqueue\n");
176+
trace_tick_stop(0, TICK_DEP_MASK_SCHED);
177177
return;
178178
}
179179

180180
if (dep & TICK_DEP_MASK_CLOCK_UNSTABLE)
181-
trace_tick_stop(0, "unstable sched clock\n");
181+
trace_tick_stop(0, TICK_DEP_MASK_CLOCK_UNSTABLE);
182182
}
183183

184184
static bool can_stop_full_tick(struct tick_sched *ts)
@@ -206,17 +206,17 @@ static bool can_stop_full_tick(struct tick_sched *ts)
206206
}
207207

208208
if (!sched_can_stop_tick()) {
209-
trace_tick_stop(0, "more than 1 task in runqueue\n");
209+
trace_tick_stop(0, TICK_DEP_MASK_SCHED);
210210
return false;
211211
}
212212

213213
if (!posix_cpu_timers_can_stop_tick(current)) {
214-
trace_tick_stop(0, "posix timers running\n");
214+
trace_tick_stop(0, TICK_DEP_MASK_POSIX_TIMER);
215215
return false;
216216
}
217217

218218
if (!perf_event_can_stop_tick()) {
219-
trace_tick_stop(0, "perf events running\n");
219+
trace_tick_stop(0, TICK_DEP_MASK_PERF_EVENTS);
220220
return false;
221221
}
222222

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

822822
ts->last_tick = hrtimer_get_expires(&ts->sched_timer);
823823
ts->tick_stopped = 1;
824-
trace_tick_stop(1, " ");
824+
trace_tick_stop(1, TICK_DEP_MASK_NONE);
825825
}
826826

827827
/*

0 commit comments

Comments
 (0)