Hey Francesco, I appreciate the new tool, and have some feedback below. I'll separate my response and ideas into 2 categories: - issues raised from your sample report - feedback on the tool itself and send them as separate emails. > -----Original Message----- > From: Francesco Valla <francesco@xxxxxxxx> > Dear fellow boot time optimizers, > > following the first boot time SIG meeting, which I lurked with much pleasure > (but didn't participate to, as I was a bit in awe among such authorities), I'd > like to introduce myself with code rather than a presentation or resume. > > Here is a python script which can analyze a dmesg output with initcall_debug > option enabled and extract some useful information. It can for example be used > to analyze the output of the grab-boot-data.sh tool that Tim presented on this > list [1] just a few days ago. > > Usage is very simple, as the output of dmesg can be piped directly to it: > > dmesg | analyze-initcall-debug.py > > If no option is specified, it outputs a brief summary, like the following one > (obtained on my Beagleplay): > > 1758 drivers has been initialized, of which 1758 before userspace > 119 probes happened outside of the init of their driver > 0 deferred probes pending > --- > Top 10 init/probes durations: > * 30200000.dss -> 523002us This call, and a lot of the others are missing function names. Did you compile the kernel with CONFIG_KALLSYMS=y? If that's the case, is there a way to use the System.map file for the kernel (used on the machine where the dmesg was obtained from) to map these addresses to their respective function names? > * deferred_probe_initcall -> 487483us I feel like this function is interfering with the ability to correctly assign boot time delays to the correct initcall. I would really like to see someone tackle this issue, by studying the deferred_probe_initcall function, to see if there's a way to instrument it so that the cost of each probe can be reported and then associated with corresponding initcall, when initcall_debug is used. Does anyone want to look into this issue? It falls under the category of improving instrumentation and reducing blind spots during boot. > * fd00000.gpu -> 162859us > * 8000f00.mdio -> 142521us > * 44043000.system-controller -> 71390us > * 2-004c -> 71178us > * 40900000.crypto -> 59350us > * 8000000.ethernet -> 58419us > * 44043000.system-controller:clock-controller -> 56599us > * jent_mod_init -> 52140us > > A more complete output, reporting all durations as well as statuses, impact of > probe deferral and so on, can be produced either in HTML or Markdown format, > using respectively the --html or --markdown parameters. This seems quite useful, as this will allow me to add this output to my boot-time wiki quite easily. > > Note: it hasn't (yet?) been used in a "production" environment, as I never > found the motivation to write a script and always analyzed manually the > initcall_debug output. > > If you have time to take a look, please tell me what you think and what > can be added. I'll give feedback on the tool itself in a separate message. -- Tim > > [1] https://lore.kernel.org/linux- > embedded/MW5PR13MB5632F54DCBDA0C74370E531FFD5C2@xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx/ >
