1. Patchew
  2. linux
  3. View series

[PATCH] init/main.c: log initcall level when initcall_debug is used

Francesco Valla posted 1 patch 9 months ago 
init/main.c | 18 ++++++++++++++++--
1 file changed, 16 insertions(+), 2 deletions(-)
[PATCH] init/main.c: log initcall level when initcall_debug is used
Posted by Francesco Valla 9 months ago 
When initcall_debug is specified on the command line, the start and
return point for each initcall is printed. However, no information on
the initcall level is reported.

Add to the initcall_debug infrastructure an additional print that
informs when a new initcall level is entered. This is particularly
useful when debugging dependency chains and/or working on boot time
reduction.

Signed-off-by: Francesco Valla <francesco@valla.it>
---
 init/main.c | 18 ++++++++++++++++--
 1 file changed, 16 insertions(+), 2 deletions(-)

diff --git a/init/main.c b/init/main.c
index 2a1757826397..80a07563036d 100644
--- a/init/main.c
+++ b/init/main.c
@@ -1214,6 +1214,12 @@ trace_initcall_finish_cb(void *data, initcall_t fn, int ret)
 		 fn, ret, (unsigned long long)ktime_us_delta(rettime, *calltime));
 }
 
+static __init_or_module void
+trace_initcall_level_cb(void *data, const char *level)
+{
+	printk(KERN_DEBUG "entering initcall level: %s\n", level);
+}
+
 static ktime_t initcall_calltime;
 
 #ifdef TRACEPOINTS_ENABLED
@@ -1225,10 +1231,12 @@ static void __init initcall_debug_enable(void)
 					    &initcall_calltime);
 	ret |= register_trace_initcall_finish(trace_initcall_finish_cb,
 					      &initcall_calltime);
+	ret |= register_trace_initcall_level(trace_initcall_level_cb, NULL);
 	WARN(ret, "Failed to register initcall tracepoints\n");
 }
 # define do_trace_initcall_start	trace_initcall_start
 # define do_trace_initcall_finish	trace_initcall_finish
+# define do_trace_initcall_level	trace_initcall_level
 #else
 static inline void do_trace_initcall_start(initcall_t fn)
 {
@@ -1242,6 +1250,12 @@ static inline void do_trace_initcall_finish(initcall_t fn, int ret)
 		return;
 	trace_initcall_finish_cb(&initcall_calltime, fn, ret);
 }
+static inline void do_trace_initcall_level(const char *level)
+{
+	if (!initcall_debug)
+		return;
+	trace_initcall_level_cb(NULL, level);
+}
 #endif /* !TRACEPOINTS_ENABLED */
 
 int __init_or_module do_one_initcall(initcall_t fn)
@@ -1314,7 +1328,7 @@ static void __init do_initcall_level(int level, char *command_line)
 		   level, level,
 		   NULL, ignore_unknown_bootoption);
 
-	trace_initcall_level(initcall_level_names[level]);
+	do_trace_initcall_level(initcall_level_names[level]);
 	for (fn = initcall_levels[level]; fn < initcall_levels[level+1]; fn++)
 		do_one_initcall(initcall_from_entry(fn));
 }
@@ -1358,7 +1372,7 @@ static void __init do_pre_smp_initcalls(void)
 {
 	initcall_entry_t *fn;
 
-	trace_initcall_level("early");
+	do_trace_initcall_level("early");
 	for (fn = __initcall_start; fn < __initcall0_start; fn++)
 		do_one_initcall(initcall_from_entry(fn));
 }
-- 
2.48.1
Re: [PATCH] init/main.c: log initcall level when initcall_debug is used
Posted by Andrew Morton 8 months, 2 weeks ago 
On Sun, 16 Mar 2025 21:50:15 +0100 Francesco Valla <francesco@valla.it> wrote:

