Re: [PATCH 2/3] xfs: fix xfs print level wrong parsing

[Dave Chinner <david@fromorbit.com>]

On Fri, Apr 21, 2023 at 11:31:41AM +0800, Guo Xuenan wrote:
> Recently, during my xfs bugfix work, notice a bug that makes
> xfs_stack_trace never take effect. This has been around here at xfs
> debug framework for a long time.
> 
> The root cause is misuse of `kstrtoint` which always return -EINVAL
> because KERN_<LEVEL> with KERN_SOH prefix unable to parse correctly by
> it. By skipping the prefix KERN_SOH we can get correct printk level.
> 
> Fixes: 847f9f6875fb ("xfs: more info from kmem deadlocks and high-level error msgs")
> Signed-off-by: Guo Xuenan <guoxuenan@huawei.com>
> ---
>  fs/xfs/xfs_message.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/fs/xfs/xfs_message.c b/fs/xfs/xfs_message.c
> index 8f495cc23903..bda4c0a0ca42 100644
> --- a/fs/xfs/xfs_message.c
> +++ b/fs/xfs/xfs_message.c
> @@ -45,7 +45,7 @@ xfs_printk_level(
>  
>  	va_end(args);
>  
> -	if (!kstrtoint(kern_level, 0, &level) &&
> +	if (!kstrtoint(kern_level + strlen(KERN_SOH), 0, &level) &&
>  	    level <= LOGLEVEL_ERR &&
>  	    xfs_error_level >= XFS_ERRLEVEL_HIGH)
>  		xfs_stack_trace();

Ugh. KERN_* is a string with a special character as a header, not
just an stringified number. Ok, I see how this fixes the bug, but
let's have a look at where kern_level comes from. i.e.
xfs_message.h:

extern __printf(3, 4)
void xfs_printk_level(const char *kern_level, const struct xfs_mount *mp,
                        const char *fmt, ...);

define xfs_printk_index_wrap(kern_level, mp, fmt, ...)         \
({                                                              \
        printk_index_subsys_emit("%sXFS%s: ", kern_level, fmt); \
        xfs_printk_level(kern_level, mp, fmt, ##__VA_ARGS__);   \
})
#define xfs_emerg(mp, fmt, ...) \
        xfs_printk_index_wrap(KERN_EMERG, mp, fmt, ##__VA_ARGS__)
#define xfs_alert(mp, fmt, ...) \
        xfs_printk_index_wrap(KERN_ALERT, mp, fmt, ##__VA_ARGS__)
#define xfs_crit(mp, fmt, ...) \
        xfs_printk_index_wrap(KERN_CRIT, mp, fmt, ##__VA_ARGS__)
#define xfs_err(mp, fmt, ...) \
        xfs_printk_index_wrap(KERN_ERR, mp, fmt, ##__VA_ARGS__)
.....

IOWs, we define the level value directly in these macros, they
aren't spread throughout the code. Hence we should be able to use
some preprocessor string concatenation magic here to get rid of the
kstrtoint() call altogether.

 extern __printf(3, 4)
-void xfs_printk_level(const char *kern_level, const struct xfs_mount *mp,
-                        const char *fmt, ...);
+void xfs_printk_level(const char *kern_level, const int log_level,
+			const struct xfs_mount *mp, const char *fmt, ...);

 define xfs_printk_index_wrap(level, mp, fmt, ...)         \
 ({                                                              \
-        printk_index_subsys_emit("%sXFS%s: ", kern_level, fmt); \
-        xfs_printk_level(kern_level, mp, fmt, ##__VA_ARGS__);   \
+        printk_index_subsys_emit("%sXFS%s: ", KERN_##level, fmt); \
+        xfs_printk_level(KERN_##level, LOGLEVEL_##level mp, fmt, ##__VA_ARGS__);   \
 })
 #define xfs_emerg(mp, fmt, ...) \
-        xfs_printk_index_wrap(KERN_EMERG, mp, fmt, ##__VA_ARGS__)
+        xfs_printk_index_wrap(EMERG, mp, fmt, ##__VA_ARGS__)
 #define xfs_alert(mp, fmt, ...) \
-        xfs_printk_index_wrap(KERN_ALERT, mp, fmt, ##__VA_ARGS__)
-        xfs_printk_index_wrap(ALERT, mp, fmt, ##__VA_ARGS__)
 #define xfs_crit(mp, fmt, ...) \
-        xfs_printk_index_wrap(KERN_CRIT, mp, fmt, ##__VA_ARGS__)
-        xfs_printk_index_wrap(CRIT, mp, fmt, ##__VA_ARGS__)
 #define xfs_err(mp, fmt, ...) \
-       xfs_printk_index_wrap(KERN_ERR, mp, fmt, ##__VA_ARGS__)
-       xfs_printk_index_wrap(ERR, mp, fmt, ##__VA_ARGS__)
....

Then xfs_printk_level() is passed the log level as an integer value
at runtime - the compiler does is all for us - and the code
is then simply:

	if (log_level < LOGLEVEL_ERR &&
	    xfs_error_level >= XFS_ERRLEVEL_HIGH)
		xfs_stack_trace();

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com