LinuxLists.cc - [RFC PATCH 0/4] Drop custom logging

[permalink] [raw]

Subject: Re: [RFC PATCH 0/4] Drop custom logging

Hi Umang,

[add Phil]

Am 18.01.23 um 12:58 schrieb Umang Jain:
> Drop custom logging from the vchiq interface.
> Mostly of them are replaced with dev_dbg and friends
> and/or pr_info and friends.
>
> The debugfs log levels (in 4/4) are mapped to kernel
> logs levels (coming from include/linux/kern_levels.h)
> Would like some thoughts on it as I am not sure (hence
> marking this is RFC)
>
> From drivers/staging/vc04_services/interface/TODO:
>
> """
> * Cleanup logging mechanism
>
> The driver should probably be using the standard kernel logging mechanisms
> such as dev_info, dev_dbg, and friends.

i don't have any experience with vchiq logging/debug. So i'm not sure if
it's acceptable to lose the second log level dimension (like
vchiq_arm_log_level) completely. Complex drivers like brcmfmac have a
debug mask to avoid log spamming [1]. Maybe this is a compromise.

Btw some loglevel locations has already been messed up during
refactoring :-(

[1] - drivers/net/wireless/broadcom/brcm80211/brcmfmac/debug.h

> """
>
> Umang Jain (4):
> staging: vc04_services: vchiq_core: Drop custom logging
> staging: vc04_services: vchiq_arm: Drop custom logging
> staging: vc04_services: Drop custom logging
> staging: vc04_services: Drop remnants of custom logging
>
> .../interface/vchiq_arm/vchiq_arm.c | 151 +++---
> .../interface/vchiq_arm/vchiq_connected.c | 5 +-
> .../interface/vchiq_arm/vchiq_core.c | 479 ++++++++----------
> .../interface/vchiq_arm/vchiq_core.h | 39 --
> .../interface/vchiq_arm/vchiq_debugfs.c | 26 +-
> .../interface/vchiq_arm/vchiq_dev.c | 78 ++-
> 6 files changed, 329 insertions(+), 449 deletions(-)
>

2023-01-18 18:45:58

[permalink] [raw]

Subject: Re: [RFC PATCH 4/4] staging: vc04_services: Drop remnants of custom logging

Hi Umang,

[add Phil]

