lkml.org 
[lkml]   [2021]   [May]   [26]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: [PATCH v6 4/4] printk: index: Add indexing support to dev_printk
On Tue 2021-05-18 13:00:48, Chris Down wrote:
> While for most kinds of issues we have counters, tracepoints, or metrics
> with a stable interface which can reliably be used to indicate issues,
> in order to react to production issues quickly we sometimes need to work
> with the interface which most kernel developers naturally use when
> developing: printk, and printk-esques like dev_printk.
>
> dev_printk is by far the most likely custom subsystem printk to benefit
> from the printk indexing infrastructure, since niche device issues
> brought about by production changes, firmware upgrades, and the like are
> one of the most common things that we need printk infrastructure's
> assistance to monitor.
>
> Often these errors were never expected to practically manifest in
> reality, and exhibit in code without extensive (or any) metrics present.
> As such, there are typically very few options for issue detection
> available to those with large fleets at the time the incident happens,
> and we thus benefit strongly from monitoring netconsole in these
> instances.
>
> As such, add the infrastructure for dev_printk to be indexed in the
> printk index. Even on a minimal kernel config, the coverage of the base
> kernel's printk index is significantly improved:
>
> Before:
>
> [root@ktst ~]# wc -l /sys/kernel/debug/printk/index/vmlinux
> 4497 /sys/kernel/debug/printk/index/vmlinux
>
> After:
>
> [root@ktst ~]# wc -l /sys/kernel/debug/printk/index/vmlinux
> 5573 /sys/kernel/debug/printk/index/vmlinux

Cool.

> In terms of implementation, in order to trivially disambiguate them,
> dev_printk is now a macro which wraps _dev_printk. If preferred, it's
> also possible to have the macro and function have the same name.

I prefer to use _dev_printk to disambiguate the macro and function
names. By other words, I prefer the approach used in this patch.

Please, remove the "If preferred..." sentence in the next version.

> diff --git a/include/linux/dev_printk.h b/include/linux/dev_printk.h
> index 6f009559ee54..202c6a9ea7eb 100644
> --- a/include/linux/dev_printk.h
> +++ b/include/linux/dev_printk.h
> @@ -97,25 +97,54 @@ void _dev_info(const struct device *dev, const char *fmt, ...)
>
> #endif
>
> +/*
> + * Some callsites directly call dev_printk rather than going through the
> + * dev_<level> infrastructure, so we need to emit here as well as inside those
> + * level-specific macros. Only one index entry will be produced, either way,
> + * since dev_printk's `fmt` isn't known at compile time if going through the
> + * dev_<level> macros.
> + */
> +#define dev_printk(level, dev, fmt, ...) ({ \
> + dev_printk_index_emit(level, fmt); \

Please, define dev_printk_index_emit() macro before it is used
for the first time.

> + _dev_printk(level, dev, fmt, ##__VA_ARGS__); \
> +})
> +
> /*
> * #defines for all the dev_<level> macros to prefix with whatever
> * possible use of #define dev_fmt(fmt) ...
> */
>
> -#define dev_emerg(dev, fmt, ...) \
> - _dev_emerg(dev, dev_fmt(fmt), ##__VA_ARGS__)
> -#define dev_crit(dev, fmt, ...) \
> - _dev_crit(dev, dev_fmt(fmt), ##__VA_ARGS__)
> -#define dev_alert(dev, fmt, ...) \
> - _dev_alert(dev, dev_fmt(fmt), ##__VA_ARGS__)
> -#define dev_err(dev, fmt, ...) \
> - _dev_err(dev, dev_fmt(fmt), ##__VA_ARGS__)
> -#define dev_warn(dev, fmt, ...) \
> - _dev_warn(dev, dev_fmt(fmt), ##__VA_ARGS__)
> -#define dev_notice(dev, fmt, ...) \
> - _dev_notice(dev, dev_fmt(fmt), ##__VA_ARGS__)
> -#define dev_info(dev, fmt, ...) \
> - _dev_info(dev, dev_fmt(fmt), ##__VA_ARGS__)
> +#define dev_printk_index_emit(level, fmt) \
> + printk_index_subsys_emit("%s %s: ", "", level, fmt)
> +
> +#define dev_emerg(dev, fmt, ...) ({ \
> + dev_printk_index_emit(KERN_EMERG, dev_fmt(fmt)); \
> + _dev_emerg(dev, dev_fmt(fmt), ##__VA_ARGS__); \
> +})
> +#define dev_crit(dev, fmt, ...) ({ \
> + dev_printk_index_emit(KERN_CRIT, dev_fmt(fmt)); \
> + _dev_crit(dev, dev_fmt(fmt), ##__VA_ARGS__); \
> +})
> +#define dev_alert(dev, fmt, ...) ({ \
> + dev_printk_index_emit(KERN_ALERT, dev_fmt(fmt)); \
> + _dev_alert(dev, dev_fmt(fmt), ##__VA_ARGS__); \
> +})

I would slightly reduce the duplcation the follwing way:

#define dev_printk_index_wrap(_p_func, level, dev, fmt, ...) \
({ \
printk_index_subsys_emit("%s %s: ", "", level, dev_fmt(fmt)); \
_p_func(dev, dev_fmt(fmt), ##__VA_ARGS__); \
})

#define dev_printk(level, dev, fmt, ...) \
dev_printk_index_wrap(_dev_printk, level, dev, ##__VA_ARGS__)

#define dev_crit(dev, fmt, ...) \
dev_printk_index_wrap(_dev_crit, KERN_CRIT, dev, ##__VA_ARGS__)
#define dev_alert(dev, fmt, ...) \
dev_printk_index_wrap(_dev_alert, KERN_ALERT, dev, ##__VA_ARGS__)


Note that I did not try to complile it, so there might be a mistake.


BTW: I was curious why we actually need _dev_crit() defined as a function.
But it seems to reduce size of the kernel binaries, see
the commit 38a1ec40efa196efbac0253 ("device.h drivers/base/core.c
Convert dev_<level> logging macros to functions"). Sigh.

Best Regards,
Petr

\
 
 \ /
  Last update: 2021-05-26 10:57    [W:0.226 / U:0.084 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site