From patchwork Tue Jan 17 04:40:10 2023 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Steven Rostedt X-Patchwork-Id: 4094 Return-Path: Delivered-To: ouuuleilei@gmail.com Received: by 2002:adf:eb09:0:0:0:0:0 with SMTP id s9csp1559041wrn; Mon, 16 Jan 2023 20:42:35 -0800 (PST) X-Google-Smtp-Source: AMrXdXu+nSOnGpdHBY5w3S1XcBzdNWxC0IBcVv9HVFdqbnMjmC/STUICnCL1AZBDkETiOzIsgpxr X-Received: by 2002:a17:907:bd7:b0:86d:70e7:ab2c with SMTP id ez23-20020a1709070bd700b0086d70e7ab2cmr1262731ejc.15.1673930555192; Mon, 16 Jan 2023 20:42:35 -0800 (PST) ARC-Seal: i=1; a=rsa-sha256; t=1673930555; cv=none; d=google.com; s=arc-20160816; b=ZE6+Tw3Ne8PEFyzziu6pmwGFx8W/xbpbr407GJtUnqx41/6GSsWho/u7fWPsHVvxgt jGSAx0lbT4IGcMYYI+kaOshVq/E4d8q5e7beB+mzWv+OqreS3CCaqHhrRZ/kAxkFQTOw Cm9ij/KjvKd3uSE6+tTa37LtiBCbqEjPG2hNganWUVaM6r/F6XK6rUUKqzgcP6lfWQMe xSAqJx3twVLJXR/KQW3bDE5/yjp5PvJQG69DxUTkkzVnAGw1eDCn0dAERxxLIcHquw9+ j3iBY0GeFaVG0chm+X3RrYAODqrpSDj/TwlkXJB2dHOlMiK4PPD0Badb7b0ZfgJcLjAN uh4Q== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816; h=list-id:precedence:subject:cc:to:from:date:user-agent:message-id; bh=f6MAY5vodNWSYmmCU4Vslq6KEh4nf4obJLSyFZHw4Qk=; b=JpmtykBk0hzqtMLwKRqb4Uf2ekjixPbGJs0Uf4G7fcD06QP9cBbkuHkNIy8hTr94eL 9d/UUQ1WiHxjtpq1M1+UOdMpGvQ5nHvDMSfCMysmz/xeMU0EqpNt0pqRkE7X6eLl6oOq UV9fA1CpFYLE8ZWRKmnBN/YJPd+mjSvzZDT2xSz7x1gAn+I+ztU5tPITZMNVmeDK5j7B eyEfCGzhexoD0VWEcn/TRmwMNsvUa7+1E4Qm/dghjMgG++e8LQiTRUpwGq6yq1/fmWDg wr5n4b3Nclk9y6ACHdPdCQfhHGDQNIkHcKpW2vkNUrOHBsvWp02j73cVHhUyeW4Hu0+Q 47rg== ARC-Authentication-Results: i=1; mx.google.com; spf=pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org Received: from out1.vger.email (out1.vger.email. [2620:137:e000::1:20]) by mx.google.com with ESMTP id gt14-20020a1709072d8e00b0087002a0d8basi7332207ejc.699.2023.01.16.20.42.10; Mon, 16 Jan 2023 20:42:35 -0800 (PST) Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20; Authentication-Results: mx.google.com; spf=pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S235406AbjAQElO (ORCPT + 99 others); Mon, 16 Jan 2023 23:41:14 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:59380 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S235351AbjAQElH (ORCPT ); Mon, 16 Jan 2023 23:41:07 -0500 Received: from dfw.source.kernel.org (dfw.source.kernel.org [IPv6:2604:1380:4641:c500::1]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 1D60318AAE; Mon, 16 Jan 2023 20:41:03 -0800 (PST) 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 dfw.source.kernel.org (Postfix) with ESMTPS id AD0FC60FCA; Tue, 17 Jan 2023 04:41:02 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id 15649C433F1; Tue, 17 Jan 2023 04:41:02 +0000 (UTC) Received: from rostedt by gandalf.local.home with local (Exim 4.96) (envelope-from ) id 1pHdmO-001rrA-2V; Mon, 16 Jan 2023 23:41:00 -0500 Message-ID: <20230117044010.838685230@goodmis.org> User-Agent: quilt/0.66 Date: Mon, 16 Jan 2023 23:40:10 -0500 From: Steven Rostedt To: linux-kernel@vger.kernel.org, linux-trace-kernel@vger.kernel.org Cc: Masami Hiramatsu , Andrew Morton , Ross Zwisler Subject: [PATCH 0/5] tracing/histograms: Pass stacktrace from synthetic start event to end event X-Spam-Status: No, score=-6.7 required=5.0 tests=BAYES_00, HEADER_FROM_DIFFERENT_DOMAINS,RCVD_IN_DNSWL_HI,SPF_HELO_NONE,SPF_PASS autolearn=ham autolearn_force=no version=3.4.6 X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on lindbergh.monkeyblade.net Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org X-getmail-retrieved-from-mailbox: =?utf-8?q?INBOX?= X-GMAIL-THRID: =?utf-8?q?1755243405925229224?= X-GMAIL-MSGID: =?utf-8?q?1755243405925229224?= I finally got around to implementing what I've been wanting to do for a long time! That is to pass stacktraces from the start to the end event of a synthetic event. Specifically, I need to get the stacktrace of a task as it schedules out, but I don't want to see it until it schedules back in and I check the timings to show that it is longer than normal. That is now done with: # echo 's:block_lat pid_t pid; u64 delta; unsigned long[] stack;' > dynamic_events # echo 'hist:keys=next_pid:ts=common_timestamp.usecs,st=stacktrace if prev_state == 2' >> events/sched/sched_switch/trigger # echo 'hist:keys=prev_pid:delta=common_timestamp.usecs-$ts,s=$st:onmax($delta).trace(block_lat,prev_pid,$delta,$s)' >> events/sched/sched_switch/trigger The above creates a synthetic event that will trigger on the max delta of a task blocked in an uninterruptible state. It will show you the stack trace of where that occurred! # echo 1 > events/synthetic/block_lat/enable # ls -lR > /dev/null # cat trace # tracer: nop # # entries-in-buffer/entries-written: 2/2 #P:8 # # _-----=> irqs-off/BH-disabled # / _----=> need-resched # | / _---=> hardirq/softirq # || / _--=> preempt-depth # ||| / _-=> migrate-disable # |||| / delay # TASK-PID CPU# ||||| TIMESTAMP FUNCTION # | | | ||||| | | -0 [005] d..4. 521.164922: block_lat: pid=0 delta=8322 stack=STACK: => __schedule+0x448/0x7b0 => schedule+0x5a/0xb0 => io_schedule+0x42/0x70 => bit_wait_io+0xd/0x60 => __wait_on_bit+0x4b/0x140 => out_of_line_wait_on_bit+0x91/0xb0 => jbd2_journal_commit_transaction+0x1679/0x1a70 => kjournald2+0xa9/0x280 => kthread+0xe9/0x110 => ret_from_fork+0x2c/0x50 <...>-2 [004] d..4. 525.184257: block_lat: pid=2 delta=76 stack=STACK: => __schedule+0x448/0x7b0 => schedule+0x5a/0xb0 => schedule_timeout+0x11a/0x150 => wait_for_completion_killable+0x144/0x1f0 => __kthread_create_on_node+0xe7/0x1e0 => kthread_create_on_node+0x51/0x70 => create_worker+0xcc/0x1a0 => worker_thread+0x2ad/0x380 => kthread+0xe9/0x110 => ret_from_fork+0x2c/0x50 Steven Rostedt (Google) (5): tracing: Simplify calculating entry size using struct_size() tracing: Allow stacktraces to be saved as histogram variables tracing: Allow synthetic events to pass around stacktraces tracing/histogram: Document variable stacktrace tracing/histogram: Add simple tests for stacktrace usage of synthetic events ---- Documentation/trace/histogram.rst | 49 +++++++++++++ kernel/trace/trace.c | 2 +- kernel/trace/trace.h | 4 ++ kernel/trace/trace_events_hist.c | 42 ++++++++--- kernel/trace/trace_events_synth.c | 83 +++++++++++++++++++++- kernel/trace/trace_synth.h | 1 + .../inter-event/trigger-synthetic-event-stack.tc | 24 +++++++ .../inter-event/trigger-synthetic-event-syntax.tc | 6 ++ 8 files changed, 196 insertions(+), 15 deletions(-) create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic-event-stack.tc