From patchwork Thu Feb 9 13:59:29 2017 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Dario Faggioli X-Patchwork-Id: 9564641 Return-Path: Received: from mail.wl.linuxfoundation.org (pdx-wl-mail.web.codeaurora.org [172.30.200.125]) by pdx-korg-patchwork.web.codeaurora.org (Postfix) with ESMTP id A8C2C601C3 for ; Thu, 9 Feb 2017 14:01:55 +0000 (UTC) Received: from mail.wl.linuxfoundation.org (localhost [127.0.0.1]) by mail.wl.linuxfoundation.org (Postfix) with ESMTP id 949BD2849B for ; Thu, 9 Feb 2017 14:01:55 +0000 (UTC) Received: by mail.wl.linuxfoundation.org (Postfix, from userid 486) id 899DB284EB; Thu, 9 Feb 2017 14:01:55 +0000 (UTC) X-Spam-Checker-Version: SpamAssassin 3.3.1 (2010-03-16) on pdx-wl-mail.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-3.6 required=2.0 tests=BAYES_00,DKIM_SIGNED, RCVD_IN_DNSWL_MED,RCVD_IN_SORBS_SPAM,T_DKIM_INVALID autolearn=ham version=3.3.1 Received: from lists.xenproject.org (lists.xenproject.org [192.237.175.120]) (using TLSv1.2 with cipher AES128-GCM-SHA256 (128/128 bits)) (No client certificate requested) by mail.wl.linuxfoundation.org (Postfix) with ESMTPS id 1F2E72849B for ; Thu, 9 Feb 2017 14:01:55 +0000 (UTC) Received: from localhost ([127.0.0.1] helo=lists.xenproject.org) by lists.xenproject.org with esmtp (Exim 4.84_2) (envelope-from ) id 1cbpG2-0004IJ-TC; Thu, 09 Feb 2017 13:59:34 +0000 Received: from mail6.bemta6.messagelabs.com ([193.109.254.103]) by lists.xenproject.org with esmtp (Exim 4.84_2) (envelope-from ) id 1cbpG1-0004He-QL for xen-devel@lists.xenproject.org; Thu, 09 Feb 2017 13:59:33 +0000 Received: from [85.158.143.35] by server-3.bemta-6.messagelabs.com id A6/17-22349-5C57C985; Thu, 09 Feb 2017 13:59:33 +0000 X-Brightmail-Tracker: H4sIAAAAAAAAA+NgFmpmleJIrShJLcpLzFFi42K5GNpwSPdI6Zw IgxVdHBbft0xmcmD0OPzhCksAYxRrZl5SfkUCa8aEr4tZC6aqVcxtu8nYwLhZtouRi0NIYCaj RP/ka4wgDovAGlaJIzsfs4I4EgKXWCU6Z58GcjiBnBiJO413WSDsSomF+9eyg9hCAioSN7evY oIY9ZtR4tGlm2ANwgJ6EkeO/mCHsCMlNuy/zQRiswkYSLzZsResRkRASeLeqslAcQ4OZgF9id VfeUBMFgFVic0zrUEqeAU8JXb/Xs8MYnMKeEu8vwez1kti2d+lYOeICshJrLzcwgpRLyhxcuY TFoiJmhLrd+mDhJkF5CW2v53DPIFRZBaSqlkIVbOQVC1gZF7FqFGcWlSWWqRraKCXVJSZnlGS m5iZA+SZ6eWmFhcnpqfmJCYV6yXn525iBAY/AxDsYLy3LOAQoyQHk5Ior2zBnAghvqT8lMqMx OKM+KLSnNTiQ4wyHBxKErwfS4BygkWp6akVaZk5wDiESUtw8CiJ8F4FSfMWFyTmFmemQ6ROMd pz9HSdfsnEcWYTiDx1A0Tu2XX5JZMQS15+XqqUOC8TMPKFBEDaMkrz4IbC0sYlRlkpYV5GoDO FeApSi3IzS1DlXzGKczAqCfM+B1nOk5lXArf7FdBZTEBnXT89C+SskkSElFQDY4eQcuZPyf6M DcvmnFsQJc2XUrOlP99BV+orj8CxMFHd3onF0bul3T4o7M2fZzlzvWXn6oSSq2lCgUbCLFc2R KczqJgzpwTfyDpaH9nYtn3iSecrZ+Z875tvuWmj9puGtauvfP20M0aJ2/DFMpHZt63+SHVfjG had/tA8kZO+eXG07Oinqy9qcRSnJFoqMVcVJwIABCU2gIWAwAA X-Env-Sender: raistlin.df@gmail.com X-Msg-Ref: server-16.tower-21.messagelabs.com!1486648771!52441146!1 X-Originating-IP: [209.85.128.194] X-SpamReason: No, hits=0.0 required=7.0 tests= X-StarScan-Received: X-StarScan-Version: 9.2.3; banners=-,-,- X-VirusChecked: Checked Received: (qmail 14468 invoked from network); 9 Feb 2017 13:59:32 -0000 Received: from mail-wr0-f194.google.com (HELO mail-wr0-f194.google.com) (209.85.128.194) by server-16.tower-21.messagelabs.com with AES128-GCM-SHA256 encrypted SMTP; 9 Feb 2017 13:59:32 -0000 Received: by mail-wr0-f194.google.com with SMTP id o16so12047793wra.2 for ; Thu, 09 Feb 2017 05:59:32 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=sender:subject:from:to:cc:date:message-id:in-reply-to:references :user-agent:mime-version:content-transfer-encoding; bh=hDIM3j1n2MNpdsB0uljvfHVgV8FxKe/RKg44FNrMiuU=; b=lUZroBCNbVRL35MAI0kH6RX3Jro41pwng5jnIOFSqO9Zt+s8QG7YPKFQR80GvCWjRF 1EmPD37C1HMRJP6f8rUMTBt4SNcLn85f3US84xWXCD3XKk80NkHr4H+alxcFk1Qm/IlN KzBpo1557C1umEla/Sycr3AvVrmp0sa1g7PbJHNIYdmaRD49QdsWxln2Ta8IXfcHTANP BlDxaEcIlhKzpuoZTGt2jgQsTddMl7WV1cr0dBEgprs3RqKtQamGBfXL2hKBfjQj7gGt m+X5qAka9Wopza4Nef0qW8+ZxTDkXpO4xrraz5bGob5X1ztb/chsjifc85TxnJNEQFn1 DuwQ== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:sender:subject:from:to:cc:date:message-id :in-reply-to:references:user-agent:mime-version :content-transfer-encoding; bh=hDIM3j1n2MNpdsB0uljvfHVgV8FxKe/RKg44FNrMiuU=; b=CL33ingNwAjA6m6AFy75khMlnQQBxhmx02S0iA0gGUxz+9PQiszv69ldU6pMQPK2NF Wa6YOvbJaOf3ex288hIWObhDWHl2l2ErAOP0OmJMVWkeb6Kbk3iM28F7v37ttAhCWIpW t30Vf4eXCZOfiHdDE+V7FeHh/RZD4YlrQHxt7ykm79fc/joN6Hpw1+TAG2a4wWWFhv48 QoHRsQRyA+fAjfzOTM6vAbn6eZj4O32Jk/uKklKJpcZa+CnaQXWyN8vZXemMJsn7vTHW mb5NqWnoCiG5fYijEIgrae/QT6yVBF7Urg5+hfPdTEUCrXMv47Mlcr4jGUl33UFXieCc CwXw== X-Gm-Message-State: AMke39ndTlKgzeAUjcBhWnAja4It6ojK0QsVtYubNOfLASKK5vEKW+I/jP6zUCYhR8Gkmw== X-Received: by 10.223.163.199 with SMTP id m7mr2928658wrb.63.1486648771640; Thu, 09 Feb 2017 05:59:31 -0800 (PST) Received: from Solace.fritz.box ([80.66.223.139]) by smtp.gmail.com with ESMTPSA id m29sm18617929wrm.38.2017.02.09.05.59.29 (version=TLS1_2 cipher=ECDHE-RSA-AES128-GCM-SHA256 bits=128/128); Thu, 09 Feb 2017 05:59:30 -0800 (PST) From: Dario Faggioli To: xen-devel@lists.xenproject.org Date: Thu, 09 Feb 2017 14:59:29 +0100 Message-ID: <148664876901.595.6987450024828384400.stgit@Solace.fritz.box> In-Reply-To: <148664844741.595.10506268024432565895.stgit@Solace.fritz.box> References: <148664844741.595.10506268024432565895.stgit@Solace.fritz.box> User-Agent: StGit/0.17.1-dirty MIME-Version: 1.0 Cc: George Dunlap Subject: [Xen-devel] [PATCH v2 10/10] xen/tools: tracing: always report how long next slice will be. X-BeenThere: xen-devel@lists.xen.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: Xen developer discussion List-Unsubscribe: , List-Post: List-Help: List-Subscribe: , Errors-To: xen-devel-bounces@lists.xen.org Sender: "Xen-devel" X-Virus-Scanned: ClamAV using ClamSMTP In fact, it is quite useful a pice of information, to know how long it is the "next time slice" a vCPU has been granted. It allows one to assume (and then check) when the scheduler is supposed to run next, and other things. While this information is indeed reported when a context switch happens, it is not when the same vCPU that is running, continues to run. Fix that, with the following outcome. Before this change: csched2:schedule cpu 9, rq# 1, idle, SMT idle, tickled csched2:runq_candidate d0v3, 0 vcpus skipped, cpu 9 was tickled sched_switch prev d32767v9, run for 991.186us sched_switch next d0v3, was runnable for 2.515us, next slice 10000.0us sched_switch prev d32767v9 next d0v3 ^^^^^^^^^^^^^^^^^^^^ runstate_change d32767v9 running->runnable ... csched2:schedule cpu 2, rq# 0, busy, not tickled csched2:burn_credits d1v5, credit = 9996950, delta = 502913 csched2:runq_candidate d1v5, 0 vcpus skipped, no cpu was tickled runstate_continue d1v5 running->running ????????????? That is, in the second block, it is shown that d1v5 was already running and will continue to do so, but we have no idea for how long. OTOH, after the change: csched2:schedule cpu 1, rq# 0, busy, not tickled csched2:burn_credits d0v8, credit = 9998645, delta = 12104 csched2:runq_candidate d0v8, credit = 9998645, 0 vcpus skipped, no cpu was tickled sched_switch continue d0v8, run for 1125.820us, next slice 9998.645us runstate_continue d0v8 running->running ^^^^^^^^^^^^^^^^^^^^^ Signed-off-by: Dario Faggioli --- Cc: George Dunlap --- tools/xentrace/formats | 1 + tools/xentrace/xenalyze.c | 17 +++++++++++++++++ xen/common/schedule.c | 4 ++++ xen/include/public/trace.h | 1 + 4 files changed, 23 insertions(+) diff --git a/tools/xentrace/formats b/tools/xentrace/formats index 72c0b24..a055231 100644 --- a/tools/xentrace/formats +++ b/tools/xentrace/formats @@ -35,6 +35,7 @@ 0x0002800e CPU%(cpu)d %(tsc)d (+%(reltsc)8d) switch_infprev [ dom:vcpu = 0x%(1)04x%(2)04x, runtime = %(3)d ] 0x0002800f CPU%(cpu)d %(tsc)d (+%(reltsc)8d) switch_infnext [ new_dom:vcpu = 0x%(1)04x%(2)04x, time = %(3)d, r_time = %(4)d ] 0x00028010 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) domain_shutdown_code [ dom:vcpu = 0x%(1)04x%(2)04x, reason = 0x%(3)08x ] +0x00028011 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) switch_infcont [ dom:vcpu = 0x%(1)04x%(2)04x, runtime = %(3)d, r_time = %(4)d ] 0x00022001 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:sched_tasklet 0x00022002 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:account_start [ dom:vcpu = 0x%(1)04x%(2)04x, active = %(3)d ] diff --git a/tools/xentrace/xenalyze.c b/tools/xentrace/xenalyze.c index 2678e2a..68ffcc2 100644 --- a/tools/xentrace/xenalyze.c +++ b/tools/xentrace/xenalyze.c @@ -7528,6 +7528,23 @@ void sched_process(struct pcpu_info *p) printf("\n"); } break; + case TRC_SCHED_SWITCH_INFCONT: + if(opt.dump_all) + { + struct { + unsigned int domid, vcpuid, rsince; + int slice; + } *r = (typeof(r))ri->d; + + printf(" %s sched_switch continue d%uv%u, run for %u.%uus", + ri->dump_header, r->domid, r->vcpuid, + r->rsince / 1000, r->rsince % 1000); + if ( r->slice > 0 ) + printf(", next slice %u.%uus", r->slice / 1000, + r->slice % 1000); + printf("\n"); + } + break; case TRC_SCHED_CTL: case TRC_SCHED_S_TIMER_FN: case TRC_SCHED_T_TIMER_FN: diff --git a/xen/common/schedule.c b/xen/common/schedule.c index e4320f3..495f138 100644 --- a/xen/common/schedule.c +++ b/xen/common/schedule.c @@ -1398,6 +1398,10 @@ static void schedule(void) if ( unlikely(prev == next) ) { pcpu_schedule_unlock_irq(lock, cpu); + TRACE_4D(TRC_SCHED_SWITCH_INFCONT, + next->domain->domain_id, next->vcpu_id, + now - prev->runstate.state_entry_time, + next_slice.time); trace_continue_running(next); return continue_running(prev); } diff --git a/xen/include/public/trace.h b/xen/include/public/trace.h index 5ef9c37..7f2e891 100644 --- a/xen/include/public/trace.h +++ b/xen/include/public/trace.h @@ -115,6 +115,7 @@ #define TRC_SCHED_SWITCH_INFPREV (TRC_SCHED_VERBOSE + 14) #define TRC_SCHED_SWITCH_INFNEXT (TRC_SCHED_VERBOSE + 15) #define TRC_SCHED_SHUTDOWN_CODE (TRC_SCHED_VERBOSE + 16) +#define TRC_SCHED_SWITCH_INFCONT (TRC_SCHED_VERBOSE + 17) #define TRC_DOM0_DOM_ADD (TRC_DOM0_DOMOPS + 1) #define TRC_DOM0_DOM_REM (TRC_DOM0_DOMOPS + 2)