[PATCH] Prepend timestamp in msgbuf
Hi folks, You'll find hereafter a new version of the patch to add timestamp to msgbuf. Broken out patches are available in the git repository at: git://github.com/lacombar/freebsd.git master/topic/msgbuf-timestamp Diff since RFC: - build should be fixed on LP64 - micro-second field is now fixed width Arnaud Lacombe (3): msgbuf(4): convert `msg_needsnl' to a bit flag msgbuf(4): add logic to prepend timestamp on new line msgbuf(4): add a sysctl to toggle timestamp prepend sys/kern/subr_msgbuf.c | 54 --- sys/sys/msgbuf.h |4 ++- 2 files changed, 49 insertions(+), 9 deletions(-) diff --git a/sys/kern/subr_msgbuf.c b/sys/kern/subr_msgbuf.c index cd9c551..6b462eb 100644 --- a/sys/kern/subr_msgbuf.c +++ b/sys/kern/subr_msgbuf.c @@ -34,6 +34,7 @@ #include sys/lock.h #include sys/mutex.h #include sys/msgbuf.h +#include sys/sysctl.h /* * Maximum number conversion buffer length: uintmax_t in base 2, plus @@ -47,6 +48,13 @@ static u_int msgbuf_cksum(struct msgbuf *mbp); /* + * + */ +static int msgbuf_show_timestamp = 1; +SYSCTL_INT(_kern, OID_AUTO, msgbuf_show_timestamp, CTLFLAG_RW, +msgbuf_show_timestamp, 0, Show timestamp in msgbuf); + +/* * Initialize a message buffer of the specified size at the specified * location. This also zeros the buffer area. */ @@ -60,7 +68,7 @@ msgbuf_init(struct msgbuf *mbp, void *ptr, int size) msgbuf_clear(mbp); mbp-msg_magic = MSG_MAGIC; mbp-msg_lastpri = -1; - mbp-msg_needsnl = 0; + mbp-msg_flags = 0; bzero(mbp-msg_lock, sizeof(mbp-msg_lock)); mtx_init(mbp-msg_lock, msgbuf, NULL, MTX_SPIN); } @@ -95,7 +103,7 @@ msgbuf_reinit(struct msgbuf *mbp, void *ptr, int size) mbp-msg_lastpri = -1; /* Assume that the old message buffer didn't end in a newline. */ - mbp-msg_needsnl = 1; + mbp-msg_flags |= MSGBUF_NEEDNL; bzero(mbp-msg_lock, sizeof(mbp-msg_lock)); mtx_init(mbp-msg_lock, msgbuf, NULL, MTX_SPIN); } @@ -134,7 +142,7 @@ msgbuf_getcount(struct msgbuf *mbp) * The caller should hold the message buffer spinlock. */ static inline void -msgbuf_do_addchar(struct msgbuf *mbp, u_int *seq, int c) +__msgbuf_do_addchar(struct msgbuf *mbp, u_int *seq, int c) { u_int pos; @@ -149,6 +157,35 @@ msgbuf_do_addchar(struct msgbuf *mbp, u_int *seq, int c) *seq = MSGBUF_SEQNORM(mbp, *seq + 1); } +static inline void +msgbuf_do_addchar(struct msgbuf *mbp, u_int *seq, int c) +{ + + if (msgbuf_show_timestamp mbp-msg_flags MSGBUF_NEXT_NEW_LINE) { + char buf[32], *bufp; + struct timespec ts; + int err; + + buf[0] = '\0'; + getnanouptime(ts); + err = snprintf(buf, sizeof buf, [%zd.%.6ld] , + ts.tv_sec, ts.tv_nsec / 1000); + + bufp = buf; + while (*bufp != '\0') { + __msgbuf_do_addchar(mbp, seq, *bufp); + bufp++; + } + + mbp-msg_flags = ~MSGBUF_NEXT_NEW_LINE; + } + + __msgbuf_do_addchar(mbp, seq, c); + + if (c == '\n') + mbp-msg_flags |= MSGBUF_NEXT_NEW_LINE; +} + /* * Append a character to a message buffer. */ @@ -207,10 +244,10 @@ msgbuf_addstr(struct msgbuf *mbp, int pri, char *str, int filter_cr) * did not end with a newline. If that is the case, we need to * insert a newline before this string. */ - if (mbp-msg_lastpri != pri mbp-msg_needsnl != 0) { + if (mbp-msg_lastpri != pri (mbp-msg_flags MSGBUF_NEEDNL) != 0) { msgbuf_do_addchar(mbp, seq, '\n'); - mbp-msg_needsnl = 0; + mbp-msg_flags = ~MSGBUF_NEEDNL; } for (i = 0; i len; i++) { @@ -219,7 +256,7 @@ msgbuf_addstr(struct msgbuf *mbp, int pri, char *str, int filter_cr) * (and therefore prefix_len != 0), then we need a priority * prefix for this line. */ - if (mbp-msg_needsnl == 0 prefix_len != 0) { + if ((mbp-msg_flags MSGBUF_NEEDNL) == 0 prefix_len != 0) { int j; for (j = 0; j prefix_len; j++) @@ -242,9 +279,9 @@ msgbuf_addstr(struct msgbuf *mbp, int pri, char *str, int filter_cr) * we need to insert a new prefix or insert a newline later. */ if (str[i] == '\n') - mbp-msg_needsnl = 0; + mbp-msg_flags = ~MSGBUF_NEEDNL; else - mbp-msg_needsnl = 1; + mbp-msg_flags |= MSGBUF_NEEDNL; msgbuf_do_addchar(mbp, seq, str[i]); } @@ -395,3 +432,4 @@ msgbuf_copy(struct msgbuf *src, struct msgbuf *dst) while ((c = msgbuf_getchar(src)) = 0) msgbuf_addchar(dst, c); } +
Re: [PATCH] Prepend timestamp in msgbuf
Hi Arnaud! * Arnaud Lacombe lacom...@gmail.com, 20111017 22:41: + buf[0] = '\0'; + getnanouptime(ts); + err = snprintf(buf, sizeof buf, [%zd.%.6ld] , + ts.tv_sec, ts.tv_nsec / 1000); What's the use of buf[0] = '\0'? snprintf() will overwrite it anyway, right? Also. please use %jd and cast ts.tv_sec to intmax_t. The size of time_t and size_t are independent. As far as I know, you should be able to use a 64-bit time_t on i386 by simply changing the typedef and recompiling everything. + bufp = buf; + while (*bufp != '\0') { + __msgbuf_do_addchar(mbp, seq, *bufp); + bufp++; + } It would be nicer to write this as follows: for (bufp = buf; *bufp != '\0'; bufp++) __msgbuf_do_addchar(mbp, seq, *bufp); - intmsg_needsnl; /* set when newline needed */ + uint32_t msg_flags; Why change this to uint32_t instead of leaving it the way it is (or changing it to unsigned int)? Even though they are likely to be equal in size, there is no reason why msg_flags must be 32 bits. :-) -- Ed Schouten e...@80386.nl WWW: http://80386.nl/ pgpFwZRV69K8d.pgp Description: PGP signature
Re: [PATCH] Prepend timestamp in msgbuf
Ah, missed something. + getnanouptime(ts); + err = snprintf(buf, sizeof buf, [%zd.%.6ld] , + ts.tv_sec, ts.tv_nsec / 1000); It seems we also have a getmicrouptime(), which returns a struct timeval. Also a more general question: is it actually safe to call getnanouptime() here? This code gets executed from an arbitrary context, right? -- Ed Schouten e...@80386.nl WWW: http://80386.nl/ pgpOeBagOuQDB.pgp Description: PGP signature
Re: [PATCH] Prepend timestamp in msgbuf
Hi, On Mon, Oct 17, 2011 at 6:19 PM, Ed Schouten e...@80386.nl wrote: Hi Arnaud! * Arnaud Lacombe lacom...@gmail.com, 20111017 22:41: + buf[0] = '\0'; + getnanouptime(ts); + err = snprintf(buf, sizeof buf, [%zd.%.6ld] , + ts.tv_sec, ts.tv_nsec / 1000); What's the use of buf[0] = '\0'? snprintf() will overwrite it anyway, right? leftover from previous debug I guess; fixed. Also. please use %jd and cast ts.tv_sec to intmax_t. The size of time_t and size_t are independent. fixed. As far as I know, you should be able to use a 64-bit time_t on i386 by simply changing the typedef and recompiling everything. As long as you do not care about breaking the ABI, yes. But yet, the kernel and the userland may not need to each have the same representation of what `time_t' is, as long as they agree on the interface. + bufp = buf; + while (*bufp != '\0') { + __msgbuf_do_addchar(mbp, seq, *bufp); + bufp++; + } It would be nicer to write this as follows: for (bufp = buf; *bufp != '\0'; bufp++) __msgbuf_do_addchar(mbp, seq, *bufp); fixed. - int msg_needsnl; /* set when newline needed */ + uint32_t msg_flags; Why change this to uint32_t instead of leaving it the way it is (or changing it to unsigned int)? Even though they are likely to be equal in size, there is no reason why msg_flags must be 32 bits. :-) made it `unsigned int'; I don't like playing with signed bit-field. - Arnaud -- Ed Schouten e...@80386.nl WWW: http://80386.nl/ ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: [PATCH] Prepend timestamp in msgbuf
Hi, On Mon, Oct 17, 2011 at 6:22 PM, Ed Schouten e...@80386.nl wrote: Ah, missed something. + getnanouptime(ts); + err = snprintf(buf, sizeof buf, [%zd.%.6ld] , + ts.tv_sec, ts.tv_nsec / 1000); It seems we also have a getmicrouptime(), which returns a struct timeval. fixed. Also a more general question: is it actually safe to call getnanouptime() here? This code gets executed from an arbitrary context, right? right, but getmicrouptime() is not doing much magic. Just reading a cached value, do an arithmetic conversion. I do not really see any unsafe part. - Arnaud -- Ed Schouten e...@80386.nl WWW: http://80386.nl/ ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org
Re: [PATCH] Prepend timestamp in msgbuf
On Mon, Oct 17, 2011 at 5:18 PM, Arnaud Lacombe lacom...@gmail.com wrote: Hi, On Mon, Oct 17, 2011 at 6:22 PM, Ed Schouten e...@80386.nl wrote: Ah, missed something. + getnanouptime(ts); + err = snprintf(buf, sizeof buf, [%zd.%.6ld] , + ts.tv_sec, ts.tv_nsec / 1000); It seems we also have a getmicrouptime(), which returns a struct timeval. fixed. Also a more general question: is it actually safe to call getnanouptime() here? This code gets executed from an arbitrary context, right? right, but getmicrouptime() is not doing much magic. Just reading a cached value, do an arithmetic conversion. I do not really see any unsafe part. Based on glancing around other areas of the kernel, I'd assume that using this KPI as-is is fine because I don't see any locking employed elsewhere... -Garrett ___ freebsd-current@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to freebsd-current-unsubscr...@freebsd.org