Hi Tim, thank you for taking the time to review the tool. My reply too will be splitted in two parts. On Tuesday, 3 December 2024 at 21:33:06 Bird, Tim <Tim.Bird@xxxxxxxx> wrote: > 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? > These are not in fact addresses, but rather device names. In my understanding, they are printed when a probe happens outside of the initialization function for their driver. I still don't have an idea on how to match probes with their original initcall, in order to present the user the complete picture. > > * 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? I can take a look, but probably toward the end of the year. Another similar area I'd like to investigate is related to initcall time vs actual probe time: for drivers instantiated multiple time, I'd like to know how much time each probe took rather than the overall time. Regards, Francesco
