From nobody Tue Dec 16 08:34:55 2025 Received: from APC01-SG2-obe.outbound.protection.outlook.com (mail-sg2apc01on2101.outbound.protection.outlook.com [40.107.215.101]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by smtp.subspace.kernel.org (Postfix) with ESMTPS id 4EECF610D for ; Mon, 7 Apr 2025 03:21:39 +0000 (UTC) Authentication-Results: smtp.subspace.kernel.org; arc=fail smtp.client-ip=40.107.215.101 ARC-Seal: i=2; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1743996102; cv=fail; b=eHE9WwdnJQLWdzWY/malWiFnGeVOw/suxB5ZACISU+UXGrI1ZGd8pJMUuPb0558Y0jKxYCc22b1lGraCBJt+1Rnbc46tMIAOp9dMNg22IyMdqj0Y75konXWnF2XcBvW8WrxAWNTVHY9HtzZZfBWs1XtYzpHOHVBRShWRc8vjNOU= ARC-Message-Signature: i=2; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1743996102; c=relaxed/simple; bh=jqsYKBGyVtmDx6cgzSMFwZD//EqFovfrTdBB24qI98g=; h=From:To:CC:Subject:Date:Message-ID:Content-Type:MIME-Version; b=bVUnGMTU0QxrNMTZr0bzPzNtgkYtuOz+pt8NSz4xyHzUe1f44SDuWEo8jzKJXk3vqARVd0K7JKxgrsJDC9VkWqRROry55KmbxJBs1t4ieM4WJhQG2pBoaLvbkk6z1IAMqFN6zlZHpJ3tLf0u6a2tTJ2sQkqiqoVIdXwWUGKicVI= ARC-Authentication-Results: i=2; smtp.subspace.kernel.org; dmarc=none (p=none dis=none) header.from=transsion.com; spf=pass smtp.mailfrom=transsion.com; dkim=pass (1024-bit key) header.d=transsion.com header.i=@transsion.com header.b=PM30sKtk; arc=fail smtp.client-ip=40.107.215.101 Authentication-Results: smtp.subspace.kernel.org; dmarc=none (p=none dis=none) header.from=transsion.com Authentication-Results: smtp.subspace.kernel.org; spf=pass smtp.mailfrom=transsion.com Authentication-Results: smtp.subspace.kernel.org; dkim=pass (1024-bit key) header.d=transsion.com header.i=@transsion.com header.b="PM30sKtk" ARC-Seal: i=1; a=rsa-sha256; s=arcselector10001; d=microsoft.com; cv=none; b=XXkWj5fNLpgJfzfAPjirIxvCsxXY4NoX+9M3B7i6y3JnOT78Ch7MnPdJHwyOFEFsO6EYJCCcF2m/uhiugogWEvwA8tDjKWVIpEZKot4puZBq0o+fLl4z3pBH+rl6QCJKLsKYvKFi7MpJ3Nk5vdSQD+hKH3BD1xQG+4wA1MILPevvbTOQpsqrqITauEhdeX+/3G7M/ud2EQFB3HVlHbsmAhAxFEMBaux7fzWIripM8hoeeoNOUIlFiL4Xefq9II03LrtI8FcyWgArZfklpO+IiKyVi2wUGzIrr96CyjI2Y8AXK98FquS0T7BLFI69fBblEk3w7J0tn/3aj1s4duuVlA== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=microsoft.com; s=arcselector10001; h=From:Date:Subject:Message-ID:Content-Type:MIME-Version:X-MS-Exchange-AntiSpam-MessageData-ChunkCount:X-MS-Exchange-AntiSpam-MessageData-0:X-MS-Exchange-AntiSpam-MessageData-1; bh=jqsYKBGyVtmDx6cgzSMFwZD//EqFovfrTdBB24qI98g=; b=v+BRoT+sQx0aY69Yz7Hb+FIYdEcRMhqIwWfBRSvIeFLtn+nzZcVrojivVSwcbzolaThYjOUzrJ0V277uob4ekzdejiKaw/NoAvvn3UcLRwFavc8OoQyAYuFJ8K1RVhcpYGmKr+s2bwBwb6zfLaRD/GvFC5sGNKJegPzI8BioyKTO9IncspRAW6NCzjZZ3VRircTIGOiprF7TIkyaalqDjps2lpfOx57IAuItxkhvXvulOSLPvbctX9RthMpzoPCsORkQADtuzmq1YUXNq7BrDc25Ue/A4GUk+01CByKuNwPvtEw2aZH+lMy3jLI+CsFSzsL5z/RIYigF9sK5jZSkxA== ARC-Authentication-Results: i=1; mx.microsoft.com 1; spf=fail (sender ip is 58.246.63.154) smtp.rcpttodomain=redhat.com smtp.mailfrom=transsion.com; dmarc=none action=none header.from=transsion.com; dkim=none (message not signed); arc=none (0) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=transsion.com; s=selector1; h=From:Date:Subject:Message-ID:Content-Type:MIME-Version:X-MS-Exchange-SenderADCheck; bh=jqsYKBGyVtmDx6cgzSMFwZD//EqFovfrTdBB24qI98g=; b=PM30sKtkAwxe5cLKKi+zCvzVqyNq9Oik+JVeElVCjJtVmkeWejVb0H7IVWpp/+AU7WaopdD0US9pd34B+ANMI/jXmS2vz04h1gyAMXILXPtzteIuFWkSVSaWHwJOXmPhv3YKlj7T5kYuWjRaDWIrf4qt5VgCge46F2yRyfqRN2o= Received: from SI1PR02CA0025.apcprd02.prod.outlook.com (2603:1096:4:1f4::13) by JH0PR04MB7536.apcprd04.prod.outlook.com (2603:1096:990:6f::12) with Microsoft SMTP Server (version=TLS1_2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id 15.20.8606.34; Mon, 7 Apr 2025 03:21:33 +0000 Received: from HK3PEPF0000021D.apcprd03.prod.outlook.com (2603:1096:4:1f4:cafe::f5) by SI1PR02CA0025.outlook.office365.com (2603:1096:4:1f4::13) with Microsoft SMTP Server (version=TLS1_3, cipher=TLS_AES_256_GCM_SHA384) id 15.20.8606.34 via Frontend Transport; Mon, 7 Apr 2025 03:21:33 +0000 X-MS-Exchange-Authentication-Results: spf=fail (sender IP is 58.246.63.154) smtp.mailfrom=transsion.com; dkim=none (message not signed) header.d=none;dmarc=none action=none header.from=transsion.com; Received-SPF: Fail (protection.outlook.com: domain of transsion.com does not designate 58.246.63.154 as permitted sender) receiver=protection.outlook.com; client-ip=58.246.63.154; helo=mail.transsion.com; Received: from mail.transsion.com (58.246.63.154) by HK3PEPF0000021D.mail.protection.outlook.com (10.167.8.39) with Microsoft SMTP Server (version=TLS1_2, cipher=TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256) id 15.20.8632.13 via Frontend Transport; Mon, 7 Apr 2025 03:21:32 +0000 Received: from SH-EXC-MX06.transsion.com (10.150.2.44) by SH-EXC-MX03.transsion.com (10.150.2.43) with Microsoft SMTP Server (version=TLS1_2, cipher=TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256_P256) id 15.1.2507.44; Mon, 7 Apr 2025 11:21:30 +0800 Received: from SH-EXC-MX06.transsion.com ([fe80::954b:3df8:a403:9ca3]) by SH-EXC-MX06.transsion.com ([fe80::954b:3df8:a403:9ca3%12]) with mapi id 15.01.2507.044; Mon, 7 Apr 2025 11:21:30 +0800 From: =?gb2312?B?eGlhbmhlLnpob3Uo1tzP1LrVKQ==?= To: "mingo@redhat.com" , "peterz@infradead.org" , "juri.lelli@redhat.com" , "incent.guittot@linaro.org" , "vincent.guittot@linaro.org" CC: "dietmar.eggemann@arm.com" , "rostedt@goodmis.org" , "bsegall@google.com" , "mgorman@suse.de" , "vschneid@redhat.com" , "linux-kernel@vger.kernel.org" Subject: [PATCH RESEND] sched: Fix incorrect runnable time calculation in sched_stat_wait tracepoint Thread-Topic: [PATCH RESEND] sched: Fix incorrect runnable time calculation in sched_stat_wait tracepoint Thread-Index: Aduna6yc9WP8s4RtTTy3MbaASRKX2g== Date: Mon, 7 Apr 2025 03:21:30 +0000 Message-ID: Accept-Language: zh-CN, en-US Content-Language: zh-CN X-MS-Has-Attach: X-MS-TNEF-Correlator: Content-Transfer-Encoding: quoted-printable Precedence: bulk X-Mailing-List: linux-kernel@vger.kernel.org List-Id: List-Subscribe: List-Unsubscribe: MIME-Version: 1.0 X-EOPAttributedMessage: 0 X-MS-PublicTrafficType: Email X-MS-TrafficTypeDiagnostic: HK3PEPF0000021D:EE_|JH0PR04MB7536:EE_ X-MS-Office365-Filtering-Correlation-Id: af7f37fb-fd0f-4165-6300-08dd75834b70 X-MS-Exchange-SenderADCheck: 1 X-MS-Exchange-AntiSpam-Relay: 0 X-Microsoft-Antispam: BCL:0;ARA:13230040|376014|7416014|82310400026|36860700013|1800799024; X-Microsoft-Antispam-Message-Info: =?gb2312?B?STkxcUljVndzQ2x4RHhUaG9sMWlncW1IK0Z5V0svOTFKQ3dwTmpxdmJ5RUZC?= =?gb2312?B?eXp6enhnTG9nVnV2MXZwL3NXM2ZSR2pXbXFFcmdDTDFUaEsvODA5aUhhTVVu?= =?gb2312?B?eGRBa3RiL2NNUnZxTEZKeUUvdmxqM3ZjZmV2aU9xUlA2Tm5aNnpUSjFzMWxl?= =?gb2312?B?Z05CZmhYKytBS3ZseGdjR2pGVVZXdnJkTGZFWTJIZXZaOU5JdmdVUEdOSytj?= =?gb2312?B?cElHdHEvaFB0Y1dTdGd6ckdhYVVwL2FyRHFhWVQvRFpFMTZJNTFLR1hUR3M2?= =?gb2312?B?bHVIRHVhSnBKdXlGVmxCUi9oMlhZczZ6Z1hHblVFTVArZzhsV0RGSWp6aUZh?= =?gb2312?B?bGd2YzlTR04zZndiN1RoSlRhWE0vZENKRVpETjdNa3lpYXh1cm12dmtyVXZr?= =?gb2312?B?bzU2UnhTNnpGU1FZS2MvR0l6WlU0RWlsOVJCbkN5QnNvVWFRQVJNakNwZTY1?= =?gb2312?B?L3NIQXlWVisrOHN1VHp4MUw4WUFoSUJJTVBDT1pYWUlnT1NnT1VtelowNDY5?= =?gb2312?B?UjRaTXV2QkhUTFArUnhRWEhoQjMrL1lUNnBuUnhFWm5XdnVTTCtsdjliYkpI?= =?gb2312?B?NU05VHV6aXhXUW1RUFA4aWlydHBqeXdVb0ZQM3JqeC80RXA4WHN2d0VONnJk?= =?gb2312?B?T2JjY3dmaml1VlBSOVpwQjdoR01vYWtaa2ovREFiZDNkOUFpWUZyZDZFQzE5?= =?gb2312?B?a29HYmZtSXBaSVhQZVVlSUFMZGFPanA1dVRCK0pBODhpWC9YWFltaE9ITUp4?= =?gb2312?B?bE9FcGxRNjBMSGozSG83WTNIS3ovRi9Bb2V4cEdDRVE0c0tEdG5UQ0QxY05V?= =?gb2312?B?VUYvc1NPWnprNkJZSHBzWWdaV2ZEUlBtSGlRTWdwUjRmUS82c3BZbnBxdmxC?= =?gb2312?B?MTVDSEdVWXNOMHcrU3loNldwajNqL0FOMWZ6bXRMVU01WVRBS2sweWczMUNv?= =?gb2312?B?SU9qODRJdHdWU21YNWhSUXFHYVgvVVh5dktNY0lMS0xxWHZidXY2YmszNGFy?= =?gb2312?B?V2J1NUtvMVp6d2hnTWhvN09UQXdrSmFTRE45cDBjc25NVytMTFcxcFFqWXlD?= =?gb2312?B?NHIwQ3BMT0tQVm03MnJHNzBOcDhJMDBNb3VheGxqM3FVb0RaQ0t1VmtwbTFR?= =?gb2312?B?QVg2VlhtaFdkdU5LY3BCWHBGR1haaXBvSE1yL3J0UVpuK0IvZ2xJSlpCMi9J?= =?gb2312?B?Nk8xSHpGMExMNmNoT0ZnaTVUWW5kNVFzRnMzMVJrNktkVkQvY1I4Y1R5bUlq?= =?gb2312?B?NDhodmQ5RWtkb3p5VjFuUEFJNnBjaVNVRFFQSHNERFg2N1JUVEFjczBvZm1a?= =?gb2312?B?Kys3cUtQNEl0Y1Z6VHdRVEN3SmVPV1Q0ajFYL3c1cmNybnJ6TkhLREp1a3M2?= =?gb2312?B?S01VbTVoQUhZZjhKRVNCTTBqdjMvOUMxYk9NU1ZWTndJYXAvdkUzTnBrYzVu?= =?gb2312?B?NE9GQ0xhMWFMdmoyS1lRT2hWWmxtSkZxam9mQXpSZWJTVUM3K3orMkNxd3Uv?= =?gb2312?B?L3E5TGt4YnRld0ozUkwrMDQxTjAzU3J3V2dDcEdMbHl0OXJPc0RubG1LTGsy?= =?gb2312?B?dHhOT0xIeEF6RUs2a2kwWnhMRjBNTUd6WFEzaDdmbnZKK0NuRWxMbkljWXNX?= =?gb2312?B?U0c5ZWlBU2FFeGFXb1hMYU44YjE5ajlIdGpPalM1dVBmZzlyenM1azB1QmJM?= =?gb2312?B?OFhGOVBSdE1jenk5RjFzdWpieUpUeSt6SW5tckpRMVRPUGFwMHMyVExOWnpZ?= =?gb2312?B?VmJtdithSzZHejFmQlNCaUs3NEVuakxJREc2ZllIY3ExS2Rvb01oTDl2UWMx?= =?gb2312?B?a1JiY1pEdWpMNCtZWTQ4c0hEMFd3MHVPMkhuUzRTR0ZIcThjelhpSlpaUHE5?= =?gb2312?B?SDBrajUvdENneVZCak5DT0JlK1JsRU8yQlJxc0xZcnNub2o1UDBQRzdnMkVu?= =?gb2312?B?WVc3NTR4SnBibDI5K3hBNVFXMmk2TGtaMTJVQjNHMGFCYklTSnFiWjUyUFov?= =?gb2312?B?YlpvZHZLTEFnPT0=?= X-Forefront-Antispam-Report: CIP:58.246.63.154;CTRY:CN;LANG:en;SCL:1;SRV:;IPV:NLI;SFV:NSPM;H:mail.transsion.com;PTR:InfoDomainNonexistent;CAT:NONE;SFS:(13230040)(376014)(7416014)(82310400026)(36860700013)(1800799024);DIR:OUT;SFP:1102; X-OriginatorOrg: transsion.com X-MS-Exchange-CrossTenant-OriginalArrivalTime: 07 Apr 2025 03:21:32.1113 (UTC) X-MS-Exchange-CrossTenant-Network-Message-Id: af7f37fb-fd0f-4165-6300-08dd75834b70 X-MS-Exchange-CrossTenant-Id: 2e8503a6-2d01-4333-8e36-6ab7c8cd7ae2 X-MS-Exchange-CrossTenant-OriginalAttributedTenantConnectingIp: TenantId=2e8503a6-2d01-4333-8e36-6ab7c8cd7ae2;Ip=[58.246.63.154];Helo=[mail.transsion.com] X-MS-Exchange-CrossTenant-AuthSource: HK3PEPF0000021D.apcprd03.prod.outlook.com X-MS-Exchange-CrossTenant-AuthAs: Anonymous X-MS-Exchange-CrossTenant-FromEntityHeader: HybridOnPrem X-MS-Exchange-Transport-CrossTenantHeadersStamped: JH0PR04MB7536 Content-Type: text/plain; charset="utf-8" From b07df3ed3fd2186a698ef87ad366523ec7c7fccb Mon Sep 17 00:00:00 2001 From: "xianhe.zhou" Date: Thu, 20 Feb 2025 22:01:26 +0800 Subject: [PATCH] sched: Fix incorrect runnable time calculation in sched_stat_wait tracepoint The sched_stat_wait tracepoint is intended to record the runnable time of a task. However, due to incorrect timestamp handling, two major issues arise: 1. The tracepoint may incorrectly record consecutive start timestamps or consecutive end timestamps, rather than properly pairing them. This leads to incorrect runnable time calculations. 2. The recorded time may include temporary dequeuing and enqueuing events, such as when modifying a task's nice value while it is running. This patch ensures that timestamps are properly paired and excludes temporary dequeuing events to prevent incorrect measurements. Testing: This issue was tested on an Android 14 device. The following are the trace results before and after applying the patch: Before the fix (incorrect values): sched_stat_wait: comm=3DOverlayEngine_0 pid=3D1533 delay=3D352418315839 [ns] sched_stat_wait: comm=3DOverlayEngine_0 pid=3D1533 delay=3D352409961840 [ns] sched_stat_wait: comm=3DOverlayEngine_0 pid=3D1533 delay=3D352393317455 [ns] sched_stat_wait: comm=3Dbinder:1148_3 pid=3D2102 delay=3D352380493377 [ns] sched_stat_wait: comm=3DOverlayEngine_0 pid=3D1533 delay=3D352360033377 [ns] Clearly, these runnable time values, in the hundreds of seconds, are incorrect. After the fix (corrected values): sched_stat_wait: comm=3Dkworker/7:1 pid=3D13682 delay=3D63516923 [ns] sched_stat_wait: comm=3DSuperA_R[136] pid=3D15074 delay=3D51324385 [ns] sched_stat_wait: comm=3DSuperA_R[136] pid=3D15080 delay=3D50280539 [ns] sched_stat_wait: comm=3DSuperA_R[136] pid=3D15071 delay=3D48995692 [ns] sched_stat_wait: comm=3DSuperA_R[34] pid=3D14951 delay=3D41876308 [ns] After the fix, the recorded runnable times are within expected ranges. Fixes: 768d0c27226e ("sched: Add wait, sleep and iowait accounting tracepoi= nts") Signed-off-by: xianhe.zhou --- kernel/sched/fair.c | 13 +++++++------ kernel/sched/rt.c | 15 ++++++++++++--- kernel/sched/stats.c | 7 ++++++- 3 files changed, 25 insertions(+), 10 deletions(-) diff --git a/kernel/sched/fair.c b/kernel/sched/fair.c index 1c0ef435a7aa..37a315b3906b 100644 --- a/kernel/sched/fair.c +++ b/kernel/sched/fair.c @@ -1331,11 +1331,12 @@ update_stats_enqueue_fair(struct cfs_rq *cfs_rq, st= ruct sched_entity *se, int fl if (!schedstat_enabled()) return; =20 - /* - * Are we enqueueing a waiting task? (for current tasks - * a dequeue/enqueue event is a NOP) + /* + * Are we enqueueing a waiting task? And it is not + * a temporary enqueue?(for current tasks a + * dequeue/enqueue event is a NOP) */ - if (se !=3D cfs_rq->curr) + if (se !=3D cfs_rq->curr && !(flags & ENQUEUE_RESTORE)) update_stats_wait_start_fair(cfs_rq, se); =20 if (flags & ENQUEUE_WAKEUP) @@ -1351,9 +1352,9 @@ update_stats_dequeue_fair(struct cfs_rq *cfs_rq, stru= ct sched_entity *se, int fl =20 /* * Mark the end of the wait period if dequeueing a - * waiting task: + * waiting task and it is not a temporary dequeue: */ - if (se !=3D cfs_rq->curr) + if (se !=3D cfs_rq->curr && !(flags & DEQUEUE_SAVE)) update_stats_wait_end_fair(cfs_rq, se); =20 if ((flags & DEQUEUE_SLEEP) && entity_is_task(se)) { diff --git a/kernel/sched/rt.c b/kernel/sched/rt.c index 4b8e33c615b1..991251feeaf6 100644 --- a/kernel/sched/rt.c +++ b/kernel/sched/rt.c @@ -1310,9 +1310,17 @@ static inline void update_stats_enqueue_rt(struct rt_rq *rt_rq, struct sched_rt_entity *rt_se, int flags) { + struct task_struct *p =3D NULL; + if (!schedstat_enabled()) return; =20 + if (rt_entity_is_task(rt_se)) + p =3D rt_task_of(rt_se); + + if (p !=3D rq_of_rt_rq(rt_rq)->curr && !(flags & ENQUEUE_RESTORE)) + update_stats_wait_start_rt(rt_rq, rt_se); + if (flags & ENQUEUE_WAKEUP) update_stats_enqueue_sleeper_rt(rt_rq, rt_se); } @@ -1348,6 +1356,10 @@ update_stats_dequeue_rt(struct rt_rq *rt_rq, struct = sched_rt_entity *rt_se, if (rt_entity_is_task(rt_se)) p =3D rt_task_of(rt_se); =20 + if (p !=3D rq_of_rt_rq(rt_rq)->curr && !(flags & DEQUEUE_SAVE)) { + update_stats_wait_end_rt(rt_rq, rt_se); + } + if ((flags & DEQUEUE_SLEEP) && p) { unsigned int state; =20 @@ -1474,9 +1486,6 @@ enqueue_task_rt(struct rq *rq, struct task_struct *p,= int flags) if (flags & ENQUEUE_WAKEUP) rt_se->timeout =3D 0; =20 - check_schedstat_required(); - update_stats_wait_start_rt(rt_rq_of_se(rt_se), rt_se); - enqueue_rt_entity(rt_se, flags); =20 if (!task_current(rq, p) && p->nr_cpus_allowed > 1) diff --git a/kernel/sched/stats.c b/kernel/sched/stats.c index 4346fd81c31f..367f4bb1c759 100644 --- a/kernel/sched/stats.c +++ b/kernel/sched/stats.c @@ -20,8 +20,13 @@ void __update_stats_wait_start(struct rq *rq, struct tas= k_struct *p, void __update_stats_wait_end(struct rq *rq, struct task_struct *p, struct sched_statistics *stats) { - u64 delta =3D rq_clock(rq) - schedstat_val(stats->wait_start); + u64 delta; + u64 wait_start =3D schedstat_val(stats->wait_start); =20 + if (!wait_start) + return; + + delta =3D rq_clock(rq) - wait_start; if (p) { if (task_on_rq_migrating(p)) { /* --=20 2.34.1