From patchwork Thu Aug 18 07:09:26 2016 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Binoy Jayan X-Patchwork-Id: 74138 Delivered-To: patch@linaro.org Received: by 10.140.29.52 with SMTP id a49csp205567qga; Thu, 18 Aug 2016 00:10:11 -0700 (PDT) X-Received: by 10.98.63.1 with SMTP id m1mr1500954pfa.14.1471504207163; Thu, 18 Aug 2016 00:10:07 -0700 (PDT) Return-Path: Received: from vger.kernel.org (vger.kernel.org. [209.132.180.67]) by mx.google.com with ESMTP id w4si1032064pfk.173.2016.08.18.00.10.06; Thu, 18 Aug 2016 00:10:07 -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 S1753749AbcHRHJv (ORCPT + 27 others); Thu, 18 Aug 2016 03:09:51 -0400 Received: from mail-pf0-f169.google.com ([209.85.192.169]:33854 "EHLO mail-pf0-f169.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1753636AbcHRHJs (ORCPT ); Thu, 18 Aug 2016 03:09:48 -0400 Received: by mail-pf0-f169.google.com with SMTP id p64so4125522pfb.1 for ; Thu, 18 Aug 2016 00:09:47 -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=cCvXfpNQZaJCJkaHm7M+/WB4Gs05ZdCkaNx3GMSLa1A=; b=HMXA8jy004AMowL+/WFXQUIrQXumU67H9Cf8nqvGdhwgtZrPTiDyfTOnd2cBZp/Viu 5EIaJHlcsw3tU7OWQ5/AvViSdDDKkpmNAEDVoyTAQdpmdGUrc4iL3junEuxy/BV9eCdk Q06SUrSZVxf8FZ+XjEG4e7mGO4U6eMc6GdCFk= 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=cCvXfpNQZaJCJkaHm7M+/WB4Gs05ZdCkaNx3GMSLa1A=; b=iKYGy+TvsNYuNeQPXopbtgGPcfTllA5+QWNHPNiY9oUDKrMh7YM8W27Lq7WXWB/Ur5 0YhO0DVj9hE09Z137z3eha2BRQgC8iSvfmqHptW99q0awH/Zms/8zuX6D9/aPBD8eo6u NpFGkhJcirAIn0+qvLq4GmMO7qJ4qjBl3Q3SP9Iqa2qdExtvqVhPM2L6sy0X+kpAz6fg m9W9XHcAOR7m0aEoHEKW6QM8lRR/J5C6diiUvLofQolouHSu7HHKZl+H2wwsxt7cjwex 8vaNzOV8xOmkq1hEf7/huUeF0Y8nu93j6ZUJNPJ4io8wMf53LvpSlUZuqDJHleGYrrBC z1KA== X-Gm-Message-State: AEkoouuuGlcSYzr5EojVXbKAYwAuH8gkDQ4RaMSG0vZUhN4E5n3b4nJFBoRHGR93dPcqv3WB X-Received: by 10.98.8.13 with SMTP id c13mr1450698pfd.166.1471504187241; Thu, 18 Aug 2016 00:09:47 -0700 (PDT) Received: from blr-ubuntu-59.ap.qualcomm.com ([202.46.23.61]) by smtp.gmail.com with ESMTPSA id ra13sm1414849pac.29.2016.08.18.00.09.44 (version=TLS1_1 cipher=ECDHE-RSA-AES128-SHA bits=128/128); Thu, 18 Aug 2016 00:09:46 -0700 (PDT) From: Binoy Jayan To: Arnd Bergmann , linaro-kernel@lists.linaro.org Cc: Daniel Wagner , Carsten Emde , linux-kernel@vger.kernel.org, "Steven Rostedt (Red Hat)" , Binoy Jayan Subject: [PATCH 3/3] tracing: Histogram for missed timer offsets Date: Thu, 18 Aug 2016 12:39:26 +0530 Message-Id: <1471504166-27665-4-git-send-email-binoy.jayan@linaro.org> X-Mailer: git-send-email 1.8.2.1 In-Reply-To: <1471504166-27665-1-git-send-email-binoy.jayan@linaro.org> References: <1471504166-27665-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,cpu:val=toffset,hitcount' Signed-off-by: Binoy Jayan --- include/linux/hrtimer.h | 1 + include/trace/events/latency.h | 31 +++++++++++++++++++++++++++++++ kernel/time/hrtimer.c | 27 +++++++++++++++++++++++++++ 3 files changed, 59 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..19cb76c 100644 --- a/include/linux/hrtimer.h +++ b/include/linux/hrtimer.h @@ -104,6 +104,7 @@ struct hrtimer { struct hrtimer_clock_base *base; u8 state; u8 is_rel; + ktime_t praecox; #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 b279e2d..32317a7 100644 --- a/include/trace/events/latency.h +++ b/include/trace/events/latency.h @@ -36,6 +36,37 @@ DEFINE_EVENT(latency_template, latency_critical_timings, TP_PROTO(int cpu, cycles_t latency), TP_ARGS(cpu, latency)); +TRACE_EVENT(latency_hrtimer_interrupt, + + TP_PROTO(int cpu, long long toffset, struct task_struct *curr, + struct task_struct *task), + + TP_ARGS(cpu, toffset, curr, task), + + TP_STRUCT__entry( + __field(int, cpu) + __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->cpu = cpu; + __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("cpu=%d toffset=%lld curr=%s[%d] thread=%s[%d]", + __entry->cpu, __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..71e6fcb 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: * @@ -992,6 +995,15 @@ void hrtimer_start_range_ns(struct hrtimer *timer, ktime_t tim, timer_stats_hrtimer_set_start_info(timer); + 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); + } + leftmost = enqueue_hrtimer(timer, new_base); if (!leftmost) goto unlock; @@ -1265,6 +1277,19 @@ static void __run_hrtimer(struct hrtimer_cpu_base *cpu_base, cpu_base->running = NULL; } +static inline void trace_missed_hrtimer(struct hrtimer *timer, ktime_t basenow) +{ + if (trace_latency_hrtimer_interrupt_enabled()) + trace_latency_hrtimer_interrupt(raw_smp_processor_id(), + 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); + +} static void __hrtimer_run_queues(struct hrtimer_cpu_base *cpu_base, ktime_t now) { struct hrtimer_clock_base *base = cpu_base->clock_base; @@ -1284,6 +1309,8 @@ static void __hrtimer_run_queues(struct hrtimer_cpu_base *cpu_base, ktime_t now) timer = container_of(node, struct hrtimer, node); + trace_missed_hrtimer(timer, basenow); + /* * The immediate goal for using the softexpires is * minimizing wakeups, not running timers at the