Why the kernel/system log time sequence is conflict after reboot?

Dear NV_Team,

When we trace the kernel and system log, we find a problem the time record in the log file is conflict after reboot? Before reboot the last time is Aug 13 10:42:04 but after reboot the kernel log record time start at Aug 13 09:57:52 ? Can you help to check why it happens ?

Aug 13 10:22:04 nano kernel: [265581.677111] RTW: set group key camid:2, addr:00:00:00:00:00:00, kid:2, type:TKIP
Aug 13 10:32:04 nano kernel: [266181.667807] RTW: set group key camid:1, addr:00:00:00:00:00:00, kid:1, type:TKIP
Aug 13 10:42:04 nano kernel: [266781.658291] RTW: set group key camid:2, addr:00:00:00:00:00:00, kid:2, type:TKIP
Aug 13 09:57:52 nano kernel: [    0.000000] Booting Linux on physical CPU 0x0
Aug 13 09:57:52 nano kernel: [    0.000000] Linux version 4.9.140-tegra (twsrv01@twsrv01) (gcc version 7.3.1 20180425 [linaro-7.3-2018.05 revision d29120a424ecfbc167ef90065c0eeb7f91977701] (Linaro GCC 7.3-2018.05) ) #21 SMP PREEMPT Thu Jul 2 19:04:32 CST 2020
Aug 13 09:57:52 nano kernel: [    0.000000] Boot CPU: AArch64 Processor [411fd071]
Aug 13 09:57:52 nano kernel: [    0.000000] OF: fdt:memory scan node memory@80000000, reg size 48,

kern.log (845.2 KB)

I don’t know why the times are " 0.000000" for several entries, but do beware that up until the Linux kernel itself boots, that bootloader software is its own separate operating system. A bootloader is an operating system, and its only purpose is to overwrite itself with another operating system. Timestamps in bootloader stages get reset when Linux loads because it is a fresh start. The Linux kernel is not running under U-Boot, it is replacing U-Boot.

The very first thing the Linux kernel does at the start of its life is indeed time “0.000000”. I could see the possibility that if the timestamp were queried only once, and then a few statements printed from that, then all would be the same time.

FYI, bootloaders overwrite themselves, the kernel is PID 0, and its only goal (at the start) is to run init, PID 1, as a process/child. Since Linux does not get overwritten all timestamps should be continuous and increasing.

Hi linuxdev,

Thanks for your information. What I want to figure out is why the log written in kern.log(time in the first column of the file) is not in accordance with time (not kernel time) .

The kernel log time from ‘0.0000’ is okay(we understand that), but the kern.log file time after reboot, should be start later then 'Aug 13 10:42:04 ’ not start from ‘Aug 13 09:57:52’. Can you get the whole kern.log?

hello Ciya.Jiang,

I don’t see this issue with my setups. could you please enable $ sudo hwclock --show, for checking before rebooting.
BTW, we usually checking kernel times with [ 0.000000].

I don’t know what the log rotation rules are for kern.log. A lot of these logs rotate at each boot, but it may be that kern.log only rotates after it grows to a certain size. Possibly, the older content is from a previous boot and logs simply did not yet rotate.

Do you have a battery or supercap actually connected to the Nano, to support the built-in RTC?
Have you enabled the hardware clock, using “systemctl enable hwclock.service” after making sure the battery works?
The Nano won’t keep time after it loses power if you don’t have a separate supercap or battery.

1 Like