From nobody Sat Mar 12 17:44:07 2022 X-Original-To: current@mlmmj.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mlmmj.nyi.freebsd.org (Postfix) with ESMTP id 40DE01A1C2AF for ; Sat, 12 Mar 2022 17:44:20 +0000 (UTC) (envelope-from Alexander@leidinger.net) Received: from mailgate.Leidinger.net (bastille.leidinger.net [89.238.82.207]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256 client-signature ECDSA (P-256) client-digest SHA256) (Client CN "mailgate.leidinger.net", Issuer "R3" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 4KG9Cl01zXz4kgW for ; Sat, 12 Mar 2022 17:44:19 +0000 (UTC) (envelope-from Alexander@leidinger.net) Received: from outgoing.leidinger.net (p5b165562.dip0.t-ipconnect.de [91.22.85.98]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature ECDSA (P-256) client-signature ECDSA (P-256)) (Client CN "outgoing.leidinger.net", Issuer "R3" (verified OK)) by mailgate.Leidinger.net (Postfix) with ESMTPSA id 189E21A01; Sat, 12 Mar 2022 18:44:10 +0100 (CET) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=leidinger.net; s=outgoing-alex; t=1647107050; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version:content-type:content-type: in-reply-to:in-reply-to:references:references; bh=fRUW9WUBfHVDohcfMg4N6VylI+FJ9mGtha+AzWvbC+I=; b=WM7g9lZvZDA2RF95W8Wuev6T6U7DOLbfstbOaie0Ib8eVmk6mpI2yC2lXRz2Q0CEP/mIq5 0kPjCkluXmx6EiTIIddK7t4mIME7lhD9yGEJHuomcGQiB3xGzEynSUjxFVDttN76fs8s1y /jYKbR6SmMYGVryN8qa535TooKQJAmSYr21cOcYS/6Hj9PkWem+/KrVLLKeTbACemi4Y9K hmUSRMtPMrMG7mVgqsJ9D1CxkWIYr84NGMT29wfp7LPOL5anUEEc8HktRQCCaQYW86zcxT IiGrlXAjjvfJxIGjTPyIMz+gu7HL9XhAU9Gmh29v4lZn3TFDW9pjLnJ2i/kNtA== Received: from webmail.leidinger.net (localhost [127.0.0.1]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature ECDSA (P-256) server-digest SHA256) (Client did not present a certificate) by outgoing.leidinger.net (Postfix) with ESMTPS id D6D10A387; Sat, 12 Mar 2022 18:44:07 +0100 (CET) Date: Sat, 12 Mar 2022 18:44:07 +0100 Message-ID: <20220312184407.Horde.T5lVaVvzo9-ulIE4UZaKY1H@webmail.leidinger.net> From: Alexander Leidinger To: Warner Losh Cc: FreeBSD Current Subject: Re: What are the in-kernel functions to print human readable timestamps (bintime)? References: <20220311105149.Horde.uO0yyQjwC3xmwZvuZWV1ADl@webmail.leidinger.net> In-Reply-To: Accept-Language: de,en Content-Type: multipart/signed; boundary="=_cY8l_FQJmHsikIO5P-QFghT"; protocol="application/pgp-signature"; micalg=pgp-sha256 List-Id: Discussions about the use of FreeBSD-current List-Archive: https://lists.freebsd.org/archives/freebsd-current List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-freebsd-current@freebsd.org MIME-Version: 1.0 X-Rspamd-Queue-Id: 4KG9Cl01zXz4kgW X-Spamd-Bar: ----- Authentication-Results: mx1.freebsd.org; dkim=pass header.d=leidinger.net header.s=outgoing-alex header.b=WM7g9lZv; dmarc=pass (policy=quarantine) header.from=leidinger.net; spf=pass (mx1.freebsd.org: domain of Alexander@leidinger.net designates 89.238.82.207 as permitted sender) smtp.mailfrom=Alexander@leidinger.net X-Spamd-Result: default: False [-5.07 / 15.00]; ARC_NA(0.00)[]; RCVD_VIA_SMTP_AUTH(0.00)[]; R_DKIM_ALLOW(-0.20)[leidinger.net:s=outgoing-alex]; NEURAL_HAM_MEDIUM(-0.97)[-0.969]; FROM_HAS_DN(0.00)[]; R_SPF_ALLOW(-0.20)[+mx:c]; NEURAL_HAM_LONG(-1.00)[-1.000]; MIME_GOOD(-0.20)[multipart/signed,text/plain]; RCVD_COUNT_THREE(0.00)[3]; TO_MATCH_ENVRCPT_SOME(0.00)[]; TO_DN_ALL(0.00)[]; DKIM_TRACE(0.00)[leidinger.net:+]; RCPT_COUNT_TWO(0.00)[2]; DMARC_POLICY_ALLOW(-0.50)[leidinger.net,quarantine]; NEURAL_HAM_SHORT(-1.00)[-1.000]; MID_RHS_MATCH_FROMTLD(0.00)[]; MLMMJ_DEST(0.00)[current]; SIGNED_PGP(-2.00)[]; FROM_EQ_ENVFROM(0.00)[]; MIME_TRACE(0.00)[0:+,1:+,2:~]; SUBJECT_ENDS_QUESTION(1.00)[]; ASN(0.00)[asn:34240, ipnet:89.238.64.0/18, country:DE]; RCVD_TLS_ALL(0.00)[]; RECEIVED_SPAMHAUS_PBL(0.00)[91.22.85.98:received] X-ThisMailContainsUnwantedMimeParts: N This message is in MIME format and has been PGP signed. --=_cY8l_FQJmHsikIO5P-QFghT Content-Type: text/plain; charset=utf-8; format=flowed; DelSp=Yes Content-Disposition: inline Content-Transfer-Encoding: quoted-printable Quoting Warner Losh (from Fri, 11 Mar 2022 08:57:33 -0700)= : > On Fri, Mar 11, 2022 at 2:52 AM Alexander Leidinger > wrote: > >> Hi, >> >> I'm looking for a function to convert bintime to a human readable >> format in the kernel... and what is the usual format we use? >> > > Yes. We don't generally log it. Would it be acceptable in this particular case (or should I keep this=20=20 change=20for me)? I have to check out the kern.msgbuf_show_timestamp part in this=20=20 thread,=20which looks interesting. It may fit my needs here. >> The use case for this is: if something throws a log from the kernel >> about a signal, I want to know when it happened, or in terms of code >> see below (tabs are most probably messed up). >> >> Do we have some kind of policy in terms of kernel messages and >> timestamps? Like "do not commit logging with timestamps"? > > > Correct. The kernel doesn't know enough to properly render timestamps, > nor should it. It's a lot more complicated than you'd expect, and the > simple, > naive implementation has too many flaws... I'm aware that it is complicated. IMO too complicated for a full=20=20 implementation=20which will satisfy all needs. >> I have the >> code below because I needed it at least once and think something like >> this (in a human readably shape) would be beneficial to have in the >> tree. >> > > I really don't want to see code like that in the tree. Having it per-mess= age > in an ad-hoc manner strikes me as quite unwise, since how do you interpre= t > it after the fact, especially in the face of adjustments to boottime for = any > time adjustments that happen after the event. Sorry, I was not verbose enough in my mail it seems. I do _not_ want=20=20 to=20commit this code like it is. I was looking for stuff which could=20=20 print=20something human readable, like "2022-12-03 14:23:22.45=20=20 'kernel-time'"=20(just as an example). I don't want to push the TZ into=20= =20 the=20kernel, or the knowledge if the cmos clock is set to localtime or=20= =20 UTC.=20I want to provide an admin with a way to determine when such a=20=20 message=20may have printed. Currently there is no way to know at which=20= =20 time=20it was printed. The admin needs to know if the clock is set in=20=20 UTC=20or localtime, and how to calculate the wall-clock time from this,=20= =20 which=20is less heavy on the implementation and provides a mean to=20=20 correlate=20the mesage with some action on the machine. > Now, having said that, having good timestamps in the dmesg buffer is > a desirable feature. 'Good' is subjective here, and there are times early > in boot where it's simply not possible to get a time better than '0' unti= l > the timehands are ticking... But the dmesg buffer has more than what > dmesg prints: it has syslog'd things (at least some of them) as well. > There's > also a priority that some lines have. <3>Foo, for example. It would be > better, > imho, to add a timestamp to the start of the lines (perhaps optionally > since that might be expensive in $HUGE systems, or at times of > extreme dmesg spew and the could be omitted in those cases). > If you are interested in just the log messages, it wouldn't be terrible > since we already add stuff to what's printed for the priority. We could s= ay > <3,seconds-since-boot.fracsec> instead of just <3> and hack dmesg > to print the right thing. From the other message in the thread it looks like=20=20 kern.msgbuf_show_timestamp=20is what you describe here? And it looks like kern.msgbuf_show_timestamp is not the same as=20=20 printing=20a timestamp to the console... (it looks like the timestamp is=20= =20 printed=20in the dmesg, but not to the console, which is what I have in=20= =20 mind=20for this particular message... respectively could be added log()=20= =20 with=20a sysctl to activate it or not). Bye, Alexander. > Warner > > >> Code: >> ---snip--- >> diff --git a/sys/kern/kern_sig.c b/sys/kern/kern_sig.c >> index 4a15bd45355..a83eebe0736 100644 >> --- a/sys/kern/kern_sig.c >> +++ b/sys/kern/kern_sig.c >> @@ -80,6 +80,7 @@ __FBSDID("$FreeBSD$"); >> #include >> #include >> #include >> +#include >> #include >> #include >> #include >> @@ -3440,14 +3441,18 @@ sigexit(struct thread *td, int sig) >> */ >> if (coredump(td) =3D=3D 0) >> sig |=3D WCOREFLAG; >> - if (kern_logsigexit) >> + if (kern_logsigexit) { >> + struct bintime now; >> + >> + getbintime(&now); >> log(LOG_INFO, >> - "pid %d (%s), jid %d, uid %d: exited on " >> - "signal %d%s\n", p->p_pid, p->p_comm, >> + "%zd: pid %d (%s), jid %d, uid %d: exited on= " >> + "signal %d%s\n", now.sec, p->p_pid, p->p_com= m, >> p->p_ucred->cr_prison->pr_id, >> td->td_ucred->cr_uid, >> sig &~ WCOREFLAG, >> sig & WCOREFLAG ? " (core dumped)" : ""); >> + } >> } else >> PROC_UNLOCK(p); >> exit1(td, 0, sig); >> ---snip--- >> >> Bye, >> Alexander. >> >> -- >> http://www.Leidinger.net Alexander@Leidinger.net: PGP 0x8F31830F9F2772BF >> http://www.FreeBSD.org netchild@FreeBSD.org : PGP 0x8F31830F9F2772BF >> --=20 http://www.Leidinger.net=20Alexander@Leidinger.net: PGP 0x8F31830F9F2772BF http://www.FreeBSD.org netchild@FreeBSD.org : PGP 0x8F31830F9F2772BF --=_cY8l_FQJmHsikIO5P-QFghT Content-Type: application/pgp-signature Content-Description: Digitale PGP-Signatur Content-Disposition: inline -----BEGIN PGP SIGNATURE----- Version: GnuPG v2 iQIzBAABCAAdFiEER9UlYXp1PSd08nWXEg2wmwP42IYFAmIs2+YACgkQEg2wmwP4 2IYCyw//a5EQ6l4QVfwxXUXGOrRKRkBmL+QkfLvaGFLExi8V1i17/QGsRpOCf4Pl WKv5e1vVI9okZiiGeBwuL51lh4wzc9vRwOq2z2UvxRPaP9u+HfgOSOJYNJMW/+mf y/73d/NvCGLsELUDyYr08wKYTChURqrliPWeHvzn7UsgW8TPzht8hnOqOdr8vM1G JW7Kdk2FvgrXIvG8eE4FUwOtPBXhRNlViyr4cDBUhsTPiAlpIwH7OhxpnkNDEMkN bJZkBzfGAxxunfFNPaaUVkKuiGIcZ3FiKRn3Oa/arTsMO4vpjKLUzY8KWyqh5kCF GdIAbaZdXAov46A/7Zw67j272PA7vd9/Gw/6td8BZwVlTSC6KH/DLVCXLGm9k2LK ThDmxbjzrqBxZC9oV21df55Nj5E8A0X1gx6pYu43VVEWTWuw7a6GlDVcdGZ094Ky xA1kSlM19bPA1siK5n7laeI5zg2V67cYKnCUgVhtqP9cNAmWaicVPdP/ppumG2OI 2iKg+iK2LLwm+73AdYChCtGhQ8AcUMlZZTs83vu1Hhl66nWnoAq4LxyVH6euGfvb PnSlPaZPP3ECjc+Hh1iSkX6duGnTn0v7zh/akwMrdtbyjqPhTFcXJmLiPDcLy/Cy JvYS2opoYGibBTdavxkCf/zMEI9ObZdysvxdx2Vw9gqa9J4WBOs= =O5pL -----END PGP SIGNATURE----- --=_cY8l_FQJmHsikIO5P-QFghT--