From patchwork Fri Feb 10 21:33:03 2023 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Tom Zanussi X-Patchwork-Id: 13136473 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id 199E6C05027 for ; Fri, 10 Feb 2023 21:33:20 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S233658AbjBJVdS (ORCPT ); Fri, 10 Feb 2023 16:33:18 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:50822 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S233060AbjBJVdR (ORCPT ); Fri, 10 Feb 2023 16:33:17 -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 0B53681CE7; Fri, 10 Feb 2023 13:33:16 -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 9B75F61EB0; Fri, 10 Feb 2023 21:33:15 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id 6A2AEC4339B; Fri, 10 Feb 2023 21:33:14 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1676064795; bh=Q+mebY4c3zacwP7iUcduIJ55Eb1P+wduM9Mf8TUntHs=; h=From:To:Cc:Subject:Date:In-Reply-To:References:From; b=R9pU2S78+U+gZL7D3AKlX4gDAtMTXPiXRcu4Q9p5d2UyenduaIpDmvjMaiDXhPp6b Un8mra23/uOYi+nv1kIzOgljgCFrXAOdhdoeIZrVRzU+aT9vx1rf58iSG+EDht5Wk2 w+M52S4Lwq7zjYkiEQQYw2fWj4HKxb07h/+kcNuZKUNI3NaDU5mAJAdhFKU0KMUi/F nLjtpSxs1gWeo6AdXs2hCewduhNm4SUfRY1AVMeXv0w9MsD0FfOp3rE+rQYx95ZEwp BTtYoiveqt3MS+q0ssy1Al5S1bJM9R81IuHWi//U/mBIXD4Dm5P8+u5xyrVOt+EdHG 52E2rRdhlZhkQ== From: Tom Zanussi To: rostedt@goodmis.org Cc: mhiramat@kernel.org, linux-kernel@vger.kernel.org, linux-trace-kernel@vger.kernel.org, akpm@linux-foundation.org, zwisler@google.com, chinglinyu@google.com Subject: [PATCH 1/4] tracing/histogram: Don't use strlen to find length of stacktrace variables Date: Fri, 10 Feb 2023 15:33:03 -0600 Message-Id: <1ed6906cd9d6477ef2bd8e63c61de20a9ffe64d7.1676063532.git.zanussi@kernel.org> X-Mailer: git-send-email 2.34.1 In-Reply-To: References: MIME-Version: 1.0 Precedence: bulk List-ID: X-Mailing-List: linux-trace-kernel@vger.kernel.org Because stacktraces are saved in dynamic strings, trace_event_raw_event_synth() uses strlen to determine the length of the stack. Stacktraces may contain 0-bytes, though, in the saved addresses, so the length found and passed to reserve() will be too small. Fix this by using the first unsigned long in the stack variables to store the actual number of elements in the stack and have trace_event_raw_event_synth() use that to determine the length of the stack. Signed-off-by: Tom Zanussi --- kernel/trace/trace_events_hist.c | 12 ++++++++---- kernel/trace/trace_events_synth.c | 7 ++++++- 2 files changed, 14 insertions(+), 5 deletions(-) diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c index 888b7a394ce5..76bd105988c6 100644 --- a/kernel/trace/trace_events_hist.c +++ b/kernel/trace/trace_events_hist.c @@ -3135,13 +3135,15 @@ static inline void __update_field_vars(struct tracing_map_elt *elt, size = min(val->size, STR_VAR_LEN_MAX); strscpy(str, val_str, size); } else { + char *stack_start = str + sizeof(unsigned long); int e; - e = stack_trace_save((void *)str, + e = stack_trace_save((void *)stack_start, HIST_STACKTRACE_DEPTH, HIST_STACKTRACE_SKIP); if (e < HIST_STACKTRACE_DEPTH - 1) - ((unsigned long *)str)[e] = 0; + ((unsigned long *)stack_start)[e] = 0; + *((unsigned long *)str) = e; } var_val = (u64)(uintptr_t)str; } @@ -5133,13 +5135,15 @@ static void hist_trigger_elt_update(struct hist_trigger_data *hist_data, size = min(hist_field->size, STR_VAR_LEN_MAX); strscpy(str, val_str, size); } else { + char *stack_start = str + sizeof(unsigned long); int e; - e = stack_trace_save((void *)str, + e = stack_trace_save((void *)stack_start, HIST_STACKTRACE_DEPTH, HIST_STACKTRACE_SKIP); if (e < HIST_STACKTRACE_DEPTH - 1) - ((unsigned long *)str)[e] = 0; + ((unsigned long *)stack_start)[e] = 0; + *((unsigned long *)str) = e; } hist_val = (u64)(uintptr_t)str; } diff --git a/kernel/trace/trace_events_synth.c b/kernel/trace/trace_events_synth.c index d458d7a0dfd7..6209b23c863f 100644 --- a/kernel/trace/trace_events_synth.c +++ b/kernel/trace/trace_events_synth.c @@ -538,7 +538,12 @@ static notrace void trace_event_raw_event_synth(void *__data, val_idx = var_ref_idx[field_pos]; str_val = (char *)(long)var_ref_vals[val_idx]; - len = kern_fetch_store_strlen((unsigned long)str_val); + if (event->dynamic_fields[i]->is_stack) { + len = *((unsigned long *)str_val); + len *= sizeof(unsigned long); + } else { + len = kern_fetch_store_strlen((unsigned long)str_val); + } fields_size += len; } From patchwork Fri Feb 10 21:33:04 2023 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Tom Zanussi X-Patchwork-Id: 13136474 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id A0021C636D4 for ; Fri, 10 Feb 2023 21:33:22 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S232755AbjBJVdV (ORCPT ); Fri, 10 Feb 2023 16:33:21 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:50856 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S233714AbjBJVdT (ORCPT ); Fri, 10 Feb 2023 16:33:19 -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 E96F581CF9; Fri, 10 Feb 2023 13:33:17 -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 80BCA61EAC; Fri, 10 Feb 2023 21:33:17 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id 49633C433A0; Fri, 10 Feb 2023 21:33:16 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1676064796; bh=8Wp51GEJhxkWAv208sw812gEC1Ns3UsGlw8XJXAOBfc=; h=From:To:Cc:Subject:Date:In-Reply-To:References:From; b=RacDxOuoU9ykbZJl9ucZfUqfshpJpkZoDTumdpuwWcjQr8S8HB2GpZPXbPLcVmvpj YZ1Jn+b6D5VH0VCCPSloBKsQc1ATaCVMigI/+s2JScily4sPmdIRwThBpK4Jn9zs5f hnjptz5tcWoloGXHcpoFsHZ6QdPohOhNjDn1yoZteIb/B8y9t0g8HTrPtoBpCiHxHN t885swjR0SDMmh9wUHgcAojmekFxRTtH58rkFevDd4grlwDS1360GvypIB4Qvuewjy qDWWS0WFcmCpIThOb8mK7oitnWHHSj61IUqBEeQGGaEB8p757aGso1yyX8tfB6E9mE KxjwiAmgmBwiA== From: Tom Zanussi To: rostedt@goodmis.org Cc: mhiramat@kernel.org, linux-kernel@vger.kernel.org, linux-trace-kernel@vger.kernel.org, akpm@linux-foundation.org, zwisler@google.com, chinglinyu@google.com Subject: [PATCH 2/4] tracing/histogram: Fix a few problems with stacktrace variable printing Date: Fri, 10 Feb 2023 15:33:04 -0600 Message-Id: <60bebd4e546728e012a7a2bcbf58716d48ba6edb.1676063532.git.zanussi@kernel.org> X-Mailer: git-send-email 2.34.1 In-Reply-To: References: MIME-Version: 1.0 Precedence: bulk List-ID: X-Mailing-List: linux-trace-kernel@vger.kernel.org Currently, there are a few problems when printing hist triggers and trace output when using stacktrace variables. This fixes the problems seen below: # echo 'hist:keys=delta.buckets=100,stack.stacktrace:sort=delta' > /sys/kernel/debug/tracing/events/synthetic/block_lat/trigger # cat /sys/kernel/debug/tracing/events/synthetic/block_lat/trigger hist:keys=delta.buckets=100,stacktrace:vals=hitcount:sort=delta.buckets=100:size=2048 [active] # echo 'hist:keys=next_pid:ts=common_timestamp.usecs,st=stacktrace if prev_state == 2' >> /sys/kernel/debug/tracing/events/sched/sched_switch/trigger # cat /sys/kernel/debug/tracing/events/sched/sched_switch/trigger hist:keys=next_pid:vals=hitcount:ts=common_timestamp.usecs,st=stacktrace.stacktrace:sort=hitcount:size=2048:clock=global if prev_state == 2 [active] and also in the trace output (should be stack.stacktrace): { delta: ~ 100-199, stacktrace __schedule+0xa19/0x1520 Signed-off-by: Tom Zanussi --- kernel/trace/trace_events_hist.c | 26 ++++++++++++++++++-------- 1 file changed, 18 insertions(+), 8 deletions(-) diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c index 76bd105988c6..a58380702491 100644 --- a/kernel/trace/trace_events_hist.c +++ b/kernel/trace/trace_events_hist.c @@ -1356,9 +1356,12 @@ static const char *hist_field_name(struct hist_field *field, field_name = field->name; } else if (field->flags & HIST_FIELD_FL_TIMESTAMP) field_name = "common_timestamp"; - else if (field->flags & HIST_FIELD_FL_STACKTRACE) - field_name = "stacktrace"; - else if (field->flags & HIST_FIELD_FL_HITCOUNT) + else if (field->flags & HIST_FIELD_FL_STACKTRACE) { + if (field->field) + field_name = field->field->name; + else + field_name = "stacktrace"; + } else if (field->flags & HIST_FIELD_FL_HITCOUNT) field_name = "hitcount"; if (field_name == NULL) @@ -5334,7 +5337,10 @@ static void hist_trigger_print_key(struct seq_file *m, seq_printf(m, "%s: %-30s[%3llu]", field_name, syscall_name, uval); } else if (key_field->flags & HIST_FIELD_FL_STACKTRACE) { - seq_puts(m, "stacktrace:\n"); + if (key_field->field) + seq_printf(m, "%s.stacktrace", key_field->field->name); + else + seq_puts(m, "stacktrace:\n"); hist_trigger_stacktrace_print(m, key + key_field->offset, HIST_STACKTRACE_DEPTH); @@ -5879,7 +5885,8 @@ static void hist_field_print(struct seq_file *m, struct hist_field *hist_field) if (hist_field->flags) { if (!(hist_field->flags & HIST_FIELD_FL_VAR_REF) && - !(hist_field->flags & HIST_FIELD_FL_EXPR)) { + !(hist_field->flags & HIST_FIELD_FL_EXPR) && + !(hist_field->flags & HIST_FIELD_FL_STACKTRACE)) { const char *flags = get_hist_field_flags(hist_field); if (flags) @@ -5912,9 +5919,12 @@ static int event_hist_trigger_print(struct seq_file *m, if (i > hist_data->n_vals) seq_puts(m, ","); - if (field->flags & HIST_FIELD_FL_STACKTRACE) - seq_puts(m, "stacktrace"); - else + if (field->flags & HIST_FIELD_FL_STACKTRACE) { + if (field->field) + seq_printf(m, "%s.stacktrace", field->field->name); + else + seq_puts(m, "stacktrace"); + } else hist_field_print(m, field); } From patchwork Fri Feb 10 21:33:05 2023 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Tom Zanussi X-Patchwork-Id: 13136475 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id 432ECC64EC7 for ; Fri, 10 Feb 2023 21:33:23 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S233060AbjBJVdW (ORCPT ); Fri, 10 Feb 2023 16:33:22 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:50882 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S233724AbjBJVdV (ORCPT ); Fri, 10 Feb 2023 16:33:21 -0500 Received: from dfw.source.kernel.org (dfw.source.kernel.org [139.178.84.217]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 9C02481CEF; Fri, 10 Feb 2023 13:33:19 -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 1D47D61EAC; Fri, 10 Feb 2023 21:33:19 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id DAF72C433EF; Fri, 10 Feb 2023 21:33:17 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1676064798; bh=sRSOdM4Wfg7Ma3bCU80sAVGk7VjXjySJtZlopisAO0k=; h=From:To:Cc:Subject:Date:In-Reply-To:References:From; b=UA99pG83VqBN1lTlIczV3HRqBXJRDR8Pkom0L6SNZpPi44QqQ5NJr1IQXQ0rrmBdj O/3K8xmoZKQoTDNZVGE+wsmfCOkPa7AXhJK3x/GR7eQRc5LuIyKLiL1ZcwRHrReJiy H76jeeBC7RNBGy1aa97xUsGQYQOzBpxO065P+yOBE70Z8ZSDoxDivMjndBa6c1vxUE wHOE8vRUMNTZsWi94Dh8NHRwrEACsNND3AT74ackDTGBQfSoTEVSz9rMdSxRTpqWqw mra+2SkK3L8lBoK6Q+TxHSkD3nUTwfzvnpuam1u2lmIrlVNEhaftJzfwm1bMqhqcl2 9fGPTWHGU/C5A== From: Tom Zanussi To: rostedt@goodmis.org Cc: mhiramat@kernel.org, linux-kernel@vger.kernel.org, linux-trace-kernel@vger.kernel.org, akpm@linux-foundation.org, zwisler@google.com, chinglinyu@google.com Subject: [PATCH 3/4] tracing/histogram: Fix stacktrace key Date: Fri, 10 Feb 2023 15:33:05 -0600 Message-Id: <11aa614c82976adbfa4ea763dbe885b5fb01d59c.1676063532.git.zanussi@kernel.org> X-Mailer: git-send-email 2.34.1 In-Reply-To: References: MIME-Version: 1.0 Precedence: bulk List-ID: X-Mailing-List: linux-trace-kernel@vger.kernel.org The current code will always use the current stacktrace as a key even if a stacktrace contained in a specific event field was specified. For example, we expect to use the 'unsigned long[] stack' field in the below event in the histogram: # echo 's:block_lat pid_t pid; u64 delta; unsigned long[] stack;' > /sys/kernel/debug/tracing/dynamic_events # echo 'hist:keys=delta.buckets=100,stack.stacktrace:sort=delta' > /sys/kernel/debug/tracing/events/synthetic/block_lat/trigger But in fact, when we type out the trigger, we see that it's using the plain old global 'stacktrace' as the key, which is just the stacktrace when the event was hit and not the stacktrace contained in the event, which is what we want: # cat /sys/kernel/debug/tracing/events/synthetic/block_lat/trigger hist:keys=delta.buckets=100,stacktrace:vals=hitcount:sort=delta.buckets=100:size=2048 [active] And in fact, there's no code to actually retrieve it from the event, so we need to add HIST_FIELD_FN_STACK and hist_field_stack() to get it and hook it into the trigger code. For now, since the stack is just using dynamic strings, this could just use the dynamic string function, but it seems cleaner to have a dedicated function an be able to tweak independently as necessary. Signed-off-by: Tom Zanussi --- kernel/trace/trace_events_hist.c | 34 +++++++++++++++++++++++++++++--- 1 file changed, 31 insertions(+), 3 deletions(-) diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c index a58380702491..eb812cfdaa88 100644 --- a/kernel/trace/trace_events_hist.c +++ b/kernel/trace/trace_events_hist.c @@ -135,6 +135,7 @@ enum hist_field_fn { HIST_FIELD_FN_DIV_NOT_POWER2, HIST_FIELD_FN_DIV_MULT_SHIFT, HIST_FIELD_FN_EXECNAME, + HIST_FIELD_FN_STACK, }; /* @@ -1982,7 +1983,10 @@ static struct hist_field *create_hist_field(struct hist_trigger_data *hist_data, } if (flags & HIST_FIELD_FL_STACKTRACE) { - hist_field->fn_num = HIST_FIELD_FN_NOP; + if (field) + hist_field->fn_num = HIST_FIELD_FN_STACK; + else + hist_field->fn_num = HIST_FIELD_FN_NOP; hist_field->size = HIST_STACKTRACE_SIZE; hist_field->type = kstrdup_const("unsigned long[]", GFP_KERNEL); if (!hist_field->type) @@ -4269,6 +4273,19 @@ static u64 hist_field_execname(struct hist_field *hist_field, return (u64)(unsigned long)(elt_data->comm); } +static u64 hist_field_stack(struct hist_field *hist_field, + struct tracing_map_elt *elt, + struct trace_buffer *buffer, + struct ring_buffer_event *rbe, + void *event) +{ + u32 str_item = *(u32 *)(event + hist_field->field->offset); + int str_loc = str_item & 0xffff; + char *addr = (char *)(event + str_loc); + + return (u64)(unsigned long)addr; +} + static u64 hist_fn_call(struct hist_field *hist_field, struct tracing_map_elt *elt, struct trace_buffer *buffer, @@ -4332,6 +4349,8 @@ static u64 hist_fn_call(struct hist_field *hist_field, return div_by_mult_and_shift(hist_field, elt, buffer, rbe, event); case HIST_FIELD_FN_EXECNAME: return hist_field_execname(hist_field, elt, buffer, rbe, event); + case HIST_FIELD_FN_STACK: + return hist_field_stack(hist_field, elt, buffer, rbe, event); default: return 0; } @@ -5233,8 +5252,17 @@ static void event_hist_trigger(struct event_trigger_data *data, if (key_field->flags & HIST_FIELD_FL_STACKTRACE) { memset(entries, 0, HIST_STACKTRACE_SIZE); - stack_trace_save(entries, HIST_STACKTRACE_DEPTH, - HIST_STACKTRACE_SKIP); + if (key_field->field) { + unsigned long *stack, n_entries; + + field_contents = hist_fn_call(key_field, elt, buffer, rbe, rec); + stack = (unsigned long *)field_contents; + n_entries = *stack; + memcpy(entries, ++stack, n_entries * sizeof(unsigned long)); + } else { + stack_trace_save(entries, HIST_STACKTRACE_DEPTH, + HIST_STACKTRACE_SKIP); + } key = entries; } else { field_contents = hist_fn_call(key_field, elt, buffer, rbe, rec); From patchwork Fri Feb 10 21:33:06 2023 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Tom Zanussi X-Patchwork-Id: 13136476 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id BD58FC636D4 for ; Fri, 10 Feb 2023 21:33:28 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S233735AbjBJVd1 (ORCPT ); Fri, 10 Feb 2023 16:33:27 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:50936 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S233740AbjBJVdW (ORCPT ); Fri, 10 Feb 2023 16:33:22 -0500 Received: from dfw.source.kernel.org (dfw.source.kernel.org [139.178.84.217]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 0247881CE3; Fri, 10 Feb 2023 13:33:21 -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 905CF61E97; Fri, 10 Feb 2023 21:33:20 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id 531B6C433D2; Fri, 10 Feb 2023 21:33:19 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1676064800; bh=Yvn/2pRR/pLsXGeQzzHurpdq6EEdh7KDrfPjbztvlr4=; h=From:To:Cc:Subject:Date:In-Reply-To:References:From; b=WQvvMq34Q1PruRtq5L/V+840AuiNNWY167Djxa8kDJ+nt8FyTVJj0IYiQ3SUOqQnP 0gmTDQOxfujtDFcMU4MTj3N7V34n+paNi/MpdZGf634B9jkPbwcO2caGYFjxy+fBWP 2UHxASNLL9y5gWpXCSqV3C5I6kcCaJAOYHRm2tt1E+jWC23bQO2nUHJeC6MFAE48S7 yYghAyNH7C2AGdXxRnw8kD70aYqHTPyyZiWAcdRs6xXEWjTf8BpQKBqqS1obmCcnSF 9+0nnT2i2gyAL0XYMa+QHqHT4BGQP+zHOewgCF5ai6lmjhEWku2PunhDcPz1YmmkLq yVJaqO5E+6tcQ== From: Tom Zanussi To: rostedt@goodmis.org Cc: mhiramat@kernel.org, linux-kernel@vger.kernel.org, linux-trace-kernel@vger.kernel.org, akpm@linux-foundation.org, zwisler@google.com, chinglinyu@google.com Subject: [PATCH 4/4] tracing/histogram: Fix stacktrace histogram Documententation Date: Fri, 10 Feb 2023 15:33:06 -0600 Message-Id: X-Mailer: git-send-email 2.34.1 In-Reply-To: References: MIME-Version: 1.0 Precedence: bulk List-ID: X-Mailing-List: linux-trace-kernel@vger.kernel.org Fix a small problem with the histogram specification in the Documentation, and change the example to show output using a stacktrace field rather than the global stacktrace. Signed-off-by: Tom Zanussi --- Documentation/trace/histogram.rst | 156 +++++++++++++++++------------- 1 file changed, 90 insertions(+), 66 deletions(-) diff --git a/Documentation/trace/histogram.rst b/Documentation/trace/histogram.rst index 5c391328b9bb..d024cdae4fbd 100644 --- a/Documentation/trace/histogram.rst +++ b/Documentation/trace/histogram.rst @@ -1992,82 +1992,106 @@ uninterruptible state: A synthetic event that has a stacktrace field may use it as a key in histogram: - # echo 'hist:delta.buckets=100,stack.stacktrace:sort=delta' > events/synthetic/block_lat/trigger + # echo 'hist:keys=delta.buckets=100,stack.stacktrace:sort=delta' > events/synthetic/block_lat/trigger # cat events/synthetic/block_lat/hist # event histogram # - # trigger info: hist:keys=delta.buckets=100,stacktrace:vals=hitcount:sort=delta.buckets=100:size=2048 [active] + # trigger info: hist:keys=delta.buckets=100,stack.stacktrace:vals=hitcount:sort=delta.buckets=100:size=2048 [active] # - - { delta: ~ 0-99, stacktrace: - event_hist_trigger+0x464/0x480 - event_triggers_call+0x52/0xe0 - trace_event_buffer_commit+0x193/0x250 - trace_event_raw_event_sched_switch+0xfc/0x150 - __traceiter_sched_switch+0x41/0x60 - __schedule+0x448/0x7b0 - schedule_idle+0x26/0x40 - cpu_startup_entry+0x19/0x20 - start_secondary+0xed/0xf0 - secondary_startup_64_no_verify+0xe0/0xeb - } hitcount: 6 - { delta: ~ 0-99, stacktrace: - event_hist_trigger+0x464/0x480 - event_triggers_call+0x52/0xe0 - trace_event_buffer_commit+0x193/0x250 - trace_event_raw_event_sched_switch+0xfc/0x150 - __traceiter_sched_switch+0x41/0x60 - __schedule+0x448/0x7b0 - schedule_idle+0x26/0x40 - cpu_startup_entry+0x19/0x20 - __pfx_kernel_init+0x0/0x10 - arch_call_rest_init+0xa/0x24 - start_kernel+0x964/0x98d - secondary_startup_64_no_verify+0xe0/0xeb + { delta: ~ 0-99, stack.stacktrace __schedule+0xa19/0x1520 + schedule+0x6b/0x110 + io_schedule+0x46/0x80 + bit_wait_io+0x11/0x80 + __wait_on_bit+0x4e/0x120 + out_of_line_wait_on_bit+0x8d/0xb0 + __wait_on_buffer+0x33/0x40 + jbd2_journal_commit_transaction+0x155a/0x19b0 + kjournald2+0xab/0x270 + kthread+0xfa/0x130 + ret_from_fork+0x29/0x50 + } hitcount: 1 + { delta: ~ 0-99, stack.stacktrace __schedule+0xa19/0x1520 + schedule+0x6b/0x110 + io_schedule+0x46/0x80 + rq_qos_wait+0xd0/0x170 + wbt_wait+0x9e/0xf0 + __rq_qos_throttle+0x25/0x40 + blk_mq_submit_bio+0x2c3/0x5b0 + __submit_bio+0xff/0x190 + submit_bio_noacct_nocheck+0x25b/0x2b0 + submit_bio_noacct+0x20b/0x600 + submit_bio+0x28/0x90 + ext4_bio_write_page+0x1e0/0x8c0 + mpage_submit_page+0x60/0x80 + mpage_process_page_bufs+0x16c/0x180 + mpage_prepare_extent_to_map+0x23f/0x530 + } hitcount: 1 + { delta: ~ 0-99, stack.stacktrace __schedule+0xa19/0x1520 + schedule+0x6b/0x110 + schedule_hrtimeout_range_clock+0x97/0x110 + schedule_hrtimeout_range+0x13/0x20 + usleep_range_state+0x65/0x90 + __intel_wait_for_register+0x1c1/0x230 [i915] + intel_psr_wait_for_idle_locked+0x171/0x2a0 [i915] + intel_pipe_update_start+0x169/0x360 [i915] + intel_update_crtc+0x112/0x490 [i915] + skl_commit_modeset_enables+0x199/0x600 [i915] + intel_atomic_commit_tail+0x7c4/0x1080 [i915] + intel_atomic_commit_work+0x12/0x20 [i915] + process_one_work+0x21c/0x3f0 + worker_thread+0x50/0x3e0 + kthread+0xfa/0x130 } hitcount: 3 - { delta: ~ 0-99, stacktrace: - event_hist_trigger+0x464/0x480 - event_triggers_call+0x52/0xe0 - trace_event_buffer_commit+0x193/0x250 - trace_event_raw_event_sched_switch+0xfc/0x150 - __traceiter_sched_switch+0x41/0x60 - __schedule+0x448/0x7b0 - schedule+0x5a/0xb0 - worker_thread+0xaf/0x380 - kthread+0xe9/0x110 - ret_from_fork+0x2c/0x50 + { delta: ~ 0-99, stack.stacktrace __schedule+0xa19/0x1520 + schedule+0x6b/0x110 + schedule_timeout+0x11e/0x160 + __wait_for_common+0x8f/0x190 + wait_for_completion+0x24/0x30 + __flush_work.isra.0+0x1cc/0x360 + flush_work+0xe/0x20 + drm_mode_rmfb+0x18b/0x1d0 [drm] + drm_mode_rmfb_ioctl+0x10/0x20 [drm] + drm_ioctl_kernel+0xb8/0x150 [drm] + drm_ioctl+0x243/0x560 [drm] + __x64_sys_ioctl+0x92/0xd0 + do_syscall_64+0x59/0x90 + entry_SYSCALL_64_after_hwframe+0x72/0xdc } hitcount: 1 - { delta: ~ 100-199, stacktrace: - event_hist_trigger+0x464/0x480 - event_triggers_call+0x52/0xe0 - trace_event_buffer_commit+0x193/0x250 - trace_event_raw_event_sched_switch+0xfc/0x150 - __traceiter_sched_switch+0x41/0x60 - __schedule+0x448/0x7b0 - schedule_idle+0x26/0x40 - cpu_startup_entry+0x19/0x20 - start_secondary+0xed/0xf0 - secondary_startup_64_no_verify+0xe0/0xeb - } hitcount: 15 - [..] - { delta: ~ 8500-8599, stacktrace: - event_hist_trigger+0x464/0x480 - event_triggers_call+0x52/0xe0 - trace_event_buffer_commit+0x193/0x250 - trace_event_raw_event_sched_switch+0xfc/0x150 - __traceiter_sched_switch+0x41/0x60 - __schedule+0x448/0x7b0 - schedule_idle+0x26/0x40 - cpu_startup_entry+0x19/0x20 - start_secondary+0xed/0xf0 - secondary_startup_64_no_verify+0xe0/0xeb + { delta: ~ 0-99, stack.stacktrace __schedule+0xa19/0x1520 + schedule+0x6b/0x110 + schedule_timeout+0x87/0x160 + __wait_for_common+0x8f/0x190 + wait_for_completion_timeout+0x1d/0x30 + drm_atomic_helper_wait_for_flip_done+0x57/0x90 [drm_kms_helper] + intel_atomic_commit_tail+0x8ce/0x1080 [i915] + intel_atomic_commit_work+0x12/0x20 [i915] + process_one_work+0x21c/0x3f0 + worker_thread+0x50/0x3e0 + kthread+0xfa/0x130 + ret_from_fork+0x29/0x50 + } hitcount: 1 + { delta: ~ 100-199, stack.stacktrace __schedule+0xa19/0x1520 + schedule+0x6b/0x110 + schedule_hrtimeout_range_clock+0x97/0x110 + schedule_hrtimeout_range+0x13/0x20 + usleep_range_state+0x65/0x90 + pci_set_low_power_state+0x17f/0x1f0 + pci_set_power_state+0x49/0x250 + pci_finish_runtime_suspend+0x4a/0x90 + pci_pm_runtime_suspend+0xcb/0x1b0 + __rpm_callback+0x48/0x120 + rpm_callback+0x67/0x70 + rpm_suspend+0x167/0x780 + rpm_idle+0x25a/0x380 + pm_runtime_work+0x93/0xc0 + process_one_work+0x21c/0x3f0 } hitcount: 1 Totals: - Hits: 89 - Entries: 11 - Dropped: 0 + Hits: 10 + Entries: 7 + Dropped: 0 2.2.3 Hist trigger 'handlers' and 'actions' -------------------------------------------