[PATCH v2] kexec: fix the unexpected kexec_dprintk() macro

[PATCH v2] kexec: fix the unexpected kexec_dprintk() macro

[Baoquan He]

Jiri reported that the current kexec_dprintk() always prints out
debugging message whenever kexec/kdmmp loading is triggered. That is
not wanted. The debugging message is supposed to be printed out when
'kexec -s -d' is specified for kexec/kdump loading.

After investigating, the reason is the current kexec_dprintk() takes
printk(KERN_INFO) or printk(KERN_DEBUG) depending on whether '-d' is
specified. However, distros usually have defaulg log level like below:

 [~]# cat /proc/sys/kernel/printk
 7       4      1       7

So, even though '-d' is not specified, printk(KERN_DEBUG) also always
prints out. I thought printk(KERN_DEBUG) is equal to pr_debug(), it's
not.

Fix it by changing to use pr_info() instead which are expected to work.

Fixes: cbc2fe9d9cb2 ("kexec_file: add kexec_file flag to control debug printing")
Signed-off-by: Baoquan He <bhe@redhat.com>
Reported-by: Jiri Slaby <jirislaby@kernel.org>
Closes: https://lore.kernel.org/all/4c775fca-5def-4a2d-8437-7130b02722a2@kernel.org
---
v1->v2:
- Change to use pr_info() only when "kexec -s -d" is specified. With
  this change, those debugging message for "kexec -c -d" of kexec_load
  will be missed. We'll see if we need add them for kexec_load too, if
  someone explicitly requests it.

 include/linux/kexec.h | 6 ++----
 1 file changed, 2 insertions(+), 4 deletions(-)

