From patchwork Thu Jan 26 00:30:50 2017 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Dario Faggioli X-Patchwork-Id: 9538207 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 3D05E604A7 for ; Thu, 26 Jan 2017 00:32:52 +0000 (UTC) Received: from mail.wl.linuxfoundation.org (localhost [127.0.0.1]) by mail.wl.linuxfoundation.org (Postfix) with ESMTP id 2FC3326B39 for ; Thu, 26 Jan 2017 00:32:52 +0000 (UTC) Received: by mail.wl.linuxfoundation.org (Postfix, from userid 486) id 24AB327F85; Thu, 26 Jan 2017 00:32:52 +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 B49AD26B39 for ; Thu, 26 Jan 2017 00:32:51 +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 1cWXxn-0006BK-Qg; Thu, 26 Jan 2017 00:30:55 +0000 Received: from mail6.bemta6.messagelabs.com ([193.109.254.103]) by lists.xenproject.org with esmtp (Exim 4.84_2) (envelope-from ) id 1cWXxm-00069x-5n for xen-devel@lists.xenproject.org; Thu, 26 Jan 2017 00:30:54 +0000 Received: from [193.109.254.147] by server-2.bemta-6.messagelabs.com id 65/11-22326-D3349885; Thu, 26 Jan 2017 00:30:53 +0000 X-Brightmail-Tracker: H4sIAAAAAAAAA+NgFvrJIsWRWlGSWpSXmKPExsXiVRvkqGvj3Bl h0P5I1eL7lslMDowehz9cYQlgjGLNzEvKr0hgzVj37RR7wVS1it17O5gbGDfLdjFycggJzGSU mLlHqouRi4NFYA2rxL5Hh1hBHAmBS6wS0xqnsXQxcgA5MRILljmDNEgIlEmcfX+OHaJZReLm9 lVMIPVCAtOZJPad28IGkhAW0JM4cvQHO0ivsECIxOa9JiBhNgEDiTc79rKC2CICShL3Vk1mAi lhFtCXWP2VByTMIqAq8WrZF7ApvAJeEp/ergGzOQW8JWZM/gBWLgQUn3YgByQsKiAnsfJyCyt EuaDEyZlPWCAmakqs36UPEmYWkJfY/nYO8wRGkVlIqmYhVM1CUrWAkXkVo3pxalFZapGuqV5S UWZ6RkluYmaOrqGBmV5uanFxYnpqTmJSsV5yfu4mRmDQMwDBDsbpl/0PMUpyMCmJ8t7U7owQ4 kvKT6nMSCzOiC8qzUktPsQow8GhJMFr4wSUEyxKTU+tSMvMAcYfTFqCg0dJhNcTJM1bXJCYW5 yZDpE6xWjJcWbT6ZdMHKdugMhduy6/ZBJiycvPS5US57UDaRAAacgozYMbB0sRlxhlpYR5GYE OFOIpSC3KzSxBlX/FKM7BqCTMywMyhSczrwRu6yugg5iADrrA3A5yUEkiQkqqgbG05q12keaP kIUf9ZXtn1xyY4m7mFnUc/hQlHDomynuIu/ENn9o+xy9aHu4zpsXfuKNx68F+7NOuXBs7zo/l jsRO9s8rDhnnWM+sF2LP95n9RW3Qs+q+mcZbJZb+9czb3jXeFc7tVj7O+vVpPrnr08eL0jhm3 jLyOSfin7hWcm05UdVrUPOTlBiKc5INNRiLipOBAAskXwYDAMAAA== X-Env-Sender: raistlin.df@gmail.com X-Msg-Ref: server-15.tower-27.messagelabs.com!1485390652!30913428!1 X-Originating-IP: [74.125.82.65] X-SpamReason: No, hits=0.0 required=7.0 tests= X-StarScan-Received: X-StarScan-Version: 9.1.1; banners=-,-,- X-VirusChecked: Checked Received: (qmail 20524 invoked from network); 26 Jan 2017 00:30:52 -0000 Received: from mail-wm0-f65.google.com (HELO mail-wm0-f65.google.com) (74.125.82.65) by server-15.tower-27.messagelabs.com with AES128-GCM-SHA256 encrypted SMTP; 26 Jan 2017 00:30:52 -0000 Received: by mail-wm0-f65.google.com with SMTP id r126so46455070wmr.3 for ; Wed, 25 Jan 2017 16:30:52 -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=TxudjHAMaeiYiuaVO6gUv9jXi/HqGl4orP6rUb/v+rI=; b=cwkYrAInxPRNzY8UvEQnk/SR+ElcJEAuwhHEhj84R/PwK8k1Y7l3fEzYztPd0lEkO1 /JwuPoATQW0buLyTkQ++Cmkmt3mb3svnFNA2PvKRo1+WQsMO64DtwqjvrQMoOiYC59XN nfH3XcJvYmHFDwaVybRFSOiiZGO50XbR3NzW/I4eLxJQyImKYiO8j4dKZXZ9hPTKw/xL 4nQ7SYRc1MUO8elxBvqJxwi5TpQf8jcEGPjAclJO0wwdm89bkMN8unS+SVwOiTTpEwn3 SJCV+KxT+C9gU/J70Bi2hLZtvpksnVJNfyA1Z8USEC8UfINtyBkxQsN7TPEJzM0iv9Ed ppcg== 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=TxudjHAMaeiYiuaVO6gUv9jXi/HqGl4orP6rUb/v+rI=; b=LCM4mHIil6pTg9ctxiPEcVKL9qOB6k8GiZ8EXSfJe79543IPRhTpjZAI55sikpc02a mXTX44tr8ldB4PJeP7GJ81POT0uC0A6YAvW93G1TJHnR2IwhWb6Wr+S23qR2y9TQAKy3 KhR3ZGxL+pLY7aMBJKzQEn7qVLJvQwPTrkgNZucyZPnZCf5hASwKNCfhFzEbKexhkkxY Ys2ueox2rKg9vUwGGfcGbZvz1eHb9CE4GuVJaz8E0W2r8NHMRem84Y2I0/cx3IKJAwhq /l/GgjTC1Cjt8zKCVIA5YwDuOfdp95xeANIFQEodk25+ko+V7bnYDKcILSC7yXc1C67t g4rQ== X-Gm-Message-State: AIkVDXLtBW2MQ/v3s78FEjlHXuf6peYqBjkkEGHFeHv0GEfJNU/dEKyhcnHIFf2C8j2ifA== X-Received: by 10.28.68.6 with SMTP id r6mr23613214wma.57.1485390652109; Wed, 25 Jan 2017 16:30:52 -0800 (PST) Received: from Solace.fritz.box (58-209-66-80.hosts.abilene.it. [80.66.209.58]) by smtp.gmail.com with ESMTPSA id p7sm27245620wrc.2.2017.01.25.16.30.51 (version=TLS1_2 cipher=ECDHE-RSA-AES128-GCM-SHA256 bits=128/128); Wed, 25 Jan 2017 16:30:51 -0800 (PST) From: Dario Faggioli To: xen-devel@lists.xenproject.org Date: Thu, 26 Jan 2017 01:30:50 +0100 Message-ID: <148539065044.5464.1696740509977853174.stgit@Solace.fritz.box> In-Reply-To: <148539008889.5464.5896389113741708672.stgit@Solace.fritz.box> References: <148539008889.5464.5896389113741708672.stgit@Solace.fritz.box> User-Agent: StGit/0.17.1-dirty MIME-Version: 1.0 Cc: George Dunlap Subject: [Xen-devel] [PATCH 9/9] 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 43b5b99..3947f6c 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)