Am 18.01.23 um 12:58 schrieb Umang Jain:
> Drop remnants of custom logging such as header definitions and such.
> Also migrate the vchiq_debugfs to use the log levels coming from
> include/linux/kern_levels.h instead.
since we switch to default kernel logging, i would prefer to drop all of
these logging specific debugfs entries too. Or just leave one entry to
specify a logging mask as suggested before.
>
> Signed-off-by: Umang Jain <[email protected]>
> ---
> .../interface/vchiq_arm/vchiq_arm.c | 4 --
> .../interface/vchiq_arm/vchiq_core.c | 39 +++++++------------
> .../interface/vchiq_arm/vchiq_core.h | 39 -------------------
> .../interface/vchiq_arm/vchiq_debugfs.c | 26 ++++++++-----
> 4 files changed, 31 insertions(+), 77 deletions(-)
>
> diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
> index ed3773b996a3..45e28ca368ee 100644
> --- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
> +++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_arm.c
> @@ -60,10 +60,6 @@
> #define KEEPALIVE_VER 1
> #define KEEPALIVE_VER_MIN KEEPALIVE_VER
>
> -/* Run time control of log level, based on KERN_XXX level. */
> -int vchiq_arm_log_level = VCHIQ_LOG_DEFAULT;
> -int vchiq_susp_log_level = VCHIQ_LOG_ERROR;
> -
> DEFINE_SPINLOCK(msg_queue_spinlock);
> struct vchiq_state g_state;
>
> diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
> index 7b3c57326d28..4cf710a3ca28 100644
> --- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
> +++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
> @@ -9,6 +9,7 @@
> #include <linux/wait.h>
> #include <linux/delay.h>
> #include <linux/slab.h>
> +#include <linux/kern_levels.h>
> #include <linux/kref.h>
> #include <linux/rcupdate.h>
> #include <linux/sched/signal.h>
> @@ -103,10 +104,8 @@ static_assert((unsigned int)VCHIQ_PORT_MAX <
>
> #define BULK_INDEX(x) ((x) & (VCHIQ_NUM_SERVICE_BULKS - 1))
>
> -#define SRVTRACE_LEVEL(srv) \
> - (((srv) && (srv)->trace) ? VCHIQ_LOG_TRACE : vchiq_core_msg_log_level)
> #define SRVTRACE_ENABLED(srv, lev) \
> - (((srv) && (srv)->trace) || (vchiq_core_msg_log_level >= (lev)))
> + (((srv) && (srv)->trace) || (LOGLEVEL_DEFAULT >= (lev)))
>
> #define NO_CLOSE_RECVD 0
> #define CLOSE_RECVD 1
> @@ -154,11 +153,6 @@ static inline void check_sizes(void)
> BUILD_BUG_ON_NOT_POWER_OF_2(VCHIQ_MAX_SERVICES);
> }
>
> -/* Run time control of log level, based on KERN_XXX level. */
> -int vchiq_core_log_level = VCHIQ_LOG_DEFAULT;
> -int vchiq_core_msg_log_level = VCHIQ_LOG_DEFAULT;
> -int vchiq_sync_log_level = VCHIQ_LOG_DEFAULT;
> -
> DEFINE_SPINLOCK(bulk_waiter_spinlock);
> static DEFINE_SPINLOCK(quota_spinlock);
>
> @@ -1035,8 +1029,7 @@ queue_message(struct vchiq_state *state, struct vchiq_service *service,
> return -EINVAL;
> }
>
> - if (SRVTRACE_ENABLED(service,
> - VCHIQ_LOG_INFO))
> + if (SRVTRACE_ENABLED(service, LOGLEVEL_INFO))
> vchiq_log_dump_mem("Sent", 0,
> header->data,
> min_t(size_t, 16, callback_result));
> @@ -1144,6 +1137,7 @@ queue_message_sync(struct vchiq_state *state, struct vchiq_service *service,
> struct vchiq_shared_state *local;
> struct vchiq_header *header;
> ssize_t callback_result;
> + int svc_fourcc;
>
> local = state->local;
>
> @@ -1184,8 +1178,7 @@ queue_message_sync(struct vchiq_state *state, struct vchiq_service *service,
> }
>
> if (service) {
> - if (SRVTRACE_ENABLED(service,
> - VCHIQ_LOG_INFO))
> + if (SRVTRACE_ENABLED(service, LOGLEVEL_INFO))
> vchiq_log_dump_mem("Sent", 0,
> header->data,
> min_t(size_t, 16, callback_result));
> @@ -1199,19 +1192,15 @@ queue_message_sync(struct vchiq_state *state, struct vchiq_service *service,
> header->size = size;
> header->msgid = msgid;
>
> - if (vchiq_sync_log_level >= VCHIQ_LOG_TRACE) {
> - int svc_fourcc;
>
> - svc_fourcc = service
> - ? service->base.fourcc
> - : VCHIQ_MAKE_FOURCC('?', '?', '?', '?');
> + svc_fourcc = service ? service->base.fourcc
> + : VCHIQ_MAKE_FOURCC('?', '?', '?', '?');
>
> - dev_dbg(state->dev,
> - "Sent Sync Msg %s(%u) to %c%c%c%c s:%u d:%d len:%d",
> - msg_type_str(VCHIQ_MSG_TYPE(msgid)), VCHIQ_MSG_TYPE(msgid),
> - VCHIQ_FOURCC_AS_4CHARS(svc_fourcc), VCHIQ_MSG_SRCPORT(msgid),
> - VCHIQ_MSG_DSTPORT(msgid), size);
> - }
> + dev_dbg(state->dev,
> + "Sent Sync Msg %s(%u) to %c%c%c%c s:%u d:%d len:%d",
> + msg_type_str(VCHIQ_MSG_TYPE(msgid)), VCHIQ_MSG_TYPE(msgid),
> + VCHIQ_FOURCC_AS_4CHARS(svc_fourcc), VCHIQ_MSG_SRCPORT(msgid),
> + VCHIQ_MSG_DSTPORT(msgid), size);
>
> remote_event_signal(&state->remote->sync_trigger);
>
> @@ -1624,7 +1613,7 @@ parse_message(struct vchiq_state *state, struct vchiq_header *header)
> break;
> }
>
> - if (SRVTRACE_ENABLED(service, VCHIQ_LOG_INFO)) {
> + if (SRVTRACE_ENABLED(service, LOGLEVEL_INFO)) {
> int svc_fourcc;
>
> svc_fourcc = service
> @@ -2031,7 +2020,7 @@ sync_func(void *v)
> continue;
> }
>
> - if (vchiq_sync_log_level >= VCHIQ_LOG_TRACE) {
> + if (vchiq_sync_log_level >= LOGLEVEL_DEBUG) {
> int svc_fourcc;
>
> svc_fourcc = service
> diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
> index ec3505424718..960bf4efeab5 100644
> --- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
> +++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.h
> @@ -30,39 +30,6 @@
> #define VCHIQ_SLOT_SIZE 4096
> #define VCHIQ_MAX_MSG_SIZE (VCHIQ_SLOT_SIZE - sizeof(struct vchiq_header))
>
> -/* Run time control of log level, based on KERN_XXX level. */
> -#define VCHIQ_LOG_DEFAULT 4
> -#define VCHIQ_LOG_ERROR 3
> -#define VCHIQ_LOG_WARNING 4
> -#define VCHIQ_LOG_INFO 6
> -#define VCHIQ_LOG_TRACE 7
> -
> -#define VCHIQ_LOG_PREFIX KERN_INFO "vchiq: "
> -
> -#ifndef vchiq_log_error
> -#define vchiq_log_error(cat, fmt, ...) \
> - do { if (cat >= VCHIQ_LOG_ERROR) \
> - printk(VCHIQ_LOG_PREFIX fmt "\n", ##__VA_ARGS__); } while (0)
> -#endif
> -#ifndef vchiq_log_warning
> -#define vchiq_log_warning(cat, fmt, ...) \
> - do { if (cat >= VCHIQ_LOG_WARNING) \
> - printk(VCHIQ_LOG_PREFIX fmt "\n", ##__VA_ARGS__); } while (0)
> -#endif
> -#ifndef vchiq_log_info
> -#define vchiq_log_info(cat, fmt, ...) \
> - do { if (cat >= VCHIQ_LOG_INFO) \
> - printk(VCHIQ_LOG_PREFIX fmt "\n", ##__VA_ARGS__); } while (0)
> -#endif
> -#ifndef vchiq_log_trace
> -#define vchiq_log_trace(cat, fmt, ...) \
> - do { if (cat >= VCHIQ_LOG_TRACE) \
> - printk(VCHIQ_LOG_PREFIX fmt "\n", ##__VA_ARGS__); } while (0)
> -#endif
> -
> -#define vchiq_loud_error(...) \
> - vchiq_log_error(vchiq_core_log_level, "===== " __VA_ARGS__)
> -
> #define VCHIQ_SLOT_MASK (VCHIQ_SLOT_SIZE - 1)
> #define VCHIQ_SLOT_QUEUE_MASK (VCHIQ_MAX_SLOTS_PER_SIDE - 1)
> #define VCHIQ_SLOT_ZERO_SLOTS DIV_ROUND_UP(sizeof(struct vchiq_slot_zero), \
> @@ -496,12 +463,6 @@ vchiq_dump_state(void *dump_context, struct vchiq_state *state);
> extern int
> vchiq_dump_service_state(void *dump_context, struct vchiq_service *service);
>
> -extern void
> -vchiq_loud_error_header(void);
> -
> -extern void
> -vchiq_loud_error_footer(void);
> -
> extern void
> request_poll(struct vchiq_state *state, struct vchiq_service *service,
> int poll_type);
> diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_debugfs.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_debugfs.c
> index dc667afd1f8c..1d142752351d 100644
> --- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_debugfs.c
> +++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_debugfs.c
> @@ -5,6 +5,8 @@
> */
>
> #include <linux/debugfs.h>
> +#include <linux/kern_levels.h>
> +
> #include "vchiq_core.h"
> #include "vchiq_arm.h"
> #include "vchiq_debugfs.h"
> @@ -22,6 +24,12 @@
> static struct dentry *vchiq_dbg_dir;
> static struct dentry *vchiq_dbg_clients;
>
> +int vchiq_arm_log_level = LOGLEVEL_DEFAULT;
> +int vchiq_susp_log_level = LOGLEVEL_ERR;
> +int vchiq_core_log_level = LOGLEVEL_DEFAULT;
> +int vchiq_core_msg_log_level = LOGLEVEL_DEFAULT;
> +int vchiq_sync_log_level = LOGLEVEL_DEFAULT;
> +
> /* Log category debugfs entries */
> struct vchiq_debugfs_log_entry {
> const char *name;
> @@ -42,16 +50,16 @@ static int debugfs_log_show(struct seq_file *f, void *offset)
> char *log_value = NULL;
>
> switch (*levp) {
> - case VCHIQ_LOG_ERROR:
> + case LOGLEVEL_ERR:
> log_value = VCHIQ_LOG_ERROR_STR;
> break;
> - case VCHIQ_LOG_WARNING:
> + case LOGLEVEL_WARNING:
> log_value = VCHIQ_LOG_WARNING_STR;
> break;
> - case VCHIQ_LOG_INFO:
> + case LOGLEVEL_INFO:
> log_value = VCHIQ_LOG_INFO_STR;
> break;
> - case VCHIQ_LOG_TRACE:
> + case LOGLEVEL_DEBUG:
> log_value = VCHIQ_LOG_TRACE_STR;
> break;
> default:
> @@ -85,15 +93,15 @@ static ssize_t debugfs_log_write(struct file *file,
> kbuf[count - 1] = 0;
>
> if (strncmp("error", kbuf, strlen("error")) == 0)
> - *levp = VCHIQ_LOG_ERROR;
> + *levp = LOGLEVEL_ERR;
> else if (strncmp("warning", kbuf, strlen("warning")) == 0)
> - *levp = VCHIQ_LOG_WARNING;
> + *levp = LOGLEVEL_WARNING;
> else if (strncmp("info", kbuf, strlen("info")) == 0)
> - *levp = VCHIQ_LOG_INFO;
> + *levp = LOGLEVEL_INFO;
> else if (strncmp("trace", kbuf, strlen("trace")) == 0)
> - *levp = VCHIQ_LOG_TRACE;
> + *levp = LOGLEVEL_DEBUG;
> else
> - *levp = VCHIQ_LOG_DEFAULT;
> + *levp = LOGLEVEL_DEFAULT;
>
> *ppos += count;
>

2023-01-18 18:47:18

[permalink] [raw]

Subject: Re: [RFC PATCH 1/4] staging: vc04_services: vchiq_core: Drop custom logging

Hi Umang,

Am 18.01.23 um 12:58 schrieb Umang Jain:
> Drop custom logging from the vchiq_core.c and use standard kernel
> logging infrastructure (dev_dbg() and friends for struct Device
> stuff) and pr_info (and similar) for vchiq_services/instances things.
i'm sorry but your "staging: vc04_services: vchiq: Register devices with
a custom bus_type" is still in my backlog. I was busy with some
regressions on bcm2835/bcm2711.
>
> Signed-off-by: Umang Jain <[email protected]>
> ---
> .../interface/vchiq_arm/vchiq_core.c | 450 ++++++++----------
> 1 file changed, 204 insertions(+), 246 deletions(-)
>
> diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
> index 4e705a447a62..7b3c57326d28 100644
> --- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
> +++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
> @@ -227,10 +227,11 @@ static const char *msg_type_str(unsigned int msg_type)
> static inline void
> set_service_state(struct vchiq_service *service, int newstate)
> {
> - vchiq_log_info(vchiq_core_log_level, "%d: srv:%d %s->%s",
> - service->state->id, service->localport,
> - srvstate_names[service->srvstate],
> - srvstate_names[newstate]);
> + struct vchiq_state *state = service->state;
> +
> + dev_info(state->dev, "%d: srv:%d %s->%s", state->id,
> + service->localport, srvstate_names[service->srvstate],
> + srvstate_names[newstate]);
> service->srvstate = newstate;
> }
>
> @@ -255,8 +256,7 @@ find_service_by_handle(struct vchiq_instance *instance, unsigned int handle)
> return service;
> }
> rcu_read_unlock();
> - vchiq_log_info(vchiq_core_log_level,
> - "Invalid service handle 0x%x", handle);
> + pr_info("vchiq: Invalid service handle 0x%x", handle);

Some log levels like this here doesn't make sense. I would expect here a
warning or an error. Could you please have look at it in a separate patch?

Thanks

2023-01-19 05:26:15

[permalink] [raw]

Subject: Re: [RFC PATCH 0/4] Drop custom logging

On Wed, Jan 18, 2023 at 06:54:56PM +0100, Stefan Wahren wrote:
> Hi Umang,
>
> [add Phil]
>
> Am 18.01.23 um 12:58 schrieb Umang Jain:
> > Drop custom logging from the vchiq interface.
> > Mostly of them are replaced with dev_dbg and friends
> > and/or pr_info and friends.
> >
> > The debugfs log levels (in 4/4) are mapped to kernel
> > logs levels (coming from include/linux/kern_levels.h)
> > Would like some thoughts on it as I am not sure (hence
> > marking this is RFC)
> >
> > From drivers/staging/vc04_services/interface/TODO:
> >
> > """
> > * Cleanup logging mechanism
> >
> > The driver should probably be using the standard kernel logging mechanisms
> > such as dev_info, dev_dbg, and friends.
>
> i don't have any experience with vchiq logging/debug. So i'm not sure if
> it's acceptable to lose the second log level dimension (like
> vchiq_arm_log_level) completely. Complex drivers like brcmfmac have a debug
> mask to avoid log spamming [1]. Maybe this is a compromise.
>
> Btw some loglevel locations has already been messed up during refactoring
> :-(
>
> [1] - drivers/net/wireless/broadcom/brcm80211/brcmfmac/debug.h
>

Kernel logging is actually has a bunch of features. You can turn them
on for just a module or function or enable a specific message. See
Documentation/admin-guide/dynamic-debug-howto.rst
for more info.

This vchiq logging is a re-implementation of a subset of the features
that normal kernel logging infrastructure provides. Moving to normal
logging will make it cleaner but also more flexible and powerful. It's
better in every way.

The broadcom stuff is different and more complicated than what this
module is trying to do. They are sorting out their logging according to
various components. I understand the motivation, but they would
probably have been better just use standard logging like everyone else.

regards,
dan carpenter

2023-01-19 14:41:57

[permalink] [raw]

Subject: Re: [RFC PATCH 1/4] staging: vc04_services: vchiq_core: Drop custom logging

On Wed, Jan 18, 2023 at 05:28:07PM +0530, Umang Jain wrote:
> diff --git a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
> index 4e705a447a62..7b3c57326d28 100644
> --- a/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
> +++ b/drivers/staging/vc04_services/interface/vchiq_arm/vchiq_core.c
> @@ -227,10 +227,11 @@ static const char *msg_type_str(unsigned int msg_type)
> static inline void
> set_service_state(struct vchiq_service *service, int newstate)
> {
> - vchiq_log_info(vchiq_core_log_level, "%d: srv:%d %s->%s",
> - service->state->id, service->localport,
> - srvstate_names[service->srvstate],
> - srvstate_names[newstate]);
> + struct vchiq_state *state = service->state;
> +
> + dev_info(state->dev, "%d: srv:%d %s->%s", state->id,
> + service->localport, srvstate_names[service->srvstate],
> + srvstate_names[newstate]);

This should be a debug level printk. Don't spam dmesg in the success
path. Success should not be noteworthy.

> service->srvstate = newstate;
> }

regards,
dan carpenter

2023-01-19 14:41:58

[permalink] [raw]

Subject: Re: [RFC PATCH 0/4] Drop custom logging

Hi all,

On Wed, 18 Jan 2023 at 17:55, Stefan Wahren <[email protected]> wrote:
>
> Hi Umang,
>
> [add Phil]
>
> Am 18.01.23 um 12:58 schrieb Umang Jain:
> > Drop custom logging from the vchiq interface.
> > Mostly of them are replaced with dev_dbg and friends
> > and/or pr_info and friends.
> >
> > The debugfs log levels (in 4/4) are mapped to kernel
> > logs levels (coming from include/linux/kern_levels.h)
> > Would like some thoughts on it as I am not sure (hence
> > marking this is RFC)
> >
> > From drivers/staging/vc04_services/interface/TODO:
> >
> > """
> > * Cleanup logging mechanism
> >
> > The driver should probably be using the standard kernel logging mechanisms
> > such as dev_info, dev_dbg, and friends.
>
> i don't have any experience with vchiq logging/debug. So i'm not sure if
> it's acceptable to lose the second log level dimension (like
> vchiq_arm_log_level) completely. Complex drivers like brcmfmac have a
> debug mask to avoid log spamming [1]. Maybe this is a compromise.
>
> Btw some loglevel locations has already been messed up during
> refactoring :-(
>
> [1] - drivers/net/wireless/broadcom/brcm80211/brcmfmac/debug.h
>
> > """
> >
> > Umang Jain (4):
> > staging: vc04_services: vchiq_core: Drop custom logging
> > staging: vc04_services: vchiq_arm: Drop custom logging
> > staging: vc04_services: Drop custom logging
> > staging: vc04_services: Drop remnants of custom logging
> >
> > .../interface/vchiq_arm/vchiq_arm.c | 151 +++---
> > .../interface/vchiq_arm/vchiq_connected.c | 5 +-
> > .../interface/vchiq_arm/vchiq_core.c | 479 ++++++++----------
> > .../interface/vchiq_arm/vchiq_core.h | 39 --
> > .../interface/vchiq_arm/vchiq_debugfs.c | 26 +-
> > .../interface/vchiq_arm/vchiq_dev.c | 78 ++-
> > 6 files changed, 329 insertions(+), 449 deletions(-)
> >

Thanks for the nudge - this patch set hasn't yet made its way through
the sluggish rpi-kernel moderation.

I understand the desire to remove the custom logging. I don't welcome
the loss of flexibility that comes with such a strategy, but I'm not
going to argue about it. What's harder to understand is the state that
this patchset leaves VCHIQ logging in. From what I can see, the
per-service logging control has gone, but the code still contains
macros that hint at something useful. Similarly, the debugfs support
is completely vestigial, giving the appearance of control while
actually achieving nothing.

Phil

2023-01-19 14:43:36

[permalink] [raw]

Subject: Re: [RFC PATCH 0/4] Drop custom logging

On Thu, Jan 19, 2023 at 01:47:44PM +0000, Phil Elwell wrote:
> > > I understand the desire to remove the custom logging. I don't welcome
> > > the loss of flexibility that comes with such a strategy
> >
> > What "loss of flexibility"? You now have access to the full dynamic
> > debugging facilities that all of the rest of the kernel has. What is
> > lacking?
>
> Perhaps I've missed something, either in this patch set or the kernel
> as a whole, but how is one supposed to set different logging levels on
> different facilities within a driver/module, or even for the module as
> a whole?

Yeah. You will be still able to do that and more besides after the
transition. Cleaning this up makes the code better in every way.

Documentation/admin-guide/dynamic-debug-howto.rst

regards,
dan carpenter

2023-01-19 14:59:59

[permalink] [raw]

Subject: Re: [RFC PATCH 0/4] Drop custom logging

On Thu, 19 Jan 2023 at 13:37, Greg Kroah-Hartman
<[email protected]> wrote:
>
> On Thu, Jan 19, 2023 at 01:31:12PM +0000, Phil Elwell wrote:
> > Hi all,
> >
> >
> > On Wed, 18 Jan 2023 at 17:55, Stefan Wahren <[email protected]> wrote:
> > >
> > > Hi Umang,
> > >
> > > [add Phil]
> > >
> > > Am 18.01.23 um 12:58 schrieb Umang Jain:
> > > > Drop custom logging from the vchiq interface.
> > > > Mostly of them are replaced with dev_dbg and friends
> > > > and/or pr_info and friends.
> > > >
> > > > The debugfs log levels (in 4/4) are mapped to kernel
> > > > logs levels (coming from include/linux/kern_levels.h)
> > > > Would like some thoughts on it as I am not sure (hence
> > > > marking this is RFC)
> > > >
> > > > From drivers/staging/vc04_services/interface/TODO:
> > > >
> > > > """
> > > > * Cleanup logging mechanism
> > > >
> > > > The driver should probably be using the standard kernel logging mechanisms
> > > > such as dev_info, dev_dbg, and friends.
> > >
> > > i don't have any experience with vchiq logging/debug. So i'm not sure if
> > > it's acceptable to lose the second log level dimension (like
> > > vchiq_arm_log_level) completely. Complex drivers like brcmfmac have a
> > > debug mask to avoid log spamming [1]. Maybe this is a compromise.
> > >
> > > Btw some loglevel locations has already been messed up during
> > > refactoring :-(
> > >
> > > [1] - drivers/net/wireless/broadcom/brcm80211/brcmfmac/debug.h
> > >
> > > > """
> > > >
> > > > Umang Jain (4):
> > > > staging: vc04_services: vchiq_core: Drop custom logging
> > > > staging: vc04_services: vchiq_arm: Drop custom logging
> > > > staging: vc04_services: Drop custom logging
> > > > staging: vc04_services: Drop remnants of custom logging
> > > >
> > > > .../interface/vchiq_arm/vchiq_arm.c | 151 +++---
> > > > .../interface/vchiq_arm/vchiq_connected.c | 5 +-
> > > > .../interface/vchiq_arm/vchiq_core.c | 479 ++++++++----------
> > > > .../interface/vchiq_arm/vchiq_core.h | 39 --
> > > > .../interface/vchiq_arm/vchiq_debugfs.c | 26 +-
> > > > .../interface/vchiq_arm/vchiq_dev.c | 78 ++-
> > > > 6 files changed, 329 insertions(+), 449 deletions(-)
> > > >
> >
> > Thanks for the nudge - this patch set hasn't yet made its way through
> > the sluggish rpi-kernel moderation.
> >
> > I understand the desire to remove the custom logging. I don't welcome
> > the loss of flexibility that comes with such a strategy
>
> What "loss of flexibility"? You now have access to the full dynamic
> debugging facilities that all of the rest of the kernel has. What is
> lacking?

Perhaps I've missed something, either in this patch set or the kernel
as a whole, but how is one supposed to set different logging levels on
different facilities within a driver/module, or even for the module as
a whole? I don't consider anything that requires reference to
individual lines in the source code to be a suitable replacement,
clever though it is.

> > , but I'm not
> > going to argue about it. What's harder to understand is the state that
> > this patchset leaves VCHIQ logging in. From what I can see, the
> > per-service logging control has gone, but the code still contains
> > macros that hint at something useful. Similarly, the debugfs support
> > is completely vestigial, giving the appearance of control while
> > actually achieving nothing.
>
> The debugfs files should also be removed if they don't do anything
> anymore.
>
> thanks,
>
> greg k-h

2023-01-19 15:20:10

[permalink] [raw]

Subject: Re: [RFC PATCH 0/4] Drop custom logging

On Thu, 19 Jan 2023 at 14:37, Dan Carpenter <[email protected]> wrote:
>
> On Thu, Jan 19, 2023 at 02:31:50PM +0000, Phil Elwell wrote:
> > On Thu, 19 Jan 2023 at 14:25, Dan Carpenter <[email protected]> wrote:
> > >
> > > On Thu, Jan 19, 2023 at 01:47:44PM +0000, Phil Elwell wrote:
> > > > > > I understand the desire to remove the custom logging. I don't welcome
> > > > > > the loss of flexibility that comes with such a strategy
> > > > >
> > > > > What "loss of flexibility"? You now have access to the full dynamic
> > > > > debugging facilities that all of the rest of the kernel has. What is
> > > > > lacking?
> > > >
> > > > Perhaps I've missed something, either in this patch set or the kernel
> > > > as a whole, but how is one supposed to set different logging levels on
> > > > different facilities within a driver/module, or even for the module as
> > > > a whole?
> > >
> > > Yeah. You will be still able to do that and more besides after the
> > > transition. Cleaning this up makes the code better in every way.
> > >
> > > Documentation/admin-guide/dynamic-debug-howto.rst
> >
> > Are you saying this patch set gets us to that point?
>
> Yes. The patch has some issues, but yes.

OK, thanks. I'll be watching how this plays out with interest.

Phil

2023-01-19 15:20:30

[permalink] [raw]

Subject: Re: [RFC PATCH 0/4] Drop custom logging

On Thu, Jan 19, 2023 at 02:31:50PM +0000, Phil Elwell wrote:
> On Thu, 19 Jan 2023 at 14:25, Dan Carpenter <[email protected]> wrote:
> >
> > On Thu, Jan 19, 2023 at 01:47:44PM +0000, Phil Elwell wrote:
> > > > > I understand the desire to remove the custom logging. I don't welcome
> > > > > the loss of flexibility that comes with such a strategy
> > > >
> > > > What "loss of flexibility"? You now have access to the full dynamic
> > > > debugging facilities that all of the rest of the kernel has. What is
> > > > lacking?
> > >
> > > Perhaps I've missed something, either in this patch set or the kernel
> > > as a whole, but how is one supposed to set different logging levels on
> > > different facilities within a driver/module, or even for the module as
> > > a whole?
> >
> > Yeah. You will be still able to do that and more besides after the
> > transition. Cleaning this up makes the code better in every way.
> >
> > Documentation/admin-guide/dynamic-debug-howto.rst
>
> Are you saying this patch set gets us to that point?

Yes. The patch has some issues, but yes.

regards,
dan carpenter

2023-01-19 15:26:42

[permalink] [raw]

Subject: Re: [RFC PATCH 0/4] Drop custom logging

On Thu, 19 Jan 2023 at 14:25, Dan Carpenter <[email protected]> wrote:
>
> On Thu, Jan 19, 2023 at 01:47:44PM +0000, Phil Elwell wrote:
> > > > I understand the desire to remove the custom logging. I don't welcome
> > > > the loss of flexibility that comes with such a strategy
> > >
> > > What "loss of flexibility"? You now have access to the full dynamic
> > > debugging facilities that all of the rest of the kernel has. What is
> > > lacking?
> >
> > Perhaps I've missed something, either in this patch set or the kernel
> > as a whole, but how is one supposed to set different logging levels on
> > different facilities within a driver/module, or even for the module as
> > a whole?
>
> Yeah. You will be still able to do that and more besides after the
> transition. Cleaning this up makes the code better in every way.
>
> Documentation/admin-guide/dynamic-debug-howto.rst

Are you saying this patch set gets us to that point?

2023-01-20 01:28:53

by Laurent Pinchart

[permalink] [raw]

Subject: Re: [RFC PATCH 0/4] Drop custom logging

On Thu, Jan 19, 2023 at 05:37:48PM +0300, Dan Carpenter wrote:
> On Thu, Jan 19, 2023 at 02:31:50PM +0000, Phil Elwell wrote:
> > On Thu, 19 Jan 2023 at 14:25, Dan Carpenter wrote:
> > > On Thu, Jan 19, 2023 at 01:47:44PM +0000, Phil Elwell wrote:
> > > > > > I understand the desire to remove the custom logging. I don't welcome
> > > > > > the loss of flexibility that comes with such a strategy
> > > > >
> > > > > What "loss of flexibility"? You now have access to the full dynamic
> > > > > debugging facilities that all of the rest of the kernel has. What is
> > > > > lacking?
> > > >
> > > > Perhaps I've missed something, either in this patch set or the kernel
> > > > as a whole, but how is one supposed to set different logging levels on
> > > > different facilities within a driver/module, or even for the module as
> > > > a whole?
> > >
> > > Yeah. You will be still able to do that and more besides after the
> > > transition. Cleaning this up makes the code better in every way.
> > >
> > > Documentation/admin-guide/dynamic-debug-howto.rst
> >
> > Are you saying this patch set gets us to that point?
>
> Yes. The patch has some issues, but yes.

I think I'm missing something too then. Dynamic debug provides the
ability to easily switch dev_dbg() messages on and off at runtime, but
it doesn't provide, as far as I'm aware, log levels or log categories.

Log levels are currently used by the vchiq code to suppress messages
below a certain level. Kernel log levels are not an exact replacement,
as the messages still end up in the kernel log (except for debug
messages).

Log categories are used to group messages in categories and control
their log level per category. As far as I know, dynamic debug doesn't
provide any such feature.

--
Regards,

Laurent Pinchart

2023-01-20 02:06:14

by Laurent Pinchart

[permalink] [raw]

Subject: Re: [RFC PATCH 0/4] Drop custom logging

On Fri, Jan 20, 2023 at 02:53:17AM +0200, Laurent Pinchart wrote:
> On Thu, Jan 19, 2023 at 05:37:48PM +0300, Dan Carpenter wrote:
> > On Thu, Jan 19, 2023 at 02:31:50PM +0000, Phil Elwell wrote:
> > > On Thu, 19 Jan 2023 at 14:25, Dan Carpenter wrote:
> > > > On Thu, Jan 19, 2023 at 01:47:44PM +0000, Phil Elwell wrote:
> > > > > > > I understand the desire to remove the custom logging. I don't welcome
> > > > > > > the loss of flexibility that comes with such a strategy
> > > > > >
> > > > > > What "loss of flexibility"? You now have access to the full dynamic
> > > > > > debugging facilities that all of the rest of the kernel has. What is
> > > > > > lacking?
> > > > >
> > > > > Perhaps I've missed something, either in this patch set or the kernel
> > > > > as a whole, but how is one supposed to set different logging levels on
> > > > > different facilities within a driver/module, or even for the module as
> > > > > a whole?
> > > >
> > > > Yeah. You will be still able to do that and more besides after the
> > > > transition. Cleaning this up makes the code better in every way.
> > > >
> > > > Documentation/admin-guide/dynamic-debug-howto.rst
> > >
> > > Are you saying this patch set gets us to that point?
> >
> > Yes. The patch has some issues, but yes.
>
> I think I'm missing something too then. Dynamic debug provides the
> ability to easily switch dev_dbg() messages on and off at runtime, but
> it doesn't provide, as far as I'm aware, log levels or log categories.
>
> Log levels are currently used by the vchiq code to suppress messages
> below a certain level. Kernel log levels are not an exact replacement,
> as the messages still end up in the kernel log (except for debug
> messages).
>
> Log categories are used to group messages in categories and control
> their log level per category. As far as I know, dynamic debug doesn't
> provide any such feature.

After a bit more research (which I should have done before replying,
sorry), it looks like dynamic debug has support for classes, which are
used by, for instance, the DRM logging infrastructure (see
include/drm/drm_print.h). I don't see that being wired up to dev_*()
print macros though, am I missing something, or would vchiq need to keep
using custom logging macros (with dynamic debug used as a backend,
replacing the current custom implementation) to make use of this feature
?

--
Regards,

Laurent Pinchart

2023-01-20 05:30:27

by Greg KH

[permalink] [raw]

Subject: Re: [RFC PATCH 0/4] Drop custom logging

On Wed, Jan 18, 2023 at 05:28:06PM +0530, Umang Jain wrote:
> Drop custom logging from the vchiq interface.
> Mostly of them are replaced with dev_dbg and friends
> and/or pr_info and friends.

Everything should be dev_*() calls, there should never be a pr_* call in
a driver.

> The debugfs log levels (in 4/4) are mapped to kernel
> logs levels (coming from include/linux/kern_levels.h)
> Would like some thoughts on it as I am not sure (hence
> marking this is RFC)

Do not have any "custom" debugging controls in a driver, they are not
special and should follow the whole rest of the kernel. Just remove
them all and rely on the existing dev_*() calls instead please.

thanks,

greg k-h

2023-01-20 05:55:18

by Greg KH

[permalink] [raw]

Subject: Re: [RFC PATCH 0/4] Drop custom logging

On Thu, Jan 19, 2023 at 01:31:12PM +0000, Phil Elwell wrote:
> Hi all,
>
>
> On Wed, 18 Jan 2023 at 17:55, Stefan Wahren <[email protected]> wrote:
> >
> > Hi Umang,
> >
> > [add Phil]
> >
> > Am 18.01.23 um 12:58 schrieb Umang Jain:
> > > Drop custom logging from the vchiq interface.
> > > Mostly of them are replaced with dev_dbg and friends
> > > and/or pr_info and friends.
> > >
> > > The debugfs log levels (in 4/4) are mapped to kernel
> > > logs levels (coming from include/linux/kern_levels.h)
> > > Would like some thoughts on it as I am not sure (hence
> > > marking this is RFC)
> > >
> > > From drivers/staging/vc04_services/interface/TODO:
> > >
> > > """
> > > * Cleanup logging mechanism
> > >
> > > The driver should probably be using the standard kernel logging mechanisms
> > > such as dev_info, dev_dbg, and friends.
> >
> > i don't have any experience with vchiq logging/debug. So i'm not sure if
> > it's acceptable to lose the second log level dimension (like
> > vchiq_arm_log_level) completely. Complex drivers like brcmfmac have a
> > debug mask to avoid log spamming [1]. Maybe this is a compromise.
> >
> > Btw some loglevel locations has already been messed up during
> > refactoring :-(
> >
> > [1] - drivers/net/wireless/broadcom/brcm80211/brcmfmac/debug.h
> >
> > > """
> > >
> > > Umang Jain (4):
> > > staging: vc04_services: vchiq_core: Drop custom logging
> > > staging: vc04_services: vchiq_arm: Drop custom logging
> > > staging: vc04_services: Drop custom logging
> > > staging: vc04_services: Drop remnants of custom logging
> > >
> > > .../interface/vchiq_arm/vchiq_arm.c | 151 +++---
> > > .../interface/vchiq_arm/vchiq_connected.c | 5 +-
> > > .../interface/vchiq_arm/vchiq_core.c | 479 ++++++++----------
> > > .../interface/vchiq_arm/vchiq_core.h | 39 --
> > > .../interface/vchiq_arm/vchiq_debugfs.c | 26 +-
> > > .../interface/vchiq_arm/vchiq_dev.c | 78 ++-
> > > 6 files changed, 329 insertions(+), 449 deletions(-)
> > >
>
> Thanks for the nudge - this patch set hasn't yet made its way through
> the sluggish rpi-kernel moderation.
>
> I understand the desire to remove the custom logging. I don't welcome
> the loss of flexibility that comes with such a strategy

What "loss of flexibility"? You now have access to the full dynamic
debugging facilities that all of the rest of the kernel has. What is
lacking?

> , but I'm not
> going to argue about it. What's harder to understand is the state that
> this patchset leaves VCHIQ logging in. From what I can see, the
> per-service logging control has gone, but the code still contains
> macros that hint at something useful. Similarly, the debugfs support
> is completely vestigial, giving the appearance of control while
> actually achieving nothing.

The debugfs files should also be removed if they don't do anything
anymore.

thanks,

greg k-h

2023-01-22 14:26:42

[permalink] [raw]

Subject: Re: [RFC PATCH 0/4] Drop custom logging

Hi Umang,

Am 18.01.23 um 12:58 schrieb Umang Jain:
> Drop custom logging from the vchiq interface.
> Mostly of them are replaced with dev_dbg and friends
> and/or pr_info and friends.
>
> The debugfs log levels (in 4/4) are mapped to kernel
> logs levels (coming from include/linux/kern_levels.h)
> Would like some thoughts on it as I am not sure (hence
> marking this is RFC)
>
> From drivers/staging/vc04_services/interface/TODO:
>
> """
> * Cleanup logging mechanism
>
> The driver should probably be using the standard kernel logging mechanisms
> such as dev_info, dev_dbg, and friends.
> """

at first i want to thank you for the work on vchiq so far.

There is something which is not directly related to this series, but it
is also about debugging. The driver has a buffer which is accessed by
it's own DEBUG_* macros. The content of this debug buffer can be dumped
via the /dev/vchiq which is also used by ioctl. I would appreciate to
move this dump feature into a new debugfs entry.

Best regards

2023-01-22 16:27:03

by Kieran Bingham

[permalink] [raw]

Subject: Re: [RFC PATCH 0/4] Drop custom logging

Hi Stefan,

Quoting Stefan Wahren (2023-01-22 14:21:05)
> Hi Umang,
>
> Am 18.01.23 um 12:58 schrieb Umang Jain:
> > Drop custom logging from the vchiq interface.
> > Mostly of them are replaced with dev_dbg and friends
> > and/or pr_info and friends.
> >
> > The debugfs log levels (in 4/4) are mapped to kernel
> > logs levels (coming from include/linux/kern_levels.h)
> > Would like some thoughts on it as I am not sure (hence
> > marking this is RFC)
> >
> > From drivers/staging/vc04_services/interface/TODO:
> >
> > """
> > * Cleanup logging mechanism
> >
> > The driver should probably be using the standard kernel logging mechanisms
> > such as dev_info, dev_dbg, and friends.
> > """
>
> at first i want to thank you for the work on vchiq so far.
>
> There is something which is not directly related to this series, but it
> is also about debugging. The driver has a buffer which is accessed by
> it's own DEBUG_* macros. The content of this debug buffer can be dumped
> via the /dev/vchiq which is also used by ioctl. I would appreciate to
> move this dump feature into a new debugfs entry.

Do you have a full list of the tasks you'd like to see completed ?
(including/or above drivers/staging/vc04_services/interface/TODO)

It would help to have a clear picture of tasks needed to get this driver
destaged, so that we can support the ISP upstream.

Regards
--
Kieran

2023-01-22 18:07:28

[permalink] [raw]

Subject: Re: [RFC PATCH 0/4] Drop custom logging

Hi Kieran,

Am 22.01.23 um 17:26 schrieb Kieran Bingham:
> Hi Stefan,
>
> Quoting Stefan Wahren (2023-01-22 14:21:05)
>> Hi Umang,
>>
>> Am 18.01.23 um 12:58 schrieb Umang Jain:
>>> Drop custom logging from the vchiq interface.
>>> Mostly of them are replaced with dev_dbg and friends
>>> and/or pr_info and friends.
>>>
>>> The debugfs log levels (in 4/4) are mapped to kernel
>>> logs levels (coming from include/linux/kern_levels.h)
>>> Would like some thoughts on it as I am not sure (hence
>>> marking this is RFC)
>>>
>>> From drivers/staging/vc04_services/interface/TODO:
>>>
>>> """
>>> * Cleanup logging mechanism
>>>
>>> The driver should probably be using the standard kernel logging mechanisms
>>> such as dev_info, dev_dbg, and friends.
>>> """
>> at first i want to thank you for the work on vchiq so far.
>>
>> There is something which is not directly related to this series, but it
>> is also about debugging. The driver has a buffer which is accessed by
>> it's own DEBUG_* macros. The content of this debug buffer can be dumped
>> via the /dev/vchiq which is also used by ioctl. I would appreciate to
>> move this dump feature into a new debugfs entry.
> Do you have a full list of the tasks you'd like to see completed ?
> (including/or above drivers/staging/vc04_services/interface/TODO)

i consider every point except of point 1 (importing new drivers) as
necessary to leave staging.

Additionally there is the additional point (i can add them to the TODO)
above. Unfortunately i don't have a complete insight, how vchiq should
be to be acceptable. Sorry, if i can't help you further with possible
resource planning.

Are some points on the TODO list unclear?

Thanks

>
> It would help to have a clear picture of tasks needed to get this driver
> destaged, so that we can support the ISP upstream.
>
> Regards
> --
> Kieran

2023-01-23 12:04:43