diff --git a/include/linux/kexec.h b/include/linux/kexec.h
index 060835bb82d5..f31bd304df45 100644
--- a/include/linux/kexec.h
+++ b/include/linux/kexec.h
@@ -461,10 +461,8 @@ static inline void arch_kexec_pre_free_pages(void *vaddr, unsigned int pages) {
 
 extern bool kexec_file_dbg_print;
 
-#define kexec_dprintk(fmt, ...)					\
-	printk("%s" fmt,					\
-	       kexec_file_dbg_print ? KERN_INFO : KERN_DEBUG,	\
-	       ##__VA_ARGS__)
+#define kexec_dprintk(fmt, arg...) \
+        do { if (kexec_file_dbg_print) pr_info(fmt, ##arg); } while (0)
 
 #else /* !CONFIG_KEXEC_CORE */
 struct pt_regs;
-- 
2.41.0

Re: [PATCH v2] kexec: fix the unexpected kexec_dprintk() macro

[Dave Young]

On Tue, 9 Apr 2024 at 12:23, Baoquan He <bhe@redhat.com> wrote:
>
> Jiri reported that the current kexec_dprintk() always prints out
> debugging message whenever kexec/kdmmp loading is triggered. That is
> not wanted. The debugging message is supposed to be printed out when
> 'kexec -s -d' is specified for kexec/kdump loading.
>
> After investigating, the reason is the current kexec_dprintk() takes
> printk(KERN_INFO) or printk(KERN_DEBUG) depending on whether '-d' is
> specified. However, distros usually have defaulg log level like below:
>
>  [~]# cat /proc/sys/kernel/printk
>  7       4      1       7
>
> So, even though '-d' is not specified, printk(KERN_DEBUG) also always
> prints out. I thought printk(KERN_DEBUG) is equal to pr_debug(), it's
> not.
>
> Fix it by changing to use pr_info() instead which are expected to work.

Could you also update the kernel/crash_core.c and
kernel/crash_reserve.c to include the filename prefix?
#define pr_fmt(fmt) KBUILD_MODNAME ": " fmt

Otherwise:
Reviewed-by: Dave Young <dyoung@redhat.com>

>
> Fixes: cbc2fe9d9cb2 ("kexec_file: add kexec_file flag to control debug printing")
> Signed-off-by: Baoquan He <bhe@redhat.com>
> Reported-by: Jiri Slaby <jirislaby@kernel.org>
> Closes: https://lore.kernel.org/all/4c775fca-5def-4a2d-8437-7130b02722a2@kernel.org
> ---
> v1->v2:
> - Change to use pr_info() only when "kexec -s -d" is specified. With
>   this change, those debugging message for "kexec -c -d" of kexec_load
>   will be missed. We'll see if we need add them for kexec_load too, if
>   someone explicitly requests it.
>
>  include/linux/kexec.h | 6 ++----
>  1 file changed, 2 insertions(+), 4 deletions(-)
>
> diff --git a/include/linux/kexec.h b/include/linux/kexec.h
> index 060835bb82d5..f31bd304df45 100644
> --- a/include/linux/kexec.h
> +++ b/include/linux/kexec.h
> @@ -461,10 +461,8 @@ static inline void arch_kexec_pre_free_pages(void *vaddr, unsigned int pages) {
>
>  extern bool kexec_file_dbg_print;
>
> -#define kexec_dprintk(fmt, ...)                                        \
> -       printk("%s" fmt,                                        \
> -              kexec_file_dbg_print ? KERN_INFO : KERN_DEBUG,   \
> -              ##__VA_ARGS__)
> +#define kexec_dprintk(fmt, arg...) \
> +        do { if (kexec_file_dbg_print) pr_info(fmt, ##arg); } while (0)
>
>  #else /* !CONFIG_KEXEC_CORE */
>  struct pt_regs;
> --
> 2.41.0
>
>

Re: [PATCH v2] kexec: fix the unexpected kexec_dprintk() macro

[Baoquan He]

On 04/12/24 at 03:28pm, Dave Young wrote:
> On Tue, 9 Apr 2024 at 12:23, Baoquan He <bhe@redhat.com> wrote:
> >
> > Jiri reported that the current kexec_dprintk() always prints out
> > debugging message whenever kexec/kdmmp loading is triggered. That is
> > not wanted. The debugging message is supposed to be printed out when
> > 'kexec -s -d' is specified for kexec/kdump loading.
> >
> > After investigating, the reason is the current kexec_dprintk() takes
> > printk(KERN_INFO) or printk(KERN_DEBUG) depending on whether '-d' is
> > specified. However, distros usually have defaulg log level like below:
> >
> >  [~]# cat /proc/sys/kernel/printk
> >  7       4      1       7
> >
> > So, even though '-d' is not specified, printk(KERN_DEBUG) also always
> > prints out. I thought printk(KERN_DEBUG) is equal to pr_debug(), it's
> > not.
> >
> > Fix it by changing to use pr_info() instead which are expected to work.
> 
> Could you also update the kernel/crash_core.c and
> kernel/crash_reserve.c to include the filename prefix?
> #define pr_fmt(fmt) KBUILD_MODNAME ": " fmt

OK, thanks for testing and spotting this. 

When I tested this patch, I only did test kexec reboot functionality.
So the line of printing in kernel/crash_core.c is missed. While there
seems to be no kexec_dprintk() in kernel/crash_reserve.c. Anyway,
adding pr_fmt() is a good idea for debug printing in that file. I will
post a standalone patch to add these.

> 
> Otherwise:
> Reviewed-by: Dave Young <dyoung@redhat.com>

Thanks again.

> 
> >
> > Fixes: cbc2fe9d9cb2 ("kexec_file: add kexec_file flag to control debug printing")
> > Signed-off-by: Baoquan He <bhe@redhat.com>
> > Reported-by: Jiri Slaby <jirislaby@kernel.org>
> > Closes: https://lore.kernel.org/all/4c775fca-5def-4a2d-8437-7130b02722a2@kernel.org
> > ---
> > v1->v2:
> > - Change to use pr_info() only when "kexec -s -d" is specified. With
> >   this change, those debugging message for "kexec -c -d" of kexec_load
> >   will be missed. We'll see if we need add them for kexec_load too, if
> >   someone explicitly requests it.
> >
> >  include/linux/kexec.h | 6 ++----
> >  1 file changed, 2 insertions(+), 4 deletions(-)
> >
> > diff --git a/include/linux/kexec.h b/include/linux/kexec.h
> > index 060835bb82d5..f31bd304df45 100644
> > --- a/include/linux/kexec.h
> > +++ b/include/linux/kexec.h
> > @@ -461,10 +461,8 @@ static inline void arch_kexec_pre_free_pages(void *vaddr, unsigned int pages) {
> >
> >  extern bool kexec_file_dbg_print;
> >
> > -#define kexec_dprintk(fmt, ...)                                        \
> > -       printk("%s" fmt,                                        \
> > -              kexec_file_dbg_print ? KERN_INFO : KERN_DEBUG,   \
> > -              ##__VA_ARGS__)
> > +#define kexec_dprintk(fmt, arg...) \
> > +        do { if (kexec_file_dbg_print) pr_info(fmt, ##arg); } while (0)
> >
> >  #else /* !CONFIG_KEXEC_CORE */
> >  struct pt_regs;
> > --
> > 2.41.0
> >
> >
> 

Re: [PATCH v2] kexec: fix the unexpected kexec_dprintk() macro

[Baoquan He]

Hi Dave,

On 04/12/24 at 03:28pm, Dave Young wrote:
> On Tue, 9 Apr 2024 at 12:23, Baoquan He <bhe@redhat.com> wrote:
> >
> > Jiri reported that the current kexec_dprintk() always prints out
> > debugging message whenever kexec/kdmmp loading is triggered. That is
> > not wanted. The debugging message is supposed to be printed out when
> > 'kexec -s -d' is specified for kexec/kdump loading.
> >
> > After investigating, the reason is the current kexec_dprintk() takes
> > printk(KERN_INFO) or printk(KERN_DEBUG) depending on whether '-d' is
> > specified. However, distros usually have defaulg log level like below:
> >
> >  [~]# cat /proc/sys/kernel/printk
> >  7       4      1       7
> >
> > So, even though '-d' is not specified, printk(KERN_DEBUG) also always
> > prints out. I thought printk(KERN_DEBUG) is equal to pr_debug(), it's
> > not.
> >
> > Fix it by changing to use pr_info() instead which are expected to work.
> 
> Could you also update the kernel/crash_core.c and
> kernel/crash_reserve.c to include the filename prefix?
> #define pr_fmt(fmt) KBUILD_MODNAME ": " fmt

When I added pr_fmt() to kernel/crash_reserve.c and tested code, the
printed boot log about crashkernel reservation is changed as below:

[  +0.000000] crash_reserve: crashkernel reserved: 0x000000007d000000 - 0x0000000095000000 (384 MB)

When I looked around, I noticed all other lines around don't have the
module name printed out. Seems it's not appropriate to add one for
crashkernel alone. And the kexec_dprintk() doesn't exist in
kernel/crash_reserve.c. Furthermore, the kexec_dprintk() is added to
enable debugging printing for kexec_file_load when loading kexec/kdump
kernel. This crashkernel reservation may not be related. Combinbed these
all, I would suggest not adding pr_fmt() for kernel/crash_reserve.c for
now, let's add pr_fmt() for kernel/crash_core.c, what do you think?

> 
> >
> > Fixes: cbc2fe9d9cb2 ("kexec_file: add kexec_file flag to control debug printing")
> > Signed-off-by: Baoquan He <bhe@redhat.com>
> > Reported-by: Jiri Slaby <jirislaby@kernel.org>
> > Closes: https://lore.kernel.org/all/4c775fca-5def-4a2d-8437-7130b02722a2@kernel.org
> > ---
> > v1->v2:
> > - Change to use pr_info() only when "kexec -s -d" is specified. With
> >   this change, those debugging message for "kexec -c -d" of kexec_load
> >   will be missed. We'll see if we need add them for kexec_load too, if
> >   someone explicitly requests it.
> >
> >  include/linux/kexec.h | 6 ++----
> >  1 file changed, 2 insertions(+), 4 deletions(-)
> >
> > diff --git a/include/linux/kexec.h b/include/linux/kexec.h
> > index 060835bb82d5..f31bd304df45 100644
> > --- a/include/linux/kexec.h
> > +++ b/include/linux/kexec.h
> > @@ -461,10 +461,8 @@ static inline void arch_kexec_pre_free_pages(void *vaddr, unsigned int pages) {
> >
> >  extern bool kexec_file_dbg_print;
> >
> > -#define kexec_dprintk(fmt, ...)                                        \
> > -       printk("%s" fmt,                                        \
> > -              kexec_file_dbg_print ? KERN_INFO : KERN_DEBUG,   \
> > -              ##__VA_ARGS__)
> > +#define kexec_dprintk(fmt, arg...) \
> > +        do { if (kexec_file_dbg_print) pr_info(fmt, ##arg); } while (0)
> >
> >  #else /* !CONFIG_KEXEC_CORE */
> >  struct pt_regs;
> > --
> > 2.41.0
> >
> >
> 

Re: [PATCH v2] kexec: fix the unexpected kexec_dprintk() macro

[Dave Young]

On Sun, 14 Apr 2024 at 10:54, Baoquan He <bhe@redhat.com> wrote:
>
> Hi Dave,
>
> On 04/12/24 at 03:28pm, Dave Young wrote:
> > On Tue, 9 Apr 2024 at 12:23, Baoquan He <bhe@redhat.com> wrote:
> > >
> > > Jiri reported that the current kexec_dprintk() always prints out
> > > debugging message whenever kexec/kdmmp loading is triggered. That is
> > > not wanted. The debugging message is supposed to be printed out when
> > > 'kexec -s -d' is specified for kexec/kdump loading.
> > >
> > > After investigating, the reason is the current kexec_dprintk() takes
> > > printk(KERN_INFO) or printk(KERN_DEBUG) depending on whether '-d' is
> > > specified. However, distros usually have defaulg log level like below:
> > >
> > >  [~]# cat /proc/sys/kernel/printk
> > >  7       4      1       7
> > >
> > > So, even though '-d' is not specified, printk(KERN_DEBUG) also always
> > > prints out. I thought printk(KERN_DEBUG) is equal to pr_debug(), it's
> > > not.
> > >
> > > Fix it by changing to use pr_info() instead which are expected to work.
> >
> > Could you also update the kernel/crash_core.c and
> > kernel/crash_reserve.c to include the filename prefix?
> > #define pr_fmt(fmt) KBUILD_MODNAME ": " fmt
>
> When I added pr_fmt() to kernel/crash_reserve.c and tested code, the
> printed boot log about crashkernel reservation is changed as below:
>
> [  +0.000000] crash_reserve: crashkernel reserved: 0x000000007d000000 - 0x0000000095000000 (384 MB)
>
> When I looked around, I noticed all other lines around don't have the
> module name printed out. Seems it's not appropriate to add one for
> crashkernel alone. And the kexec_dprintk() doesn't exist in
> kernel/crash_reserve.c. Furthermore, the kexec_dprintk() is added to
> enable debugging printing for kexec_file_load when loading kexec/kdump
> kernel. This crashkernel reservation may not be related. Combinbed these
> all, I would suggest not adding pr_fmt() for kernel/crash_reserve.c for
> now, let's add pr_fmt() for kernel/crash_core.c, what do you think?

Hi Baoquan,  I'm fine with it.

But adding pr_fmt is always good as all the pr_* will have a prefix
instead of manually add "crashkernel:" in every pr_warn etc.  There
are indeed a few without any prefix in this file though.  But it can
be done separately, not necessary to be done here together with the
debug print though.

Thanks
Dave

>
> >
> > >
> > > Fixes: cbc2fe9d9cb2 ("kexec_file: add kexec_file flag to control debug printing")
> > > Signed-off-by: Baoquan He <bhe@redhat.com>
> > > Reported-by: Jiri Slaby <jirislaby@kernel.org>
> > > Closes: https://lore.kernel.org/all/4c775fca-5def-4a2d-8437-7130b02722a2@kernel.org
> > > ---
> > > v1->v2:
> > > - Change to use pr_info() only when "kexec -s -d" is specified. With
> > >   this change, those debugging message for "kexec -c -d" of kexec_load
> > >   will be missed. We'll see if we need add them for kexec_load too, if
> > >   someone explicitly requests it.
> > >
> > >  include/linux/kexec.h | 6 ++----
> > >  1 file changed, 2 insertions(+), 4 deletions(-)
> > >
> > > diff --git a/include/linux/kexec.h b/include/linux/kexec.h
> > > index 060835bb82d5..f31bd304df45 100644
> > > --- a/include/linux/kexec.h
> > > +++ b/include/linux/kexec.h
> > > @@ -461,10 +461,8 @@ static inline void arch_kexec_pre_free_pages(void *vaddr, unsigned int pages) {
> > >
> > >  extern bool kexec_file_dbg_print;
> > >
> > > -#define kexec_dprintk(fmt, ...)                                        \
> > > -       printk("%s" fmt,                                        \
> > > -              kexec_file_dbg_print ? KERN_INFO : KERN_DEBUG,   \
> > > -              ##__VA_ARGS__)
> > > +#define kexec_dprintk(fmt, arg...) \
> > > +        do { if (kexec_file_dbg_print) pr_info(fmt, ##arg); } while (0)
> > >
> > >  #else /* !CONFIG_KEXEC_CORE */
> > >  struct pt_regs;
> > > --
> > > 2.41.0
> > >
> > >
> >
>