From patchwork Mon Dec 18 21:31:17 2023 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Steven Rostedt X-Patchwork-Id: 180655 Return-Path: Delivered-To: ouuuleilei@gmail.com Received: by 2002:a05:7300:24d3:b0:fb:cd0c:d3e with SMTP id r19csp1544390dyi; Mon, 18 Dec 2023 13:30:37 -0800 (PST) X-Google-Smtp-Source: AGHT+IHba6qKc4YQSZmn8VImpx3uCRe1rTiZ9K5d9A6i0gl5jxbVxBkjf55FdFrNXNJNTOt+L4AV X-Received: by 2002:a17:90a:9304:b0:28b:2b:b038 with SMTP id p4-20020a17090a930400b0028b002bb038mr5175763pjo.77.1702935037453; Mon, 18 Dec 2023 13:30:37 -0800 (PST) ARC-Seal: i=1; a=rsa-sha256; t=1702935037; cv=none; d=google.com; s=arc-20160816; b=IbbLyS28GUgcRJ4tuwAhKgivR68j3jm17+J3EoIR4z6b32W1QrimPD9oGq5BV8wrUl huFsMENur6RBQYrLNC+Pjx0MweMwx/WVZGwH/EPUD9IBw8MwPTCMwB8xJK/+qLAAw0pr hXze7h8Kgh5KgWrLcQ6J8qDN2Z/EaJQC03d5E95N4iceSK+r5+vvs/8+XPrgg047zSrE 1rnzPk3ajic9Mb9rK2MVrH/IsyMHem4SETNnXjRwnadfchgMGNR0yXrfzabGBT5nNlr3 Nlkcw7nKjcqw7PM00QO/+b+uVPHdRJji4lRmk4L++g8M3b1IyKeUnoBG/16YjVeCsq+4 TZdA== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816; h=content-transfer-encoding:mime-version:list-unsubscribe :list-subscribe:list-id:precedence:message-id:subject:cc:to:from :date; bh=WyaufHB6jhxabJBRu05c9p519Ba+cDyhsMW7Ony5H+s=; fh=S/OrYSeOA1aSrBSqnLKrkyLzV3RDOIc0IFkfjbF7p6w=; b=CAsIODyEo006AfWHVjN2GU8hizpSVd09XgQ7K9hJDYAgsM9sMm7RL4jNinJy0qRoAi UrJy3t+q3ZMOLypZRFKZvmfsWfWx6BCzysAazENzBCiI4AyjtUQlEZ8iLDfkFpJ96btL FAz1cy3qxU2bQhtjtidHb+3Ez1ytf4I6lkAbJ2qt0aP+VUVtbv0xyPafOe7qVIn92YKY Bf33HzcKeLlNhxOsi/AtTPdzKT4Hgaj2ztApXqBhhg2M+MTiUZ4KTfyrIrfMW38jPmca MYZ4AU0FLdhDoYpg1Om9lwZLWej3ILtOWMn5i71Jf59FR5ONHUa8fvX5TO0MSsmma/8M w8Eg== ARC-Authentication-Results: i=1; mx.google.com; spf=pass (google.com: domain of linux-kernel+bounces-4408-ouuuleilei=gmail.com@vger.kernel.org designates 2604:1380:45e3:2400::1 as permitted sender) smtp.mailfrom="linux-kernel+bounces-4408-ouuuleilei=gmail.com@vger.kernel.org" Received: from sv.mirrors.kernel.org (sv.mirrors.kernel.org. [2604:1380:45e3:2400::1]) by mx.google.com with ESMTPS id b9-20020a17090ae38900b0028baf60257csi521609pjz.157.2023.12.18.13.30.37 for (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Mon, 18 Dec 2023 13:30:37 -0800 (PST) Received-SPF: pass (google.com: domain of linux-kernel+bounces-4408-ouuuleilei=gmail.com@vger.kernel.org designates 2604:1380:45e3:2400::1 as permitted sender) client-ip=2604:1380:45e3:2400::1; Authentication-Results: mx.google.com; spf=pass (google.com: domain of linux-kernel+bounces-4408-ouuuleilei=gmail.com@vger.kernel.org designates 2604:1380:45e3:2400::1 as permitted sender) smtp.mailfrom="linux-kernel+bounces-4408-ouuuleilei=gmail.com@vger.kernel.org" Received: from smtp.subspace.kernel.org (wormhole.subspace.kernel.org [52.25.139.140]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by sv.mirrors.kernel.org (Postfix) with ESMTPS id 2A803282B1F for ; Mon, 18 Dec 2023 21:30:37 +0000 (UTC) Received: from localhost.localdomain (localhost.localdomain [127.0.0.1]) by smtp.subspace.kernel.org (Postfix) with ESMTP id 11C3074E05; Mon, 18 Dec 2023 21:30:25 +0000 (UTC) X-Original-To: linux-kernel@vger.kernel.org Received: from smtp.kernel.org (aws-us-west-2-korg-mail-1.web.codeaurora.org [10.30.226.201]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by smtp.subspace.kernel.org (Postfix) with ESMTPS id 8B00042361; Mon, 18 Dec 2023 21:30:23 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id A2A5BC433C7; Mon, 18 Dec 2023 21:30:22 +0000 (UTC) Date: Mon, 18 Dec 2023 16:31:17 -0500 From: Steven Rostedt To: LKML , Linux Trace Kernel Cc: Masami Hiramatsu , Mark Rutland , Mathieu Desnoyers , Joel Fernandes Subject: [PATCH] ring-buffer: Add interrupt information to dump of data sub-buffer Message-ID: <20231218163117.74292291@gandalf.local.home> X-Mailer: Claws Mail 3.19.1 (GTK+ 2.24.33; x86_64-pc-linux-gnu) Precedence: bulk X-Mailing-List: linux-kernel@vger.kernel.org List-Id: List-Subscribe: List-Unsubscribe: MIME-Version: 1.0 X-getmail-retrieved-from-mailbox: INBOX X-GMAIL-THRID: 1785656810276250907 X-GMAIL-MSGID: 1785656810276250907 From: "Steven Rostedt (Google)" When the ring buffer timestamp verifier triggers, it dumps the content of the sub-buffer. But currently it only dumps the timestamps and the offset of the data as well as the deltas. It would be even more informative if the event data also showed the interrupt context level it was in. That is, if each event showed that the event was written in normal, softirq, irq or NMI context. Then a better idea about how the events may have been interrupted from each other. As the payload of the ring buffer is really a black box of the ring buffer, just assume that if the payload is larger than a trace entry, that it is a trace entry. As trace entries have the interrupt context information saved in a flags field, look at that location and report the output of the flags. If the payload is not a trace entry, there's no way to really know, and the information will be garbage. But that's OK, because this is for debugging only (this output is not used in production as the buffer check that calls it causes a huge overhead to the tracing). This information, when available, is crucial for debugging timestamp issues. If it's garbage, it will also be pretty obvious that its garbage too. As this output usually happens in kselftests of the tracing code, the user will know what the payload is at the time. Suggested-by: Joel Fernandes (Google) Signed-off-by: Steven Rostedt (Google) --- kernel/trace/ring_buffer.c | 52 ++++++++++++++++++++++++++++++++++++-- 1 file changed, 50 insertions(+), 2 deletions(-) diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c index 3eda81ed7d7e..ca1d9fcefaba 100644 --- a/kernel/trace/ring_buffer.c +++ b/kernel/trace/ring_buffer.c @@ -3225,6 +3225,53 @@ EXPORT_SYMBOL_GPL(ring_buffer_unlock_commit); #define CHECK_FULL_PAGE 1L #ifdef CONFIG_RING_BUFFER_VALIDATE_TIME_DELTAS + +/* Assume this is an trace event */ +static const char *show_flags(struct ring_buffer_event *event) +{ + struct trace_entry *entry; + int bits = 0; + const char *type[] = { + ".", // 0 + "s", // 1 + "h", // 2 + "Hs", // 3 + "n", // 4 + "Ns", // 5 + "Nh", // 6 + "NHs", // 7 + }; + + if (rb_event_data_length(event) - RB_EVNT_HDR_SIZE < sizeof(*entry)) + return "X"; + + entry = ring_buffer_event_data(event); + + if (entry->flags & TRACE_FLAG_SOFTIRQ) + bits |= 1; + + if (entry->flags & TRACE_FLAG_HARDIRQ) + bits |= 2; + + if (entry->flags & TRACE_FLAG_NMI) + bits |= 4; + + return type[bits]; +} + +static const char *show_irq(struct ring_buffer_event *event) +{ + struct trace_entry *entry; + + if (rb_event_data_length(event) - RB_EVNT_HDR_SIZE < sizeof(*entry)) + return ""; + + entry = ring_buffer_event_data(event); + if (entry->flags & TRACE_FLAG_IRQS_OFF) + return "d"; + return ""; +} + static void dump_buffer_page(struct buffer_data_page *bpage, struct rb_event_info *info, unsigned long tail) @@ -3264,8 +3311,9 @@ static void dump_buffer_page(struct buffer_data_page *bpage, case RINGBUF_TYPE_DATA: ts += event->time_delta; - pr_warn(" 0x%x: [%lld] delta:%d\n", - e, ts, event->time_delta); + pr_warn(" 0x%x: [%lld] delta:%d %s%s\n", + e, ts, event->time_delta, + show_flags(event), show_irq(event)); break; default: