From patchwork Tue Aug 30 10:28:44 2016 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Binoy Jayan X-Patchwork-Id: 74967 Delivered-To: patch@linaro.org Received: by 10.140.29.52 with SMTP id a49csp2072479qga; Tue, 30 Aug 2016 03:29:34 -0700 (PDT) X-Received: by 10.66.20.41 with SMTP id k9mr4913032pae.142.1472552974184; Tue, 30 Aug 2016 03:29:34 -0700 (PDT) Return-Path: Received: from vger.kernel.org (vger.kernel.org. [209.132.180.67]) by mx.google.com with ESMTP id 185si44618310pfu.115.2016.08.30.03.29.32; Tue, 30 Aug 2016 03:29:34 -0700 (PDT) Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67; Authentication-Results: mx.google.com; dkim=pass header.i=@linaro.org; spf=pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org; dmarc=pass (p=NONE dis=NONE) header.from=linaro.org Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1758086AbcH3K3X (ORCPT + 27 others); Tue, 30 Aug 2016 06:29:23 -0400 Received: from mail-pf0-f170.google.com ([209.85.192.170]:35418 "EHLO mail-pf0-f170.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1757861AbcH3K3G (ORCPT ); Tue, 30 Aug 2016 06:29:06 -0400 Received: by mail-pf0-f170.google.com with SMTP id x72so6705383pfd.2 for ; Tue, 30 Aug 2016 03:29:05 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=linaro.org; s=google; h=from:to:cc:subject:date:message-id:in-reply-to:references; bh=lFr8cXuCsQT4gtCrS1NQ/80FBliyQr1vS5xn3AyG76s=; b=MR5iDphif/x4L/hoXVT58oaThrpvjRL4IBGkvR1NBw8ZlAH5io5UTWYbQLQpd+BVwo qspdv0S4C/qmCEebSuG7fA/oCTY8mRIeFDX8aCDbYrTaRcUOr1Lcqv5lnWX4qK8DInIN mEoyvcesZt0uRG08Z+9Q2Tb5z2p2VFKvgIRQE= X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:from:to:cc:subject:date:message-id:in-reply-to :references; bh=lFr8cXuCsQT4gtCrS1NQ/80FBliyQr1vS5xn3AyG76s=; b=ktUEUoHEW1NYqpEVXrnphTfamXXQLKHR/1hx9TBusf3OxNAyboYRfpGSM4PTdyfkrH OEUc4vvrLj8qtR5VRiTyW7reMyZeOh5SWT/EepM3eF3KNZVVhMfcldPkaxTvATOaafjf wUmx+fuowXkGUrYz+aAzb00N/boQ9EpPggUaCCldtdYl6zdKIshrDN88rA6YAVLE/NrS lQ/lB9F0jP8x4dmvRrXOKtPeb1lM4h63Ap1qOcYMe4BnLehLIEJEpelqt0kVRJ1+Z8jU R2JDRGyL0olLaRfZylBx9IbuMMudN6I0TLNPmx7TKlitAx7Zrn02onke6NbATmz3LmdO GYMQ== X-Gm-Message-State: AE9vXwOUgNjIq7St+k/gcbREkALs7yuHSdhtUjr0wES9dtg5KDjVYAAiEQlGGiccfSjaGNN1 X-Received: by 10.98.196.138 with SMTP id h10mr4938669pfk.60.1472552944602; Tue, 30 Aug 2016 03:29:04 -0700 (PDT) Received: from blr-ubuntu-59.ap.qualcomm.com ([202.46.23.61]) by smtp.gmail.com with ESMTPSA id k78sm55893307pfa.78.2016.08.30.03.29.01 (version=TLS1_1 cipher=ECDHE-RSA-AES128-SHA bits=128/128); Tue, 30 Aug 2016 03:29:04 -0700 (PDT) From: Binoy Jayan To: "Steven Rostedt (Red Hat)" Cc: Ingo Molnar , Daniel Wagner , Arnd Bergmann , linux-kernel@vger.kernel.org, Masami , Binoy Jayan Subject: [PATCH v4 3/3] tracing: Histogram for missed timer offsets Date: Tue, 30 Aug 2016 15:58:44 +0530 Message-Id: <1472552924-22297-4-git-send-email-binoy.jayan@linaro.org> X-Mailer: git-send-email 1.8.2.1 In-Reply-To: <1472552924-22297-1-git-send-email-binoy.jayan@linaro.org> References: <1472552924-22297-1-git-send-email-binoy.jayan@linaro.org> Sender: linux-kernel-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Latencies of missed timer offsets. Generate a histogram of missed timer offsets in microseconds. This will be a based along with irq and preemption latencies to calculate the effective process wakeup latencies. The following filter(s) may be used 'hist:key=common_pid.execname' 'hist:key=common_pid.execname:val=toffset,hitcount' Signed-off-by: Binoy Jayan --- include/linux/hrtimer.h | 3 +++ include/trace/events/latency.h | 29 +++++++++++++++++++++++++++++ kernel/time/hrtimer.c | 40 ++++++++++++++++++++++++++++++++++++++++ 3 files changed, 72 insertions(+) -- The Qualcomm Innovation Center, Inc. is a member of the Code Aurora Forum, a Linux Foundation Collaborative Project diff --git a/include/linux/hrtimer.h b/include/linux/hrtimer.h index 5e00f80..e09de14 100644 --- a/include/linux/hrtimer.h +++ b/include/linux/hrtimer.h @@ -104,6 +104,9 @@ struct hrtimer { struct hrtimer_clock_base *base; u8 state; u8 is_rel; +#if defined(CONFIG_PREEMPT_TRACER) || defined(CONFIG_IRQSOFF_TRACER) + ktime_t praecox; +#endif #ifdef CONFIG_TIMER_STATS int start_pid; void *start_site; diff --git a/include/trace/events/latency.h b/include/trace/events/latency.h index e89be12..7fca7cd 100644 --- a/include/trace/events/latency.h +++ b/include/trace/events/latency.h @@ -29,6 +29,35 @@ DEFINE_EVENT(latency_template, latency_preempt, TP_PROTO(int ltype, cycles_t latency), TP_ARGS(ltype, latency)); +TRACE_EVENT(latency_hrtimer_interrupt, + + TP_PROTO(long long toffset, struct task_struct *curr, + struct task_struct *task), + + TP_ARGS(toffset, curr, task), + + TP_STRUCT__entry( + __field(long long, toffset) + __array(char, ccomm, TASK_COMM_LEN) + __field(int, cprio) + __array(char, tcomm, TASK_COMM_LEN) + __field(int, tprio) + ), + + TP_fast_assign( + __entry->toffset = toffset; + memcpy(__entry->ccomm, curr->comm, TASK_COMM_LEN); + __entry->cprio = curr->prio; + memcpy(__entry->tcomm, task != NULL ? task->comm : "", + task != NULL ? TASK_COMM_LEN : 7); + __entry->tprio = task != NULL ? task->prio : -1; + ), + + TP_printk("toffset=%lld curr=%s[%d] thread=%s[%d]", + __entry->toffset, __entry->ccomm, __entry->cprio, + __entry->tcomm, __entry->tprio) +); + #endif /* _TRACE_HIST_H */ /* This part must be outside protection */ diff --git a/kernel/time/hrtimer.c b/kernel/time/hrtimer.c index 9ba7c82..f3e1d92 100644 --- a/kernel/time/hrtimer.c +++ b/kernel/time/hrtimer.c @@ -53,9 +53,12 @@ #include #include +#include #include "tick-internal.h" +static enum hrtimer_restart hrtimer_wakeup(struct hrtimer *timer); + /* * The timer bases: * @@ -960,6 +963,39 @@ static inline ktime_t hrtimer_update_lowres(struct hrtimer *timer, ktime_t tim, return tim; } +static inline void trace_latency_hrtimer_mark_ts(struct hrtimer *timer, + struct hrtimer_clock_base *new_base, + ktime_t tim) +{ +#if defined(CONFIG_PREEMPT_TRACER) || defined(CONFIG_IRQSOFF_TRACER) + if (trace_latency_hrtimer_interrupt_enabled()) { + ktime_t now = new_base->get_time(); + + if (ktime_to_ns(tim) < ktime_to_ns(now)) + timer->praecox = now; + else + timer->praecox = ktime_set(0, 0); + } +#endif +} + +static inline void trace_latency_missed_hrtimer(struct hrtimer *timer, + ktime_t basenow) +{ +#if defined(CONFIG_PREEMPT_TRACER) || defined(CONFIG_IRQSOFF_TRACER) + if (trace_latency_hrtimer_interrupt_enabled()) + trace_latency_hrtimer_interrupt( + ktime_to_ns(ktime_sub(ktime_to_ns(timer->praecox) ? + timer->praecox : hrtimer_get_expires(timer), + basenow)), + current, + timer->function == hrtimer_wakeup ? + container_of(timer, struct hrtimer_sleeper, + timer)->task : NULL); +#endif + +} + /** * hrtimer_start_range_ns - (re)start an hrtimer on the current CPU * @timer: the timer to be added @@ -992,6 +1028,8 @@ void hrtimer_start_range_ns(struct hrtimer *timer, ktime_t tim, timer_stats_hrtimer_set_start_info(timer); + trace_latency_hrtimer_mark_ts(timer, new_base, tim); + leftmost = enqueue_hrtimer(timer, new_base); if (!leftmost) goto unlock; @@ -1284,6 +1322,8 @@ static void __hrtimer_run_queues(struct hrtimer_cpu_base *cpu_base, ktime_t now) timer = container_of(node, struct hrtimer, node); + trace_latency_missed_hrtimer(timer, basenow); + /* * The immediate goal for using the softexpires is * minimizing wakeups, not running timers at the