From patchwork Fri Sep 30 02:54:00 2016 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Dario Faggioli X-Patchwork-Id: 9357465 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 3542A6077A for ; Fri, 30 Sep 2016 02:56:13 +0000 (UTC) Received: from mail.wl.linuxfoundation.org (localhost [127.0.0.1]) by mail.wl.linuxfoundation.org (Postfix) with ESMTP id 2993829D3E for ; Fri, 30 Sep 2016 02:56:13 +0000 (UTC) Received: by mail.wl.linuxfoundation.org (Postfix, from userid 486) id 1E18129D43; Fri, 30 Sep 2016 02:56:13 +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=-4.1 required=2.0 tests=BAYES_00,DKIM_SIGNED, RCVD_IN_DNSWL_MED,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 2EE7729D3E for ; Fri, 30 Sep 2016 02:56:12 +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 1bpnxd-0001zm-3v; Fri, 30 Sep 2016 02:54:05 +0000 Received: from mail6.bemta6.messagelabs.com ([193.109.254.103]) by lists.xenproject.org with esmtp (Exim 4.84_2) (envelope-from ) id 1bpnxb-0001yv-Vb for xen-devel@lists.xenproject.org; Fri, 30 Sep 2016 02:54:04 +0000 Received: from [193.109.254.147] by server-9.bemta-6.messagelabs.com id BB/2C-28857-BC3DDE75; Fri, 30 Sep 2016 02:54:03 +0000 X-Brightmail-Tracker: H4sIAAAAAAAAA+NgFvrAIsWRWlGSWpSXmKPExsXiVRvkqHvq8tt wg9nL1Cy+b5nM5MDocfjDFZYAxijWzLyk/IoE1oxf+6MLHlhUPLxwl6mBca1WFyMnh5DAdEaJ 9Tsjuxi5OFgE1rBKrF6+iAXEkRC4xCox8f4hNpAqCYEYif13LjBB2OUSMw7MZIPoVpG4uX0VE 0iDkMAvRomzvz+ygCSEBfQkjhz9wQ5hR0nsWvqZFcRmEzCQeLNjL5gtIqAkcW/VZLChzAJVEs dPLmUEsVkEVCV27j8NVsMr4CNx7MBPsDmcAr4Sv7a9YIFY7CPxe/lysCNEBeQkVl5ugaoXlDg 58wlQDQfQTE2J9bv0IcbLS2x/O4d5AqPILCRVsxCqZiGpWsDIvIpRvTi1qCy1SNdUL6koMz2j JDcxM0fX0MBMLze1uDgxPTUnMalYLzk/dxMjMPQZgGAH4/TL/ocYJTmYlER5ZY++DRfiS8pPq cxILM6ILyrNSS0+xCjDwaEkwet6CSgnWJSanlqRlpkDjEKYtAQHj5II70qQNG9xQWJucWY6RO oUoy7Hlqn31jIJseTl56VKifM2gRQJgBRllObBjYAlhEuMslLCvIxARwnxFKQW5WaWoMq/YhT nYFQS5i0DmcKTmVcCt+kV0BFMQEfkH30DckRJIkJKqoFxwUSt5PCaP5631kw9F/HTc5u52wVj gxqbzXmLt6tv/hfs2c5SJRTI+uaSYknSu68XNOo2iq2o/lcbqOG7e/Km9MuWVYZT90gGiO90/ KZ8WFWaM65ZW/UuiwfHjxOe6s1nxa4Wnvjw4KfAs2+bvtcceFp2xmVSgUort1dbb/wtE3+bgm srSj8osRRnJBpqMRcVJwIA9KVKAwMDAAA= X-Env-Sender: raistlin.df@gmail.com X-Msg-Ref: server-6.tower-27.messagelabs.com!1475204042!62542475!1 X-Originating-IP: [74.125.82.65] X-SpamReason: No, hits=0.0 required=7.0 tests= X-StarScan-Received: X-StarScan-Version: 8.84; banners=-,-,- X-VirusChecked: Checked Received: (qmail 57116 invoked from network); 30 Sep 2016 02:54:02 -0000 Received: from mail-wm0-f65.google.com (HELO mail-wm0-f65.google.com) (74.125.82.65) by server-6.tower-27.messagelabs.com with AES128-GCM-SHA256 encrypted SMTP; 30 Sep 2016 02:54:02 -0000 Received: by mail-wm0-f65.google.com with SMTP id w72so1397534wmf.1 for ; Thu, 29 Sep 2016 19:54:02 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=sender:subject:from:to:cc:date:message-id:in-reply-to:references :user-agent:mime-version:content-transfer-encoding; bh=HDJ7fLu2D0P6SASv4vlQlUKropyYOHNyHcwhbI1EW5g=; b=cBzqzThD+oQehx9YiSMijRcmtFTFj9/QFTo6QLnI+0/jhC5MQTy9HZvFjOv3Akzh8E VgiZWAIcU6sTOEQAvxQhDkub/mGd2j9+r4Z+g4m2eedWc1hJbYZojMnHXjKhdQZTf4uz 6CY+1t3uAENJRDYCWhJPJO3cIW12d7ZnGe5NbQYaShXFyOkf1BfbasCo1HKP5/I++Bya 91HPstSOlryPp8ZUeAV/sqBd2XZaHPSpV3k98p3Twa4bbXRlO/OVyn4zY+WoIX9e1DBI 9upOn24k0g373qAKZs28Q/oGyBHkPISppBvaPnTgLXY+okqn00WqpoCBbDHVkS/L3nOY owPw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; 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=HDJ7fLu2D0P6SASv4vlQlUKropyYOHNyHcwhbI1EW5g=; b=SqtCTzDUlGGVxR4Y2e5E3ra5X9Umm4ySc6iv1NOnmw5fS6ooUqGhiBlX+4Ldzp30Tf qqw3yt1U+tb4fjjuiq0N2Tz2kXlG3cFJbUbgqmMyT0U/FMMC5mHmDqvkBnNaXH2TVsV/ GZq+8ffUQsVHOyUwDXlq62kzwvr4QvI7c6hWWyQj9b2LUmYYHzkdwks/Rn9748PVuwJj Oc+4MnQrvU9t31T21y8fTb9zvXnO7TtZqA5KttYc54jPuMRFC0hhONBN5C7Ga6CVzgRq 8KvtWzlLCcZcr0CY31xbq6BYLr9uKywobyNxPCAPtWjsL7BvGZaxfylfRUbY+wzIUkjd Dx3w== X-Gm-Message-State: AA6/9RltyOxLL1oFjZseAJuqzL6e6iLvqwqL6S4Sz8MMtgSGFdgC8QIqoIn30AaapcH57g== X-Received: by 10.28.48.19 with SMTP id w19mr1608243wmw.54.1475204042222; Thu, 29 Sep 2016 19:54:02 -0700 (PDT) Received: from Solace.fritz.box ([80.66.223.126]) by smtp.gmail.com with ESMTPSA id i2sm17131341wjz.28.2016.09.29.19.54.01 (version=TLS1_2 cipher=ECDHE-RSA-AES128-GCM-SHA256 bits=128/128); Thu, 29 Sep 2016 19:54:01 -0700 (PDT) From: Dario Faggioli To: xen-devel@lists.xenproject.org Date: Fri, 30 Sep 2016 04:54:00 +0200 Message-ID: <147520404038.22544.12557551024149852193.stgit@Solace.fritz.box> In-Reply-To: <147520253247.22544.10673844222866363947.stgit@Solace.fritz.box> References: <147520253247.22544.10673844222866363947.stgit@Solace.fritz.box> User-Agent: StGit/0.17.1-dirty MIME-Version: 1.0 Cc: George Dunlap , Anshul Makkar , Meng Xu Subject: [Xen-devel] [PATCH v2 06/10] xen: tracing: add trace records for schedule and rate-limiting. 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 As far as {csched, csched2, rt}_schedule() are concerned, an "empty" event, would already make it easier to read and understand a trace. But while there, add a few useful information, like if the cpu that is going through the scheduler has been tickled or not, if it is currently idle, etc (they vary, on a per-scheduler basis). For Credit1 and Credit2, add a record about when rate-limiting kicks in too. Signed-off-by: Dario Faggioli Acked-by: George Dunlap Reviewed-by: Meng Xu --- Cc: George Dunlap Cc: Meng Xu Cc: Anshul Makkar --- Changes from v1: * corrected the schedule record for sched_rt.c, as pointed out during review; * pack the Credit1 records as well, as requested during review. --- xen/common/sched_credit.c | 32 ++++++++++++++++++++++++++++++++ xen/common/sched_credit2.c | 40 +++++++++++++++++++++++++++++++++++++++- xen/common/sched_rt.c | 15 +++++++++++++++ 3 files changed, 86 insertions(+), 1 deletion(-) diff --git a/xen/common/sched_credit.c b/xen/common/sched_credit.c index 5700763..fc3a321 100644 --- a/xen/common/sched_credit.c +++ b/xen/common/sched_credit.c @@ -133,6 +133,8 @@ #define TRC_CSCHED_TICKLE TRC_SCHED_CLASS_EVT(CSCHED, 6) #define TRC_CSCHED_BOOST_START TRC_SCHED_CLASS_EVT(CSCHED, 7) #define TRC_CSCHED_BOOST_END TRC_SCHED_CLASS_EVT(CSCHED, 8) +#define TRC_CSCHED_SCHEDULE TRC_SCHED_CLASS_EVT(CSCHED, 9) +#define TRC_CSCHED_RATELIMIT TRC_SCHED_CLASS_EVT(CSCHED, 10) /* @@ -1774,6 +1776,23 @@ csched_schedule( SCHED_STAT_CRANK(schedule); CSCHED_VCPU_CHECK(current); + /* + * Here in Credit1 code, we usually just call TRACE_nD() helpers, and + * don't care about packing. But scheduling happens very often, so it + * actually is important that the record is as small as possible. + */ + if ( unlikely(tb_init_done) ) + { + struct { + unsigned cpu:16, tasklet:8, idle:8; + } d; + d.cpu = cpu; + d.tasklet = tasklet_work_scheduled; + d.idle = is_idle_vcpu(current); + __trace_var(TRC_CSCHED_SCHEDULE, 1, sizeof(d), + (unsigned char *)&d); + } + runtime = now - current->runstate.state_entry_time; if ( runtime < 0 ) /* Does this ever happen? */ runtime = 0; @@ -1829,6 +1848,19 @@ csched_schedule( tslice = MICROSECS(prv->ratelimit_us) - runtime; if ( unlikely(runtime < CSCHED_MIN_TIMER) ) tslice = CSCHED_MIN_TIMER; + if ( unlikely(tb_init_done) ) + { + struct { + unsigned vcpu:16, dom:16; + unsigned runtime; + } d; + d.dom = scurr->vcpu->domain->domain_id; + d.vcpu = scurr->vcpu->vcpu_id; + d.runtime = runtime; + __trace_var(TRC_CSCHED_RATELIMIT, 1, sizeof(d), + (unsigned char *)&d); + } + ret.migrated = 0; goto out; } diff --git a/xen/common/sched_credit2.c b/xen/common/sched_credit2.c index fde61ef..5cf3f16 100644 --- a/xen/common/sched_credit2.c +++ b/xen/common/sched_credit2.c @@ -55,6 +55,8 @@ #define TRC_CSCHED2_LOAD_BALANCE TRC_SCHED_CLASS_EVT(CSCHED2, 17) #define TRC_CSCHED2_PICKED_CPU TRC_SCHED_CLASS_EVT(CSCHED2, 19) #define TRC_CSCHED2_RUNQ_CANDIDATE TRC_SCHED_CLASS_EVT(CSCHED2, 20) +#define TRC_CSCHED2_SCHEDULE TRC_SCHED_CLASS_EVT(CSCHED2, 21) +#define TRC_CSCHED2_RATELIMIT TRC_SCHED_CLASS_EVT(CSCHED2, 22) /* * WARNING: This is still in an experimental phase. Status and work can be found at the @@ -2288,12 +2290,29 @@ runq_candidate(struct csched2_runqueue_data *rqd, * no point forcing it to do so until rate limiting expires. */ if ( __test_and_clear_bit(__CSFLAG_vcpu_yield, &scurr->flags) ) + { yield_bias = CSCHED2_YIELD_BIAS; + } else if ( prv->ratelimit_us && !is_idle_vcpu(scurr->vcpu) && vcpu_runnable(scurr->vcpu) && (now - scurr->vcpu->runstate.state_entry_time) < MICROSECS(prv->ratelimit_us) ) + { + if ( unlikely(tb_init_done) ) + { + struct { + unsigned vcpu:16, dom:16; + unsigned runtime; + } d; + d.dom = scurr->vcpu->domain->domain_id; + d.vcpu = scurr->vcpu->vcpu_id; + d.runtime = now - scurr->vcpu->runstate.state_entry_time; + __trace_var(TRC_CSCHED2_RATELIMIT, 1, + sizeof(d), + (unsigned char *)&d); + } return scurr; + } /* Default to current if runnable, idle otherwise */ if ( vcpu_runnable(scurr->vcpu) ) @@ -2383,6 +2402,7 @@ csched2_schedule( struct csched2_vcpu *snext = NULL; unsigned int skipped_vcpus = 0; struct task_slice ret; + bool_t tickled; SCHED_STAT_CRANK(schedule); CSCHED2_VCPU_CHECK(current); @@ -2397,13 +2417,31 @@ csched2_schedule( BUG_ON(!is_idle_vcpu(scurr->vcpu) && scurr->rqd != rqd); /* Clear "tickled" bit now that we've been scheduled */ - if ( cpumask_test_cpu(cpu, &rqd->tickled) ) + tickled = cpumask_test_cpu(cpu, &rqd->tickled); + if ( tickled ) { __cpumask_clear_cpu(cpu, &rqd->tickled); cpumask_andnot(cpumask_scratch, &rqd->idle, &rqd->tickled); smt_idle_mask_set(cpu, cpumask_scratch, &rqd->smt_idle); } + if ( unlikely(tb_init_done) ) + { + struct { + unsigned cpu:16, rq_id:16; + unsigned tasklet:8, idle:8, smt_idle:8, tickled:8; + } d; + d.cpu = cpu; + d.rq_id = c2r(ops, cpu); + d.tasklet = tasklet_work_scheduled; + d.idle = is_idle_vcpu(current); + d.smt_idle = cpumask_test_cpu(cpu, &rqd->smt_idle); + d.tickled = tickled; + __trace_var(TRC_CSCHED2_SCHEDULE, 1, + sizeof(d), + (unsigned char *)&d); + } + /* Update credits */ burn_credits(rqd, scurr, now); diff --git a/xen/common/sched_rt.c b/xen/common/sched_rt.c index 41c61a7..d95f798 100644 --- a/xen/common/sched_rt.c +++ b/xen/common/sched_rt.c @@ -160,6 +160,7 @@ #define TRC_RTDS_BUDGET_BURN TRC_SCHED_CLASS_EVT(RTDS, 3) #define TRC_RTDS_BUDGET_REPLENISH TRC_SCHED_CLASS_EVT(RTDS, 4) #define TRC_RTDS_SCHED_TASKLET TRC_SCHED_CLASS_EVT(RTDS, 5) +#define TRC_RTDS_SCHEDULE TRC_SCHED_CLASS_EVT(RTDS, 6) static void repl_timer_handler(void *data); @@ -1035,6 +1036,20 @@ rt_schedule(const struct scheduler *ops, s_time_t now, bool_t tasklet_work_sched struct rt_vcpu *snext = NULL; struct task_slice ret = { .migrated = 0 }; + /* TRACE */ + { + struct __packed { + unsigned cpu:16, tasklet:8, tickled:4, idle:4; + } d; + d.cpu = cpu; + d.tasklet = tasklet_work_scheduled; + d.tickled = cpumask_test_cpu(cpu, &prv->tickled); + d.idle = is_idle_vcpu(current); + trace_var(TRC_RTDS_SCHEDULE, 1, + sizeof(d), + (unsigned char *)&d); + } + /* clear ticked bit now that we've been scheduled */ cpumask_clear_cpu(cpu, &prv->tickled);