Re: kern/56797: timestamps messed up in quiet boot dmesg

[Valery Ushakov <uwe%stderr.spb.ru@localhost>]

The following reply was made to PR kern/56797; it has been noted by GNATS.

From: Valery Ushakov <uwe%stderr.spb.ru@localhost>
To: gnats-bugs%netbsd.org@localhost
Cc: 
Subject: Re: kern/56797: timestamps messed up in quiet boot dmesg
Date: Tue, 19 Apr 2022 16:24:32 +0300

 From RTFS i think the issue is that the timestamp logic is in the
 wrong place.  The timestamp needs to be added at different points in
 the output to the console (naive) and to the log (normal+) but we use
 only one boolean needtstamp variable to track this state.
 
 Consider e.g. acpivga0 at acpi0 attachment.
 
 autoconf prints:
 
     aprint_naive("Found ");
     aprint_naive("%s at %s", ...);
     aprint_normal("%s at %s", ...);
 
 and then acpi_display.c driver prints:
 
     aprint_naive(": ACPI Display Adapter\n");
     aprint_normal(": ACPI Display Adapter\n");
 
 
 The result is that on the console we print:
 
   [   1.0310259] Found acpivga0 at acpi0: ACPI Display Adapter
 
 and in the log we print:
 
   acpivga0 at acpi0 (GFX0)[   1.0310259] : ACPI Display Adapter
 
 
 The following probably happens behind the scenes.
 
 naive("Found") is printed on the console and triggers printing of
 timestamp on the console, but not to the log.  naive("%s at %s") is
 printed on the console.  At this point needtstamp is false b/c we are
 in the middle of the line on the console.
 
 normal("%s at %s") is NOT printed on the cosole b/c we are quiet, but
 is sent to the the log.  But the same needtstamp variable is used and
 it is false, so no timestamp is added to the log.
 
 
 Then the driver prints naive(": ACPI Display Adapter\n") which is
 printed on the console and sets needtstamp to true b/c of the newline.
 
 Now the driver prints normal(": ACPI Display Adapter\n") that goes
 only to the log.  But the needtstamp is set, so the timestamp is added
 in the middle of the log line.
 
 -uwe