[PATCH 0/5] log: convert pr_*() to logging

In drivers we use a family of printing functions including pr_err() and pr_cont(). CONFIG_LOGLEVEL is used to control which of these lead to output via printf().
Our logging functions allow finer grained control of output. So replace printf() by the matching logging functions. The usage of CONFIG_LOGLEVEL remains unchanged.
The first patch changes the k3-j721e RAM driver to avoid a duplicate use of the macro name BIT_MASK().
The second patch ensures that debug_cond() can be used like a function.
The third patch provides macros for logging at levels EMERGENCY, ALERT, CRITICAL and for message continuation.
The fourth patch uses the logging macros to implement the pr_*() macros.
The fifth patch provices a unit test.
Heinrich Schuchardt (5): ram: k3-j721e: rename BIT_MASK() log: make debug_cond() function like log: provide missing macros log: convert pr_*() to logging test: unit test for pr_err(), pr_cont()
drivers/ram/k3-j721e/lpddr4.c | 14 ++--- drivers/ram/k3-j721e/lpddr4_private.h | 20 ++++--- include/linux/bitops.h | 4 +- include/linux/printk.h | 82 +++++++++++++++------------ include/log.h | 25 +++++--- test/log/Makefile | 1 + test/log/pr_cont_test.c | 45 +++++++++++++++ 7 files changed, 129 insertions(+), 62 deletions(-) create mode 100644 test/log/pr_cont_test.c
-- 2.29.2

