Re: "dmesg -T" date doesn't match "date" output

[Robert Elz <kre%munnari.OZ.AU@localhost>]

    Date:        Mon, 29 Oct 2018 07:03:21 -0000 (UTC)
    From:        mlelstv%serpens.de@localhost (Michael van Elst)
    Message-ID:  <pr6bbd$96b$1%serpens.de@localhost>

  | Being "plausible" is irrelevant here, we are just talking about
  | time stamps that are useful, not some meaning in the real world.

That might be what you're concerned with, but I am interested more
in the latter - fixing dmesg timestamp reporting is easy (there are
several ways) - the question of more interest to me is in identifying
what we really mean by "the system booted now" (and do recall
that kern.boottime provides microsecond precision for that) and
have it really mean something in the real world.

For that we need to be able to say what it means.

  | Uptime is counted when the counters start counting, and that's 3a.
  | Without counters counting you cannot count time, so that here is the
  | earliest possibility to get uptime information. Anything later will
  | just lose information.

Agreed, though on sme architectures we can go back before the
regular clocks are enabled.


  | w doesn't report $uptime but current time - $boottime. 

That's what I said....    But that's what most people call the
uptime (including the output from w / uptime).   That there is
a difference between that, and the "period during which the clocks
have been running" time, is something no-one has really paid any
attention to.    There is no reason though that the two need to
be the same.

  | That data is more precise than what is printed by w, which is obvious as
  | w produces output for humans.

Sure, w rounds things to minutes, which is about as much as we
can handle normally (or want to) though it could avoid doing that
if it wanted.

  | We are talking about internal kernel data. If you need $uptime, you
  | could expose it like $boottime.

We could, but deisigning a system where now - boottime != uptime is
kind of weird, don't you think?   boottime is where it all starts, if boottime
is X, and uptime is Y, then X + Y should be now.

None of that means that there can't be activity before boot time of
course, we need to pick an epoch, (just like unix timestamps have
0 at 1 Jan 1970) and it should be something meaningful, with
some practical reason to exist - but pick a point to call 0 does
not mean earlier times don't exist.

  | I don't see why starting init (a very variable point in time) can be
  | more relevant than mounting root (a less variable point in time).

Starting init is when userland begins to run - that could be considered
to be when the system is booted.   Mounting root is just part of the
init sequence the kernel goes through to get to that point.

But this gets into the question of what time should be boot time,
when userland starts is just one of  the possibilities.

Do understand that I am not advocating for any of the possibilities,
for which there is any reasonable reason for selection (but I
will argue against selecting something just because it is the
easiest to implement.)

  | But mounting root is the earliest of these points where we can
  | get an absolute time, so why defer it?

It depends what we (as people) consider to be when the system
has booted?   Do you count a system as booted if it fails to
mount root, and stops to ask you where to find it?   Or if it
hangs probing the video card after that?

This all gets back to my initial question - when is the system
booted (not how does a NetBSD kernel operate, but what attributes
do we need to have occurred before we agree that booting has
happened.)   Whatever we settlte on as the answer to that
question will drive everything else.

  | If init is so important, I guess the time when specific services
  | start or when network is operational or when the first login
  | (or the distinct time for a remote login) is much more important
  | to any operator or user.

Yes, it might be - when logins are enabled was one of the other
possible choices for boot time.

Which of those possibilities we should pick is the question to
answer.    That we might not all agree, and some of us might
have different needs than others is why I suggested that perhaps
we shold allow the system admin to choose what they consider
to be the point where the system is booted, and label that as
the boot time (and the time from which uptime counts - with
whatever happens previously being while the system was
still down, or recovering, or ...)

  | So maybe such information is useful but
  | not really a good basis for $boottime. $boottime should simply
  | predate all such events,

Whty  Surely it should be the time that the system booted
(Whatever that means.)

If other stuff happens before that, then that's pre-boot
activity.

  | 3b is the earliest point when an absolute time value exists, that
  | makes it special.

Not really, since we have been counting time since 3a, once we
get that time at 3b, all earlier times now have an absolute time as
well.  Since 3b happens before anyone has a mechanism to
query the time (for any purpose) it doesn't matter that had
someone asked bewteen 3a and 3b what time something
happened, we would not have been able to answer, because
they cannot do that.   After 3b has occurred, we can
attribute absolute times to evenrything since 3a.

  | Init usually starts a split-second later. If it can be started.

On my laptop, it seems to take almost 2 seconds to get from
mounting root to starting init (1.n seconds typically).

