Paul,

On Wed, 17 Oct 2018, Paul Menzel wrote:
> 
> Please find the debug patches attached. The `random: %i` messages are from
> `crng_fast_load()`.
> 
> My question is, how can I figure out, what happens in the code below?
> 
>         complete(&kthreadd_done);
>         pr_info("After kthreadd_done\n");
> 
>         /*
>          * The boot idle thread must execute schedule()
>          * at least once to get things moving:
>          */
>         schedule_preempt_disabled();
>         pr_info("After schedule_preempt_disabled\n");
> 
> Looking at `schedule_preempt_disabled()`, it shouldnąt take much time, and I
> was unable to find out where `crng_fast_load()` is called from.
> 
> I guess threading is somehow working at that point, and I would though that
> it is the `complete()` call, but wonder why the `After kthreadd_done` is
> printed earlier.

This creates the init thread from the idle thread with preemption
disabled. To get the init thread on the CPU the idle thread must schedule
voluntary, which it does by calling schedule_preempt_disabled(). So the
scheduler picks the init thread and that executes the init callbacks.

The random calls are invoked by add_interrupt_randomness() or
add_hwgenerator_randomness(). But they are probably not consuming all the
time.

The time is consumed by the initcalls which are required before bringing up
the (non boot) CPUs. See kernel_init_freeable() which is called from
kernel_init(). If you add initcall_debug to the command line you will get
more information at least about the functions which are marked with
initcall.

Thanks,

	tglx