The macro BIT_MASK is already defined in include/linux/bitops.h. To avoid name collisions rename BIT_MASK() in drivers/ram/k3-j721e/lpddr4_private.h to LPDDR4_BIT_MASK().
Remove superfluous parantheses. Remove superfluous comparison to 0.
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de --- drivers/ram/k3-j721e/lpddr4.c | 14 +++++++------- drivers/ram/k3-j721e/lpddr4_private.h | 20 ++++++++++++-------- 2 files changed, 19 insertions(+), 15 deletions(-)
diff --git a/drivers/ram/k3-j721e/lpddr4.c b/drivers/ram/k3-j721e/lpddr4.c index fc80fb1e2c..68043d7cb6 100644 --- a/drivers/ram/k3-j721e/lpddr4.c +++ b/drivers/ram/k3-j721e/lpddr4.c @@ -719,7 +719,7 @@ uint32_t lpddr4_checkctlinterrupt(const lpddr4_privatedata * pd,
/* MISRA compliance (Shifting operation) check */ if (fieldshift < WORD_SHIFT) { - if (((ctlirqstatus >> fieldshift) & BIT_MASK) > 0U) { + if ((ctlirqstatus >> fieldshift) & LPDDR4_BIT_MASK) { *irqstatus = true; } else { *irqstatus = false; @@ -746,11 +746,11 @@ uint32_t lpddr4_ackctlinterrupt(const lpddr4_privatedata * pd, if (localinterrupt > WORD_SHIFT) { localinterrupt = (localinterrupt - (uint32_t) WORD_SHIFT); - regval = ((uint32_t) BIT_MASK << localinterrupt); + regval = (uint32_t)LPDDR4_BIT_MASK << localinterrupt; CPS_REG_WRITE(&(ctlregbase->LPDDR4__INT_ACK_1__REG), regval); } else { - regval = ((uint32_t) BIT_MASK << localinterrupt); + regval = (uint32_t)LPDDR4_BIT_MASK << localinterrupt; CPS_REG_WRITE(&(ctlregbase->LPDDR4__INT_ACK_0__REG), regval); } @@ -823,7 +823,7 @@ uint32_t lpddr4_checkphyindepinterrupt(const lpddr4_privatedata * pd, phyindepirqstatus = CPS_REG_READ(&(ctlregbase->LPDDR4__PI_INT_STATUS__REG)); *irqstatus = - (((phyindepirqstatus >> (uint32_t) intr) & BIT_MASK) > 0U); + !!((phyindepirqstatus >> (uint32_t)intr) & LPDDR4_BIT_MASK); } return result; } @@ -841,7 +841,7 @@ uint32_t lpddr4_ackphyindepinterrupt(const lpddr4_privatedata * pd, lpddr4_ctlregs *ctlregbase = (lpddr4_ctlregs *) pd->ctlbase;
/* Write 1 to the requested bit to ACk the interrupt */ - regval = ((uint32_t) BIT_MASK << ui32shiftinterrupt); + regval = (uint32_t)LPDDR4_BIT_MASK << ui32shiftinterrupt; CPS_REG_WRITE(&(ctlregbase->LPDDR4__PI_INT_ACK__REG), regval); }
@@ -894,7 +894,7 @@ static void lpddr4_checkwrlvlerror(lpddr4_ctlregs * ctlregbase, (volatile uint32_t *)(&(ctlregbase->LPDDR4__PHY_WRLVL_ERROR_OBS_0__REG)); /* PHY_WRLVL_ERROR_OBS_X[1:0] should be zero */ - errbitmask = (BIT_MASK << 1) | (BIT_MASK); + errbitmask = (LPDDR4_BIT_MASK << 1) | LPDDR4_BIT_MASK; for (snum = 0U; snum < DSLICE_NUM; snum++) { regval = CPS_REG_READ(regaddress); if ((regval & errbitmask) != 0U) { @@ -1054,7 +1054,7 @@ static void lpddr4_seterrors(lpddr4_ctlregs * ctlregbase, lpddr4_debuginfo * debuginfo, bool * errfoundptr) {
- uint32_t errbitmask = (BIT_MASK << 0x1U) | (BIT_MASK); + uint32_t errbitmask = (LPDDR4_BIT_MASK << 0x1U) | LPDDR4_BIT_MASK; /* Check PLL observation registers for PLL lock errors */
debuginfo->pllerror = diff --git a/drivers/ram/k3-j721e/lpddr4_private.h b/drivers/ram/k3-j721e/lpddr4_private.h index 42c923464a..3d5017ea47 100644 --- a/drivers/ram/k3-j721e/lpddr4_private.h +++ b/drivers/ram/k3-j721e/lpddr4_private.h @@ -14,9 +14,9 @@ #define VERSION_0 (0x54d5da40U) #define VERSION_1 (0xc1865a1U)
-#define BIT_MASK (0x1U) -#define BYTE_MASK (0xffU) -#define NIBBLE_MASK (0xfU) +#define LPDDR4_BIT_MASK (0x1U) +#define BYTE_MASK (0xffU) +#define NIBBLE_MASK (0xfU)
#define WORD_SHIFT (32U) #define WORD_MASK (0xffffffffU) @@ -46,11 +46,15 @@ #define IO_CALIB_DONE ((uint32_t)0x1U << 23U) #define IO_CALIB_FIELD ((uint32_t)NIBBLE_MASK << 28U) #define IO_CALIB_STATE ((uint32_t)0xBU << 28U) -#define RX_CAL_DONE ((uint32_t)BIT_MASK << 4U) -#define CA_TRAIN_RL (((uint32_t)BIT_MASK << 5U) | ((uint32_t)BIT_MASK << 4U)) +#define RX_CAL_DONE ((uint32_t)LPDDR4_BIT_MASK << 4U) +#define CA_TRAIN_RL (((uint32_t)LPDDR4_BIT_MASK << 5U) | \ + ((uint32_t)LPDDR4_BIT_MASK << 4U)) #define WR_LVL_STATE (((uint32_t)NIBBLE_MASK) << 13U) -#define GATE_LVL_ERROR_FIELDS (((uint32_t)BIT_MASK << 7U) | ((uint32_t)BIT_MASK << 6U)) -#define READ_LVL_ERROR_FIELDS ((((uint32_t)NIBBLE_MASK) << 28U) | (((uint32_t)BYTE_MASK) << 16U)) -#define DQ_LVL_STATUS (((uint32_t)BIT_MASK << 26U) | (((uint32_t)BYTE_MASK) << 18U)) +#define GATE_LVL_ERROR_FIELDS (((uint32_t)LPDDR4_BIT_MASK << 7U) | \ + ((uint32_t)LPDDR4_BIT_MASK << 6U)) +#define READ_LVL_ERROR_FIELDS ((((uint32_t)NIBBLE_MASK) << 28U) | \ + (((uint32_t)BYTE_MASK) << 16U)) +#define DQ_LVL_STATUS (((uint32_t)LPDDR4_BIT_MASK << 26U) | \ + (((uint32_t)BYTE_MASK) << 18U))
#endif /* LPDDR4_PRIV_H */ -- 2.29.2

On Mon, 4 Jan 2021 at 00:03, Heinrich Schuchardt xypron.glpk@gmx.de wrote:
The macro BIT_MASK is already defined in include/linux/bitops.h. To avoid name collisions rename BIT_MASK() in drivers/ram/k3-j721e/lpddr4_private.h to LPDDR4_BIT_MASK().
Remove superfluous parantheses. Remove superfluous comparison to 0.
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de
drivers/ram/k3-j721e/lpddr4.c | 14 +++++++------- drivers/ram/k3-j721e/lpddr4_private.h | 20 ++++++++++++-------- 2 files changed, 19 insertions(+), 15 deletions(-)
Reviewed-by: Simon Glass sjg@chromium.org

On Mon, Jan 04, 2021 at 08:02:52AM +0100, Heinrich Schuchardt wrote:
The macro BIT_MASK is already defined in include/linux/bitops.h. To avoid name collisions rename BIT_MASK() in drivers/ram/k3-j721e/lpddr4_private.h to LPDDR4_BIT_MASK().
Remove superfluous parantheses. Remove superfluous comparison to 0.
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de Reviewed-by: Simon Glass sjg@chromium.org
Applied to u-boot/master, thanks!

Change debug_cond() such that it can be used instead of a function like debug().
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de --- include/log.h | 17 ++++++++--------- 1 file changed, 8 insertions(+), 9 deletions(-)
diff --git a/include/log.h b/include/log.h index 29f18a82dc..34cea802a1 100644 --- a/include/log.h +++ b/include/log.h @@ -217,10 +217,9 @@ static inline int _log_nop(enum log_category_t cat, enum log_level_t level, #if !_DEBUG && CONFIG_IS_ENABLED(LOG)
#define debug_cond(cond, fmt, args...) \ - do { \ - if (1) \ - log(LOG_CATEGORY, LOGL_DEBUG, fmt, ##args); \ - } while (0) +({ \ + log(LOG_CATEGORY, LOGL_DEBUG, fmt, ##args); \ +})
#else /* _DEBUG */
@@ -229,11 +228,11 @@ static inline int _log_nop(enum log_category_t cat, enum log_level_t level, * computed by a preprocessor in the best case, allowing for the best * optimization. */ -#define debug_cond(cond, fmt, args...) \ - do { \ - if (cond) \ - printf(pr_fmt(fmt), ##args); \ - } while (0) +#define debug_cond(cond, fmt, args...) \ +({ \ + if (cond) \ + printf(pr_fmt(fmt), ##args); \ +})
#endif /* _DEBUG */
-- 2.29.2

On Mon, 4 Jan 2021 at 00:03, Heinrich Schuchardt xypron.glpk@gmx.de wrote:
Change debug_cond() such that it can be used instead of a function like debug().
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de
include/log.h | 17 ++++++++--------- 1 file changed, 8 insertions(+), 9 deletions(-)
Reviewed-by: Simon Glass sjg@chromium.org

On Mon, Jan 04, 2021 at 08:02:53AM +0100, Heinrich Schuchardt wrote:
Change debug_cond() such that it can be used instead of a function like debug().
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de Reviewed-by: Simon Glass sjg@chromium.org
Applied to u-boot/master, thanks!

With commit d094a0734cee ("log: allow for message continuation") we have defined a special log level and category for message continuation. Let's have a macro for using these.
If logging is enabled log_cont() will create a continuation log output with the same logging level and category as the previous message.
If logging is not enabled, log_cont() will print like printf().
Provide macros for logging levels LOG_EMERG, LOG_ALERT, LOG_CRIT.
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de --- include/log.h | 8 ++++++++ 1 file changed, 8 insertions(+)
diff --git a/include/log.h b/include/log.h index 34cea802a1..830707ef3d 100644 --- a/include/log.h +++ b/include/log.h @@ -156,6 +156,9 @@ static inline int _log_nop(enum log_category_t cat, enum log_level_t level, */ #if CONFIG_IS_ENABLED(LOG) #define _LOG_MAX_LEVEL CONFIG_VAL(LOG_MAX_LEVEL) +#define log_emer(_fmt...) log(LOG_CATEGORY, LOGL_EMERG, ##_fmt) +#define log_alert(_fmt...) log(LOG_CATEGORY, LOGL_ALERT, ##_fmt) +#define log_crit(_fmt...) log(LOG_CATEGORY, LOGL_CRIT, ##_fmt) #define log_err(_fmt...) log(LOG_CATEGORY, LOGL_ERR, ##_fmt) #define log_warning(_fmt...) log(LOG_CATEGORY, LOGL_WARNING, ##_fmt) #define log_notice(_fmt...) log(LOG_CATEGORY, LOGL_NOTICE, ##_fmt) @@ -163,12 +166,17 @@ static inline int _log_nop(enum log_category_t cat, enum log_level_t level, #define log_debug(_fmt...) log(LOG_CATEGORY, LOGL_DEBUG, ##_fmt) #define log_content(_fmt...) log(LOG_CATEGORY, LOGL_DEBUG_CONTENT, ##_fmt) #define log_io(_fmt...) log(LOG_CATEGORY, LOGL_DEBUG_IO, ##_fmt) +#define log_cont(_fmt...) log(LOGC_CONT, LOGL_CONT, ##_fmt) #else #define _LOG_MAX_LEVEL LOGL_INFO +#define log_emerg(_fmt, ...) printf(_fmt, ##__VA_ARGS__) +#define log_alert(_fmt, ...) printf(_fmt, ##__VA_ARGS__) +#define log_crit(_fmt, ...) printf(_fmt, ##__VA_ARGS__) #define log_err(_fmt, ...) printf(_fmt, ##__VA_ARGS__) #define log_warning(_fmt, ...) printf(_fmt, ##__VA_ARGS__) #define log_notice(_fmt, ...) printf(_fmt, ##__VA_ARGS__) #define log_info(_fmt, ...) printf(_fmt, ##__VA_ARGS__) +#define log_cont(_fmt, ...) printf(_fmt, ##__VA_ARGS__) #define log_debug(_fmt, ...) debug(_fmt, ##__VA_ARGS__) #define log_content(_fmt...) log_nop(LOG_CATEGORY, \ LOGL_DEBUG_CONTENT, ##_fmt) -- 2.29.2

On Mon, 4 Jan 2021 at 00:03, Heinrich Schuchardt xypron.glpk@gmx.de wrote:
With commit d094a0734cee ("log: allow for message continuation") we have defined a special log level and category for message continuation. Let's have a macro for using these.
If logging is enabled log_cont() will create a continuation log output with the same logging level and category as the previous message.
If logging is not enabled, log_cont() will print like printf().
Provide macros for logging levels LOG_EMERG, LOG_ALERT, LOG_CRIT.
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de
include/log.h | 8 ++++++++ 1 file changed, 8 insertions(+)
Reviewed-by: Simon Glass sjg@chromium.org

On Mon, Jan 04, 2021 at 08:02:54AM +0100, Heinrich Schuchardt wrote:
With commit d094a0734cee ("log: allow for message continuation") we have defined a special log level and category for message continuation. Let's have a macro for using these.
If logging is enabled log_cont() will create a continuation log output with the same logging level and category as the previous message.
If logging is not enabled, log_cont() will print like printf().
Provide macros for logging levels LOG_EMERG, LOG_ALERT, LOG_CRIT.
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de Reviewed-by: Simon Glass sjg@chromium.org
Applied to u-boot/master, thanks!

In drivers we use a family of printing functions including pr_err() and pr_cont(). CONFIG_LOGLEVEL is used to control which of these lead to output via printf().
Our logging functions allow finer grained control of output. So replace printf() by the matching logging functions. The usage of CONFIG_LOGLEVEL remains unchanged.
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de --- include/linux/bitops.h | 4 ++- include/linux/printk.h | 82 +++++++++++++++++++++++------------------- 2 files changed, 48 insertions(+), 38 deletions(-)
diff --git a/include/linux/bitops.h b/include/linux/bitops.h index 16f28993f5..d2e5ca026e 100644 --- a/include/linux/bitops.h +++ b/include/linux/bitops.h @@ -6,7 +6,6 @@ #include <asm/types.h> #include <asm-generic/bitsperlong.h> #include <linux/compiler.h> -#include <linux/kernel.h>
#ifdef __KERNEL__ #define BIT(nr) (1UL << (nr)) @@ -19,6 +18,9 @@ #define BITS_TO_LONGS(nr) DIV_ROUND_UP(nr, BITS_PER_BYTE * sizeof(long)) #endif
+/* kernel.h includes log.h which include bitops.h */ +#include <linux/kernel.h> + /* * Create a contiguous bitmask starting at bit position @l and ending at * position @h. For example diff --git a/include/linux/printk.h b/include/linux/printk.h index 088513ad29..5e85513853 100644 --- a/include/linux/printk.h +++ b/include/linux/printk.h @@ -1,6 +1,7 @@ #ifndef __KERNEL_PRINTK__ #define __KERNEL_PRINTK__
+#include <log.h> #include <stdio.h> #include <linux/compiler.h>
@@ -28,49 +29,56 @@ 0; \ })
-#define __printk(level, fmt, ...) \ -({ \ - level < CONFIG_LOGLEVEL ? printk(fmt, ##__VA_ARGS__) : 0; \ -}) - #ifndef pr_fmt #define pr_fmt(fmt) fmt #endif
-#define pr_emerg(fmt, ...) \ - __printk(0, pr_fmt(fmt), ##__VA_ARGS__) -#define pr_alert(fmt, ...) \ - __printk(1, pr_fmt(fmt), ##__VA_ARGS__) -#define pr_crit(fmt, ...) \ - __printk(2, pr_fmt(fmt), ##__VA_ARGS__) -#define pr_err(fmt, ...) \ - __printk(3, pr_fmt(fmt), ##__VA_ARGS__) -#define pr_warning(fmt, ...) \ - __printk(4, pr_fmt(fmt), ##__VA_ARGS__) -#define pr_warn pr_warning -#define pr_notice(fmt, ...) \ - __printk(5, pr_fmt(fmt), ##__VA_ARGS__) -#define pr_info(fmt, ...) \ - __printk(6, pr_fmt(fmt), ##__VA_ARGS__) - -#define pr_cont(fmt, ...) \ - printk(fmt, ##__VA_ARGS__) - -/* pr_devel() should produce zero code unless DEBUG is defined */ -#ifdef DEBUG -#define pr_devel(fmt, ...) \ - __printk(7, pr_fmt(fmt), ##__VA_ARGS__) -#else -#define pr_devel(fmt, ...) \ - no_printk(pr_fmt(fmt), ##__VA_ARGS__) -#endif +#define pr_emerg(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 0 ? log_emerg(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_alert(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 1 ? log_alert(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_crit(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 2 ? log_crit(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_err(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 3 ? log_err(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_warn(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 4 ? log_warning(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_notice(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 5 ? log_notice(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_info(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 6 ? log_info(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_debug(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 7 ? log_debug(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_devel(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 7 ? log_debug(fmt, ##__VA_ARGS__) : 0; \ +})
-#ifdef DEBUG -#define pr_debug(fmt, ...) \ - __printk(7, pr_fmt(fmt), ##__VA_ARGS__) +#ifdef CONFIG_LOG +#define pr_cont(fmt, ...) \ +({ \ + gd->logl_prev < CONFIG_LOGLEVEL ? \ + log_cont(fmt, ##__VA_ARGS__) : 0; \ +}) #else -#define pr_debug(fmt, ...) \ - no_printk(pr_fmt(fmt), ##__VA_ARGS__) +#define pr_cont(fmt, ...) \ + printk(fmt, ##__VA_ARGS__) #endif
#define printk_once(fmt, ...) \ -- 2.29.2

Hi Heinrich,
On Mon, 4 Jan 2021 at 00:03, Heinrich Schuchardt xypron.glpk@gmx.de wrote:
In drivers we use a family of printing functions including pr_err() and pr_cont(). CONFIG_LOGLEVEL is used to control which of these lead to output via printf().
Our logging functions allow finer grained control of output. So replace printf() by the matching logging functions. The usage of CONFIG_LOGLEVEL remains unchanged.
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de
include/linux/bitops.h | 4 ++- include/linux/printk.h | 82 +++++++++++++++++++++++------------------- 2 files changed, 48 insertions(+), 38 deletions(-)
diff --git a/include/linux/bitops.h b/include/linux/bitops.h index 16f28993f5..d2e5ca026e 100644 --- a/include/linux/bitops.h +++ b/include/linux/bitops.h @@ -6,7 +6,6 @@ #include <asm/types.h> #include <asm-generic/bitsperlong.h> #include <linux/compiler.h> -#include <linux/kernel.h>
#ifdef __KERNEL__ #define BIT(nr) (1UL << (nr)) @@ -19,6 +18,9 @@ #define BITS_TO_LONGS(nr) DIV_ROUND_UP(nr, BITS_PER_BYTE * sizeof(long)) #endif
+/* kernel.h includes log.h which include bitops.h */ +#include <linux/kernel.h>
/*
- Create a contiguous bitmask starting at bit position @l and ending at
- position @h. For example
diff --git a/include/linux/printk.h b/include/linux/printk.h index 088513ad29..5e85513853 100644 --- a/include/linux/printk.h +++ b/include/linux/printk.h @@ -1,6 +1,7 @@ #ifndef __KERNEL_PRINTK__ #define __KERNEL_PRINTK__
+#include <log.h> #include <stdio.h> #include <linux/compiler.h>
@@ -28,49 +29,56 @@ 0; \ })
-#define __printk(level, fmt, ...) \ -({ \
level < CONFIG_LOGLEVEL ? printk(fmt, ##__VA_ARGS__) : 0; \
-})
#ifndef pr_fmt #define pr_fmt(fmt) fmt #endif
-#define pr_emerg(fmt, ...) \
__printk(0, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_alert(fmt, ...) \
__printk(1, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_crit(fmt, ...) \
__printk(2, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_err(fmt, ...) \
__printk(3, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_warning(fmt, ...) \
__printk(4, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_warn pr_warning -#define pr_notice(fmt, ...) \
__printk(5, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_info(fmt, ...) \
__printk(6, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_cont(fmt, ...) \
printk(fmt, ##__VA_ARGS__)
-/* pr_devel() should produce zero code unless DEBUG is defined */ -#ifdef DEBUG -#define pr_devel(fmt, ...) \
__printk(7, pr_fmt(fmt), ##__VA_ARGS__)
-#else -#define pr_devel(fmt, ...) \
no_printk(pr_fmt(fmt), ##__VA_ARGS__)
-#endif +#define pr_emerg(fmt, ...) \ +({ \
CONFIG_LOGLEVEL > 0 ? log_emerg(fmt, ##__VA_ARGS__) : 0; \
Should this use CONFIG_VAL(LOGLEVEL) ?
Also I don't suppose there is a way to implement this in the __printk() macro?
+}) +#define pr_alert(fmt, ...) \ +({ \
CONFIG_LOGLEVEL > 1 ? log_alert(fmt, ##__VA_ARGS__) : 0; \
+}) +#define pr_crit(fmt, ...) \ +({ \
CONFIG_LOGLEVEL > 2 ? log_crit(fmt, ##__VA_ARGS__) : 0; \
+}) +#define pr_err(fmt, ...) \ +({ \
CONFIG_LOGLEVEL > 3 ? log_err(fmt, ##__VA_ARGS__) : 0; \
+}) +#define pr_warn(fmt, ...) \ +({ \
CONFIG_LOGLEVEL > 4 ? log_warning(fmt, ##__VA_ARGS__) : 0; \
+}) +#define pr_notice(fmt, ...) \ +({ \
CONFIG_LOGLEVEL > 5 ? log_notice(fmt, ##__VA_ARGS__) : 0; \
+}) +#define pr_info(fmt, ...) \ +({ \
CONFIG_LOGLEVEL > 6 ? log_info(fmt, ##__VA_ARGS__) : 0; \
+}) +#define pr_debug(fmt, ...) \ +({ \
CONFIG_LOGLEVEL > 7 ? log_debug(fmt, ##__VA_ARGS__) : 0; \
+}) +#define pr_devel(fmt, ...) \ +({ \
CONFIG_LOGLEVEL > 7 ? log_debug(fmt, ##__VA_ARGS__) : 0; \
+})
-#ifdef DEBUG -#define pr_debug(fmt, ...) \
__printk(7, pr_fmt(fmt), ##__VA_ARGS__)
+#ifdef CONFIG_LOG +#define pr_cont(fmt, ...) \ +({ \
gd->logl_prev < CONFIG_LOGLEVEL ? \
log_cont(fmt, ##__VA_ARGS__) : 0; \
+}) #else -#define pr_debug(fmt, ...) \
no_printk(pr_fmt(fmt), ##__VA_ARGS__)
+#define pr_cont(fmt, ...) \
printk(fmt, ##__VA_ARGS__)
#endif
#define printk_once(fmt, ...) \
2.29.2
Regards, Simon

On Mon, Jan 04, 2021 at 08:02:55AM +0100, Heinrich Schuchardt wrote:
In drivers we use a family of printing functions including pr_err() and pr_cont(). CONFIG_LOGLEVEL is used to control which of these lead to output via printf().
Our logging functions allow finer grained control of output. So replace printf() by the matching logging functions. The usage of CONFIG_LOGLEVEL remains unchanged.
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de
include/linux/bitops.h | 4 ++- include/linux/printk.h | 82 +++++++++++++++++++++++------------------- 2 files changed, 48 insertions(+), 38 deletions(-)
This causes some fairly massive growth in various subsystems such as ubi and we might want to look at what, if anything, we can do, before growing some platforms by 15KiB (xilinx_zynqmp_virt) due to strings. Thanks.

On 1/17/21 1:16 AM, Tom Rini wrote:
On Mon, Jan 04, 2021 at 08:02:55AM +0100, Heinrich Schuchardt wrote:
In drivers we use a family of printing functions including pr_err() and pr_cont(). CONFIG_LOGLEVEL is used to control which of these lead to output via printf().
Our logging functions allow finer grained control of output. So replace printf() by the matching logging functions. The usage of CONFIG_LOGLEVEL remains unchanged.
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de
include/linux/bitops.h | 4 ++- include/linux/printk.h | 82 +++++++++++++++++++++++------------------- 2 files changed, 48 insertions(+), 38 deletions(-)
This causes some fairly massive growth in various subsystems such as ubi and we might want to look at what, if anything, we can do, before growing some platforms by 15KiB (xilinx_zynqmp_virt) due to strings.
xilinx_zynqmp_virt has CONFIG_LOG enabled. Switching from printf() to log() incurs size growth. Did you observe a size grows on platforms with CONFIG_LOG=n?
Best regards
Heinrich
Thanks.

On Sun, Jan 17, 2021 at 08:37:15AM +0100, Heinrich Schuchardt wrote:
On 1/17/21 1:16 AM, Tom Rini wrote:
On Mon, Jan 04, 2021 at 08:02:55AM +0100, Heinrich Schuchardt wrote:
In drivers we use a family of printing functions including pr_err() and pr_cont(). CONFIG_LOGLEVEL is used to control which of these lead to output via printf().
Our logging functions allow finer grained control of output. So replace printf() by the matching logging functions. The usage of CONFIG_LOGLEVEL remains unchanged.
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de
include/linux/bitops.h | 4 ++- include/linux/printk.h | 82 +++++++++++++++++++++++------------------- 2 files changed, 48 insertions(+), 38 deletions(-)
This causes some fairly massive growth in various subsystems such as ubi and we might want to look at what, if anything, we can do, before growing some platforms by 15KiB (xilinx_zynqmp_virt) due to strings.
xilinx_zynqmp_virt has CONFIG_LOG enabled. Switching from printf() to log() incurs size growth. Did you observe a size grows on platforms with CONFIG_LOG=n?
Yes, it has logging enabled, and we're converting a large number of things that were before compile-time discarded to no longer be so. This is, in general, good and what I've asked for. But when seeing very large growth in doing so, I think we need to maybe take a step back and look at the UBI subsystem for example and see if we can't/shouldn't tweak things more.
So, I'm going to run a size test with just this patch as the change, so we can have more concrete numbers to look at.

On Mon, Jan 18, 2021 at 08:02:41AM -0500, Tom Rini wrote:
On Sun, Jan 17, 2021 at 08:37:15AM +0100, Heinrich Schuchardt wrote:
On 1/17/21 1:16 AM, Tom Rini wrote:
On Mon, Jan 04, 2021 at 08:02:55AM +0100, Heinrich Schuchardt wrote:
In drivers we use a family of printing functions including pr_err() and pr_cont(). CONFIG_LOGLEVEL is used to control which of these lead to output via printf().
Our logging functions allow finer grained control of output. So replace printf() by the matching logging functions. The usage of CONFIG_LOGLEVEL remains unchanged.
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de
include/linux/bitops.h | 4 ++- include/linux/printk.h | 82 +++++++++++++++++++++++------------------- 2 files changed, 48 insertions(+), 38 deletions(-)
This causes some fairly massive growth in various subsystems such as ubi and we might want to look at what, if anything, we can do, before growing some platforms by 15KiB (xilinx_zynqmp_virt) due to strings.
xilinx_zynqmp_virt has CONFIG_LOG enabled. Switching from printf() to log() incurs size growth. Did you observe a size grows on platforms with CONFIG_LOG=n?
Yes, it has logging enabled, and we're converting a large number of things that were before compile-time discarded to no longer be so. This is, in general, good and what I've asked for. But when seeing very large growth in doing so, I think we need to maybe take a step back and look at the UBI subsystem for example and see if we can't/shouldn't tweak things more.
So, I'm going to run a size test with just this patch as the change, so we can have more concrete numbers to look at.
OK, so the build is done and interesting output starts at: https://gist.github.com/trini/53e7da62c6c9d18c189e6baffd01ff00#file-2021-01-...
Most of the time we're well under 1KiB, which is great. UBI has some huge growth, but it's a very few platforms, and I've added the custodians here so they can object, or not, to such size growth.

On 18.01.21 16:30, Tom Rini wrote:
On Mon, Jan 18, 2021 at 08:02:41AM -0500, Tom Rini wrote:
On Sun, Jan 17, 2021 at 08:37:15AM +0100, Heinrich Schuchardt wrote:
On 1/17/21 1:16 AM, Tom Rini wrote:
On Mon, Jan 04, 2021 at 08:02:55AM +0100, Heinrich Schuchardt wrote:
In drivers we use a family of printing functions including pr_err() and pr_cont(). CONFIG_LOGLEVEL is used to control which of these lead to output via printf().
Our logging functions allow finer grained control of output. So replace printf() by the matching logging functions. The usage of CONFIG_LOGLEVEL remains unchanged.
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de
include/linux/bitops.h | 4 ++- include/linux/printk.h | 82 +++++++++++++++++++++++------------------- 2 files changed, 48 insertions(+), 38 deletions(-)
This causes some fairly massive growth in various subsystems such as ubi and we might want to look at what, if anything, we can do, before growing some platforms by 15KiB (xilinx_zynqmp_virt) due to strings.
xilinx_zynqmp_virt has CONFIG_LOG enabled. Switching from printf() to log() incurs size growth. Did you observe a size grows on platforms with CONFIG_LOG=n?
Yes, it has logging enabled, and we're converting a large number of things that were before compile-time discarded to no longer be so. This is, in general, good and what I've asked for. But when seeing very large growth in doing so, I think we need to maybe take a step back and look at the UBI subsystem for example and see if we can't/shouldn't tweak things more.
So, I'm going to run a size test with just this patch as the change, so we can have more concrete numbers to look at.
OK, so the build is done and interesting output starts at: https://gist.github.com/trini/53e7da62c6c9d18c189e6baffd01ff00#file-2021-01-...
Most of the time we're well under 1KiB, which is great. UBI has some huge growth, but it's a very few platforms, and I've added the custodians here so they can object, or not, to such size growth.
Hello Tom,
How shall we proceed?
Best regards
Heinrich

On Thu, Feb 18, 2021 at 10:16:58AM +0100, Heinrich Schuchardt wrote:
On 18.01.21 16:30, Tom Rini wrote:
On Mon, Jan 18, 2021 at 08:02:41AM -0500, Tom Rini wrote:
On Sun, Jan 17, 2021 at 08:37:15AM +0100, Heinrich Schuchardt wrote:
On 1/17/21 1:16 AM, Tom Rini wrote:
On Mon, Jan 04, 2021 at 08:02:55AM +0100, Heinrich Schuchardt wrote:
In drivers we use a family of printing functions including pr_err() and pr_cont(). CONFIG_LOGLEVEL is used to control which of these lead to output via printf().
Our logging functions allow finer grained control of output. So replace printf() by the matching logging functions. The usage of CONFIG_LOGLEVEL remains unchanged.
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de
include/linux/bitops.h | 4 ++- include/linux/printk.h | 82 +++++++++++++++++++++++------------------- 2 files changed, 48 insertions(+), 38 deletions(-)
This causes some fairly massive growth in various subsystems such as ubi and we might want to look at what, if anything, we can do, before growing some platforms by 15KiB (xilinx_zynqmp_virt) due to strings.
xilinx_zynqmp_virt has CONFIG_LOG enabled. Switching from printf() to log() incurs size growth. Did you observe a size grows on platforms with CONFIG_LOG=n?
Yes, it has logging enabled, and we're converting a large number of things that were before compile-time discarded to no longer be so. This is, in general, good and what I've asked for. But when seeing very large growth in doing so, I think we need to maybe take a step back and look at the UBI subsystem for example and see if we can't/shouldn't tweak things more.
So, I'm going to run a size test with just this patch as the change, so we can have more concrete numbers to look at.
OK, so the build is done and interesting output starts at: https://gist.github.com/trini/53e7da62c6c9d18c189e6baffd01ff00#file-2021-01-...
Most of the time we're well under 1KiB, which is great. UBI has some huge growth, but it's a very few platforms, and I've added the custodians here so they can object, or not, to such size growth.
Hello Tom,
How shall we proceed?
Michal? Patrice or Patrick? Since this patch causes noticeable growth on your platforms I'm waiting for your input here, to be clear. Thanks!

Hi Tom
On 2/18/21 2:05 PM, Tom Rini wrote:
On Thu, Feb 18, 2021 at 10:16:58AM +0100, Heinrich Schuchardt wrote:
On 18.01.21 16:30, Tom Rini wrote:
On Mon, Jan 18, 2021 at 08:02:41AM -0500, Tom Rini wrote:
On Sun, Jan 17, 2021 at 08:37:15AM +0100, Heinrich Schuchardt wrote:
On 1/17/21 1:16 AM, Tom Rini wrote:
On Mon, Jan 04, 2021 at 08:02:55AM +0100, Heinrich Schuchardt wrote:
> In drivers we use a family of printing functions including pr_err() and > pr_cont(). CONFIG_LOGLEVEL is used to control which of these lead to output > via printf(). > > Our logging functions allow finer grained control of output. So replace > printf() by the matching logging functions. The usage of CONFIG_LOGLEVEL > remains unchanged. > > Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de > --- > include/linux/bitops.h | 4 ++- > include/linux/printk.h | 82 +++++++++++++++++++++++------------------- > 2 files changed, 48 insertions(+), 38 deletions(-)
This causes some fairly massive growth in various subsystems such as ubi and we might want to look at what, if anything, we can do, before growing some platforms by 15KiB (xilinx_zynqmp_virt) due to strings.
xilinx_zynqmp_virt has CONFIG_LOG enabled. Switching from printf() to log() incurs size growth. Did you observe a size grows on platforms with CONFIG_LOG=n?
Yes, it has logging enabled, and we're converting a large number of things that were before compile-time discarded to no longer be so. This is, in general, good and what I've asked for. But when seeing very large growth in doing so, I think we need to maybe take a step back and look at the UBI subsystem for example and see if we can't/shouldn't tweak things more.
So, I'm going to run a size test with just this patch as the change, so we can have more concrete numbers to look at.
OK, so the build is done and interesting output starts at: https://gist.github.com/trini/53e7da62c6c9d18c189e6baffd01ff00#file-2021-01-...
Most of the time we're well under 1KiB, which is great. UBI has some huge growth, but it's a very few platforms, and I've added the custodians here so they can object, or not, to such size growth.
Hello Tom,
How shall we proceed?
Michal? Patrice or Patrick? Since this patch causes noticeable growth on your platforms I'm waiting for your input here, to be clear. Thanks!
No objection for stm32 platforms, ok for us ;-)
Patrice

On 1/4/21 2:02 AM, Heinrich Schuchardt wrote:
In drivers we use a family of printing functions including pr_err() and pr_cont(). CONFIG_LOGLEVEL is used to control which of these lead to output via printf().
Our logging functions allow finer grained control of output. So replace printf() by the matching logging functions. The usage of CONFIG_LOGLEVEL remains unchanged.
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de
include/linux/bitops.h | 4 ++- include/linux/printk.h | 82 +++++++++++++++++++++++------------------- 2 files changed, 48 insertions(+), 38 deletions(-)
diff --git a/include/linux/bitops.h b/include/linux/bitops.h index 16f28993f5..d2e5ca026e 100644 --- a/include/linux/bitops.h +++ b/include/linux/bitops.h @@ -6,7 +6,6 @@ #include <asm/types.h> #include <asm-generic/bitsperlong.h> #include <linux/compiler.h> -#include <linux/kernel.h>
#ifdef __KERNEL__ #define BIT(nr) (1UL << (nr)) @@ -19,6 +18,9 @@ #define BITS_TO_LONGS(nr) DIV_ROUND_UP(nr, BITS_PER_BYTE * sizeof(long)) #endif
+/* kernel.h includes log.h which include bitops.h */ +#include <linux/kernel.h>
- /*
- Create a contiguous bitmask starting at bit position @l and ending at
- position @h. For example
diff --git a/include/linux/printk.h b/include/linux/printk.h index 088513ad29..5e85513853 100644 --- a/include/linux/printk.h +++ b/include/linux/printk.h @@ -1,6 +1,7 @@ #ifndef __KERNEL_PRINTK__ #define __KERNEL_PRINTK__
+#include <log.h> #include <stdio.h> #include <linux/compiler.h>
@@ -28,49 +29,56 @@ 0; \ })
-#define __printk(level, fmt, ...) \ -({ \
- level < CONFIG_LOGLEVEL ? printk(fmt, ##__VA_ARGS__) : 0; \
Couldn't we just do
#define __printk(level, fmt, ...) log(LOG_CATEGORY, level, fmt, ##__VA_ARGS__)
-})
- #ifndef pr_fmt #define pr_fmt(fmt) fmt #endif
-#define pr_emerg(fmt, ...) \
- __printk(0, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_alert(fmt, ...) \
- __printk(1, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_crit(fmt, ...) \
- __printk(2, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_err(fmt, ...) \
- __printk(3, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_warning(fmt, ...) \
- __printk(4, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_warn pr_warning -#define pr_notice(fmt, ...) \
- __printk(5, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_info(fmt, ...) \
- __printk(6, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_cont(fmt, ...) \
- printk(fmt, ##__VA_ARGS__)
-/* pr_devel() should produce zero code unless DEBUG is defined */ -#ifdef DEBUG -#define pr_devel(fmt, ...) \
- __printk(7, pr_fmt(fmt), ##__VA_ARGS__)
-#else -#define pr_devel(fmt, ...) \
- no_printk(pr_fmt(fmt), ##__VA_ARGS__)
-#endif +#define pr_emerg(fmt, ...) \ +({ \
- CONFIG_LOGLEVEL > 0 ? log_emerg(fmt, ##__VA_ARGS__) : 0; \
+})
There is also an off-by-one mismatch between the numbers here and the log level constants. E.g. LOGL_INFO is 6, but pr_info only gets emitted if CONFIG_LOGLEVEL is >= 7.
--Sean
+#define pr_alert(fmt, ...) \ +({ \
- CONFIG_LOGLEVEL > 1 ? log_alert(fmt, ##__VA_ARGS__) : 0; \
+}) +#define pr_crit(fmt, ...) \ +({ \
- CONFIG_LOGLEVEL > 2 ? log_crit(fmt, ##__VA_ARGS__) : 0; \
+}) +#define pr_err(fmt, ...) \ +({ \
- CONFIG_LOGLEVEL > 3 ? log_err(fmt, ##__VA_ARGS__) : 0; \
+}) +#define pr_warn(fmt, ...) \ +({ \
- CONFIG_LOGLEVEL > 4 ? log_warning(fmt, ##__VA_ARGS__) : 0; \
+}) +#define pr_notice(fmt, ...) \ +({ \
- CONFIG_LOGLEVEL > 5 ? log_notice(fmt, ##__VA_ARGS__) : 0; \
+}) +#define pr_info(fmt, ...) \ +({ \
- CONFIG_LOGLEVEL > 6 ? log_info(fmt, ##__VA_ARGS__) : 0; \
+}) +#define pr_debug(fmt, ...) \ +({ \
- CONFIG_LOGLEVEL > 7 ? log_debug(fmt, ##__VA_ARGS__) : 0; \
+}) +#define pr_devel(fmt, ...) \ +({ \
- CONFIG_LOGLEVEL > 7 ? log_debug(fmt, ##__VA_ARGS__) : 0; \
+})
-#ifdef DEBUG -#define pr_debug(fmt, ...) \
- __printk(7, pr_fmt(fmt), ##__VA_ARGS__)
+#ifdef CONFIG_LOG +#define pr_cont(fmt, ...) \ +({ \
- gd->logl_prev < CONFIG_LOGLEVEL ? \
log_cont(fmt, ##__VA_ARGS__) : 0; \
+}) #else -#define pr_debug(fmt, ...) \
- no_printk(pr_fmt(fmt), ##__VA_ARGS__)
+#define pr_cont(fmt, ...) \
printk(fmt, ##__VA_ARGS__) #endif
#define printk_once(fmt, ...) \
-- 2.29.2

On 1/17/21 1:37 AM, Sean Anderson wrote:
On 1/4/21 2:02 AM, Heinrich Schuchardt wrote:
In drivers we use a family of printing functions including pr_err() and pr_cont(). CONFIG_LOGLEVEL is used to control which of these lead to output via printf().
Our logging functions allow finer grained control of output. So replace printf() by the matching logging functions. The usage of CONFIG_LOGLEVEL remains unchanged.
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de
include/linux/bitops.h | 4 ++- include/linux/printk.h | 82 +++++++++++++++++++++++------------------- 2 files changed, 48 insertions(+), 38 deletions(-)
diff --git a/include/linux/bitops.h b/include/linux/bitops.h index 16f28993f5..d2e5ca026e 100644 --- a/include/linux/bitops.h +++ b/include/linux/bitops.h @@ -6,7 +6,6 @@ #include <asm/types.h> #include <asm-generic/bitsperlong.h> #include <linux/compiler.h> -#include <linux/kernel.h>
#ifdef __KERNEL__ #define BIT(nr) (1UL << (nr)) @@ -19,6 +18,9 @@ #define BITS_TO_LONGS(nr) DIV_ROUND_UP(nr, BITS_PER_BYTE * sizeof(long)) #endif
+/* kernel.h includes log.h which include bitops.h */ +#include <linux/kernel.h>
/* * Create a contiguous bitmask starting at bit position @l and ending at * position @h. For example diff --git a/include/linux/printk.h b/include/linux/printk.h index 088513ad29..5e85513853 100644 --- a/include/linux/printk.h +++ b/include/linux/printk.h @@ -1,6 +1,7 @@ #ifndef __KERNEL_PRINTK__ #define __KERNEL_PRINTK__
+#include <log.h> #include <stdio.h> #include <linux/compiler.h>
@@ -28,49 +29,56 @@ 0; \ })
-#define __printk(level, fmt, ...) \ -({ \ - level < CONFIG_LOGLEVEL ? printk(fmt, ##__VA_ARGS__) : 0; \
Couldn't we just do
#define __printk(level, fmt, ...) log(LOG_CATEGORY, level, fmt, ##__VA_ARGS__)
Dear Sean,
Thanks for reviewing.
As of today log() does not print anything if CONFIG_LOG is not enabled.
A patch by Simon to change this behavior is pending. If it gets merged, we can do the suggested simplification.
log: Convert log values to printf() if not enabled https://patchwork.ozlabs.org/project/uboot/patch/20210114033051.483560-5-sjg...
-})
#ifndef pr_fmt #define pr_fmt(fmt) fmt #endif
-#define pr_emerg(fmt, ...) \ - __printk(0, pr_fmt(fmt), ##__VA_ARGS__) -#define pr_alert(fmt, ...) \ - __printk(1, pr_fmt(fmt), ##__VA_ARGS__) -#define pr_crit(fmt, ...) \ - __printk(2, pr_fmt(fmt), ##__VA_ARGS__) -#define pr_err(fmt, ...) \ - __printk(3, pr_fmt(fmt), ##__VA_ARGS__) -#define pr_warning(fmt, ...) \ - __printk(4, pr_fmt(fmt), ##__VA_ARGS__) -#define pr_warn pr_warning -#define pr_notice(fmt, ...) \ - __printk(5, pr_fmt(fmt), ##__VA_ARGS__) -#define pr_info(fmt, ...) \ - __printk(6, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_cont(fmt, ...) \ - printk(fmt, ##__VA_ARGS__)
-/* pr_devel() should produce zero code unless DEBUG is defined */ -#ifdef DEBUG -#define pr_devel(fmt, ...) \ - __printk(7, pr_fmt(fmt), ##__VA_ARGS__) -#else -#define pr_devel(fmt, ...) \ - no_printk(pr_fmt(fmt), ##__VA_ARGS__) -#endif +#define pr_emerg(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 0 ? log_emerg(fmt, ##__VA_ARGS__) : 0; \ +})
There is also an off-by-one mismatch between the numbers here and the log level constants. E.g. LOGL_INFO is 6, but pr_info only gets emitted if CONFIG_LOGLEVEL is >= 7.
The Kconfig for CONFIG_LOGLEVEL description reads:
"All Messages with a loglevel *smaller than* the console loglevel will be compiled in."
I did not intend to change this definition.
Best regards
Heinrich
--Sean
+#define pr_alert(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 1 ? log_alert(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_crit(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 2 ? log_crit(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_err(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 3 ? log_err(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_warn(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 4 ? log_warning(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_notice(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 5 ? log_notice(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_info(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 6 ? log_info(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_debug(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 7 ? log_debug(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_devel(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 7 ? log_debug(fmt, ##__VA_ARGS__) : 0; \ +})
-#ifdef DEBUG -#define pr_debug(fmt, ...) \ - __printk(7, pr_fmt(fmt), ##__VA_ARGS__) +#ifdef CONFIG_LOG +#define pr_cont(fmt, ...) \ +({ \ + gd->logl_prev < CONFIG_LOGLEVEL ? \ + log_cont(fmt, ##__VA_ARGS__) : 0; \ +}) #else -#define pr_debug(fmt, ...) \ - no_printk(pr_fmt(fmt), ##__VA_ARGS__) +#define pr_cont(fmt, ...) \ + printk(fmt, ##__VA_ARGS__) #endif
#define printk_once(fmt, ...) \
2.29.2

On 1/17/21 2:26 AM, Heinrich Schuchardt wrote:
On 1/17/21 1:37 AM, Sean Anderson wrote:
On 1/4/21 2:02 AM, Heinrich Schuchardt wrote:
In drivers we use a family of printing functions including pr_err() and pr_cont(). CONFIG_LOGLEVEL is used to control which of these lead to output via printf().
Our logging functions allow finer grained control of output. So replace printf() by the matching logging functions. The usage of CONFIG_LOGLEVEL remains unchanged.
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de
include/linux/bitops.h | 4 ++- include/linux/printk.h | 82 +++++++++++++++++++++++------------------- 2 files changed, 48 insertions(+), 38 deletions(-)
diff --git a/include/linux/bitops.h b/include/linux/bitops.h index 16f28993f5..d2e5ca026e 100644 --- a/include/linux/bitops.h +++ b/include/linux/bitops.h @@ -6,7 +6,6 @@ #include <asm/types.h> #include <asm-generic/bitsperlong.h> #include <linux/compiler.h> -#include <linux/kernel.h>
#ifdef __KERNEL__ #define BIT(nr) (1UL << (nr)) @@ -19,6 +18,9 @@ #define BITS_TO_LONGS(nr) DIV_ROUND_UP(nr, BITS_PER_BYTE * sizeof(long)) #endif
+/* kernel.h includes log.h which include bitops.h */ +#include <linux/kernel.h>
- /*
- Create a contiguous bitmask starting at bit position @l and ending at
- position @h. For example
diff --git a/include/linux/printk.h b/include/linux/printk.h index 088513ad29..5e85513853 100644 --- a/include/linux/printk.h +++ b/include/linux/printk.h @@ -1,6 +1,7 @@ #ifndef __KERNEL_PRINTK__ #define __KERNEL_PRINTK__
+#include <log.h> #include <stdio.h> #include <linux/compiler.h>
@@ -28,49 +29,56 @@ 0; \ })
-#define __printk(level, fmt, ...) \ -({ \
- level < CONFIG_LOGLEVEL ? printk(fmt, ##__VA_ARGS__) : 0; \
Couldn't we just do
#define __printk(level, fmt, ...) log(LOG_CATEGORY, level, fmt, ##__VA_ARGS__)
Dear Sean,
Thanks for reviewing.
As of today log() does not print anything if CONFIG_LOG is not enabled.
#if CONFIG_IS_ENABLED(LOG) #define _LOG_MAX_LEVEL CONFIG_VAL(LOG_MAX_LEVEL) #define log_err(_fmt...) log(LOG_CATEGORY, LOGL_ERR, ##_fmt) #define log_warning(_fmt...) log(LOG_CATEGORY, LOGL_WARNING, ##_fmt) #define log_notice(_fmt...) log(LOG_CATEGORY, LOGL_NOTICE, ##_fmt) #define log_info(_fmt...) log(LOG_CATEGORY, LOGL_INFO, ##_fmt) #define log_debug(_fmt...) log(LOG_CATEGORY, LOGL_DEBUG, ##_fmt) #define log_content(_fmt...) log(LOG_CATEGORY, LOGL_DEBUG_CONTENT, ##_fmt) #define log_io(_fmt...) log(LOG_CATEGORY, LOGL_DEBUG_IO, ##_fmt) #else #define _LOG_MAX_LEVEL LOGL_INFO #define log_err(_fmt, ...) printf(_fmt, ##__VA_ARGS__) #define log_warning(_fmt, ...) printf(_fmt, ##__VA_ARGS__) #define log_notice(_fmt, ...) printf(_fmt, ##__VA_ARGS__) #define log_info(_fmt, ...) printf(_fmt, ##__VA_ARGS__) #define log_debug(_fmt, ...) debug(_fmt, ##__VA_ARGS__) #define log_content(_fmt...) log_nop(LOG_CATEGORY, \ LOGL_DEBUG_CONTENT, ##_fmt) #define log_io(_fmt...) log_nop(LOG_CATEGORY, LOGL_DEBUG_IO, ##_fmt) #endif
If CONFIG_LOG is not enabled, then log statements are converted to debug and printf.
A patch by Simon to change this behavior is pending. If it gets merged, we can do the suggested simplification.
log: Convert log values to printf() if not enabled https://patchwork.ozlabs.org/project/uboot/patch/20210114033051.483560-5-sjg...
-})
- #ifndef pr_fmt #define pr_fmt(fmt) fmt #endif
-#define pr_emerg(fmt, ...) \
- __printk(0, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_alert(fmt, ...) \
- __printk(1, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_crit(fmt, ...) \
- __printk(2, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_err(fmt, ...) \
- __printk(3, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_warning(fmt, ...) \
- __printk(4, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_warn pr_warning -#define pr_notice(fmt, ...) \
- __printk(5, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_info(fmt, ...) \
- __printk(6, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_cont(fmt, ...) \
- printk(fmt, ##__VA_ARGS__)
-/* pr_devel() should produce zero code unless DEBUG is defined */ -#ifdef DEBUG -#define pr_devel(fmt, ...) \
- __printk(7, pr_fmt(fmt), ##__VA_ARGS__)
-#else -#define pr_devel(fmt, ...) \
- no_printk(pr_fmt(fmt), ##__VA_ARGS__)
-#endif +#define pr_emerg(fmt, ...) \ +({ \
- CONFIG_LOGLEVEL > 0 ? log_emerg(fmt, ##__VA_ARGS__) : 0; \
+})
There is also an off-by-one mismatch between the numbers here and the log level constants. E.g. LOGL_INFO is 6, but pr_info only gets emitted if CONFIG_LOGLEVEL is >= 7.
The Kconfig for CONFIG_LOGLEVEL description reads:
"All Messages with a loglevel *smaller than* the console loglevel will be compiled in."
Ok then, perhaps that should be rectified.
--Sean
I did not intend to change this definition.
Best regards
Heinrich
--Sean
+#define pr_alert(fmt, ...) \ +({ \
- CONFIG_LOGLEVEL > 1 ? log_alert(fmt, ##__VA_ARGS__) : 0; \
+}) +#define pr_crit(fmt, ...) \ +({ \
- CONFIG_LOGLEVEL > 2 ? log_crit(fmt, ##__VA_ARGS__) : 0; \
+}) +#define pr_err(fmt, ...) \ +({ \
- CONFIG_LOGLEVEL > 3 ? log_err(fmt, ##__VA_ARGS__) : 0; \
+}) +#define pr_warn(fmt, ...) \ +({ \
- CONFIG_LOGLEVEL > 4 ? log_warning(fmt, ##__VA_ARGS__) : 0; \
+}) +#define pr_notice(fmt, ...) \ +({ \
- CONFIG_LOGLEVEL > 5 ? log_notice(fmt, ##__VA_ARGS__) : 0; \
+}) +#define pr_info(fmt, ...) \ +({ \
- CONFIG_LOGLEVEL > 6 ? log_info(fmt, ##__VA_ARGS__) : 0; \
+}) +#define pr_debug(fmt, ...) \ +({ \
- CONFIG_LOGLEVEL > 7 ? log_debug(fmt, ##__VA_ARGS__) : 0; \
+}) +#define pr_devel(fmt, ...) \ +({ \
- CONFIG_LOGLEVEL > 7 ? log_debug(fmt, ##__VA_ARGS__) : 0; \
+})
-#ifdef DEBUG -#define pr_debug(fmt, ...) \
- __printk(7, pr_fmt(fmt), ##__VA_ARGS__)
+#ifdef CONFIG_LOG +#define pr_cont(fmt, ...) \ +({ \
- gd->logl_prev < CONFIG_LOGLEVEL ? \
log_cont(fmt, ##__VA_ARGS__) : 0; \
+}) #else -#define pr_debug(fmt, ...) \
- no_printk(pr_fmt(fmt), ##__VA_ARGS__)
+#define pr_cont(fmt, ...) \
printk(fmt, ##__VA_ARGS__) #endif
#define printk_once(fmt, ...) \
-- 2.29.2

On 1/17/21 11:27 PM, Sean Anderson wrote:
On 1/17/21 2:26 AM, Heinrich Schuchardt wrote:
On 1/17/21 1:37 AM, Sean Anderson wrote:
On 1/4/21 2:02 AM, Heinrich Schuchardt wrote:
In drivers we use a family of printing functions including pr_err() and pr_cont(). CONFIG_LOGLEVEL is used to control which of these lead to output via printf().
Our logging functions allow finer grained control of output. So replace printf() by the matching logging functions. The usage of CONFIG_LOGLEVEL remains unchanged.
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de
include/linux/bitops.h | 4 ++- include/linux/printk.h | 82 +++++++++++++++++++++++------------------- 2 files changed, 48 insertions(+), 38 deletions(-)
diff --git a/include/linux/bitops.h b/include/linux/bitops.h index 16f28993f5..d2e5ca026e 100644 --- a/include/linux/bitops.h +++ b/include/linux/bitops.h @@ -6,7 +6,6 @@ #include <asm/types.h> #include <asm-generic/bitsperlong.h> #include <linux/compiler.h> -#include <linux/kernel.h>
#ifdef __KERNEL__ #define BIT(nr) (1UL << (nr)) @@ -19,6 +18,9 @@ #define BITS_TO_LONGS(nr) DIV_ROUND_UP(nr, BITS_PER_BYTE * sizeof(long)) #endif
+/* kernel.h includes log.h which include bitops.h */ +#include <linux/kernel.h>
/* * Create a contiguous bitmask starting at bit position @l and ending at * position @h. For example diff --git a/include/linux/printk.h b/include/linux/printk.h index 088513ad29..5e85513853 100644 --- a/include/linux/printk.h +++ b/include/linux/printk.h @@ -1,6 +1,7 @@ #ifndef __KERNEL_PRINTK__ #define __KERNEL_PRINTK__
+#include <log.h> #include <stdio.h> #include <linux/compiler.h>
@@ -28,49 +29,56 @@ 0; \ })
-#define __printk(level, fmt, ...) \ -({ \ - level < CONFIG_LOGLEVEL ? printk(fmt, ##__VA_ARGS__) : 0; \
Couldn't we just do
#define __printk(level, fmt, ...) log(LOG_CATEGORY, level, fmt, ##__VA_ARGS__)
Dear Sean,
Thanks for reviewing.
As of today log() does not print anything if CONFIG_LOG is not enabled.
#if CONFIG_IS_ENABLED(LOG) #define _LOG_MAX_LEVEL CONFIG_VAL(LOG_MAX_LEVEL) #define log_err(_fmt...) log(LOG_CATEGORY, LOGL_ERR, ##_fmt) #define log_warning(_fmt...) log(LOG_CATEGORY, LOGL_WARNING, ##_fmt) #define log_notice(_fmt...) log(LOG_CATEGORY, LOGL_NOTICE, ##_fmt) #define log_info(_fmt...) log(LOG_CATEGORY, LOGL_INFO, ##_fmt) #define log_debug(_fmt...) log(LOG_CATEGORY, LOGL_DEBUG, ##_fmt) #define log_content(_fmt...) log(LOG_CATEGORY, LOGL_DEBUG_CONTENT, ##_fmt) #define log_io(_fmt...) log(LOG_CATEGORY, LOGL_DEBUG_IO, ##_fmt) #else #define _LOG_MAX_LEVEL LOGL_INFO #define log_err(_fmt, ...) printf(_fmt, ##__VA_ARGS__) #define log_warning(_fmt, ...) printf(_fmt, ##__VA_ARGS__) #define log_notice(_fmt, ...) printf(_fmt, ##__VA_ARGS__) #define log_info(_fmt, ...) printf(_fmt, ##__VA_ARGS__) #define log_debug(_fmt, ...) debug(_fmt, ##__VA_ARGS__) #define log_content(_fmt...) log_nop(LOG_CATEGORY, \ LOGL_DEBUG_CONTENT, ##_fmt) #define log_io(_fmt...) log_nop(LOG_CATEGORY, LOGL_DEBUG_IO, ##_fmt) #endif
If CONFIG_LOG is not enabled, then log statements are converted to debug and printf.
Only the ones you cited, not the function log() referenced in your proposal.
A patch by Simon to change this behavior is pending. If it gets merged, we can do the suggested simplification.
log: Convert log values to printf() if not enabled https://patchwork.ozlabs.org/project/uboot/patch/20210114033051.483560-5-sjg...
-})
#ifndef pr_fmt #define pr_fmt(fmt) fmt #endif
-#define pr_emerg(fmt, ...) \ - __printk(0, pr_fmt(fmt), ##__VA_ARGS__) -#define pr_alert(fmt, ...) \ - __printk(1, pr_fmt(fmt), ##__VA_ARGS__) -#define pr_crit(fmt, ...) \ - __printk(2, pr_fmt(fmt), ##__VA_ARGS__) -#define pr_err(fmt, ...) \ - __printk(3, pr_fmt(fmt), ##__VA_ARGS__) -#define pr_warning(fmt, ...) \ - __printk(4, pr_fmt(fmt), ##__VA_ARGS__) -#define pr_warn pr_warning -#define pr_notice(fmt, ...) \ - __printk(5, pr_fmt(fmt), ##__VA_ARGS__) -#define pr_info(fmt, ...) \ - __printk(6, pr_fmt(fmt), ##__VA_ARGS__)
-#define pr_cont(fmt, ...) \ - printk(fmt, ##__VA_ARGS__)
-/* pr_devel() should produce zero code unless DEBUG is defined */ -#ifdef DEBUG -#define pr_devel(fmt, ...) \ - __printk(7, pr_fmt(fmt), ##__VA_ARGS__) -#else -#define pr_devel(fmt, ...) \ - no_printk(pr_fmt(fmt), ##__VA_ARGS__) -#endif +#define pr_emerg(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 0 ? log_emerg(fmt, ##__VA_ARGS__) : 0; \ +})
There is also an off-by-one mismatch between the numbers here and the log level constants. E.g. LOGL_INFO is 6, but pr_info only gets emitted if CONFIG_LOGLEVEL is >= 7.
The Kconfig for CONFIG_LOGLEVEL description reads:
"All Messages with a loglevel *smaller than* the console loglevel will be compiled in."
Ok then, perhaps that should be rectified.
The current definition allows to disable log level 0. So you better don't change it.
Best regards
Heinrich
--Sean
I did not intend to change this definition.
Best regards
Heinrich
--Sean
+#define pr_alert(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 1 ? log_alert(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_crit(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 2 ? log_crit(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_err(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 3 ? log_err(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_warn(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 4 ? log_warning(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_notice(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 5 ? log_notice(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_info(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 6 ? log_info(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_debug(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 7 ? log_debug(fmt, ##__VA_ARGS__) : 0; \ +}) +#define pr_devel(fmt, ...) \ +({ \ + CONFIG_LOGLEVEL > 7 ? log_debug(fmt, ##__VA_ARGS__) : 0; \ +})
-#ifdef DEBUG -#define pr_debug(fmt, ...) \ - __printk(7, pr_fmt(fmt), ##__VA_ARGS__) +#ifdef CONFIG_LOG +#define pr_cont(fmt, ...) \ +({ \ + gd->logl_prev < CONFIG_LOGLEVEL ? \ + log_cont(fmt, ##__VA_ARGS__) : 0; \ +}) #else -#define pr_debug(fmt, ...) \ - no_printk(pr_fmt(fmt), ##__VA_ARGS__) +#define pr_cont(fmt, ...) \ + printk(fmt, ##__VA_ARGS__) #endif
#define printk_once(fmt, ...) \
2.29.2

On Mon, Jan 04, 2021 at 08:02:55AM +0100, Heinrich Schuchardt wrote:
In drivers we use a family of printing functions including pr_err() and pr_cont(). CONFIG_LOGLEVEL is used to control which of these lead to output via printf().
Our logging functions allow finer grained control of output. So replace printf() by the matching logging functions. The usage of CONFIG_LOGLEVEL remains unchanged.
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de
Applied to u-boot/master, thanks!

Provide a unit test for printing via pr_err() and pr_cont().
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de --- test/log/Makefile | 1 + test/log/pr_cont_test.c | 45 +++++++++++++++++++++++++++++++++++++++++ 2 files changed, 46 insertions(+) create mode 100644 test/log/pr_cont_test.c
diff --git a/test/log/Makefile b/test/log/Makefile index 88bc573e9f..afdafa502a 100644 --- a/test/log/Makefile +++ b/test/log/Makefile @@ -8,6 +8,7 @@ obj-$(CONFIG_CMD_LOG) += log_filter.o ifdef CONFIG_UT_LOG
obj-y += test-main.o +obj-y += pr_cont_test.o
ifdef CONFIG_SANDBOX obj-$(CONFIG_LOG_SYSLOG) += syslog_test.o diff --git a/test/log/pr_cont_test.c b/test/log/pr_cont_test.c new file mode 100644 index 0000000000..236eff4b33 --- /dev/null +++ b/test/log/pr_cont_test.c @@ -0,0 +1,45 @@ +// SPDX-License-Identifier: GPL-2.0+ +/* + * Copyright (c) 2021, Heinrich Schuchardt xypron.glpk@gmx.de + * + * Test continuation of log messages using pr_cont(). + */ + +#include <common.h> +#include <console.h> +#include <test/log.h> +#include <test/test.h> +#include <test/suites.h> +#include <test/ut.h> +#include <linux/printk.h> + +#define BUFFSIZE 64 + +#undef CONFIG_LOGLEVEL +#define CONFIG_LOGLEVEL 4 + +DECLARE_GLOBAL_DATA_PTR; + +static int log_test_pr_cont(struct unit_test_state *uts) +{ + int log_fmt; + int log_level; + + log_fmt = gd->log_fmt; + log_level = gd->default_log_level; + + /* Write two messages, the second continuing the first */ + gd->log_fmt = BIT(LOGF_MSG); + gd->default_log_level = LOGL_INFO; + console_record_reset_enable(); + pr_err("ea%d ", 1); + pr_cont("cc%d\n", 2); + gd->default_log_level = log_level; + gd->log_fmt = log_fmt; + gd->flags &= ~GD_FLG_RECORD; + ut_assertok(ut_check_console_line(uts, "ea1 cc2")); + ut_assertok(ut_check_console_end(uts)); + + return 0; +} +LOG_TEST(log_test_pr_cont); -- 2.29.2

On Mon, 4 Jan 2021 at 00:03, Heinrich Schuchardt xypron.glpk@gmx.de wrote:
Provide a unit test for printing via pr_err() and pr_cont().
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de
test/log/Makefile | 1 + test/log/pr_cont_test.c | 45 +++++++++++++++++++++++++++++++++++++++++ 2 files changed, 46 insertions(+) create mode 100644 test/log/pr_cont_test.c
Reviewed-by: Simon Glass sjg@chromium.org

On Mon, Jan 04, 2021 at 08:02:56AM +0100, Heinrich Schuchardt wrote:
Provide a unit test for printing via pr_err() and pr_cont().
Signed-off-by: Heinrich Schuchardt xypron.glpk@gmx.de Reviewed-by: Simon Glass sjg@chromium.org
Applied to u-boot/master, thanks!
participants (5)
-
Heinrich Schuchardt
-
Patrice CHOTARD
-
Sean Anderson
-
Simon Glass
-
Tom Rini