From owner-freebsd-current@FreeBSD.ORG Thu Oct 13 18:00:25 2011 Return-Path: Delivered-To: freebsd-current@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 35AA8106564A for ; Thu, 13 Oct 2011 18:00:25 +0000 (UTC) (envelope-from lacombar@gmail.com) Received: from mail-qw0-f54.google.com (mail-qw0-f54.google.com [209.85.216.54]) by mx1.freebsd.org (Postfix) with ESMTP id ED7448FC19 for ; Thu, 13 Oct 2011 18:00:24 +0000 (UTC) Received: by qadz30 with SMTP id z30so364090qad.13 for ; Thu, 13 Oct 2011 11:00:21 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=from:to:cc:subject:date:message-id:x-mailer; bh=t+ErHWB7XGNLMf0W9Ut4QjAGqbZ2CkWV55YlthfZQpc=; b=Ao1EadPV19X0TDBguEcJc4T1dZ3UoNfsKAxHVz++9JQZMqUWBpEcnkdYq6f4cvRVtW 1MzI+X7R8/3VxYAiq8d9hOt4WdYjR10gI+qr8mfeRoDAvIpWQtSvxbLe46Uf3e5bmrWO jbxVXs3MO3pOhRczGstTYE9SjdVJ7XdRN1iKs= Received: by 10.224.196.201 with SMTP id eh9mr4184679qab.39.1318528821698; Thu, 13 Oct 2011 11:00:21 -0700 (PDT) Received: from localhost.localdomain ([184.175.13.173]) by mx.google.com with ESMTPS id bh18sm8359757qab.8.2011.10.13.11.00.20 (version=SSLv3 cipher=OTHER); Thu, 13 Oct 2011 11:00:20 -0700 (PDT) From: lacombar@gmail.com To: FreeBSD Current Date: Thu, 13 Oct 2011 14:00:05 -0400 Message-Id: <4e972734.52b1e00a.15ed.ffffd873@mx.google.com> X-Mailer: git-send-email 1.7.6.153.g78432 Cc: Arnaud Lacombe Subject: [RFC] Prepend timestamp in msgbuf X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 13 Oct 2011 18:00:25 -0000 From: Arnaud Lacombe Hi folks, There is many case recently when I really wished timestamp were present in the post-mortem msgbuf. Such situation could be when userland application segfault potentially triggering a panic/crash, or have information about the time-wise location of a given message (kernel or userland). Attached patch is available in the git repository at: git://github.com/lacombar/freebsd.git master/topic/msgbuf-timestamp 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 | 53 ++++++++++++++++++++++++++++++++++++++++------- sys/sys/msgbuf.h | 4 ++- 2 files changed, 48 insertions(+), 9 deletions(-) diff --git a/sys/kern/subr_msgbuf.c b/sys/kern/subr_msgbuf.c index cd9c551..b2f0e1a 100644 --- a/sys/kern/subr_msgbuf.c +++ b/sys/kern/subr_msgbuf.c @@ -34,6 +34,7 @@ #include #include #include +#include /* * 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,34 @@ 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, "[%d.%ld] ", 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 +243,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 +255,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 +278,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 +431,4 @@ msgbuf_copy(struct msgbuf *src, struct msgbuf *dst) while ((c = msgbuf_getchar(src)) >= 0) msgbuf_addchar(dst, c); } + diff --git a/sys/sys/msgbuf.h b/sys/sys/msgbuf.h index 67f80a5..639ed72 100644 --- a/sys/sys/msgbuf.h +++ b/sys/sys/msgbuf.h @@ -46,7 +46,9 @@ struct msgbuf { u_int msg_cksum; /* checksum of contents */ u_int msg_seqmod; /* range for sequence numbers */ int msg_lastpri; /* saved priority value */ - int msg_needsnl; /* set when newline needed */ + uint32_t msg_flags; +#define MSGBUF_NEEDNL 0x01 /* set when newline needed */ +#define MSGBUF_NEXT_NEW_LINE 0x02 struct mtx msg_lock; /* mutex to protect the buffer */ };