Received: by 2002:a05:6a10:1287:0:0:0:0 with SMTP id d7csp1323541pxv; Fri, 23 Jul 2021 05:45:16 -0700 (PDT) X-Google-Smtp-Source: ABdhPJx0JjblCdkVeo5HQh4BpVmW/0iu8WZDmazwrCVbM0qIaQaCVD4jVH7SWWl22ra0WmKserXh X-Received: by 2002:a05:6402:2044:: with SMTP id bc4mr5588627edb.307.1627044316597; Fri, 23 Jul 2021 05:45:16 -0700 (PDT) ARC-Seal: i=1; a=rsa-sha256; t=1627044316; cv=none; d=google.com; s=arc-20160816; b=tymVuaRCFSkUpH7H5IzJvpEcXgE6cJSzRMrlgfsDATDaWegkxS9L82Mkhfdna2IL8+ sv2BXxDB8ydSRsSgutnvok8ZFEtxPleF8T+6UkRLbwOkES2cULD+YUT+S2PHAXo+TQxa rWQZjOnW3hF4syL/AKpPe9AxaD/C/sXRj0WW7hDnSyISaAFAtooOqsu+aF13X8QZyLu1 5bA5HYXoqOjvbnuGOuapkHXDy3bAtlfyDsa9z7YRLUU6AmKF0ZqGj7JwUVSdQP6MNKdh rO9vxaZyW0JpXfhTds07QP2IniekG6ph4wtxxglpOhbRmxhI0OufiLE8Q2kXo6tDty8m KeXg== 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=MlTKmKp1Qibo6G6qxp2F8Vg99Jg5IdxQysxOJx39L6w=; b=qZn+oNlpuTmQuqPhBjn8hBrYbitzcvRo/nv+t/oSMe2JLo7niGAZFmleADMz/l6t7Y h8vQLuRujeIhMYQkYdDcaMUK1xHcqz1tD6wrb47P7l7ou5w/kW24isS3ANhSd+rVp0B3 XSiCOp6EhNSsNucCbpda/Ya/qknfw+Uir2Qe1zHd3c4KTxcUFEggsAuOTJUhqS5c+tsX JnRv/OAvhJF9u/NYuXkvkwZQ9JQBd7KZ84xaPjxMM2PAFQTTqTl99KcbHai+apqwSuqs +cBwsSfTWNLcd9yWcGLBoh4+QbWQ5BIPP9pdJlD+U0xkILOrY9zWWMno6aoBiX2c4cNV cUxQ== 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 p20si34508805edx.40.2021.07.23.05.44.52; Fri, 23 Jul 2021 05:45:16 -0700 (PDT) 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 S234857AbhGWMA5 (ORCPT + 99 others); Fri, 23 Jul 2021 08:00:57 -0400 Received: from mail.kernel.org ([198.145.29.99]:60474 "EHLO mail.kernel.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S234601AbhGWMA4 (ORCPT ); Fri, 23 Jul 2021 08:00:56 -0400 Received: from oasis.local.home (cpe-66-24-58-225.stny.res.rr.com [66.24.58.225]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by mail.kernel.org (Postfix) with ESMTPSA id 726A060E53; Fri, 23 Jul 2021 12:41:29 +0000 (UTC) Date: Fri, 23 Jul 2021 08:41:22 -0400 From: Steven Rostedt To: Stefan Metzmacher Cc: Ingo Molnar , linux-trace-devel@vger.kernel.org, io-uring , "linux-kernel@vger.kernel.org" Subject: Re: sched_waking vs. set_event_pid crash (Re: Tracing busy processes/threads freezes/stalls the whole machine) Message-ID: <20210723084122.1ed6b27f@oasis.local.home> In-Reply-To: References: <293cfb1d-8a53-21e1-83c1-cdb6e2f32c65@samba.org> <20210504092404.6b12aba4@gandalf.local.home> <20210504093550.5719d4bd@gandalf.local.home> <8bb757fb-a83b-0ed5-5247-8273be3925c5@samba.org> <90c806a0-8a2f-1257-7337-6761100217c9@samba.org> <4ebea8f0-58c9-e571-fd30-0ce4f6f09c70@samba.org> <20210722225124.6d7d7153@rorschach.local.home> <20210723072906.4f4e7bd5@gandalf.local.home> X-Mailer: Claws Mail 3.17.3 (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 Fri, 23 Jul 2021 13:53:41 +0200 Stefan Metzmacher wrote: > Hi Steve, > > >>> Assuming this does fix your issue, I sent out a real patch with the > >>> explanation of what happened in the change log, so that you can see why > >>> that change was your issue. > >> > >> Yes, it does the trick, thanks very much! > > > > Can I get a "Tested-by" from you? > > Sure! Thanks. > > Can you check if the static_key_disable() and static_key_enable() > calls are correctly ordered compared to rcu_assign_pointer() > and explain why they are, as I not really understand that it's different > from tracepoint_update_call vs. rcu_assign_pointer The order doesn't even matter. I'm assuming you are talking about the static_key_disable/enable with respect to enabling the tracepoint. The reason it doesn't matter is because the rcu_assign_pointer is updating an array of elements that hold both the function to call and the data it needs. Inside the tracepoint loop where the callbacks are called, in the iterator code (not the static call), you will see: it_func_ptr = \ rcu_dereference_raw((&__tracepoint_##_name)->funcs); \ if (it_func_ptr) { \ do { \ it_func = READ_ONCE((it_func_ptr)->func); \ __data = (it_func_ptr)->data; \ ((void(*)(void *, proto))(it_func))(__data, args); \ } while ((++it_func_ptr)->func); \ } What that does is to get either the old array, or the new array and places that array into it_func_ptr. Each element of this array contains the callback (in .func) and the callback's data (in .data). The enabling or disabling of the tracepoint doesn't really make a difference with respect to the order of updating the funcs array. That's because the users of this will either see the old array, the new array, or NULL, in that it_func_ptr. This is how RCU works. The bug we hit was because the static_call was updated separately from the array. That makes it more imperative that you get the order correct. As my email stated, with static_calls we have this: it_func_ptr = \ rcu_dereference_raw((&__tracepoint_##name)->funcs); \ if (it_func_ptr) { \ __data = (it_func_ptr)->data; \ static_call(tp_func_##name)(__data, args); \ } Where the issue is that the static_call which chooses which callback to make, is updated asynchronously from the update of the array. > > >> Now I can finally use: > >> > >> trace-cmd record -e all -P $(pidof io_uring-cp-forever) > >> > >> But that doesn't include the iou-wrk-* threads > >> and the '-c' option seems to only work with forking. > > > > Have you tried it? It should work for threads as well. It hooks to the > > sched_process_fork tracepoint, which should be triggered even when a new > > thread is created. > > > > Or do you mean that you want that process and all its threads too that are > > already running? I could probably have it try to add it via the /proc file > > system in that case. > > > > Can you start the task via trace-cmd? > > > > trace-cmd record -e all -F -c io_uring-cp-forever ... > > I think that would work, but I typically want to analyze a process > that is already running. > > >> Is there a way to specify "trace *all* threads of the given pid"? > >> (Note the threads are comming and going, so it's not possible to > >> specifiy -P more than once) > > > > Right, although, you could append tasks manually to the set_event_pid file > > from another terminal after starting trace-cmd. Once a pid is added to that > > file, all children it makes will also be added. That could be a work around > > until we have trace-cmd do it. > > Sure, but it will always be racy. Not really. Matters what you mean by "racy". You wont be able to "instantaneously" enable a process and all its threads, but you can capture all of them after a given point. As you are attaching to a process already running, you already missed events because you were not yet tracing. But once you have a thread, you will always have it. > > With children, does new threads also count as children or only fork() children? New threads. It's the kernel point of view of a task, which does not differentiate processes from threads. Everything that can be scheduled on a CPU is called a "task". How a task interacts with other tasks is what defines it being a "thread" or a "process". > > > Care to write a bugzilla report for this feature? > > > > https://bugzilla.kernel.org/buglist.cgi?component=Trace-cmd%2FKernelshark&list_id=1088173 > > I may do later... > Thanks, -- Steve