From patchwork Tue Sep 20 13:51:56 2016 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Binoy Jayan X-Patchwork-Id: 76606 Delivered-To: patch@linaro.org Received: by 10.140.106.72 with SMTP id d66csp1498484qgf; Tue, 20 Sep 2016 06:52:29 -0700 (PDT) X-Received: by 10.98.25.133 with SMTP id 127mr1820755pfz.94.1474379549685; Tue, 20 Sep 2016 06:52:29 -0700 (PDT) Return-Path: Received: from vger.kernel.org (vger.kernel.org. [209.132.180.67]) by mx.google.com with ESMTP id w9si34420517paa.82.2016.09.20.06.52.29; Tue, 20 Sep 2016 06:52:29 -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 S1754993AbcITNwZ (ORCPT + 27 others); Tue, 20 Sep 2016 09:52:25 -0400 Received: from mail-pa0-f54.google.com ([209.85.220.54]:32949 "EHLO mail-pa0-f54.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1754922AbcITNwU (ORCPT ); Tue, 20 Sep 2016 09:52:20 -0400 Received: by mail-pa0-f54.google.com with SMTP id hm5so7416111pac.0 for ; Tue, 20 Sep 2016 06:52:19 -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=U0u3ghDjndGa7pVdqL8vF0SgylcRuD/0xrqDvjTGDSo=; b=CnukMC/h1JUqMGchiQ4wLtNWUpMDA44c9Srnmwq6Cjkm3n+u9tAvwCysG3Dz1L6FAz 0nb9YUnECBKQfiulyY1f5wl8VxBC0UJCN/5wnL+Omlj1yW+wyNI8/iHQ92mlpvf9MxCW 0ydYGSwC60mPChaD2nHobR47PisIgY590M/18= 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=U0u3ghDjndGa7pVdqL8vF0SgylcRuD/0xrqDvjTGDSo=; b=DWhoqpZCgu7XrtEtMapsdunqYdVPuC6npPzf2FQJA9sC4mIViSB8aUicWUletP5vds ygJWjIKsfYYMRf/nlCwWuz3B8pqBYKLcbGVIFnaD51LPZlB4Ozl62/2syGg8MKhvMAqI AyzGTmvkWuKtPtQzisJxPPbwxGIJfj4PigYqkmxGMyXXal92BtrCoIVfEBpGUOEwREmJ XzohsZ2ldtkomL01LLhWqLx77K2lURytUjD/5FTFA3xKjbN/S+NsTxH++bPnsiCzCvMj hPzNLjbhXpX1WNsxW5NfC0VFKecx8E5hrL//Xwom77ooiYJSUMNRl4wCYt8htLL1sxGU lSlw== X-Gm-Message-State: AE9vXwMbDYgk5qTj2+Dbq8Ui6gAXjFuiBaf/W9H2Dnqkw9kpr9eQFTc9PlI9RN3UN5hbKUQf X-Received: by 10.66.144.5 with SMTP id si5mr49651369pab.158.1474379539424; Tue, 20 Sep 2016 06:52:19 -0700 (PDT) Received: from blr-ubuntu-59.ap.qualcomm.com ([202.46.23.61]) by smtp.gmail.com with ESMTPSA id yg10sm17614008pab.8.2016.09.20.06.52.16 (version=TLS1_1 cipher=ECDHE-RSA-AES128-SHA bits=128/128); Tue, 20 Sep 2016 06:52:18 -0700 (PDT) From: Binoy Jayan To: "Steven Rostedt (Red Hat)" , Thomas Gleixner Cc: Ingo Molnar , Daniel Wagner , Arnd Bergmann , linux-kernel@vger.kernel.org, Masami , Mark Brown , Binoy Jayan , Carsten Emde Subject: [RFC PATCH v7 4/5] tracing: Measure delayed hrtimer offset latency Date: Tue, 20 Sep 2016 19:21:56 +0530 Message-Id: <1474379517-7705-5-git-send-email-binoy.jayan@linaro.org> X-Mailer: git-send-email 1.8.2.1 In-Reply-To: <1474379517-7705-1-git-send-email-binoy.jayan@linaro.org> References: <1474379517-7705-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 Measure latencies caused due to delayed timer offsets in nanoseconds. It shows the latency captured due to a delayed timer expire event. It happens for example when a timer misses its deadline due to disabled interrupts. A process if scheduled as a result of the timer expiration suffers this latency. It is used to calculate the total wakeup latency of a process which is the sum of the delayed timer offset and the wakeup latency. [ Initial work and idea by Carsten Link: https://git.kernel.org/cgit/linux/kernel/git/rt/linux-stable-rt.git/commit/?h=v3.14-rt-rebase&id=56d50cc34943bbba12b8c5942ee1ae3b29f73acb ] Cc: Carsten Emde Signed-off-by: Binoy Jayan --- include/linux/hrtimer.h | 4 ++++ include/linux/sched.h | 3 +++ kernel/time/Kconfig | 8 ++++++++ kernel/time/hrtimer.c | 47 +++++++++++++++++++++++++++++++++++++++++++++++ 4 files changed, 62 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..05d8086 100644 --- a/include/linux/hrtimer.h +++ b/include/linux/hrtimer.h @@ -90,6 +90,7 @@ enum hrtimer_restart { * @is_rel: Set if the timer was armed relative * @start_pid: timer statistics field to store the pid of the task which * started the timer + * @tim_expiry: hrtimer expiry time or 0 in case already expired * @start_site: timer statistics field to store the site where the timer * was started * @start_comm: timer statistics field to store the name of the process which @@ -104,6 +105,9 @@ struct hrtimer { struct hrtimer_clock_base *base; u8 state; u8 is_rel; +#ifdef CONFIG_TRACE_DELAYED_TIMER_OFFSETS + ktime_t tim_expiry; +#endif #ifdef CONFIG_TIMER_STATS int start_pid; void *start_site; diff --git a/include/linux/sched.h b/include/linux/sched.h index 62c68e5..7bf67f8 100644 --- a/include/linux/sched.h +++ b/include/linux/sched.h @@ -1891,6 +1891,9 @@ struct task_struct { /* bitmask and counter of trace recursion */ unsigned long trace_recursion; #endif /* CONFIG_TRACING */ +#ifdef CONFIG_TRACE_DELAYED_TIMER_OFFSETS + long timer_offset; +#endif /* CONFIG_TRACE_DELAYED_TIMER_OFFSETS */ #ifdef CONFIG_KCOV /* Coverage collection mode enabled for this task (0 if disabled). */ enum kcov_mode kcov_mode; diff --git a/kernel/time/Kconfig b/kernel/time/Kconfig index 4008d9f..de4793c 100644 --- a/kernel/time/Kconfig +++ b/kernel/time/Kconfig @@ -193,5 +193,13 @@ config HIGH_RES_TIMERS hardware is not capable then this option only increases the size of the kernel image. +config TRACE_DELAYED_TIMER_OFFSETS + depends on HIGH_RES_TIMERS + select GENERIC_TRACER + bool "Delayed Timer Offsets" + help + Capture offsets of delayed hrtimer in nanoseconds. It is used + to construct wakeup latency histogram. + endmenu endif diff --git a/kernel/time/hrtimer.c b/kernel/time/hrtimer.c index 9ba7c82..7048f86 100644 --- a/kernel/time/hrtimer.c +++ b/kernel/time/hrtimer.c @@ -56,6 +56,8 @@ #include "tick-internal.h" +static enum hrtimer_restart hrtimer_wakeup(struct hrtimer *timer); + /* * The timer bases: * @@ -960,6 +962,47 @@ static inline ktime_t hrtimer_update_lowres(struct hrtimer *timer, ktime_t tim, return tim; } +#ifdef CONFIG_TRACE_DELAYED_TIMER_OFFSETS +static inline void latency_hrtimer_timing_start(struct hrtimer *timer, + struct hrtimer_clock_base *new_base, + ktime_t tim) +{ + ktime_t now = new_base->get_time(); + + if (ktime_to_ns(tim) < ktime_to_ns(now)) + timer->tim_expiry = now; + else + timer->tim_expiry = ktime_set(0, 0); +} + +static inline void latency_hrtimer_timing_stop(struct hrtimer *timer, + ktime_t basenow) +{ + long latency; + struct task_struct *task; + + latency = ktime_to_ns(ktime_sub(basenow, + ktime_to_ns(timer->tim_expiry) ? + timer->tim_expiry : hrtimer_get_expires(timer))); + task = timer->function == hrtimer_wakeup ? + container_of(timer, struct hrtimer_sleeper, + timer)->task : NULL; + if (task && latency > 0) + task->timer_offset = latency; +} +#else +static inline void latency_hrtimer_timing_start(struct hrtimer *timer, + struct hrtimer_clock_base *new_base, + ktime_t tim) +{ +} +static inline void latency_hrtimer_timing_stop(struct hrtimer *timer, + ktime_t basenow) +{ +} + +#endif + /** * hrtimer_start_range_ns - (re)start an hrtimer on the current CPU * @timer: the timer to be added @@ -992,6 +1035,8 @@ void hrtimer_start_range_ns(struct hrtimer *timer, ktime_t tim, timer_stats_hrtimer_set_start_info(timer); + latency_hrtimer_timing_start(timer, new_base, tim); + leftmost = enqueue_hrtimer(timer, new_base); if (!leftmost) goto unlock; @@ -1284,6 +1329,8 @@ static void __hrtimer_run_queues(struct hrtimer_cpu_base *cpu_base, ktime_t now) timer = container_of(node, struct hrtimer, node); + latency_hrtimer_timing_stop(timer, basenow); + /* * The immediate goal for using the softexpires is * minimizing wakeups, not running timers at the