On Thu, 12 Dec 2019 15:32:35 -0500 Sean Paul <s...@poorly.run> wrote:
> > What about trace_printk()? It doesn't give us the control we get from using > tracepoints and it's not meant to be left sprinkled around in code. Not to mention that trace_printk() is not for production use (only for developers debugging purposes). > > Cc: David Airlie <airl...@gmail.com> > Cc: Daniel Vetter <daniel.vet...@ffwll.ch> > Cc: Pekka Paalanen <ppaala...@gmail.com> > Cc: Joonas Lahtinen <joonas.lahti...@linux.intel.com> > Cc: Thomas Zimmermann <tzimmerm...@suse.de> > Cc: Rob Clark <robdcl...@gmail.com> > Cc: Ville Syrjälä <ville.syrj...@linux.intel.com> > Acked-by: Daniel Vetter <daniel.vet...@ffwll.ch> > Signed-off-by: Sean Paul <seanp...@chromium.org> > Link: > https://patchwork.freedesktop.org/patch/msgid/20191010204823.195540-1-s...@poorly.run > #v1 > > Changes in v2: > - Went with a completely different approach: > https://lists.freedesktop.org/archives/dri-devel/2019-November/243230.html > > Changes in v3: > - Changed commit message to be a bit less RFC-y > - Make class_drm_category_log an actual trace class > --- > > Even though we don't want it to be, this is UAPI. So here's some userspace > code which uses it: > https://chromium-review.googlesource.com/c/chromiumos/platform2/+/1965562 > > > drivers/gpu/drm/drm_print.c | 143 ++++++++++++++++++++++++++----- > include/trace/events/drm_print.h | 116 +++++++++++++++++++++++++ > 2 files changed, 239 insertions(+), 20 deletions(-) > create mode 100644 include/trace/events/drm_print.h > > diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c > index 9a25d73c155c..f591292811aa 100644 > --- a/drivers/gpu/drm/drm_print.c > +++ b/drivers/gpu/drm/drm_print.c > @@ -27,11 +27,15 @@ > > #include <stdarg.h> > > +#include <linux/bitops.h> > #include <linux/io.h> > #include <linux/moduleparam.h> > #include <linux/seq_file.h> > #include <linux/slab.h> > > +#define CREATE_TRACE_POINTS > +#include <trace/events/drm_print.h> > + > #include <drm/drm.h> > #include <drm/drm_drv.h> > #include <drm/drm_print.h> > @@ -241,10 +245,10 @@ void drm_dev_printk(const struct device *dev, const > char *level, > struct va_format vaf; > va_list args; > > - va_start(args, format); > vaf.fmt = format; > vaf.va = &args; > > + va_start(args, format); > if (dev) > dev_printk(level, dev, "[" DRM_NAME ":%ps] %pV", > __builtin_return_address(0), &vaf); > @@ -253,49 +257,145 @@ void drm_dev_printk(const struct device *dev, const > char *level, > level, __builtin_return_address(0), &vaf); > > va_end(args); > + > + va_start(args, format); > + trace_drm_log(level, dev, &vaf); > + va_end(args); > } > EXPORT_SYMBOL(drm_dev_printk); > > +static unsigned int drm_trace_enabled(unsigned int category) > +{ > + unsigned int bit; > + > + for_each_set_bit(bit, (unsigned long*)&category, sizeof(category) * 8) { > + switch (BIT(bit)) { > + case DRM_UT_NONE: > + return trace_drm_dbg_none_enabled(); > + case DRM_UT_CORE: > + return trace_drm_dbg_core_enabled(); > + case DRM_UT_DRIVER: > + return trace_drm_dbg_driver_enabled(); > + case DRM_UT_KMS: > + return trace_drm_dbg_kms_enabled(); > + case DRM_UT_PRIME: > + return trace_drm_dbg_prime_enabled(); > + case DRM_UT_ATOMIC: > + return trace_drm_dbg_atomic_enabled(); > + case DRM_UT_VBL: > + return trace_drm_dbg_vbl_enabled(); > + case DRM_UT_STATE: > + return trace_drm_dbg_state_enabled(); > + case DRM_UT_LEASE: > + return trace_drm_dbg_lease_enabled(); > + case DRM_UT_DP: > + return trace_drm_dbg_dp_enabled(); > + default: > + return trace_drm_dbg_unknown_enabled(); > + } Why this double loop? > + } > + return false; > +} > + > +static void drm_do_trace(const struct device *dev, unsigned int category, > + struct va_format *vaf) > +{ > + WARN_ON(hweight32(category) > 1); > + > + switch (category) { > + case DRM_UT_NONE: > + trace_drm_dbg_none(dev, vaf); > + break; > + case DRM_UT_CORE: > + trace_drm_dbg_core(dev, vaf); > + break; > + case DRM_UT_DRIVER: > + trace_drm_dbg_driver(dev, vaf); > + break; > + case DRM_UT_KMS: > + trace_drm_dbg_kms(dev, vaf); > + break; > + case DRM_UT_PRIME: > + trace_drm_dbg_prime(dev, vaf); > + break; > + case DRM_UT_ATOMIC: > + trace_drm_dbg_atomic(dev, vaf); > + break; > + case DRM_UT_VBL: > + trace_drm_dbg_vbl(dev, vaf); > + break; > + case DRM_UT_STATE: > + trace_drm_dbg_state(dev, vaf); > + break; > + case DRM_UT_LEASE: > + trace_drm_dbg_lease(dev, vaf); > + break; > + case DRM_UT_DP: > + trace_drm_dbg_dp(dev, vaf); > + break; > + default: > + trace_drm_dbg_unknown(dev, vaf); > + break; Why is there a separate trace event for each of these? > + } > +} > + > void drm_dev_dbg(const struct device *dev, unsigned int category, > const char *format, ...) > { > struct va_format vaf; > + unsigned int bit; > va_list args; > > - if (!drm_debug_enabled(category)) > - return; > - > - va_start(args, format); > vaf.fmt = format; > vaf.va = &args; > > - if (dev) > - dev_printk(KERN_DEBUG, dev, "[" DRM_NAME ":%ps] %pV", > - __builtin_return_address(0), &vaf); > - else > - printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV", > - __builtin_return_address(0), &vaf); > + if (drm_debug_enabled(category)) { > + va_start(args, format); > + if (dev) > + dev_printk(KERN_DEBUG, dev, "[" DRM_NAME ":%ps] %pV", > + __builtin_return_address(0), &vaf); > + else > + printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV", > + __builtin_return_address(0), &vaf); > + va_end(args); > + } > + > + if (!drm_trace_enabled(category)) > + return; > + > + for_each_set_bit(bit, (unsigned long*)&category, sizeof(category) * 8) { > + va_start(args, format); > + drm_do_trace(dev, BIT(bit), &vaf); > + va_end(args); I'm thinking we could find a way to move the logic here to have a single loop. Note, the current approach is racy. The state can change between the "drm_trace_enabled()" and this for loop. -- Steve > + } > > - va_end(args); > } > EXPORT_SYMBOL(drm_dev_dbg); > > void drm_dbg(unsigned int category, const char *format, ...) > { > struct va_format vaf; > + unsigned int bit; > va_list args; > > - if (!drm_debug_enabled(category)) > - return; > - > - va_start(args, format); > vaf.fmt = format; > vaf.va = &args; > > - printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV", > - __builtin_return_address(0), &vaf); > + if (drm_debug_enabled(category)) { > + va_start(args, format); > + printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV", > + __builtin_return_address(0), &vaf); > + va_end(args); > + } > > - va_end(args); > + if (!drm_trace_enabled(category)) > + return; > + > + for_each_set_bit(bit, (unsigned long*)&category, sizeof(category) * 8) { > + va_start(args, format); > + drm_do_trace(NULL, BIT(bit), &vaf); > + va_end(args); > + } > } > EXPORT_SYMBOL(drm_dbg); > > @@ -304,13 +404,16 @@ void drm_err(const char *format, ...) > struct va_format vaf; > va_list args; > > - va_start(args, format); > vaf.fmt = format; > vaf.va = &args; > > + va_start(args, format); > printk(KERN_ERR "[" DRM_NAME ":%ps] *ERROR* %pV", > __builtin_return_address(0), &vaf); > + va_end(args); > > + va_start(args, format); > + trace_drm_err(NULL, &vaf); > va_end(args); > } > EXPORT_SYMBOL(drm_err); > diff --git a/include/trace/events/drm_print.h > b/include/trace/events/drm_print.h > new file mode 100644 > index 000000000000..862728fe0f89 > --- /dev/null > +++ b/include/trace/events/drm_print.h > @@ -0,0 +1,116 @@ > +// SPDX-License-Identifier: MIT > +/* > + * Copyright (C) 2019 Google, Inc. > + * > + * Authors: > + * Sean Paul <seanp...@chromium.org> > + */ > +#undef TRACE_SYSTEM > +#define TRACE_SYSTEM drm_print > + > +#if !defined(_TRACE_DRM_PRINT_H) || defined(TRACE_HEADER_MULTI_READ) > + > +#include <linux/device.h> > +#include <linux/tracepoint.h> > + > +#define DRM_PRINT_MAX 256 > + > +#define _TRACE_DRM_PRINT_H > + > +TRACE_EVENT(drm_log, > + TP_PROTO(const char * level, const struct device *dev, > + struct va_format *vaf), > + TP_ARGS(level, dev, vaf), > + TP_STRUCT__entry( > + __field(const char *, level ) > + __field(const struct device *, dev ) > + __dynamic_array(char, msg, DRM_PRINT_MAX ) > + __field(int, len ) > + ), > + TP_fast_assign( > + __entry->level = level; > + __entry->dev = dev; > + __entry->len = vsnprintf(__get_str(msg), DRM_PRINT_MAX, > + vaf->fmt, *vaf->va); > + if (__entry->len > 0 && > + __get_str(msg)[__entry->len - 1] == '\n') > + __get_str(msg)[--__entry->len] = '\0'; > + ), > + TP_printk("%s %s %s: %s", __entry->level, > + __entry->dev ? dev_driver_string(__entry->dev) : "(NULL):", > + __entry->dev ? dev_name(__entry->dev) : "", __get_str(msg)) > +); > + > +DECLARE_EVENT_CLASS(class_drm_category_log, > + TP_PROTO(const struct device *dev, struct va_format *vaf), > + TP_ARGS(dev, vaf), > + TP_STRUCT__entry( > + __field(const struct device *, dev ) > + __dynamic_array(char, msg, DRM_PRINT_MAX ) > + __field(int, len ) > + ), > + TP_fast_assign( > + __entry->dev = dev; > + __entry->len = vsnprintf(__get_str(msg), DRM_PRINT_MAX, > + vaf->fmt, *vaf->va); > + if (__entry->len > 0 && > + __get_str(msg)[__entry->len - 1] == '\n') > + __get_str(msg)[--__entry->len] = '\0'; > + ), > + TP_printk("%s %s%s%s", > + __entry->dev ? dev_driver_string(__entry->dev) : "", > + __entry->dev ? dev_name(__entry->dev) : "", > + __entry->dev ? ": " : "", __get_str(msg)) > +); > +DEFINE_EVENT(class_drm_category_log, drm_err, > + TP_PROTO(const struct device *dev, struct va_format *vaf), > + TP_ARGS(dev, vaf) > +); > +DEFINE_EVENT(class_drm_category_log, drm_dbg_none, > + TP_PROTO(const struct device *dev, struct va_format *vaf), > + TP_ARGS(dev, vaf) > +); > +DEFINE_EVENT(class_drm_category_log, drm_dbg_core, > + TP_PROTO(const struct device *dev, struct va_format *vaf), > + TP_ARGS(dev, vaf) > +); > +DEFINE_EVENT(class_drm_category_log, drm_dbg_driver, > + TP_PROTO(const struct device *dev, struct va_format *vaf), > + TP_ARGS(dev, vaf) > +); > +DEFINE_EVENT(class_drm_category_log, drm_dbg_kms, > + TP_PROTO(const struct device *dev, struct va_format *vaf), > + TP_ARGS(dev, vaf) > +); > +DEFINE_EVENT(class_drm_category_log, drm_dbg_prime, > + TP_PROTO(const struct device *dev, struct va_format *vaf), > + TP_ARGS(dev, vaf) > +); > +DEFINE_EVENT(class_drm_category_log, drm_dbg_atomic, > + TP_PROTO(const struct device *dev, struct va_format *vaf), > + TP_ARGS(dev, vaf) > +); > +DEFINE_EVENT(class_drm_category_log, drm_dbg_vbl, > + TP_PROTO(const struct device *dev, struct va_format *vaf), > + TP_ARGS(dev, vaf) > +); > +DEFINE_EVENT(class_drm_category_log, drm_dbg_state, > + TP_PROTO(const struct device *dev, struct va_format *vaf), > + TP_ARGS(dev, vaf) > +); > +DEFINE_EVENT(class_drm_category_log, drm_dbg_lease, > + TP_PROTO(const struct device *dev, struct va_format *vaf), > + TP_ARGS(dev, vaf) > +); > +DEFINE_EVENT(class_drm_category_log, drm_dbg_dp, > + TP_PROTO(const struct device *dev, struct va_format *vaf), > + TP_ARGS(dev, vaf) > +); > +DEFINE_EVENT(class_drm_category_log, drm_dbg_unknown, > + TP_PROTO(const struct device *dev, struct va_format *vaf), > + TP_ARGS(dev, vaf) > +); > +#endif > + > +/* This part must be outside protection */ > +#include <trace/define_trace.h> _______________________________________________ dri-devel mailing list dri-devel@lists.freedesktop.org https://lists.freedesktop.org/mailman/listinfo/dri-devel