> When initcall_debug is specified on the command line, the start and
> return point for each initcall is printed. However, no information on
> the initcall level is reported.
> 
> Add to the initcall_debug infrastructure an additional print that
> informs when a new initcall level is entered. This is particularly
> useful when debugging dependency chains and/or working on boot time
> reduction.
> 
> ...
>
> --- a/init/main.c
> +++ b/init/main.c
> @@ -1214,6 +1214,12 @@ trace_initcall_finish_cb(void *data, initcall_t fn, int ret)
>  		 fn, ret, (unsigned long long)ktime_us_delta(rettime, *calltime));
>  }
>  
> +static __init_or_module void
> +trace_initcall_level_cb(void *data, const char *level)
> +{
> +	printk(KERN_DEBUG "entering initcall level: %s\n", level);
> +}

Please review and test this fixlet:

--- a/init/main.c~init-mainc-log-initcall-level-when-initcall_debug-is-used-fix
+++ a/init/main.c
@@ -1217,7 +1217,7 @@ trace_initcall_finish_cb(void *data, ini
 static __init_or_module void
 trace_initcall_level_cb(void *data, const char *level)
 {
-	printk(KERN_DEBUG "entering initcall level: %s\n", level);
+	pr_debug("entering initcall level: %s\n", level);
 }
 
 static ktime_t initcall_calltime;
Re: [PATCH] init/main.c: log initcall level when initcall_debug is used
Posted by Geert Uytterhoeven 8 months, 2 weeks ago 
Hi Andrew,

On Thu, 3 Apr 2025 at 04:56, Andrew Morton <akpm@linux-foundation.org> wrote:
> On Sun, 16 Mar 2025 21:50:15 +0100 Francesco Valla <francesco@valla.it> wrote:
> > When initcall_debug is specified on the command line, the start and
> > return point for each initcall is printed. However, no information on
> > the initcall level is reported.
> >
> > Add to the initcall_debug infrastructure an additional print that
> > informs when a new initcall level is entered. This is particularly
> > useful when debugging dependency chains and/or working on boot time
> > reduction.
> >
> > ...
> >
> > --- a/init/main.c
> > +++ b/init/main.c
> > @@ -1214,6 +1214,12 @@ trace_initcall_finish_cb(void *data, initcall_t fn, int ret)
> >                fn, ret, (unsigned long long)ktime_us_delta(rettime, *calltime));
> >  }
> >
> > +static __init_or_module void
> > +trace_initcall_level_cb(void *data, const char *level)
> > +{
> > +     printk(KERN_DEBUG "entering initcall level: %s\n", level);
> > +}
>
> Please review and test this fixlet:
>
> --- a/init/main.c~init-mainc-log-initcall-level-when-initcall_debug-is-used-fix
> +++ a/init/main.c
> @@ -1217,7 +1217,7 @@ trace_initcall_finish_cb(void *data, ini
>  static __init_or_module void
>  trace_initcall_level_cb(void *data, const char *level)
>  {
> -       printk(KERN_DEBUG "entering initcall level: %s\n", level);
> +       pr_debug("entering initcall level: %s\n", level);
>  }
>
>  static ktime_t initcall_calltime;

I think the "printk(KERN_DEBUG ...)" construct is intentional.
The message should be logged when "initcall_debug" is passed on
the kernel command line, while pr_debug() is a no-op unless DEBUG is
defined inside the source file.

See also the two existing users in init/main.c near
https://elixir.bootlin.com/linux/v6.13.7/source/init/main.c#L1207.

Gr{oetje,eeting}s,

                        Geert

-- 
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- geert@linux-m68k.org

In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
                                -- Linus Torvalds
Re: [PATCH] init/main.c: log initcall level when initcall_debug is used
Posted by Rob Landley 8 months, 2 weeks ago 
On 4/2/25 21:55, Andrew Morton wrote:
> Please review and test this fixlet:
> 
> --- a/init/main.c~init-mainc-log-initcall-level-when-initcall_debug-is-used-fix
> +++ a/init/main.c
> @@ -1217,7 +1217,7 @@ trace_initcall_finish_cb(void *data, ini
>   static __init_or_module void
>   trace_initcall_level_cb(void *data, const char *level)
>   {
> -	printk(KERN_DEBUG "entering initcall level: %s\n", level);
> +	pr_debug("entering initcall level: %s\n", level);
>   }

How do I tell kconfig to remove all pr_blah() below loglevel X so they 
aren't compiled into the kernel taking up space? I thought that was the 
reason for switching to the pr_thingy() macros (it was in the old -tiny 
tree Mackall walked away from) but last time I tried to do it in vanilla 
I couldn't find the knob or trace the relevant plumbing...

Rob
Re: [PATCH] init/main.c: log initcall level when initcall_debug is used
Posted by Andrew Morton 8 months, 2 weeks ago 
On Thu, 3 Apr 2025 01:42:46 -0500 Rob Landley <rob@landley.net> wrote:

> On 4/2/25 21:55, Andrew Morton wrote:
> > Please review and test this fixlet:
> > 
> > --- a/init/main.c~init-mainc-log-initcall-level-when-initcall_debug-is-used-fix
> > +++ a/init/main.c
> > @@ -1217,7 +1217,7 @@ trace_initcall_finish_cb(void *data, ini
> >   static __init_or_module void
> >   trace_initcall_level_cb(void *data, const char *level)
> >   {
> > -	printk(KERN_DEBUG "entering initcall level: %s\n", level);
> > +	pr_debug("entering initcall level: %s\n", level);
> >   }
> 
> How do I tell kconfig to remove all pr_blah() below loglevel X so they 
> aren't compiled into the kernel taking up space? I thought that was the 
> reason for switching to the pr_thingy() macros (it was in the old -tiny 
> tree Mackall walked away from) but last time I tried to do it in vanilla 
> I couldn't find the knob or trace the relevant plumbing...

Ask the maintainer :)

I can't see a way.  Maybe it was never merged.
Re: [PATCH] init/main.c: log initcall level when initcall_debug is used
Posted by Petr Mladek 8 months, 2 weeks ago 
On Thu 2025-04-03 00:09:35, Andrew Morton wrote:
> On Thu, 3 Apr 2025 01:42:46 -0500 Rob Landley <rob@landley.net> wrote:
> 
> > On 4/2/25 21:55, Andrew Morton wrote:
> > > Please review and test this fixlet:
> > > 
> > > --- a/init/main.c~init-mainc-log-initcall-level-when-initcall_debug-is-used-fix
> > > +++ a/init/main.c
> > > @@ -1217,7 +1217,7 @@ trace_initcall_finish_cb(void *data, ini
> > >   static __init_or_module void
> > >   trace_initcall_level_cb(void *data, const char *level)
> > >   {
> > > -	printk(KERN_DEBUG "entering initcall level: %s\n", level);
> > > +	pr_debug("entering initcall level: %s\n", level);
> > >   }
> > 
> > How do I tell kconfig to remove all pr_blah() below loglevel X so they 
> > aren't compiled into the kernel taking up space? I thought that was the 
> > reason for switching to the pr_thingy() macros (it was in the old -tiny 
> > tree Mackall walked away from) but last time I tried to do it in vanilla 
> > I couldn't find the knob or trace the relevant plumbing...
> 
> Ask the maintainer :)
> 
> I can't see a way.  Maybe it was never merged.

If I read the definition of pr_debug() correctly then it should
become nop when CONFIG_DYNAMIC_DEBUG is not defined, look
for "pr_debug" and "no_printk" in include/linux/printk.h.

That said, I have never checked this. Another condition is
that DEBUG must not be defined. But I guess that it is
the default.

Best Regards,
Petr

Patchew 2.1-devel-b67e4c2

© 2016 - 2025 Red Hat, Inc.