In the interim it is doing a bunch of drm init, attempting to load
graphics card firmware, and then doing something or other with
the wireless card, and then finally setting up all the ws* stuff
(associating devices with wsmux's etc.)

Once all that is done, init starts.   It takes longer than a split
second.

 
  | >of boottime (not when it is set, but the value it is set to) would be
  | >easier.
  |
  | It would destroy the information that exists now, so while being easier,
  | it is not necessarily better.

Huh?   What would be destroyed,if boottime were set backwards
about 6 seconds?   (Or however long it takes a particular system)

I fail to see any problem at all.

  | It is 'defined' as what exists now, there is no need to change that.

No need, perhaps, if we're happy about it being meaningless.

The current "definition" is self-referential, and hence useless.

  | You would also lose the information about when root is mounted.

no, that's in the message buffer,  if anyone ever cares, not that
I can think of any reason at all why that is of any relevance to
anything (it just happens to be the last place from which we can dig
out an absolute time ... and one that if we need to rely upon, we're
not in very good shape.)

If we suddenly decided that that was such a crucial point that we
should record it, we could easily make a ":root_mount_time" and
make that available as well as boot time, and now time (and
monotonic time).   I don't see that happening though.

  | I have no idea what "we" mean when we say "the time the system was
  | booted", so it probably doesn't matter much.

Perhaps not, but even if it seems to be kind of unimportant
wouldn't it be better to define something (agree upon something)
and document it, rather than have this "no idea what it means"
time that we currently have?

I also don't know the answer - which is why I asked the question.
That I do not know the answer does not mean that there isn't an
answer hoever.

  | Ideally you would start with power-on or when the hardware comes
  | out of reset. 

Yes - or perhaps not that exactly (consider a system, probably not
x86 class, which is not configured to auto boot, just being powered on
is probably not "boot time" - it might sit there for hours or days, until
someone comes along and types "b" or "boot" or whatever at its
console).    But in general I agree that would be best, and ...

  | We don't have that information,

yes.   The hardware makers have neglected to record this
and make it available.

  | but starting time at the earliest possible moment
  | is the best we can do.

It is certainly the earliest we can do.   Whether that is best
or not is not so clear.

Once again, if we are rescording boot time, rather than power
on time, it all depends upon what we call "booted".

It would also depend upon whether we want "boottime" to be
"start of boot sequence time" or "boot sequence finished" time.

(Here, that we cannot get the former is some incentive to
prefer the latter, as that one we can determine.)

  | >Just adding extra messages in the log buffer is no use, as
  | >we cannot expect the last of those to still be there when
  | >we need to use it (that one would vanish early, then all
  | >the later messages are still missing their offset).
  |
  | We don't need the last. The last start of the epoch is what
  | the system itself was producing and you get that information
  | just like now. You only need the currently lost information
  | from earlier epochs.

Yes, of course, but you need to work out which entries relate
to which epoch.   There's nothing in the message buffer to
tell you that (though we could add something) - we can generally
pick it as humans, but  we also sometimes get it wrong.

  | >it periodically would also not be useful (just more noise)
  | >even if we put it only in the buffer and not on the console.
  |
  | It's not noise but signal.

Well, yes, once, but all the time (over and over again)?
To me, that is noise.  And all the time is what is needed
(unless we completely redesign the message buffer)
for it to be useful.

  | It could even be useful to print it
  | (one line per epoch), but it needs to be identifiable and thus
  | stored in a record that can be distinguished from regular output.
  | No idea if the current buffer can do that.

The buffer is just a sequence of characters. in a big circular
buffer, there's no more structure than that (there is a pointer
to where the next data will be added, which is also a pointer
to the oldest data left in the buffer, the next to be overwritten)
That's it.

We kind of make "records" by picking newlines, but that working
depends upon the messages all being nicely \n terminated
(every now and then someone forgets...) and messages not being
interrupted by others (from an interrupt or similar).

  | >Even if it were there, the early messages from a new
  | >boot would be before it, and appear to belong to the
  | >old boottime, rather than the next one (though one can detect
  | >that when they suddenly get smaller).   A big mess.
  |
  | If the code can recover messages from the previous epoch, it can
  | also append new messages, and I believe it does.

Yes, of course, but unless every line (and really, every byte)
contains an absolute timestamp along with it, there's no way to
know when the old data appeared.

Eg: consider a message buffer 1000 bytes big (absurdly
small, but it means I get to type smaller numbers).   After we
have added 999 bytes of messages, there's 1 old byte from
the previous epoch (or perhaps we've added 950 bytes,
and there's 50 from the previous epoch) - from where are
we going to get that old epoch's base time, unless it is right
there in that data (perhaps in those just 1 or 2 bytes) ?

But again, this is a whole differend problem, unrelated to where
we started, and shoulld be considered separately.

kre