[<prev] [next>] [<thread-prev] [day] [month] [year] [list]
Message-ID: <CAK8ByeKw6=FCHUJ+Rqc3izUHOOh4UtV4XzcgQKC8QFTbZnos+g@mail.gmail.com>
Date: Wed, 25 Oct 2023 09:58:49 +0200
From: Łukasz Bartosik <lb@...ihalf.com>
To: Jason Baron <jbaron@...mai.com>
Cc: Jim Cromie <jim.cromie@...il.com>,
Andrew Morton <akpm@...ux-foundation.org>,
Kees Cook <keescook@...omium.org>,
Douglas Anderson <dianders@...omium.org>,
Guenter Roeck <groeck@...gle.com>,
Yaniv Tzoreff <yanivt@...gle.com>,
Benson Leung <bleung@...gle.com>, linux-kernel@...r.kernel.org,
upstream@...ihalf.com
Subject: Re: [PATCH v1] dynamic_debug: add support for logs destination
wt., 24 paź 2023 o 18:24 Jason Baron <jbaron@...mai.com> napisał(a):
>
>
>
> On 9/15/23 11:48 AM, Łukasz Bartosik wrote:
> > Add support for selection of dynamic debug logs destination.
> > When enabled it allows to configure destination of each callsite
> > individually. The option adds a framework (described by struct
> > ddebug_dst_ops) which provides flexible means to add a new destination
> > for debug logs. On top of the framework support for trace instance as
> > destination is added. By default destination of debug logs is syslog.
> > Syslog can be set explicitly by using dst keyword or is selected by
> > default when dst keyword is omitted, for example:
> >
> > localhost ~ # echo -n "module usbcore dst syslog =p" >
> > <debugfs>/dynamic_debug/control
> > or
> >
> > localhost ~ # echo -n "module usbcore =p" >
> > <debugfs>/dynamic_debug/control
> >
> > To enable a trace instance as a destination of debug logs a user
> > can for example issue the command:
> >
> > localhost ~ # echo -n "module usbcore dst trace:usb =p" >
> > <debugfs>/dynamic_debug/control
>
>
> Sorry for the late reply here. So I normally thing of the dynamic debug
> keywords- func,file,line,etc... as 'selectors'. Like these control which
> sites are selected. Whereas the 'dst' keyword is where the output of
> what is selected goes to. So it feels like it should be more like something:
>
> echo "module usbcore =T:usb" > <debugfs>/dyanmic_debug/control
>
> And then if there are other flags maybe we need a comma?
>
> echo "module usbcore =T:usb,ptm" > <debugfs>/dyanmic_debug/control
>
> or
>
> echo "module usbcore =ptmT:usb" > <debugfs>/dyanmic_debug/control
>
> And if you just have 'T' like:
>
> echo "module usbcore =ptmT" > <debugfs>/dyanmic_debug/control
>
> That means use the 'default' trace buffer. And 'p' continues to mean the
> printk buffer. So you could send lines to both. But you can't send
> output to more than one trace buffer (although we could relax that in
> the future, if needed with another ':' separator?).
>
Thanks for the comment. I will follow your suggestions.
Lukasz
> Thanks,
>
> -Jason
>
> >
> > The command will write debug logs from usbcore subsystem to the
> > trace instance named "usb" and the captured logs can be read
> > later with the command:
> >
> > localhost ~ # cat <debugfs>/tracing/instances/usb/trace
> >
> > When trace instance name is omitted the debug logs will be written
> > to "ddebug_default" trace instance:
> >
> > localhost ~ # cat <debugfs>/tracing/instances/ddebug_default/trace
> >
> > The DYNAMIC_DEBUG_DST option adds destination information
> > in the dynamic debug control:
> >
> > localhost ~ # cat <debugfs>/dynamic_debug/control
> > drivers/usb/core/usb-acpi.c:143 [usbcore]usb_acpi_set_power_state =p "acpi: power failed to be set\n" trace:usb
> > drivers/usb/core/usb-acpi.c:141 [usbcore]usb_acpi_set_power_state =p "acpi: power was set to %d\n" trace:usb
> >
> > There are two modes of operation for dynamic debug logs destination
> > which can be selected during configuration stage of a kernel:
> >
> > * Dynamic - callsites configuration and destination of debug logs
> > can be dynamically changed during runtime. This has slight impact
> > on performance because it requires SRCU to be used for synchronization.
> >
> > * Static - callsites configuration and destination of debug logs
> > can be configured only from a kernel boot command line. This option
> > hides <debugfs>/dynamic_debug/control interface. It does not require
> > SRCU synchronization because of the static configuration. It also
> > provides convenient means to capture debug logs on production systems
> > for issues which are difficult to reproduce but on the other hand
> > do not expose <debugfs>/dynamic_debug/control interface for security
> > reasons.
> >
> > For example to capture thunderbolt subsystem debug logs on production
> > system to trace instance named "thunderbolt":
> > * enable kernel configuration option CONFIG_DYNAMIC_DEBUG_CORE,
> > * enable kernel configuration option DYNAMIC_DEBUG_DST and set its
> > operation mode to Static.
> > * add the option to the thunderbolt's drivers/thunderbolt/Makefile
> > in order to compile in debug logs:
> > CFLAGS_nhi.o := -DDYNAMIC_DEBUG_MODULE
> > * compile the kernel and update it on a target device,
> > * finally append the entry to the kernel boot command line:
> > thunderbolt.dyndbg="dst trace:thunderbolt =p"
> >
> > The DYNAMIC_DEBUG_DST option increases each callsite size by
> > the pointer size.
> >
> > Signed-off-by: Łukasz Bartosik <lb@...ihalf.com>
> > ---
> > Changelog v1:
> > - initial creation
> > ---
> > include/linux/dynamic_debug.h | 30 ++
> > lib/Kconfig.debug | 103 ++++++
> > lib/dynamic_debug.c | 659 +++++++++++++++++++++++++++++++++-
> > 3 files changed, 786 insertions(+), 6 deletions(-)
> >
> > diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
> > index 41682278d2e8..8dee10f66e72 100644
> > --- a/include/linux/dynamic_debug.h
> > +++ b/include/linux/dynamic_debug.h
> > @@ -38,8 +38,18 @@ struct _ddebug {
> > #define _DPRINTK_FLAGS_INCL_LINENO (1<<3)
> > #define _DPRINTK_FLAGS_INCL_TID (1<<4)
> > #define _DPRINTK_FLAGS_INCL_SOURCENAME (1<<5)
> >
> > +#if defined CONFIG_DYNAMIC_DEBUG_DST
> > + /*
> > + * The 6th and 7th bits of the flags are used to determine
> > + * destination of debug logs, currently supported destinations
> > + * are defined in ddebug_dst_type enumeration
> > + */
> > +#define _DPRINTK_FLAGS_DST_SHIFT 6
> > +#define _DPRINTK_FLAGS_DST_MASK (3<<_DPRINTK_FLAGS_DST_SHIFT)
> > +#endif
> > +
> > #define _DPRINTK_FLAGS_INCL_ANY \
> > (_DPRINTK_FLAGS_INCL_MODNAME | _DPRINTK_FLAGS_INCL_FUNCNAME |\
> > _DPRINTK_FLAGS_INCL_LINENO | _DPRINTK_FLAGS_INCL_TID |\
> > _DPRINTK_FLAGS_INCL_SOURCENAME)
> > @@ -54,6 +64,10 @@ struct _ddebug {
> > struct static_key_false dd_key_false;
> > } key;
> > #endif
> > +
> > +#if defined CONFIG_DYNAMIC_DEBUG_DST
> > + struct ddebug_dst *dst;
> > +#endif
> > } __attribute__((aligned(8)));
> >
> > enum class_map_type {
> > @@ -280,10 +294,26 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
> > _dynamic_func_call(fmt, __dynamic_ibdev_dbg, \
> > dev, fmt, ##__VA_ARGS__)
> >
> > +#if defined CONFIG_DYNAMIC_DEBUG_DST
> > +
> > +void __print_hex_dump_dst(const struct _ddebug *descriptor, const char *level,
> > + const char *prefix_str, int prefix_type, int rowsize,
> > + int groupsize, const void *buf, size_t len,
> > + bool ascii);
> > +
> > +#define dynamic_hex_dump(prefix_str, prefix_type, rowsize, \
> > + groupsize, buf, len, ascii) \
> > + _dynamic_func_call(__builtin_constant_p(prefix_str) ? prefix_str : "hexdump", \
> > + __print_hex_dump_dst, \
> > + KERN_DEBUG, prefix_str, prefix_type, \
> > + rowsize, groupsize, buf, len, ascii)
> > +#else
> > +
> > #define dynamic_hex_dump(prefix_str, prefix_type, rowsize, \
> > groupsize, buf, len, ascii) \
> > _dynamic_func_call_no_desc(__builtin_constant_p(prefix_str) ? prefix_str : "hexdump", \
> > print_hex_dump, \
> > KERN_DEBUG, prefix_str, prefix_type, \
> > rowsize, groupsize, buf, len, ascii)
> > +#endif
> >
> > diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug
> > index f0c30ad83f22..4abfa126bde5 100644
> > --- a/lib/Kconfig.debug
> > +++ b/lib/Kconfig.debug
> > @@ -188,6 +188,109 @@ config DYNAMIC_DEBUG_CORE
> > the case of embedded system where the kernel image size is
> > sensitive for people.
> >
> > +menuconfig DYNAMIC_DEBUG_DST
> > + bool "Enable selection of dynamic debug logs destination"
> > + depends on DYNAMIC_DEBUG_CORE
> > + select TRACING
> > + help
> > + Add support for selecting destination of dynamic debug logs.
> > + When enabled it allows to configure destination of each callsite
> > + individually. The option adds a framework (described by struct
> > + ddebug_dst_ops) which provides flexible means to add a new destination
> > + for debug logs. On top of the framework support for trace instance as
> > + destination is added. By default destination of debug logs is syslog.
> > + Syslog can be set explicitly by using dst keyword or is selected by
> > + default when dst keyword is omitted, for example:
> > +
> > + localhost ~ # echo -n "module usbcore dst syslog =p" >
> > + <debugfs>/dynamic_debug/control
> > + or
> > +
> > + localhost ~ # echo -n "module usbcore =p" >
> > + <debugfs>/dynamic_debug/control
> > +
> > + To enable a trace instance as a destination of debug logs a user
> > + can for example issue the command:
> > +
> > + localhost ~ # echo -n "module usbcore dst trace:usb =p" >
> > + <debugfs>/dynamic_debug/control
> > +
> > + The command will write debug logs from usbcore subsystem to the
> > + trace instance named "usb" and the captured logs can be read
> > + later with the command:
> > +
> > + localhost ~ # cat <debugfs>/tracing/instances/usb/trace
> > +
> > + When trace instance name is omitted the debug logs will be written
> > + to "ddebug_default" trace instance:
> > +
> > + localhost ~ # cat <debugfs>/tracing/instances/ddebug_default/trace
> > +
> > + The DYNAMIC_DEBUG_DST option adds destination information
> > + in the dynamic debug control:
> > +
> > + localhost ~ # cat <debugfs>/dynamic_debug/control
> > + # filename:lineno [module]function flags format destination
> > + drivers/usb/core/usb-acpi.c:143 [usbcore]usb_acpi_set_power_state =p "acpi: power failed to be set\n" trace:usb
> > + drivers/usb/core/usb-acpi.c:141 [usbcore]usb_acpi_set_power_state =p "acpi: power was set to %d\n" trace:usb
> > +
> > + The DYNAMIC_DEBUG_DST option increases each callsite size by
> > + the pointer size.
> > +
> > +if DYNAMIC_DEBUG_DST
> > +
> > +choice
> > + prompt "Destination mode"
> > + default DYNAMIC_DEBUG_DST_DYNAMIC
> > + help
> > + There are two modes of operation for dynamic debug logs destination
> > + which can be selected during configuration stage of a kernel:
> > +
> > + * Dynamic - callsites configuration and destination of debug logs
> > + can be dynamically changed during runtime. This has slight impact
> > + on performance because it requires SRCU to be used for synchronization.
> > +
> > + * Static - callsites configuration and destination of debug logs
> > + can be configured only from a kernel boot command line. This option
> > + hides <debugfs>/dynamic_debug/control interface. It does not require
> > + SRCU synchronization because of the static configuration. It also
> > + provides convenient means to capture debug logs on production systems
> > + for issues which are difficult to reproduce and at the same time
> > + do not expose <debugfs>/dynamic_debug/control interface for security
> > + reasons.
> > +
> > +config DYNAMIC_DEBUG_DST_DYNAMIC
> > + bool "Dynamic"
> > + select SRCU
> > + help
> > + Callsites configuration and destination of debug logs can be
> > + dynamically changed during runtime. This has slight impact on
> > + performance because it requires SRCU to be used for synchronization.
> > +
> > + The interface which allows to dynamically change configuration is:
> > + <debugfs>/dynamic_debug/control
> > +
> > +config DYNAMIC_DEBUG_DST_STATIC
> > + bool "Static"
> > + help
> > + Callsites configuration and destination of debug logs can be
> > + configured only from a kernel boot command line. This option
> > + does not expose <debugfs>/dynamic_debug/control interface and
> > + therefore does not require SRCU synchronization. It also provides
> > + convenient means to capture debug logs on production systems
> > + for issues which are difficult to reproduce and at the same time
> > + do not expose <debugfs>/dynamic_debug/control interface
> > + for security reasons.
> > +
> > + For example to configure usbcore module to output its debug logs
> > + to trace instance named "usb" the following line would have to be
> > + appended to a kernel boot command line:
> > +
> > + usbcore.dyndbg="dst trace:usb =p"
> > +
> > +endchoice
> > +endif
> > +
> > config SYMBOLIC_ERRNAME
> > bool "Support symbolic error names in printf"
> > default y if PRINTK
> > diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
> > index 009f2ead09c1..0cb69b553554 100644
> > --- a/lib/dynamic_debug.c
> > +++ b/lib/dynamic_debug.c
> > @@ -44,6 +44,87 @@ extern struct _ddebug __stop___dyndbg[];
> > extern struct ddebug_class_map __start___dyndbg_classes[];
> > extern struct ddebug_class_map __stop___dyndbg_classes[];
> >
> > +#if defined CONFIG_DYNAMIC_DEBUG_DST
> > +#include <linux/trace.h>
> > +
> > +enum ddebug_dst_type {
> > + DDEBUG_DST_SYSLOG, /* destination syslog */
> > + DDEBUG_DST_TRACE, /* destination trace instance */
> > + /* DDEBUG_DST_NOT_USED_1 */
> > + /* DDEBUG_DST_NOT_USED_2 */
> > + DDEBUG_DST_MAX,
> > +};
> > +
> > +/*
> > + * The structure holds information related to debug logs output
> > + * destination other than syslog. Currently only trace instance
> > + * is supported.
> > + */
> > +struct ddebug_dst {
> > + unsigned int use_count;
> > + enum ddebug_dst_type type;
> > + struct ddebug_dst_ops *ops;
> > + union {
> > + struct {
> > + const char *instance;
> > + struct trace_array *arr;
> > + } trace;
> > + };
> > +};
> > +
> > +#ifndef CONFIG_DYNAMIC_DEBUG_DST_STATIC
> > +
> > +/*
> > + * Instead of slicing code with #ifdefs create
> > + * wrappers around SRCU functions we use
> > + */
> > +DEFINE_STATIC_SRCU(dst_srcu);
> > +
> > +#define dd_srcu_dereference(p, ssp) srcu_dereference(p, ssp)
> > +#define dd_rcu_assign_pointer(p, v) rcu_assign_pointer(p, v)
> > +
> > +static inline int dd_srcu_read_lock(struct srcu_struct *ssp)
> > +{
> > + return srcu_read_lock(ssp);
> > +}
> > +
> > +static inline void dd_srcu_read_unlock(struct srcu_struct *ssp, int idx)
> > +{
> > + return srcu_read_unlock(ssp, idx);
> > +}
> > +
> > +static void dd_synchronize_srcu(struct srcu_struct *ssp)
> > +{
> > + synchronize_srcu(ssp);
> > +}
> > +
> > +#else
> > +
> > +struct dd_srcu_struct {
> > +};
> > +
> > +static struct dd_srcu_struct dst_srcu;
> > +
> > +#define dd_srcu_dereference(p, ssp) (p)
> > +#define dd_rcu_assign_pointer(p, v) ((p) = (v))
> > +
> > +static inline int dd_srcu_read_lock(struct dd_srcu_struct *ssp)
> > +{
> > + return 0;
> > +}
> > +
> > +static inline void dd_srcu_read_unlock(struct dd_srcu_struct *ssp, int idx)
> > +{
> > +}
> > +
> > +void dd_synchronize_srcu(struct dd_srcu_struct *ssp)
> > +{
> > +}
> > +
> > +#endif /* CONFIG_DYNAMIC_DEBUG_DST_STATIC */
> > +
> > +#endif /* CONFIG_DYNAMIC_DEBUG_DST */
> > +
> > struct ddebug_table {
> > struct list_head link, maps;
> > const char *mod_name;
> > @@ -58,6 +139,7 @@ struct ddebug_query {
> > const char *format;
> > const char *class_string;
> > unsigned int first_lineno, last_lineno;
> > + struct ddebug_dst *dst;
> > };
> >
> > struct ddebug_iter {
> > @@ -126,10 +208,402 @@ do { \
> > #define v3pr_info(fmt, ...) vnpr_info(3, fmt, ##__VA_ARGS__)
> > #define v4pr_info(fmt, ...) vnpr_info(4, fmt, ##__VA_ARGS__)
> >
> > +#if defined CONFIG_DYNAMIC_DEBUG_DST
> > +
> > +static inline enum ddebug_dst_type get_dst_type(const struct _ddebug *dp)
> > +{
> > + return (dp->flags & _DPRINTK_FLAGS_DST_MASK) >>
> > + _DPRINTK_FLAGS_DST_SHIFT;
> > +}
> > +
> > +static void set_dst_type(unsigned int *newflags,
> > + enum ddebug_dst_type type)
> > +{
> > + *newflags &= ~_DPRINTK_FLAGS_DST_MASK;
> > + *newflags |= (type << _DPRINTK_FLAGS_DST_SHIFT);
> > +}
> > +
> > +#define DST_SYSLOG_STR "syslog"
> > +#define DST_TRACE_STR "trace"
> > +#define DST_INVALID_STR "invalid"
> > +#define DST_DST_STR "destination"
> > +
> > +struct dstbuf {
> > +#define DST_DESC_MAX_SIZE 32
> > + char buf[DST_DESC_MAX_SIZE];
> > +};
> > +
> > +static char *describe_dst_type(const enum ddebug_dst_type type)
> > +{
> > + switch (type) {
> > + case DDEBUG_DST_SYSLOG:
> > + return DST_SYSLOG_STR;
> > + case DDEBUG_DST_TRACE:
> > + return DST_TRACE_STR;
> > + default:
> > + return DST_INVALID_STR;
> > + }
> > +}
> > +
> > +static char *ddebug_describe_dst(const struct ddebug_dst *dst,
> > + struct dstbuf *dstb)
> > +{
> > + if (!dst)
> > + return DST_SYSLOG_STR;
> > +
> > + switch (dst->type) {
> > + case DDEBUG_DST_SYSLOG:
> > + return DST_SYSLOG_STR;
> > + case DDEBUG_DST_TRACE:
> > + snprintf(dstb->buf, DST_DESC_MAX_SIZE, "%s:%s",
> > + DST_TRACE_STR, dst->trace.instance);
> > + break;
> > + default:
> > + return DST_INVALID_STR;
> > + }
> > +
> > + return dstb->buf;
> > +}
> > +
> > +static char *ddebug_describe_dst_dp(struct _ddebug *dp, struct dstbuf *dstb)
> > +{
> > + if (!get_dst_type(dp))
> > + return DST_SYSLOG_STR;
> > +
> > + return ddebug_describe_dst(dp->dst, dstb);
> > +}
> > +
> > +/*
> > + * struct ddebug_dst_ops - dynamic debug logs destination operations
> > + *
> > + * @parse_and_init - parses and initializes destination
> > + * @has_changed - checks whether destination has changed for a callsite
> > + * @print - prints message for a callsite
> > + * @dev_print - prints device message for a callsite
> > + * @free - frees memory associated with a destination
> > + */
> > +struct ddebug_dst_ops {
> > + int (*parse_and_init)(struct ddebug_query *query, const char *arg);
> > + bool (*has_changed)(const struct ddebug_query *query,
> > + const struct _ddebug *dp);
> > + void (*print)(const struct ddebug_dst *dst, const char *fmt, ...);
> > + void (*dev_print)(const struct ddebug_dst *dst,
> > + const struct device *dev, const char *fmt, ...);
> > + void (*free)(struct ddebug_dst *dst, int arg);
> > +};
> > +
> > +static int tr_parse_and_init(struct ddebug_query *query,
> > + const char *arg)
> > +{
> > + char *instance = strchr(arg, ':');
> > + struct trace_array *arr;
> > + int ret = -EINVAL;
> > +
> > + if (instance)
> > + instance++;
> > + else
> > + instance = "ddebug_default";
> > +
> > + arr = trace_array_get_by_name(instance);
> > + if (!arr)
> > + goto err;
> > +
> > + ret = trace_array_init_printk(arr);
> > + if (ret)
> > + goto err_trace;
> > +
> > + query->dst->trace.instance = kstrdup(instance, GFP_KERNEL);
> > + if (!query->dst->trace.instance)
> > + goto err_trace;
> > +
> > + query->dst->trace.arr = arr;
> > +
> > + v3pr_info("parsed trace dst: instance name=%s, arrray=%p\n",
> > + query->dst->trace.instance, arr);
> > + return 0;
> > +err_trace:
> > + trace_array_put(arr);
> > + trace_array_destroy(arr);
> > +err:
> > + return ret;
> > +}
> > +
> > +bool tr_has_changed(const struct ddebug_query *query, const struct _ddebug *dp)
> > +{
> > + if (!dp->dst)
> > + return true;
> > + else if (dp->dst->type != DDEBUG_DST_TRACE)
> > + return true;
> > +
> > + return query->dst->trace.arr != dp->dst->trace.arr;
> > +}
> > +
> > +__printf(2, 3)
> > +static void tr_print(const struct ddebug_dst *dst, const char *fmt, ...)
> > +{
> > + va_list args;
> > + struct va_format vaf;
> > +
> > + va_start(args, fmt);
> > + vaf.fmt = fmt;
> > + vaf.va = &args;
> > +
> > + trace_array_printk(dst->trace.arr, _THIS_IP_, "%pV", &vaf);
> > +
> > + va_end(args);
> > +}
> > +
> > +__printf(3, 4)
> > +static void tr_dev_print(const struct ddebug_dst *dst,
> > + const struct device *dev, const char *fmt, ...)
> > +{
> > + va_list args;
> > + struct va_format vaf;
> > +
> > + va_start(args, fmt);
> > + vaf.fmt = fmt;
> > + vaf.va = &args;
> > +
> > + trace_array_printk(dst->trace.arr, _THIS_IP_, "%pV", &vaf);
> > + va_end(args);
> > +}
> > +
> > +static void tr_free(struct ddebug_dst *dst, int tr_arr_destroy)
> > +{
> > + WARN_ON(!dst);
> > +
> > + v2pr_info("freed dst: type=trace, instance=%s\n", dst->trace.instance);
> > +
> > + kfree(dst->trace.instance);
> > + dst->trace.instance = NULL;
> > +
> > + trace_array_put(dst->trace.arr);
> > + /*
> > + * destroy trace instance in case when query was not applied to any
> > + * of the callsites, otherwise don't try to destroy it because it will
> > + * be removed from sysfs together with captured debug logs, let a user
> > + * to delete it manually later at convenient time
> > + */
> > + if (tr_arr_destroy)
> > + trace_array_destroy(dst->trace.arr);
> > + dst->trace.arr = NULL;
> > +}
> > +
> > +bool syslog_has_changed(const struct ddebug_query *query,
> > + const struct _ddebug *dp)
> > +{
> > + if (!dp->dst)
> > + return false;
> > +
> > + return dp->dst->type != DDEBUG_DST_SYSLOG;
> > +}
> > +
> > +static void syslog_free(struct ddebug_dst *dst, int arg)
> > +{
> > + v2pr_info("freed dst: type=syslog\n");
> > +}
> > +
> > +static struct ddebug_dst_ops dst_ops[] = {
> > + // syslog destination ops
> > + {
> > + .parse_and_init = NULL,
> > + .has_changed = syslog_has_changed,
> > + .print = NULL,
> > + .dev_print = NULL,
> > + .free = syslog_free,
> > + },
> > + // trace destination ops
> > + {
> > + .parse_and_init = tr_parse_and_init,
> > + .has_changed = tr_has_changed,
> > + .print = tr_print,
> > + .dev_print = tr_dev_print,
> > + .free = tr_free,
> > + },
> > +};
> > +
> > +static int dst_parse_and_init(struct ddebug_query *query, const char *arg)
> > +{
> > + int ret = -EINVAL;
> > +
> > + if (!arg)
> > + goto err;
> > +
> > + if (query->dst)
> > + goto err;
> > +
> > + query->dst = kzalloc(sizeof(struct ddebug_dst), GFP_KERNEL);
> > + if (!query->dst) {
> > + ret = -ENOMEM;
> > + goto err;
> > + }
> > +
> > + if (!strcmp(arg, "syslog")) {
> > + query->dst->type = DDEBUG_DST_SYSLOG;
> > + query->dst->ops = &dst_ops[DDEBUG_DST_SYSLOG];
> > + } else if (!strcmp(arg, "trace") ||
> > + !strncmp(arg, "trace:", 6)) {
> > + query->dst->type = DDEBUG_DST_TRACE;
> > + query->dst->ops = &dst_ops[DDEBUG_DST_TRACE];
> > + } else
> > + goto err_mem;
> > +
> > + if (query->dst->ops->parse_and_init) {
> > + ret = query->dst->ops->parse_and_init(query, arg);
> > + if (ret)
> > + goto err_mem;
> > + }
> > +
> > + v3pr_info("parsed dst: type=%s\n", describe_dst_type(query->dst->type));
> > + return 0;
> > +err_mem:
> > + kfree(query->dst);
> > +err:
> > + return ret;
> > +}
> > +
> > +static void dst_apply_change(const struct ddebug_query *query,
> > + struct _ddebug *dp)
> > +{
> > + /* store old destination pointer */
> > + struct ddebug_dst *old_dst = dp->dst;
> > + struct ddebug_dst *new_dst;
> > +
> > + /* increase use count */
> > + query->dst->use_count++;
> > +
> > + /*
> > + * syslog destination does not require additional description
> > + * however we use it to simplify control path processing
> > + */
> > + new_dst = (query->dst->type == DDEBUG_DST_SYSLOG) ? NULL : query->dst;
> > +
> > + /* update destination pointer */
> > + dd_rcu_assign_pointer(dp->dst, new_dst);
> > +
> > + if (!old_dst)
> > + return;
> > +
> > + old_dst->use_count--;
> > + /* check if old destination pointer is still being used */
> > + if (!old_dst->use_count) {
> > + /*
> > + * wait for all read rcu critical sections
> > + * in progress to finish
> > + */
> > + dd_synchronize_srcu(&dst_srcu);
> > + /* call destination specific free function */
> > + old_dst->ops->free(old_dst, 0);
> > + /* free old destination pointer */
> > + kfree(old_dst);
> > + }
> > +}
> > +
> > +static void dst_try_free(struct ddebug_query *query)
> > +{
> > + if (!query)
> > + return;
> > +
> > + /* free destination if it wasn't applied to any callsite */
> > + if (!query->dst->use_count) {
> > + if (query->dst->ops->free)
> > + query->dst->ops->free(query->dst, 1);
> > + /*
> > + * for syslog we always free its destination because
> > + * it is used only to simplify control path processing
> > + */
> > + if (query->dst->type)
> > + v2pr_info("freed dst: didn't apply to any of the callsites\n");
> > + kfree(query->dst);
> > + query->dst = NULL;
> > + }
> > +}
> > +
> > +void __print_hex_dump_dst(const struct _ddebug *descriptor, const char *level,
> > + const char *prefix_str, int prefix_type,
> > + int rowsize, int groupsize, const void *buf,
> > + size_t len, bool ascii)
> > +{
> > + if (get_dst_type(descriptor)) {
> > + const u8 *ptr = buf;
> > + struct ddebug_dst *dst;
> > + int i, linelen, remaining = len, idx;
> > + unsigned char linebuf[32 * 3 + 2 + 32 + 1];
> > +
> > + if (rowsize != 16 && rowsize != 32)
> > + rowsize = 16;
> > +
> > + idx = dd_srcu_read_lock(&dst_srcu);
> > + dst = dd_srcu_dereference(descriptor->dst, &dst_srcu);
> > + WARN_ON(!dst);
> > + for (i = 0; i < len; i += rowsize) {
> > + linelen = min(remaining, rowsize);
> > + remaining -= rowsize;
> > +
> > + hex_dump_to_buffer(ptr + i, linelen, rowsize, groupsize,
> > + linebuf, sizeof(linebuf), ascii);
> > +
> > + switch (prefix_type) {
> > + case DUMP_PREFIX_ADDRESS:
> > + dst->ops->print(descriptor->dst, "%s%s%p: %s\n",
> > + level, prefix_str, ptr + i, linebuf);
> > + break;
> > + case DUMP_PREFIX_OFFSET:
> > + dst->ops->print(descriptor->dst, "%s%s%.8x: %s\n",
> > + level, prefix_str, i, linebuf);
> > + break;
> > + default:
> > + dst->ops->print(descriptor->dst, "%s%s%s\n",
> > + level, prefix_str, linebuf);
> > + break;
> > + }
> > + }
> > +
> > + dd_srcu_read_unlock(&dst_srcu, idx);
> > + } else
> > + print_hex_dump(level, prefix_str, prefix_type, rowsize,
> > + groupsize, buf, len, ascii);
> > +}
> > +EXPORT_SYMBOL(__print_hex_dump_dst);
> > +
> > +#else
> > +
> > +struct ddebug_dst {
> > +};
> > +
> > +struct dstbuf {
> > +};
> > +
> > +static inline unsigned int get_dst_type(const struct _ddebug *dp)
> > +{
> > + return 0;
> > +}
> > +
> > +static char *ddebug_describe_dst(const struct ddebug_dst *dst,
> > + struct dstbuf *dstb)
> > +{
> > + return "";
> > +}
> > +
> > +static char *ddebug_describe_dst_dp(struct _ddebug *dp,
> > + struct dstbuf *dstb)
> > +{
> > + return "";
> > +}
> > +
> > +static void dst_try_free(struct ddebug_query *query)
> > +{
> > +}
> > +
> > +#define DST_DST_STR ""
> > +
> > +#endif /* CONFIG_DYNAMIC_DEBUG_DST */
> > +
> > static void vpr_info_dq(const struct ddebug_query *query, const char *msg)
> > {
> > /* trim any trailing newlines */
> > int fmtlen = 0;
> > + struct dstbuf dstb;
> >
> > if (query->format) {
> > fmtlen = strlen(query->format);
> > @@ -137,13 +611,14 @@ static void vpr_info_dq(const struct ddebug_query *query, const char *msg)
> > fmtlen--;
> > }
> >
> > - v3pr_info("%s: func=\"%s\" file=\"%s\" module=\"%s\" format=\"%.*s\" lineno=%u-%u class=%s\n",
> > + v3pr_info("%s: func=\"%s\" file=\"%s\" module=\"%s\" format=\"%.*s\" lineno=%u-%u class=%s %s=%s\n",
> > msg,
> > query->function ?: "",
> > query->filename ?: "",
> > query->module ?: "",
> > fmtlen, query->format ?: "",
> > - query->first_lineno, query->last_lineno, query->class_string);
> > + query->first_lineno, query->last_lineno, query->class_string,
> > + DST_DST_STR, ddebug_describe_dst(query->dst, &dstb));
> > }
> >
> > static struct ddebug_class_map *ddebug_find_valid_class(struct ddebug_table const *dt,
> > @@ -178,8 +653,12 @@ static int ddebug_change(const struct ddebug_query *query,
> > unsigned int newflags;
> > unsigned int nfound = 0;
> > struct flagsbuf fbuf, nbuf;
> > + struct dstbuf dstbc, dstbn;
> > struct ddebug_class_map *map = NULL;
> > int __outvar valid_class;
> > +#if defined CONFIG_DYNAMIC_DEBUG_DST
> > + struct ddebug_dst_ops *dst_ops = query->dst->ops;
> > +#endif
> >
> > /* search for matching ddebugs */
> > mutex_lock(&ddebug_lock);
> > @@ -243,8 +722,19 @@ static int ddebug_change(const struct ddebug_query *query,
> > nfound++;
> >
> > newflags = (dp->flags & modifiers->mask) | modifiers->flags;
> > +#if defined CONFIG_DYNAMIC_DEBUG_DST
> > + /* set destination type in newflags */
> > + set_dst_type(&newflags, query->dst->type);
> > + if (newflags == dp->flags &&
> > + (!dst_ops->has_changed ||
> > + !dst_ops->has_changed(query, dp)))
> > + /* nothing changed */
> > + continue;
> > +#else
> > if (newflags == dp->flags)
> > continue;
> > +#endif
> > +
> > #ifdef CONFIG_JUMP_LABEL
> > if (dp->flags & _DPRINTK_FLAGS_PRINT) {
> > if (!(newflags & _DPRINTK_FLAGS_PRINT))
> > @@ -253,14 +743,24 @@ static int ddebug_change(const struct ddebug_query *query,
> > static_branch_enable(&dp->key.dd_key_true);
> > }
> > #endif
> > - v4pr_info("changed %s:%d [%s]%s %s => %s\n",
> > + v4pr_info("changed %s:%d [%s]%s %s %s => %s %s\n",
> > trim_prefix(dp->filename), dp->lineno,
> > dt->mod_name, dp->function,
> > ddebug_describe_flags(dp->flags, &fbuf),
> > - ddebug_describe_flags(newflags, &nbuf));
> > + ddebug_describe_dst_dp(dp, &dstbc),
> > + ddebug_describe_flags(newflags, &nbuf),
> > + ddebug_describe_dst(query->dst, &dstbn));
> > dp->flags = newflags;
> > +
> > +#if defined CONFIG_DYNAMIC_DEBUG_DST
> > + if (dst_ops->has_changed &&
> > + dst_ops->has_changed(query, dp))
> > + /* destination changed, apply it */
> > + dst_apply_change(query, dp);
> > +#endif
> > }
> > }
> > +
> > mutex_unlock(&ddebug_lock);
> >
> > if (!nfound && verbose)
> > @@ -456,6 +956,12 @@ static int ddebug_parse_query(char *words[], int nwords,
> > return -EINVAL;
> > } else if (!strcmp(keyword, "class")) {
> > rc = check_set(&query->class_string, arg, "class");
> > +#if defined CONFIG_DYNAMIC_DEBUG_DST
> > + } else if (!strcmp(keyword, "dst")) {
> > + rc = dst_parse_and_init(query, arg);
> > + if (rc)
> > + return rc;
> > +#endif
> > } else {
> > pr_err("unknown keyword \"%s\"\n", keyword);
> > return -EINVAL;
> > @@ -463,6 +969,15 @@ static int ddebug_parse_query(char *words[], int nwords,
> > if (rc)
> > return rc;
> > }
> > +
> > +#if defined CONFIG_DYNAMIC_DEBUG_DST
> > + /* set destination to syslog by default if it was not explicitly set */
> > + if (!query->dst) {
> > + rc = dst_parse_and_init(query, "syslog");
> > + if (rc)
> > + return rc;
> > + }
> > +#endif
> > if (!query->module && modname)
> > /*
> > * support $modname.dyndbg=<multiple queries>, when
> > @@ -549,11 +1064,14 @@ static int ddebug_exec_query(char *query_string, const char *modname)
> > }
> > if (ddebug_parse_query(words, nwords-1, &query, modname)) {
> > pr_err("query parse failed\n");
> > + dst_try_free(&query);
> > return -EINVAL;
> > }
> > +
> > /* actually go and implement the change */
> > nfound = ddebug_change(&query, &modifiers);
> > vpr_info_dq(&query, nfound ? "applied" : "no-match");
> > + dst_try_free(&query);
> >
> > return nfound;
> > }
> > @@ -856,6 +1374,10 @@ static inline char *dynamic_emit_prefix(struct _ddebug *desc, char *buf)
> >
> > void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...)
> > {
> > +#if defined CONFIG_DYNAMIC_DEBUG_DST
> > + struct ddebug_dst *dst;
> > + int idx;
> > +#endif
> > va_list args;
> > struct va_format vaf;
> > char buf[PREFIX_SIZE] = "";
> > @@ -868,6 +1390,21 @@ void __dynamic_pr_debug(struct _ddebug *descriptor, const char *fmt, ...)
> > vaf.fmt = fmt;
> > vaf.va = &args;
> >
> > +#if defined CONFIG_DYNAMIC_DEBUG_DST
> > + if (!get_dst_type(descriptor))
> > + goto syslog;
> > +
> > + idx = dd_srcu_read_lock(&dst_srcu);
> > + dst = dd_srcu_dereference(descriptor->dst, &dst_srcu);
> > + WARN_ON(!dst);
> > + dst->ops->print(dst, "%s%pV", dynamic_emit_prefix(descriptor, buf),
> > + &vaf);
> > +
> > + dd_srcu_read_unlock(&dst_srcu, idx);
> > + va_end(args);
> > + return;
> > +syslog:
> > +#endif
> > printk(KERN_DEBUG "%s%pV", dynamic_emit_prefix(descriptor, buf), &vaf);
> >
> > va_end(args);
> > @@ -877,6 +1414,10 @@ EXPORT_SYMBOL(__dynamic_pr_debug);
> > void __dynamic_dev_dbg(struct _ddebug *descriptor,
> > const struct device *dev, const char *fmt, ...)
> > {
> > +#if defined CONFIG_DYNAMIC_DEBUG_DST
> > + struct ddebug_dst *dst;
> > + int idx;
> > +#endif
> > struct va_format vaf;
> > va_list args;
> >
> > @@ -888,6 +1429,29 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor,
> > vaf.fmt = fmt;
> > vaf.va = &args;
> >
> > +#if defined CONFIG_DYNAMIC_DEBUG_DST
> > + if (!get_dst_type(descriptor))
> > + goto syslog;
> > +
> > + idx = dd_srcu_read_lock(&dst_srcu);
> > + dst = dd_srcu_dereference(descriptor->dst, &dst_srcu);
> > + WARN_ON(!dst);
> > + if (!dev) {
> > + dst->ops->print(dst, "(NULL device *): %pV", &vaf);
> > + } else {
> > + char buf[PREFIX_SIZE] = "";
> > +
> > + dst->ops->dev_print(dst, dev, "%s%s %s: %pV",
> > + dynamic_emit_prefix(descriptor, buf),
> > + dev_driver_string(dev), dev_name(dev),
> > + &vaf);
> > + }
> > +
> > + dd_srcu_read_unlock(&dst_srcu, idx);
> > + va_end(args);
> > + return;
> > +syslog:
> > +#endif
> > if (!dev) {
> > printk(KERN_DEBUG "(NULL device *): %pV", &vaf);
> > } else {
> > @@ -908,6 +1472,10 @@ EXPORT_SYMBOL(__dynamic_dev_dbg);
> > void __dynamic_netdev_dbg(struct _ddebug *descriptor,
> > const struct net_device *dev, const char *fmt, ...)
> > {
> > +#if defined CONFIG_DYNAMIC_DEBUG_DST
> > + struct ddebug_dst *dst;
> > + int idx;
> > +#endif
> > struct va_format vaf;
> > va_list args;
> >
> > @@ -919,6 +1487,35 @@ void __dynamic_netdev_dbg(struct _ddebug *descriptor,
> > vaf.fmt = fmt;
> > vaf.va = &args;
> >
> > +#if defined CONFIG_DYNAMIC_DEBUG_DST
> > + if (!get_dst_type(descriptor))
> > + goto syslog;
> > +
> > + idx = dd_srcu_read_lock(&dst_srcu);
> > + dst = dd_srcu_dereference(descriptor->dst, &dst_srcu);
> > + WARN_ON(!dst);
> > + if (dev && dev->dev.parent) {
> > + char buf[PREFIX_SIZE] = "";
> > +
> > + dst->ops->dev_print(dst, dev->dev.parent,
> > + "%s%s %s %s%s: %pV",
> > + dynamic_emit_prefix(descriptor, buf),
> > + dev_driver_string(dev->dev.parent),
> > + dev_name(dev->dev.parent),
> > + netdev_name(dev), netdev_reg_state(dev),
> > + &vaf);
> > + } else if (dev) {
> > + dst->ops->print(dst, "%s%s: %pV", netdev_name(dev),
> > + netdev_reg_state(dev), &vaf);
> > + } else {
> > + dst->ops->print(dst, "(NULL net_device *): %pV", &vaf);
> > + }
> > +
> > + dd_srcu_read_unlock(&dst_srcu, idx);
> > + va_end(args);
> > + return;
> > +syslog:
> > +#endif
> > if (dev && dev->dev.parent) {
> > char buf[PREFIX_SIZE] = "";
> >
> > @@ -947,6 +1544,10 @@ EXPORT_SYMBOL(__dynamic_netdev_dbg);
> > void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
> > const struct ib_device *ibdev, const char *fmt, ...)
> > {
> > +#if defined CONFIG_DYNAMIC_DEBUG_DST
> > + struct ddebug_dst *dst;
> > + int idx;
> > +#endif
> > struct va_format vaf;
> > va_list args;
> >
> > @@ -955,6 +1556,34 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
> > vaf.fmt = fmt;
> > vaf.va = &args;
> >
> > +#if defined CONFIG_DYNAMIC_DEBUG_DST
> > + if (!get_dst_type(descriptor))
> > + goto syslog;
> > +
> > + idx = dd_srcu_read_lock(&dst_srcu);
> > + dst = dd_srcu_dereference(descriptor->dst, &dst_srcu);
> > + WARN_ON(!dst);
> > + if (ibdev && ibdev->dev.parent) {
> > + char buf[PREFIX_SIZE] = "";
> > +
> > + dst->ops->dev_print(dst, ibdev->dev.parent,
> > + "%s%s %s %s: %pV",
> > + dynamic_emit_prefix(descriptor, buf),
> > + dev_driver_string(ibdev->dev.parent),
> > + dev_name(ibdev->dev.parent),
> > + dev_name(&ibdev->dev),
> > + &vaf);
> > + } else if (ibdev) {
> > + dst->ops->print(dst, "%s: %pV", dev_name(&ibdev->dev), &vaf);
> > + } else {
> > + dst->ops->print(dst, "(NULL ib_device): %pV", &vaf);
> > + }
> > +
> > + dd_srcu_read_unlock(&dst_srcu, idx);
> > + va_end(args);
> > + return;
> > +syslog:
> > +#endif
> > if (ibdev && ibdev->dev.parent) {
> > char buf[PREFIX_SIZE] = "";
> >
> > @@ -1127,11 +1756,16 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
> > struct ddebug_iter *iter = m->private;
> > struct _ddebug *dp = p;
> > struct flagsbuf flags;
> > + struct dstbuf dstb;
> > char const *class;
> >
> > if (p == SEQ_START_TOKEN) {
> > - seq_puts(m,
> > - "# filename:lineno [module]function flags format\n");
> > + seq_puts(m, "# filename:lineno [module]function flags format");
> > +#if defined CONFIG_DYNAMIC_DEBUG_DST
> > + seq_puts(m, " destination\n");
> > +#else
> > + seq_puts(m, "\n");
> > +#endif
> > return 0;
> > }
> >
> > @@ -1149,6 +1783,7 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
> > else
> > seq_printf(m, " class unknown, _id:%d", dp->class_id);
> > }
> > + seq_printf(m, " %s", ddebug_describe_dst_dp(dp, &dstb));
> > seq_puts(m, "\n");
> >
> > return 0;
> > @@ -1351,6 +1986,9 @@ static void ddebug_remove_all_tables(void)
> >
> > static __initdata int ddebug_init_success;
> >
> > +
> > +#ifndef CONFIG_DYNAMIC_DEBUG_DST_STATIC
> > +
> > static int __init dynamic_debug_init_control(void)
> > {
> > struct proc_dir_entry *procfs_dir;
> > @@ -1374,6 +2012,15 @@ static int __init dynamic_debug_init_control(void)
> > return 0;
> > }
> >
> > +#else
> > +
> > +static int __init dynamic_debug_init_control(void)
> > +{
> > + return 0;
> > +}
> > +
> > +#endif
> > +
> > static int __init dynamic_debug_init(void)
> > {
> > struct _ddebug *iter, *iter_mod_start;
Powered by blists - more mailing lists