[RFC] Prepend timestamp in msgbuf

[Garrett Cooper]

On Mon, Oct 17, 2011 at 12:27 PM, Arnaud Lacombe <lacombar at gmail.com> wrote:
> Hi,
>
> On Mon, Oct 17, 2011 at 2:01 PM, Alexander Best <arundel at freebsd.org> wrote:
>> On Fri Oct 14 11, Arnaud Lacombe wrote:
>>> Hi,
>>>
>>> On Fri, Oct 14, 2011 at 8:52 AM, Nali Toja <nalitoja at gmail.com> wrote:
>>> > Alexander Best <arundel at freebsd.org> writes:
>>> >
>>> >>> On Fri Oct 14 11, Poul-Henning Kamp wrote:
>>> >>> > In message <20111014085609.GA3799 at freebsd.org>, Alexander Best writes:
>>> >>> >
>>> >>> > >1) would it be possible to prepend those timestamps to the actual console
>>> >>> > >output and not only to the output of demsg? maybe via a sysctl toggle?
>>> >>> >
>>> >>> > The kernel does not know enough about timezones to emit anything
>>> >>> > but UTC timestamps.
>>> >>>
>>> >>> hmm ok.
>>> >>>
>>> >>> >
>>> >>> > >2) my dmesg output contains a lot of these entries: "<118>"
>>> >>> >
>>> >>> > These are magic markers for syslogd(8) specifying priority.
>>> >>>
>>> >>> it would be nice, if their output could be turned off via a dmesg flag imo.
>>> >>>
>>> >>> >
>>> >>> > >3) roughly the first 30 lines of my dmesg output have the timestamp "[1.0]".
>>> >>> > >would it be possible to have more accuracy there?
>>> >>> >
>>> >>> > No, because we don't know the time until we've found the RTC chip.
>>> >>>
>>> >>> maybe prepending the output with [??] instead of [1.0] would make more sense,
>>> >>> so users knows that those timestamps are bogus.
>>> >>
>>> >> maybe the granularity of the timestamps could be limited to a static value? the
>>> >> following output doesn't really look pretty:
>>> >>
>>> >> [7.729516] <118>/dev/ufs/varfs: clean, 879143 free (7407 frags, 108967 blocks, 0.7% fragmentation)
>>> >> [7.891512] <118>Mounting local file systems:WARNING: TMPFS is considered to be a highly experimental feature in FreeBSD.
>>> >> [8.33519] .
>>> >> [9.440514] <118>Setting hostname: otaku.
>>> >> [9.744516] wlan0: Ethernet address: 00:0f:b5:82:07:c8
>>> >> [9.850516] <118>Starting wpa_supplicant.
>>> >> [10.335514] <118>Starting Network: lo0 ath0.
>>> >>
>>> >> so it would be nice, if trailing zeros got printed out, too.
>>> >
>>> > Why not make formatting similar to linux/xorg logs, e.g.
>>> >
>>> >  [    31.897] (**) Option "XkbLayout" "us"
>>> >  [    31.897] (II) XINPUT: Adding extended input device "<default keyboard>" (type: KEYBOARD, id 7)
>>> >  [ 11485.404] (II) 3rd Button detected: disabling emulate3Button
>>> >
>>> >  [    0.000000] Linux version 3.0-ARCH (tobias at T-POWA-LX) (gcc version 4.6.1 20110819 (prerelease) (GCC) ) #1 SMP PREEMPT Tue Aug 30 08:53:25 CEST 2011
>>> >  [    0.000000] Command line: root=/dev/disk/by-uuid/625db1f5-9b51-4d2d-acb7-6726f4d7e199 ro
>>> >  [...]
>>> >  [   15.096862] NET: Registered protocol family 10
>>> >  [   16.792594] [drm] nouveau 0000:01:00.0: plugged DVI-I-2
>>> >  [   26.054186] eth0: no IPv6 routers present
>>> >
>>> > A way to convert those timestamps to localtime or time delta[1] post-mortem
>>> > via dmesg(8) would be good, too.
>>> >
>>> well, I do not care for the "pretty" side of the thing, however, this
>>> is just a matter length modifier in the string format; should be
>>> trivial to fix.
>>
>> cc -c -O -pipe -march=core2 -std=c99 -g -Wall -Wredundant-decls -Wnested-externs -Wstrict-prototypes -Wmissing-prototypes -Wpointer-arith -Winline -Wcast-qual -Wundef -Wno-pointer-sign -Wmissing-include-dirs -nostdinc  -I. -I/usr/git-freebsd-head/sys -I/usr/git-freebsd-head/sys/contrib/altq -D_KERNEL -DHAVE_KERNEL_OPTION_HEADERS -include opt_global.h -fno-common -finline-limit=8000 --param inline-unit-growth=100 --param large-function-growth=1000  -fno-omit-frame-pointer -mno-sse -mcmodel=kernel -mno-red-zone -mno-mmx -msoft-float -fno-asynchronous-unwind-tables -ffreestanding -fformat-extensions -fdiagnostics-show-option -fstack-protector -Werror  /usr/git-freebsd-head/sys/kern/subr_msgbuf.c
>> cc1: warnings being treated as errors
>> /usr/git-freebsd-head/sys/kern/subr_msgbuf.c: In function 'msgbuf_do_addchar':
>> /usr/git-freebsd-head/sys/kern/subr_msgbuf.c:171: warning: format '%d' expects type 'int', but argument 4 has type 'time_t' [-Wformat]
>> *** Error code 1
>>
>> Stop in /usr/obj/usr/git-freebsd-head/sys/ARUNDEL.
>> *** Error code 1
>>
>> Stop in /usr/git-freebsd-head.
>> *** Error code 1
>>
>> Stop in /usr/git-freebsd-head.
>>
> FreeBSD has no time_t PRI... macros in any <machine/_inttypes.h>,
> eventually cast it to `long'.
>
> Btw, I appreciate the very clear message of yours, no "Hi", no
> signature, no idea what "ARUNDEL" is, and especially no details on
> which architecture you are attempting to build, which should be, I
> assume, LP64 ;-)

    time_t maps to int32_t on i386 and int64_t on amd64 (at least), so
you should be able to use "%zd" in the format string as the type is
variable width depending on the architecture.
Thanks,
-Garrett