From patchwork Tue Jan 17 04:40:14 2023 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Steven Rostedt X-Patchwork-Id: 44488 Return-Path: Delivered-To: ouuuleilei@gmail.com Received: by 2002:adf:eb09:0:0:0:0:0 with SMTP id s9csp1559211wrn; Mon, 16 Jan 2023 20:43:06 -0800 (PST) X-Google-Smtp-Source: AMrXdXsvJYlFCEUZ0qyN8Y7CxfWW2JUUli4tp9rYuaud87c20bXTmLC7lwnwyzutf7TsGIr74vuU X-Received: by 2002:a17:907:9a86:b0:870:8b4f:8a71 with SMTP id km6-20020a1709079a8600b008708b4f8a71mr1489071ejc.6.1673930586096; Mon, 16 Jan 2023 20:43:06 -0800 (PST) ARC-Seal: i=1; a=rsa-sha256; t=1673930586; cv=none; d=google.com; s=arc-20160816; b=V8JrLldKl8dmQ1rznHbrS3nXHrMTrdmiVX77pZTjKco1EvkZ+hwHaxIkwVu+2njFtC JfYbb98YynpaDnnmmFWEakVluz7YbGl7Sa1oXgYgSS8egHHbn2/ag14u9GLBSHvDYs5/ Mhj7SMECvoOVCBxE0/7kjAUE9ktTveQichL6niW85VhOyfM7f3vkazl58JXNhbSTTyir qBLhrrgYUY0x3tUrzUYkqMK7h3Cpm1u5V6o71td9vgp1N89ZplHzcNqhgVBaQ+G+FBHs MUmB6SRCfeaVBj245DPx3b4CBAhiA1Mpnue9iobJ2h8ruYs2C7Bc78BbEv8RhlAgByMq BsCQ== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816; h=list-id:precedence:mime-version:references:subject:cc:to:from:date :user-agent:message-id; bh=Iz7xVewxXdx2uUtBPdCGUvZn89O8NcD08gTUyZhy+s4=; b=fXd6p7YKw3ofLHRYUDIqks2Bvl3itWQ5SLrdPcmwt7m6O3ma9FNXmGxF/bib2dL8EO ZdZk62Mi+BVearIktnMEPbl8QRJMTVTBhGcSjR2G9VNYKtnIxv6WFuqK7MbfCb5rBXPq 9rJT9mZkJbFs75y22DcxmsHYkhAY3oiCQHCUjCnsl5nCuAunBSgxIYmgXee6ucvFyOno jrexwuv6zqmsx/MGO2L8fxKp7bW2uXPHDHdke3Hv5ez+9Hj0NGip3PeWu6P5T2Omdshz JXyFcZPg4J0qrNIgTumb+f+Qtw28YJm0j6fkuoulpwNwTWCkuk39dcJT25wN6phvU/2d 7K2Q== 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 sg17-20020a170907a41100b0087101bbaf3dsi2551297ejc.750.2023.01.16.20.42.42; Mon, 16 Jan 2023 20:43:06 -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 S235440AbjAQElY (ORCPT + 99 others); Mon, 16 Jan 2023 23:41:24 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:59386 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S235362AbjAQElL (ORCPT ); Mon, 16 Jan 2023 23:41:11 -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 655211A48D; 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 F280C611B6; Tue, 17 Jan 2023 04:41:02 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id 60D40C4339B; Tue, 17 Jan 2023 04:41:02 +0000 (UTC) Received: from rostedt by gandalf.local.home with local (Exim 4.96) (envelope-from ) id 1pHdmP-001rt8-1K; Mon, 16 Jan 2023 23:41:01 -0500 Message-ID: <20230117044101.274203396@goodmis.org> User-Agent: quilt/0.66 Date: Mon, 16 Jan 2023 23:40:14 -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 4/5] tracing/histogram: Document variable stacktrace References: <20230117044010.838685230@goodmis.org> MIME-Version: 1.0 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?1755243437770000443?= X-GMAIL-MSGID: =?utf-8?q?1755243437770000443?= From: "Steven Rostedt (Google)" Add a little documentation (and a useful example) of how a stacktrace can be used within a histogram variable. Signed-off-by: Steven Rostedt (Google) --- Documentation/trace/histogram.rst | 49 +++++++++++++++++++++++++++++++ 1 file changed, 49 insertions(+) diff --git a/Documentation/trace/histogram.rst b/Documentation/trace/histogram.rst index f95459aa984f..5b7f985f35d9 100644 --- a/Documentation/trace/histogram.rst +++ b/Documentation/trace/histogram.rst @@ -1786,6 +1786,8 @@ or assigned to a variable and referenced in a subsequent expression:: # echo 'hist:keys=next_pid:us_per_sec=1000000 ...' >> event/trigger # echo 'hist:keys=next_pid:timestamp_secs=common_timestamp/$us_per_sec ...' >> event/trigger +Variables can even hold stacktraces, which are useful with synthetic events. + 2.2.2 Synthetic Events ---------------------- @@ -1940,6 +1942,53 @@ the ".buckets" modifier and specify a size (in this case groups of 10). Entries: 16 Dropped: 0 +To save stacktraces, create a synthetic event with a field of type "unsigned long[]" +or even just "long[]". For example, to see how long a task is blocked in an +uninterruptible state: + + # cd /sys/kernel/tracing + # 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 + # echo 1 > events/synthetic/block_lat/enable + # 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 + 2.2.3 Hist trigger 'handlers' and 'actions' -------------------------------------------