[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <CAPcyv4gS7iDrahX9i0PGMhR4k14XVkrCyGk3ZX8JEtO9RAQDhw@mail.gmail.com>
Date: Tue, 20 Apr 2021 23:27:19 -0700
From: Dan Williams <dan.j.williams@...el.com>
To: Steven Rostedt <rostedt@...dmis.org>
Cc: "fweisbec@...il.com" <fweisbec@...il.com>,
"jeyu@...nel.org" <jeyu@...nel.org>,
"mathieu.desnoyers@...icios.com" <mathieu.desnoyers@...icios.com>,
"linux-kernel@...r.kernel.org" <linux-kernel@...r.kernel.org>,
"mingo@...e.hu" <mingo@...e.hu>,
"chris@...is-wilson.co.uk" <chris@...is-wilson.co.uk>,
"yuanhan.liu@...ux.intel.com" <yuanhan.liu@...ux.intel.com>,
"Grumbach, Emmanuel" <emmanuel.grumbach@...el.com>
Subject: Re: [PATCH][RFC] tracing: Enable tracepoints via module parameters
On Tue, Apr 20, 2021 at 1:33 PM Steven Rostedt <rostedt@...dmis.org> wrote:
>
> On Tue, 20 Apr 2021 12:54:39 -0700
> Dan Williams <dan.j.williams@...el.com> wrote:
>
> > On Tue, Apr 20, 2021 at 5:55 AM Steven Rostedt <rostedt@...dmis.org> wrote:
> > > >
> > > > The dev_dbg() filter language is attractive, it's too bad
> > >
> > > Not sure what you mean by that. What filter language. Tracepoints do have a
> > > pretty good filtering too.
> >
> > I'm trying to replicate dev_dbg() usability with tracing. So, when
> > people say "don't use dev_dbg() for that" that tracing can reliably
> > replace everything that dev_dbg() was offering. What I think that
> > looks like is the ability to turn on function tracing by a function
> > name glob in addition to any tracepoints in those same functions all
> > from the kernel boot command line, or a module parameter.
>
> You can enable functions on the kernel command line in globs (and trace
> events as well). And if the kernel command line doesn't work properly (it's
> not as tested as the run time side is), it should be trivial to fix it.
>
>
> >
> > > > trace_printk() has such a high runtime cost as combining dynamic-debug
> > > > and tracing would seem to be a panacea.
> > >
> > > trace_printk() has a high runtime cost? Besides that it's not allowed on
> > > production code (see nasty banner), it is made to be extremely fast.
> > > Although, it does do sprintf() work.
> >
> > I was referring to the banner. dev_dbg() does not have that production
> > code restriction.
>
> You can have a tracepoint like trace_printk that doesn't give a banner.
> Basically, the reason trace_printk() has that restriction is because you
> can't filter it like you can trace events. It's similar to a printk(). If I
> had allowed trace_printk() in the kernel, it would be all over the place,
> and it would just add a bunch of noise to the trace output, because its
> either on or off. And if you have trace_printk() and so would all other
> systems, and then you would deal with trace_printk()s from everyone which
> could drown out the ones you want. Hence, I added that banner to keep that
> from happening. trace_printk() will even drown out events. (I hate it when
> I leave one in my debug kernel, and it adds a bunch of noise against what
> I'm trying to debug with events!).
>
> But you can add your own trace point, and even make it generic. That's what
> bpf did for their bpf_trace_printk. You could convert dev_dbg() into a
> tracepoint!
>
>
> static __printf(2, 3) int __dev_dbg(const struct device *dev, char *fmt, ...)
> {
> static char buf[DEV_DEBUG_PRINTK_SIZE];
> unsigned long flags;
> va_list ap;
> int ret;
>
> raw_spin_lock_irqsave(&dev_dbg_printk_lock, flags);
> va_start(ap, fmt);
> ret = vsnprintf(buf, sizeof(buf), fmt, ap);
> va_end(ap);
> /* vsnprintf() will not append null for zero-length strings */
> if (ret == 0)
> buf[0] = '\0';
> trace_dev_dbg_printk(dev, buf);
> raw_spin_unlock_irqrestore(&dev_dbg_printk_lock, flags);
>
> return ret;
> }
>
> #define dev_dbg(dev, fmt, ...) \
> do { \
> if (trace_dev_dbg_printk_enabled()) \
> __dev_dbg(dev, fmt, ##__VA_ARGS__); \
> } while (0)
>
> Note, the "trace_dev_dbg_printk_enabled()" is a static branch, which means
> it is a nop when the dev_dbg_printk tracepoint is not enabled, and is a jmp
> to the __dev_dbg() logic when it is enabled. It's not a conditional branch.
>
> And have:
>
> TRACE_EVENT(dev_dbg_printk,
>
> TP_PROTO(const struct device *dev, const char *dbg_str),
>
> TP_ARGS(dev, dbg_str),
>
> TP_STRUCT__entry(
> __field(const struct device *dev)
> __string(dev_name, dev_name(dev))
> __string(dbg_str, dbg_str)
> ),
>
> TP_fast_assign(
> __entry->dev = dev;
> __assign_str(dev_name, dev_name(dev))
> __assign_str(dbg_str, dbg_str);
> ),
>
> TP_printk("%p dev=%s %s", __entry->dev, __get_string(dev_name), __get_str(dbg_str))
> );
>
> And then you could even filter on the device name, or even parts of the
> string, as you can filter events, and even have them have glob matches.
Oooh, I might run with this, it's been on my backlog to go investigate
and you just threw out a solution. Imagine being able to to specify
't' instead of 'p' for a given debug print so that dev_dbg() users can
move from console to trace buffer, but also tracing users have access
to more tracepoints that happen to appear at useful dev_dbg()
locations.
Thanks, Steven!
Powered by blists - more mailing lists