RE: [PATCH v4 1/1] printk: fix zero-valued printk timestamps in early boot

[Bird, Tim]

> -----Original Message-----
> From: Petr Mladek <pmladek@xxxxxxxx>
> On Mon 2026-04-20 22:18:29, Bird, Tim wrote:
> > > From: Petr Mladek <pmladek@xxxxxxxx>
> > >    2. The early timestamps provided by the bogo cycles
> > >       are not synchronized with timestamps from
> > >       the proper time keeping.
> > >
> > >       Would it help to print a disclaimer, similar to,
> > >       for example, trace_printk() first use?
> > >       Something like:
> > >
> > > [    0.002912] **********************************************************
> > > [    0.002917] ****   NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE
> > > [    0.002921] **
> > > [    0.002935] ** Using BOGO early timestamps
> > > [    0.002939] **
> > > [    0.002943] ** They are not properly calibrated and might use a source
> > > [    0.002949] ** with an unstable frequency.
> > > [    0.002953] **
> > > [    0.002957] ** They are not comparable with timestamps after
> > > [    0.002961] ** the timekeeping is initialized.
> > > [    0.002966] **
> > > [    0.002968] ****   NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE
> > > [    0.002971] *******************************************************
> >
> > That's a bit long, but I think a warning like this is useful.
> 
> Yeah, feel free to make it shorter. I just wanted to explain what is
> going on and what is the effect.
> 
> > > [    0.002975] Booting Linux on physical CPU 0x0000000000 [0x410fd083]
> > > [    0.002998] Linux version 7.0.0-rc6-v8+ (tbird@timdesk) (aarch64-linux-gnu-gcc (Ubuntu 13.3.0-6ubuntu2~24.04) 13.3.0, GNU ld (GNU
> > > Binutils for Ubuntu) 2.42) #20 SMP PREEMPT Fri Apr 10 11:57:48 MDT 2026
> > > [    0.003002] KASLR enabled
> > > [    0.003338] random: crng init done
> > > [    0.003866] Machine model: Raspberry Pi 4 Model B Rev 1.5
> > > [    0.004495] efi: UEFI not found.
> > > ...
> > > [    0.183552] Root IRQ handler: gic_handle_irq
> > > [    0.183561] GIC: Using split EOI/Deactivate mode
> > > [    0.183699] rcu: srcu_init: Setting srcu_struct sizes based on contention.
> > > [    0.183958] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns
> > > [    0.183952] arch_timer: cp15 timer running at 54.00MHz (phys).
> > > [    0.183957] **********************************************************
> > > [    0.183962] ****   NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE
> > > [    0.183967] **
> > > [    0.183971] ** End of BOGO early timestamps
> > > [    0.183976] **
> > > [    0.183982] ****   NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE
> > > [    0.183989] **********************************************************
> >
> > I actually worked on a notice like this, to bridge/explain the transition (for humans).  But it turned
> > out that different platforms initialized their clocks differently enough that it would have
> > required putting the notice in different places, which would have required architecture-specific
> > #ifdefs in generic code (so I didn't do it).
> 
> I think that we could print both notices from the printk() code:
> 
>  + 1st one before the very first message
>  + 2nd one before the first message with a proper timestamp from
>    the local_clock().

Yes.  That's a good solution.  I feel a bit dumb for not having thought of it. :-)

I'll plan to add this to a V5 patch.  I'd like to wait a bit longer to submit
a V5 patch, to let the dust settle on discussion from your post.
If Thomas still objects, then I'll focus on adjusting the patch for out-of-tree
maintenance.

As an aside, having a couple of printks submitted in quick succession early on
is actually helpful to get a sense of time that each printk takes.

Thanks,
 -- Tim