From: Luca Ceresoli <luca.ceresoli@bootlin.com>
To: Steven Rostedt <rostedt@goodmis.org>
Cc: Masami Hiramatsu <mhiramat@kernel.org>,
Mathieu Desnoyers <mathieu.desnoyers@efficios.com>,
linux-kernel@vger.kernel.org, linux-trace-kernel@vger.kernel.org,
Liam Girdwood <lgirdwood@gmail.com>,
Mark Brown <broonie@kernel.org>,
Thomas Petazzoni <thomas.petazzoni@bootlin.com>
Subject: Re: TP_printk() bug with %c, and more?
Date: Fri, 15 Mar 2024 19:03:12 +0100 [thread overview]
Message-ID: <20240315190312.2bd6a198@booty> (raw)
In-Reply-To: <20240315132146.29edf416@gandalf.local.home>
Hello Steven,
thanks for the quick feedback!
On Fri, 15 Mar 2024 13:21:46 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:
> On Fri, 15 Mar 2024 17:49:00 +0100
> Luca Ceresoli <luca.ceresoli@bootlin.com> wrote:
>
> > Hello Linux tracing maintainers,
>
> Hi Luca!
>
> >
> > I've come across an unexpected behaviour in the kernel tracing
> > infrastructure that looks like a bug, or maybe two.
> >
> > Cc-ing ASoC maintainers for as it appeared using ASoC traces, but it
> > does not look ASoC-specific.
> >
> > It all started when using this trace-cmd sequence on an ARM64 board
> > running a mainline 6.8.0-rc7 kernel:
> >
> > trace-cmd record -e snd_soc_dapm_path ./my-play
> > trace-cmd report
> >
> > While this produces perfectly valid traces for other asoc events,
> > the snd_soc_dapm_path produces:
> >
> > snd_soc_dapm_path: >c<* MIC1_EN <- (direct) <-
> >
> > instead of the expected:
> >
> > snd_soc_dapm_path: *MIC1 <- (direct) <- MIC1_EN
> >
> > The originating macro is:
> >
> > TP_printk("%c%s %s %s %s %s",
> > (int) __entry->path_node &&
> > (int) __entry->path_connect ? '*' : ' ',
> > __get_str(wname), DAPM_ARROW(__entry->path_dir),
> > __get_str(pname), DAPM_ARROW(__entry->path_dir),
> > __get_str(pnname))
> >
> > It appears as if the %c placeholder always produces the three ">c<"
> > characters, the '*' or ' ' char is printed as the first %s, all the
> > other strings are shifted right by one position and the last string is
> > never printed.
> >
> > On my x86_64 laptop running the default Ubuntu kernel (6.5) I'm able to
> > trace a few events having a '%c' in their TP_printk() macros and the
> > result is:
> >
> > intel_pipe_update_start: dev 0000:00:02.0, pipe >c<, frame=1,
> > scanline=107856, min=2208, max=2154
> >
>
> What does /sys/kernel/tracing/trace show?
It is correct:
intel_pipe_update_start: dev 0000:00:02.0, pipe B, frame=377644, scanline=1466, min=2154, max=2159
> If that's fine, then the bug is in libtraceevent and not the kernel.
>
> I'm testing it out now, and I see %c not being processed properly by
> libtraceevent. I'll take a deeper look.
Thanks.
> > originating from:
> >
> > TP_printk("dev %s, pipe %c, frame=%u, scanline=%u, min=%u, max=%u",
> >
> > Here it looks like the %c produced ">c<" again, but apparently without
> > any shifting.
> >
> > Back on the ARM64 board I found a couple interesting clues.
> >
> > First, using the <debugfs>/tracing/ interface instead of trace-cmd, I'm
> > getting correctly formatted strings:
> >
> > trace-cmd: snd_soc_dapm_path: >c<* HPOUT_L -> (direct) ->
> > debugfs: snd_soc_dapm_path: *HPOUT_L <- (direct) <- HPOUT_POP_SOUND_L
> >
> > Notice the arrows pointing to the opposite direction though. The correct
> > arrow is the one in the debugfs run.
This other issue appears a separate bug however.
Luca
--
Luca Ceresoli, Bootlin
Embedded Linux and Kernel engineering
https://bootlin.com
next prev parent reply other threads:[~2024-03-15 18:03 UTC|newest]
Thread overview: 9+ messages / expand[flat|nested] mbox.gz Atom feed top
2024-03-15 16:49 TP_printk() bug with %c, and more? Luca Ceresoli
2024-03-15 17:21 ` Steven Rostedt
2024-03-15 18:03 ` Luca Ceresoli [this message]
2024-03-15 18:58 ` Steven Rostedt
2024-03-18 15:43 ` Luca Ceresoli
2024-03-18 15:53 ` Steven Rostedt
2024-04-15 8:44 ` Steven Rostedt
2024-04-16 2:08 ` Luca Ceresoli
2024-04-16 4:01 ` Steven Rostedt
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20240315190312.2bd6a198@booty \
--to=luca.ceresoli@bootlin.com \
--cc=broonie@kernel.org \
--cc=lgirdwood@gmail.com \
--cc=linux-kernel@vger.kernel.org \
--cc=linux-trace-kernel@vger.kernel.org \
--cc=mathieu.desnoyers@efficios.com \
--cc=mhiramat@kernel.org \
--cc=rostedt@goodmis.org \
--cc=thomas.petazzoni@bootlin.com \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.