Re: [RFC] Prepend timestamp in msgbuf

From: Arnaud Lacombe <lacombar_at_gmail.com>
Date: Thu, 13 Oct 2011 14:40:53 -0400
Hi,

On Thu, Oct 13, 2011 at 2:00 PM,  <lacombar_at_gmail.com> wrote:
> From: Arnaud Lacombe <lacombar_at_gmail.com>
>
> 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(-)
>
also tracked as:

http://www.freebsd.org/cgi/query-pr.cgi?pr=161553

 - Arnaud

> 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
> _at__at_ -34,6 +34,7 _at__at_
>  #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 <>
> _at__at_ -47,6 +48,13 _at__at_
>  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.
>  */
> _at__at_ -60,7 +68,7 _at__at_ 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);
>  }
> _at__at_ -95,7 +103,7 _at__at_ 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);
>  }
> _at__at_ -134,7 +142,7 _at__at_ 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;
>
> _at__at_ -149,6 +157,34 _at__at_ 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.
>  */
> _at__at_ -207,10 +243,10 _at__at_ 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++) {
> _at__at_ -219,7 +255,7 _at__at_ 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++)
> _at__at_ -242,9 +278,9 _at__at_ 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]);
>        }
> _at__at_ -395,3 +431,4 _at__at_ 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
> _at__at_ -46,7 +46,9 _at__at_ 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 */
>  };
>
>
Received on Thu Oct 13 2011 - 16:40:54 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:40:19 UTC