From patchwork Fri Sep 12 11:45:34 2014 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Pawel Moll X-Patchwork-Id: 37293 Return-Path: X-Original-To: linaro@patches.linaro.org Delivered-To: linaro@patches.linaro.org Received: from mail-wg0-f69.google.com (mail-wg0-f69.google.com [74.125.82.69]) by ip-10-151-82-157.ec2.internal (Postfix) with ESMTPS id 03A35203EE for ; Fri, 12 Sep 2014 11:53:20 +0000 (UTC) Received: by mail-wg0-f69.google.com with SMTP id y10sf404640wgg.0 for ; Fri, 12 Sep 2014 04:53:20 -0700 (PDT) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:delivered-to:message-id:subject:from:to:cc:date :in-reply-to:references:mime-version:sender:precedence:list-id :x-original-sender:x-original-authentication-results:mailing-list :list-post:list-help:list-archive:list-unsubscribe:content-type :content-transfer-encoding; bh=G+p1HjQR+xDBI9ILTFvTGzM9k9Ts7I/IYWOzQ7Bljm4=; b=hD+IfXBqWXPO3vkbpW9g/70ge95fVk5/7q77+BV9ttaHP9xP4OsqPLRGqJnBKJdz/Q YfoCcRdAATXIiuXPSk3E9CTkpnfCf8XibyqrxoGDgG9lL8hkMp2ryVhY6ObrAfB2+RSN KUQpPOeNJV1fdpd5etImeWffcEVB1ztSsDrRIAWej6poOLa8yU9hHapaQ2cLtkT9UBAv tGEMcLwkWe7DEAxyKUEInLL6qqZbTdJP2BEvWRtxnxe0PAZvyBv3ITyRmzCfGyOojRWM Wa4wWmD0WvwEXtCCZA0eLJf6Tu25MJ4KmucV5NcbZ4ag4hnpnFBvffFK//0MnEghBEIF 23JA== X-Gm-Message-State: ALoCoQkxZQqbSrmSPKaWHEsafHhn0PNZ1K2gPnorlp/g2po2EX1Xkb2OP1ckluUVkd621pAZYMnb X-Received: by 10.112.141.104 with SMTP id rn8mr2126080lbb.2.1410522799799; Fri, 12 Sep 2014 04:53:19 -0700 (PDT) X-BeenThere: patchwork-forward@linaro.org Received: by 10.152.26.73 with SMTP id j9ls177072lag.29.gmail; Fri, 12 Sep 2014 04:53:19 -0700 (PDT) X-Received: by 10.112.19.70 with SMTP id c6mr8156038lbe.20.1410522799532; Fri, 12 Sep 2014 04:53:19 -0700 (PDT) Received: from mail-lb0-f179.google.com (mail-lb0-f179.google.com [209.85.217.179]) by mx.google.com with ESMTPS id m2si6086386lbp.105.2014.09.12.04.53.19 for (version=TLSv1 cipher=ECDHE-RSA-RC4-SHA bits=128/128); Fri, 12 Sep 2014 04:53:19 -0700 (PDT) Received-SPF: pass (google.com: domain of patch+caf_=patchwork-forward=linaro.org@linaro.org designates 209.85.217.179 as permitted sender) client-ip=209.85.217.179; Received: by mail-lb0-f179.google.com with SMTP id p9so723427lbv.38 for ; Fri, 12 Sep 2014 04:53:19 -0700 (PDT) X-Received: by 10.152.179.226 with SMTP id dj2mr8535185lac.40.1410522799192; Fri, 12 Sep 2014 04:53:19 -0700 (PDT) X-Forwarded-To: patchwork-forward@linaro.org X-Forwarded-For: patch@linaro.org patchwork-forward@linaro.org Delivered-To: patch@linaro.org Received: by 10.112.141.42 with SMTP id rl10csp716246lbb; Fri, 12 Sep 2014 04:53:18 -0700 (PDT) X-Received: by 10.70.93.37 with SMTP id cr5mr10233256pdb.67.1410522797627; Fri, 12 Sep 2014 04:53:17 -0700 (PDT) Received: from vger.kernel.org (vger.kernel.org. [209.132.180.67]) by mx.google.com with ESMTP id hl5si7555187pbb.20.2014.09.12.04.53.16 for ; Fri, 12 Sep 2014 04:53:17 -0700 (PDT) Received-SPF: none (google.com: linux-kernel-owner@vger.kernel.org does not designate permitted sender hosts) client-ip=209.132.180.67; Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1754300AbaILLxM (ORCPT + 27 others); Fri, 12 Sep 2014 07:53:12 -0400 Received: from foss-mx-na.foss.arm.com ([217.140.108.86]:32863 "EHLO foss-mx-na.foss.arm.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1753747AbaILLxI (ORCPT ); Fri, 12 Sep 2014 07:53:08 -0400 X-Greylist: delayed 442 seconds by postgrey-1.27 at vger.kernel.org; Fri, 12 Sep 2014 07:53:08 EDT Received: from foss-smtp-na-1.foss.arm.com (unknown [10.80.61.8]) by foss-mx-na.foss.arm.com (Postfix) with ESMTP id 08D5540D; Fri, 12 Sep 2014 06:45:40 -0500 (CDT) Received: from collaborate-mta1.arm.com (highbank-bc01-b06.austin.arm.com [10.112.81.134]) by foss-smtp-na-1.foss.arm.com (Postfix) with ESMTP id D95F25FACF; Fri, 12 Sep 2014 06:45:36 -0500 (CDT) Received: from [10.2.201.42] (hornet.cambridge.arm.com [10.2.201.42]) by collaborate-mta1.arm.com (Postfix) with ESMTP id F1BE613F626; Fri, 12 Sep 2014 06:45:34 -0500 (CDT) Message-ID: <1410522334.16936.42.camel@hornet> Subject: Re: [RFC] sched_clock: Track monotonic raw clock From: Pawel Moll To: Richard Cochran Cc: Steven Rostedt , Ingo Molnar , Peter Zijlstra , Oleg Nesterov , Andrew Morton , Mel Gorman , Andy Lutomirski , John Stultz , Stephen Boyd , Baruch Siach , Thomas Gleixner , "linux-kernel@vger.kernel.org" Date: Fri, 12 Sep 2014 12:45:34 +0100 In-Reply-To: <20140722193939.GA15507@localhost.localdomain> References: <1405705419-4194-1-git-send-email-pawel.moll@arm.com> <20140719050233.GA4408@netboy> <1406045849.25343.72.camel@hornet> <20140722193939.GA15507@localhost.localdomain> X-Mailer: Evolution 3.10.4-0ubuntu2 Mime-Version: 1.0 Sender: linux-kernel-owner@vger.kernel.org Precedence: list List-ID: X-Mailing-List: linux-kernel@vger.kernel.org X-Removed-Original-Auth: Dkim didn't pass. X-Original-Sender: pawel.moll@arm.com X-Original-Authentication-Results: mx.google.com; spf=pass (google.com: domain of patch+caf_=patchwork-forward=linaro.org@linaro.org designates 209.85.217.179 as permitted sender) smtp.mail=patch+caf_=patchwork-forward=linaro.org@linaro.org Mailing-list: list patchwork-forward@linaro.org; contact patchwork-forward+owners@linaro.org X-Google-Group-Id: 836684582541 List-Post: , List-Help: , List-Archive: List-Unsubscribe: , On Tue, 2014-07-22 at 20:39 +0100, Richard Cochran wrote: > So the only reasonable way, IMHO, is to simply provide the needed > information in the traces, and then add some user space code to find > the relationship between the perf clock and the system clock. The > great advantage of this approach is that you don't have to create a > perfect servo from day one. The time stamps can be re-analyzed at any > time after the fact. Ok, so I had yet another (already lost count ;-) look into this... I came up with a conclusion that the simplest way it can be done is to have a periodically repeated events marked with both "kernel timestamp" and "user timestamp". And a scheduler switch is such a periodic event. Moreover, it seems quite natural: a user process is scheduled in (take a snapshot of sched clock and monotonic raw at this moment, let's call them t_s_in and t_m_in), the process "generates" the "user timestamp" by clock_gettime(CLOCK_MONOTONIC_RAW, t_m_x), the process is scheduled out (again, take sched and monotonic timestamps then, t_s_out and t_m_out). The, after extracting all the t_?_? from the trace stream, a translation (we've know the monotonic raw value t_m_x, we're looking for its sched clock equivalent t_s_x) should simply get down to: t_s_x = t_s_in + ((t_m_x - t_m_1) * (t_s_out - t_s_in)) / (t_m_out - t_m_in) I quickly made an experiment, by adding a customised variant of sched_switch trace event (note: I'm *not* proposing it to be merged) 8<------------- >From ad772fca06da4774e6dd3a116ee2424a0dd3d80f Mon Sep 17 00:00:00 2001 From: Pawel Moll Date: Fri, 22 Aug 2014 15:23:13 +0100 Subject: [PATCH] trace: ched_switch event variant with raw monotonic timestamp This patch adds a variant of sched_switch trace event, adding a field for a monotonic raw timestamp. Signed-off-by: Pawel Moll --- include/trace/events/sched.h | 48 ++++++++++++++++++++++++++++++++++++++++++++ kernel/sched/core.c | 1 + 2 files changed, 49 insertions(+) diff --git a/include/trace/events/sched.h b/include/trace/events/sched.h index 0a68d5a..1429958 100644 --- a/include/trace/events/sched.h +++ b/include/trace/events/sched.h @@ -7,6 +7,7 @@ #include #include #include +#include /* * Tracepoint for calling kthread_stop, performed to end a kthread: @@ -150,6 +151,53 @@ TRACE_EVENT(sched_switch, ); /* + * Tracepoint for task switches, including raw monotonic raw clock + * timestamp, to perform user- to kernelspace time correlation + */ +TRACE_EVENT(sched_switch_raw_monotonic, + + TP_PROTO(struct task_struct *prev, + struct task_struct *next), + + TP_ARGS(prev, next), + + TP_STRUCT__entry( + __field( u64, raw_monotonic ) + __array( char, prev_comm, TASK_COMM_LEN ) + __field( pid_t, prev_pid ) + __field( int, prev_prio ) + __field( long, prev_state ) + __array( char, next_comm, TASK_COMM_LEN ) + __field( pid_t, next_pid ) + __field( int, next_prio ) + ), + + TP_fast_assign( + struct timespec now; + getrawmonotonic(&now); + __entry->raw_monotonic = timespec_to_ns(&now); + memcpy(__entry->next_comm, next->comm, TASK_COMM_LEN); + __entry->prev_pid = prev->pid; + __entry->prev_prio = prev->prio; + __entry->prev_state = __trace_sched_switch_state(prev); + memcpy(__entry->prev_comm, prev->comm, TASK_COMM_LEN); + __entry->next_pid = next->pid; + __entry->next_prio = next->prio; + ), + + TP_printk("raw_monotonic=%Lu prev_comm=%s prev_pid=%d prev_prio=%d prev_state=%s%s ==> next_comm=%s next_pid=%d next_prio=%d", + __entry->raw_monotonic, __entry->prev_comm, + __entry->prev_pid, __entry->prev_prio, + __entry->prev_state & (TASK_STATE_MAX-1) ? + __print_flags(__entry->prev_state & (TASK_STATE_MAX-1), "|", + { 1, "S"} , { 2, "D" }, { 4, "T" }, { 8, "t" }, + { 16, "Z" }, { 32, "X" }, { 64, "x" }, + { 128, "K" }, { 256, "W" }, { 512, "P" }) : "R", + __entry->prev_state & TASK_STATE_MAX ? "+" : "", + __entry->next_comm, __entry->next_pid, __entry->next_prio) +); + +/* * Tracepoint for a task being migrated: */ TRACE_EVENT(sched_migrate_task, diff --git a/kernel/sched/core.c b/kernel/sched/core.c index ec1a286..0cc7a92 100644 --- a/kernel/sched/core.c +++ b/kernel/sched/core.c @@ -2179,6 +2179,7 @@ prepare_task_switch(struct rq *rq, struct task_struct *prev, struct task_struct *next) { trace_sched_switch(prev, next); + trace_sched_switch_raw_monotonic(prev, next); sched_info_switch(rq, prev, next); perf_event_task_sched_out(prev, next); fire_sched_out_preempt_notifiers(prev, next);