Re: [boot-time] jent_mod_init on beagleplay (was RE: [boot-time] [RFC] analyze-initcall-debug.py - a tool to analyze the initcall debug output

[Francesco Valla <francesco@valla.it>]

On Tuesday, 3 December 2024 at 22:24:28 Bird, Tim <Tim.Bird@sony.com> wrote:
> > -----Original Message-----
> > From: Francesco Valla <francesco@valla.it>
> > 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
> >  * deferred_probe_initcall -> 487483us
> >  * 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
> 
> This is odd.  On my beagleplay board, jent_mod_init only took 32326us.
> (see https://birdcloud.org/boot-time-files/boot-data-timslab-bp1-241203-134136.txt)
> 
> I'm assuming that we have similar hardware, but possibly different configs,
> kernel cmdlines or kernel versions.  I'll take a look at this and see if I can
> figure out what the difference is between our systems, that causes the
> difference in the duration for this function.
> 
> This initcall (jent_mod_init) is on my list of initcalls to research to see if they
> can be improved or deferred.  I haven't seen any degradation in system
> behavior by deferring this initcall on my system, but that could be from
> lack of my system doing some related operation that needs the RNG data, or my
> own ignorance of the effects of this call.
> 
> Can someone comment on what items or operations might depend on jent_mod_init
> in early boot?  In particular, would we expect any cryptographic problems if
> the initcall was deferred to a few seconds after booting?
> 
> It can be configured as a module, which makes me think that maybe loading
> it sometime in very late boot (or even later) is OK.
> 
> jent_mod_init is defined in crypto/jitterentropy-kcapi.c, and controlled by 
> CONFIG_CRYPTO_JITTERENTROPY (See crypto/Kconfig)
> 
> It appears to do some random number generator seeding by measuring
> the jitter of a compressiong operation in the kernel. I assume some of the cryptography
> configs affect the duration of the operations.  The initcall duration results on
> my beagleplay seem to be relatively consistent (in the 32ms range consistently),
> and from bobs_lab, on machine sam1, the duration range is also consistent
> (at between 4800 and 5200 usecs).
> 
> I'd be interested to see if the range is consistent between runs on other machines
> 
> Francesco - Can you submit another boot-data file (or 2 or 3) for francsecoslab-beagleplay, to
> provide some data on this?
> 

I actually lost this request and only found it this morning when reviewing past
emails. My apologies.

Anyway: I just uploaded another boot-data file (of a kernel with some
optimizations), but can confirm that the time spent inside jent_mod_init across
multiple runs appears consistent - or should I say fixed? - at 52ms.

Francesco