Received: by 2002:a05:6a10:af89:0:0:0:0 with SMTP id iu9csp1410353pxb; Fri, 21 Jan 2022 18:02:21 -0800 (PST) X-Google-Smtp-Source: ABdhPJx/EQlewBClfpfNLWzSasewkiAKCWOYGvk3jv0LRRGwaxTw4x5RL7bLWVjF+SdRl6Bl6ELH X-Received: by 2002:a17:902:d2c4:b0:14b:1a91:58fc with SMTP id n4-20020a170902d2c400b0014b1a9158fcmr5828770plc.127.1642816941644; Fri, 21 Jan 2022 18:02:21 -0800 (PST) ARC-Seal: i=1; a=rsa-sha256; t=1642816941; cv=none; d=google.com; s=arc-20160816; b=A6HQa7Ae+Exe5Xq1B4KAyquu50jEIfWCX/dnl/NXN/JX+DTnxSNfm+48tSCf9E+aWJ czMOq9TNN8RD2d/FsvOkzD2nnhfVB/pslXdfMl1QwZnlZlRTXGkuEzbGm4Ud+Nq75AVd ZpS3blzNaHV3QVYFvq4clTWS4Y9WYYB1zuCHR3tML9dlzknmkj+UE6KnyYtgoE590Nu0 eXU/5lqJ8DTHK1Dcg246SWIa6vjYyAySCpVt8vZWb96qUd4ticJcNXbJNvhfXwG+BzbE oix8O1OBGNRfMlruM/sy7l2yiZO3+qVdJKcqiZvM9pOcQfbubjfm8bT1nExlKtqs+pjS P1nw== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816; h=list-id:precedence:content-transfer-encoding:mime-version :references:in-reply-to:message-id:subject:cc:to:from:date; bh=AdldlIJqCluBEN2wXQpAlfZOuKGx4Rt5Blscq5AZOpo=; b=rkzMu/Q2jo+DoeX3xVcjSzGyMxZrJiWMJlG4DNTQq0YZLUJicsn9rMkKwr60ZNTHH+ 32ZTfVQRhzgOoMn54KUfLv0GDSZ8fXL4aPCfSR1NT4M2QE7qGTRZHa4ByNA/HEQbGPDG qFxVI0QSstvZL2DtIN1l3svNTLcr/iq2J8v8UiJN+2SOgIV7c7yqpA4/+D90qcrV2ZkD 6xBJaSHQJoS3aBZ3qXf1rl2XHiyOtygh4InvXvcy1g4v+RGV0phl9dia0ktXpZz8fDnh MS4fvIpSdHhiufbFDjzd8aKZAokJZWVpm37yj8D928ck9rlv1hZeFobemWSO/VJwyeLO X1uA== ARC-Authentication-Results: i=1; mx.google.com; spf=pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 23.128.96.18 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org Return-Path: Received: from vger.kernel.org (vger.kernel.org. [23.128.96.18]) by mx.google.com with ESMTP id 207si8115958pga.681.2022.01.21.18.02.08; Fri, 21 Jan 2022 18:02:21 -0800 (PST) Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 23.128.96.18 as permitted sender) client-ip=23.128.96.18; Authentication-Results: mx.google.com; spf=pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 23.128.96.18 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1379743AbiAURQH (ORCPT + 99 others); Fri, 21 Jan 2022 12:16:07 -0500 Received: from ams.source.kernel.org ([145.40.68.75]:59214 "EHLO ams.source.kernel.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1379454AbiAURQD (ORCPT ); Fri, 21 Jan 2022 12:16:03 -0500 Received: from smtp.kernel.org (relay.kernel.org [52.25.139.140]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by ams.source.kernel.org (Postfix) with ESMTPS id C5D03B82069 for ; Fri, 21 Jan 2022 17:16:02 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id 98E88C340E1; Fri, 21 Jan 2022 17:15:59 +0000 (UTC) Date: Fri, 21 Jan 2022 12:15:58 -0500 From: Steven Rostedt To: Valentin Schneider Cc: linux-kernel@vger.kernel.org, Abhijeet Dharmapurikar , Uwe =?UTF-8?B?S2xlaW5lLUvDtm5pZw==?= , Dietmar Eggemann , Peter Zijlstra , Ingo Molnar , Vincent Guittot , Thomas Gleixner , Sebastian Andrzej Siewior , Juri Lelli , Daniel Bristot de Oliveira , Kees Cook , Andrew Morton , "Eric W. Biederman" , Alexey Gladkov , "Kenta.Tada@sony.com" , Randy Dunlap , Ed Tsai Subject: Re: [PATCH v3 0/2] sched/tracing: sched_switch prev_state reported as TASK_RUNNING when it's not Message-ID: <20220121121558.618b98e7@gandalf.local.home> In-Reply-To: <20220120162520.570782-1-valentin.schneider@arm.com> References: <20220120162520.570782-1-valentin.schneider@arm.com> X-Mailer: Claws Mail 3.17.8 (GTK+ 2.24.33; x86_64-pc-linux-gnu) MIME-Version: 1.0 Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: 7bit Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Thu, 20 Jan 2022 16:25:18 +0000 Valentin Schneider wrote: > Hi folks, > > Problem > ======= > > Abhijeet pointed out that the following sequence of trace events can be > observed: > > cat-1676 [001] d..3 103.010411: sched_waking: comm=grep pid=1677 prio=120 target_cpu=004 > grep-1677 [004] d..2 103.010440: sched_switch: prev_comm=grep prev_pid=1677 prev_prio=120 prev_state=R 0x0 ==> next_comm=swapper/4 next_pid=0 next_prio=120 > -0 [004] dNh3 103.0100459: sched_wakeup: comm=grep pid=1677 prio=120 target_cpu=004 > > IOW, not-yet-woken task gets presented as runnable and switched out in > favor of the idle task... Dietmar and I had a look, turns out this sequence > can happen: > > p->__state = TASK_INTERRUPTIBLE; > __schedule() > deactivate_task(p); > ttwu() > READ !p->on_rq > p->__state=TASK_WAKING > trace_sched_switch() > __trace_sched_switch_state() > task_state_index() > return 0; > > TASK_WAKING isn't in TASK_REPORT, hence why task_state_index(p) returns 0. > This can happen as of commit c6e7bd7afaeb ("sched/core: Optimize ttwu() > spinning on p->on_cpu") which punted the TASK_WAKING write to the other > side of > > smp_cond_load_acquire(&p->on_cpu, !VAL); > > in ttwu(). > > Uwe reported on #linux-rt what I think is a similar issue with > TASK_RTLOCK_WAIT on PREEMPT_RT; again that state isn't in TASK_REPORT so > you get prev_state=0 despite the task blocking on a lock. > > Both of those are very confusing for tooling or even human observers. This all looks fine to me: Reviewed-by: Steven Rostedt (Google) Peter, want to take this through your tree? -- Steve