From e4e9c9fbf717d89be923695603d0cd5fc6c40cfa Mon Sep 17 00:00:00 2001 From: Martin Mares Date: Fri, 13 Feb 2009 19:47:00 +0100 Subject: [PATCH] Logging: Introduced struct log_msg. The logging handlers and filters are often interested in various properties of the message in their raw form. I have modified the hooks to accept a single pointer to `struct log_msg', which contains all needed information. An immediate consequence is that we no longer need the calls to time() in log-file, so a message is always timestamped at a single place when entering the log machinery. --- ucw/log-file.c | 14 +++------- ucw/log-syslog.c | 8 +++--- ucw/log.c | 71 +++++++++++++++++++++++++----------------------- ucw/log.h | 21 ++++++++++---- 4 files changed, 60 insertions(+), 54 deletions(-) diff --git a/ucw/log-file.c b/ucw/log-file.c index 015b8df2..6b5b3145 100644 --- a/ucw/log-file.c +++ b/ucw/log-file.c @@ -152,18 +152,12 @@ file_close(struct log_stream *ls) /* handler for standard files */ static int -file_handler(struct log_stream *ls, const char *m, uns cat UNUSED) +file_handler(struct log_stream *ls, struct log_msg *m) { - if (ls->udata & FF_FORMAT_NAME) - { - // FIXME: pass the time - time_t now = time(NULL); - struct tm *tm = localtime(&now); - do_log_switch(ls, tm); - } + if ((ls->udata & FF_FORMAT_NAME) && m->tm) + do_log_switch(ls, m->tm); - int len = strlen(m); - int r = write(ls->idata, m, len); + int r = write(ls->idata, m->m, m->m_len); /* FIXME: check for errors here? */ return 0; } diff --git a/ucw/log-syslog.c b/ucw/log-syslog.c index 712a7d84..dc1df456 100644 --- a/ucw/log-syslog.c +++ b/ucw/log-syslog.c @@ -40,18 +40,18 @@ syslog_level(int level) /* simple syslog write handler */ static int -syslog_handler(struct log_stream *ls, const char *m, uns flags) +syslog_handler(struct log_stream *ls, struct log_msg *m) { int prio; ASSERT(ls); ASSERT(m); // FIXME: Logging of PID - prio = syslog_level(LS_GET_LEVEL(flags)) | (ls->idata); + prio = syslog_level(LS_GET_LEVEL(m->flags)) | (ls->idata); if (ls->name) - syslog(prio | (ls->idata), "%s: %s", ls->name, m); + syslog(prio | (ls->idata), "%s: %s", ls->name, m->m); else - syslog(prio | (ls->idata), "%s", m); + syslog(prio | (ls->idata), "%s", m->m); return 0; } diff --git a/ucw/log.c b/ucw/log.c index 49b92d4d..f3c6aa14 100644 --- a/ucw/log.c +++ b/ucw/log.c @@ -27,10 +27,10 @@ void (*log_die_hook)(void); /*** The default log stream, which logs to stderr ***/ -static int default_log_handler(struct log_stream *ls, const char *m, uns cat UNUSED) +static int default_log_handler(struct log_stream *ls, struct log_msg *m) { // This is a completely bare version of the log-file module. Errors are ignored. - write(ls->idata, m, strlen(m)); + write(ls->idata, m->m, m->m_len); return 0; } @@ -74,15 +74,15 @@ void vmsg(uns cat, const char *fmt, va_list args) { struct timeval tv; - int have_tm = 0; struct tm tm; va_list args2; char stime[24]; char sutime[12]; char msgbuf[256]; - char *m, *p; + char *p; int len; struct log_stream *ls = log_stream_by_flags(cat); + struct log_msg m = { .flags = cat }; /* Check the stream existence */ if (!ls) @@ -97,19 +97,21 @@ vmsg(uns cat, const char *fmt, va_list args) /* CAVEAT: These calls are not safe in signal handlers. */ gettimeofday(&tv, NULL); if (localtime_r(&tv.tv_sec, &tm)) - have_tm = 1; + m.tm = &tm; } /* Generate time strings */ - if (have_tm) + if (m.tm) { strftime(stime, sizeof(stime), "%Y-%m-%d %H:%M:%S", &tm); snprintf(sutime, sizeof(sutime), ".%06d", (int)tv.tv_usec); + m.stime = stime; + m.sutime = sutime; } else { - snprintf(stime, sizeof(stime), "\?\?\?\?-\?\?-\?\? \?\?:\?\?:\?\?"); - snprintf(sutime, sizeof(sutime), ".\?\?\?\?\?\?"); + m.stime = "\?\?\?\?-\?\?-\?\? \?\?:\?\?:\?\?"; + m.sutime = ".\?\?\?\?\?\?"; } /* Generate the message string */ @@ -117,15 +119,15 @@ vmsg(uns cat, const char *fmt, va_list args) len = vsnprintf(msgbuf, sizeof(msgbuf), fmt, args2); va_end(args2); if (len < (int) sizeof(msgbuf)) - m = msgbuf; + m.raw_msg = msgbuf; else { - m = xmalloc(len+1); - vsnprintf(m, len+1, fmt, args); + m.raw_msg = xmalloc(len+1); + vsnprintf(m.raw_msg, len+1, fmt, args); } /* Remove non-printable characters and newlines */ - p = m; + p = m.raw_msg; while (*p) { if (*p < 0x20 && *p != '\t') @@ -134,41 +136,42 @@ vmsg(uns cat, const char *fmt, va_list args) } /* Pass the message to the log_stream */ - if (log_pass_msg(0, ls, stime, sutime, m, cat)) + if (log_pass_msg(0, ls, &m)) { /* Error (such as infinite loop) occurred */ - log_pass_msg(0, (struct log_stream *) &log_stream_default, stime, sutime, m, cat); + log_pass_msg(0, (struct log_stream *) &log_stream_default, &m); } - if (m != msgbuf) - xfree(m); + if (m.raw_msg != msgbuf) + xfree(m.raw_msg); } /* Maximal depth of log_pass_msg recursion */ #define LS_MAX_DEPTH 64 int -log_pass_msg(int depth, struct log_stream *ls, const char *stime, const char *sutime, const char *m, uns cat) +log_pass_msg(int depth, struct log_stream *ls, struct log_msg *m) { ASSERT(ls); /* Check recursion depth */ if (depth > LS_MAX_DEPTH) { - log_pass_msg(0, (struct log_stream *) &log_stream_default, stime, sutime, - "Loop in the log_stream system detected.", L_ERROR | (cat & LS_INTERNAL_MASK)); - return 1; + struct log_msg errm = *m; + errm.flags = L_ERROR | (m->flags & LS_INTERNAL_MASK); + errm.raw_msg = "Loop in the log_stream system detected."; + log_pass_msg(0, (struct log_stream *) &log_stream_default, &errm); } /* Filter by level and hook function */ - if (!((1 << LS_GET_LEVEL(cat)) & ls->levels)) + if (!((1 << LS_GET_LEVEL(m->flags)) & ls->levels)) return 0; - if (ls->filter && ls->filter(ls, m, cat)) + if (ls->filter && ls->filter(ls, m)) return 0; /* Pass the message to substreams */ CLIST_FOR_EACH(simp_node *, s, ls->substreams) - if (log_pass_msg(depth+1, s->p, stime, sutime, m, cat)) + if (log_pass_msg(depth+1, s->p, m)) return 1; /* Will pass to the handler of this stream... is there any? */ @@ -176,7 +179,7 @@ log_pass_msg(int depth, struct log_stream *ls, const char *stime, const char *su return 0; /* Upper bound on message length */ - int len = strlen(m) + strlen(stime) + strlen(sutime) + 32; + int len = strlen(m->raw_msg) + strlen(m->stime) + strlen(m->sutime) + 32; if (log_title) len += strlen(log_title); if (ls->name) @@ -184,29 +187,28 @@ log_pass_msg(int depth, struct log_stream *ls, const char *stime, const char *su /* Get a buffer and format the message */ char *free_buf = NULL; - char *buf; if (len <= 256) - buf = alloca(len); + m->m = alloca(len); else - buf = free_buf = xmalloc(len); - char *p = buf; + m->m = free_buf = xmalloc(len); + char *p = m->m; /* Level (2 chars) */ if (ls->msgfmt & LSFMT_LEVEL) { - *p++ = LS_LEVEL_LETTER(LS_GET_LEVEL(cat)); + *p++ = LS_LEVEL_LETTER(LS_GET_LEVEL(m->flags)); *p++ = ' '; } /* Time (|stime| + |sutime| + 1 chars) */ if (ls->msgfmt & LSFMT_TIME) { - const char *q = (char *)stime; + const char *q = m->stime; while (*q) *p++ = *q++; if (ls->msgfmt & LSFMT_USEC) { - q = sutime; + q = m->sutime; while (*q) *p++ = *q++; } @@ -238,12 +240,13 @@ log_pass_msg(int depth, struct log_stream *ls, const char *stime, const char *su /* The message itself ( |m| + 1 chars ) */ { - const char *q = m; + const char *q = m->raw_msg; while (*q) *p++ = *q++; *p++ = '\n'; - *p++ = '\0'; - ls->handler(ls, buf, cat); + *p = '\0'; + m->m_len = p - m->m; + ls->handler(ls, m); } if (free_buf) diff --git a/ucw/log.h b/ucw/log.h index e4642a53..306c5c94 100644 --- a/ucw/log.h +++ b/ucw/log.h @@ -16,6 +16,17 @@ /* user de/allocated program/process name for use in the logsystem */ extern char *ls_title; +struct log_msg +{ + char *m; // The formatted message itself, ending with \n\0 + int m_len; // Length without the \0 + struct tm *tm; + uns flags; + char *raw_msg; // Unformatted parts + char *stime; + char *sutime; +}; + struct log_stream { /* optional name, 0-term, de/allocated by constr./destr. or user */ @@ -29,14 +40,13 @@ struct log_stream /* severity levels to accept - bitmask of (1<