[PATCH] Prepend timestamp in msgbuf

2011-10-17 Thread Arnaud Lacombe
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

2011-10-17 Thread Ed Schouten
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

2011-10-17 Thread Ed Schouten
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

2011-10-17 Thread Arnaud Lacombe
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

2011-10-17 Thread Arnaud Lacombe
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

2011-10-17 Thread Garrett Cooper
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