From: Martin Mares Date: Fri, 13 Feb 2009 16:52:31 +0000 (+0100) Subject: Logging: Cleanup of log.c X-Git-Tag: holmes-import~102 X-Git-Url: http://mj.ucw.cz/gitweb/?a=commitdiff_plain;h=66a5e689124dc64357729702948f4bfb8a03e8da;p=libucw.git Logging: Cleanup of log.c o log_progname[] moved to log_init() o Both vmsg() and log_pass_msg() now allocate the buffer on the stack if the message is smaller than 256 bytes. o log_pid is used instead of repeated calls to getpid() o sizeof(array) always preferred over repeated constants o Many coding style cleanups to make the old and new code fit together. o Namespace cleanups o Updated comments --- diff --git a/ucw/log.c b/ucw/log.c index 44be6302..8c53d0f5 100644 --- a/ucw/log.c +++ b/ucw/log.c @@ -21,61 +21,54 @@ #include #include -static char log_progname[32]; char *log_title; int log_pid; void (*log_die_hook)(void); -// FIXME: duplicate? -static int ls_default_handler(struct log_stream* ls, const char *m, u32 cat UNUSED) +/*** The default log stream, which logs to stderr ***/ + +static int default_log_handler(struct log_stream *ls, const char *m, uns cat UNUSED) { - int len = strlen(m); - int r = write(ls->idata, m, len); - /* TODO: check the errors here? */ - if (r!=len) - return errno; + // This is a completely bare version of the log-file module. Errors are ignored. + write(ls->idata, m, strlen(m)); return 0; } -/* the default logger */ -const struct log_stream ls_default_log={ - .name = "fd2", .idata = 2, .pdata = NULL, .regnum = 0, - .handler = ls_default_handler, +const struct log_stream log_stream_default = { + .name = "stderr", + .idata = 2, + .handler = default_log_handler, .levels = LS_ALL_LEVELS, .msgfmt = LSFMT_DEFAULT, - // empty clist - .substreams.head.next = (cnode *) &ls_default_log.substreams.head, - .substreams.head.prev = (cnode *) &ls_default_log.substreams.head, + // an empty clist + .substreams.head.next = (cnode *) &log_stream_default.substreams.head, + .substreams.head.prev = (cnode *) &log_stream_default.substreams.head, }; /*** Registry of streams and their identifiers ***/ -/* The growing array of pointers to log_streams. */ -struct lsbuf_t log_streams; +struct lsbuf_t log_streams; /* A growing array of pointers to log_streams */ +int log_streams_after = 0; /* The first never-used index in log_streams.ptr */ -/* the first never-used index in ls_streams.ptr */ -int log_streams_after = 0; +/* + * Find a stream by its identifier given as LS_SET_STRNUM(flags). + * Returns NULL if the stream doesn't exist or it's invalid. + * When stream #0 is requested, fall back to log_stream_default. + */ -/* get a stream by its LS_SET_STRNUM() */ -/* returns NULL for free/invalid numbers */ -/* defaults to ls_default_stream when stream number 0 closed */ -struct log_stream *log_stream_by_flags(uns flags) +struct log_stream * +log_stream_by_flags(uns flags) { - /* get the real number */ int n = LS_GET_STRNUM(flags); - if ((n<0) || (n>=log_streams_after) || (log_streams.ptr[n]->regnum==-1) ) - { - if (n==0) - return (struct log_stream *)&ls_default_log; - else - return NULL; - } + if (n < 0 || n >= log_streams_after || log_streams.ptr[n]->regnum == -1) + return (n ? NULL : (struct log_stream *) &log_stream_default); return log_streams.ptr[n]; } /*** Logging ***/ -void vmsg(unsigned int cat, const char *fmt, va_list args) +void +vmsg(uns cat, const char *fmt, va_list args) { struct timeval tv; int have_tm = 0; @@ -83,20 +76,20 @@ void vmsg(unsigned int cat, const char *fmt, va_list args) va_list args2; char stime[24]; char sutime[12]; - char *buf,*p; + char msgbuf[256]; + char *m, *p; int len; - struct log_stream *ls=log_stream_by_flags(cat); + struct log_stream *ls = log_stream_by_flags(cat); /* Check the stream existence */ - if(!ls) + if (!ls) { - msg((LS_INTERNAL_MASK&cat)|L_WARN, "No log_stream with number %d! Logging to the default log.", - LS_GET_STRNUM(cat)); - ls=(struct log_stream *)&ls_default_log; + msg((LS_INTERNAL_MASK&cat)|L_WARN, "No log_stream with number %d! Logging to the default log.", LS_GET_STRNUM(cat)); + ls = (struct log_stream *) &log_stream_default; } - /* get the time */ - if (!(cat&LSFLAG_SIGHANDLER)) + /* Get the current time */ + if (!(cat & LSFLAG_SIGHANDLER)) { /* CAVEAT: These calls are not safe in signal handlers. */ gettimeofday(&tv, NULL); @@ -104,28 +97,32 @@ void vmsg(unsigned int cat, const char *fmt, va_list args) have_tm = 1; } - /* generate time strings */ + /* Generate time strings */ if (have_tm) { - strftime(stime, 24, "%Y-%m-%d %H:%M:%S", &tm); - snprintf(sutime, 12, ".%06d", (int)tv.tv_usec); + strftime(stime, sizeof(stime), "%Y-%m-%d %H:%M:%S", &tm); + snprintf(sutime, sizeof(sutime), ".%06d", (int)tv.tv_usec); } else { - snprintf(stime, 24, "\?\?\?\?-\?\?-\?\? \?\?:\?\?:\?\?"); - snprintf(sutime, 12, ".\?\?\?\?\?\?"); + snprintf(stime, sizeof(stime), "\?\?\?\?-\?\?-\?\? \?\?:\?\?:\?\?"); + snprintf(sutime, sizeof(sutime), ".\?\?\?\?\?\?"); } - /* generate the message string */ + /* Generate the message string */ va_copy(args2, args); - /* WARN: this may be C99 specefic */ - len = vsnprintf(NULL, 0, fmt, args2); + len = vsnprintf(msgbuf, sizeof(msgbuf), fmt, args2); va_end(args2); - buf = xmalloc(len+2); - vsnprintf(buf, len+1, fmt, args); + if (len < (int) sizeof(msgbuf)) + m = msgbuf; + else + { + m = xmalloc(len+1); + vsnprintf(m, len+1, fmt, args); + } - /* remove non-printable characters and newlines */ - p=buf; + /* Remove non-printable characters and newlines */ + p = m; while (*p) { if (*p < 0x20 && *p != '\t') @@ -133,115 +130,123 @@ void vmsg(unsigned int cat, const char *fmt, va_list args) p++; } - /* pass the message to the log_stream */ - if(ls_passmsg(0, ls, stime, sutime, buf, cat)) + /* Pass the message to the log_stream */ + if (log_pass_msg(0, ls, stime, sutime, m, cat)) { - /* error (such as looping) occured */ - ls_passmsg(0, (struct log_stream *)&ls_default_log, stime, sutime, buf, cat); + /* Error (such as infinite loop) occurred */ + log_pass_msg(0, (struct log_stream *) &log_stream_default, stime, sutime, m, cat); } - xfree(buf); + if (m != msgbuf) + xfree(m); } -/* process a message (string) */ -/* depth prevents undetected looping */ -/* returns 1 in case of loop detection or other fatal error - * 0 otherwise */ -int ls_passmsg(int depth, struct log_stream *ls, const char *stime, const char *sutime, const char *m, u32 cat) +int +log_pass_msg(int depth, struct log_stream *ls, const char *stime, const char *sutime, const char *m, uns cat) { ASSERT(ls); /* Check recursion depth */ - if( depth > LS_MAX_DEPTH ) + if (depth > LS_MAX_DEPTH) { - ls_passmsg(0, (struct log_stream *)&ls_default_log, stime, sutime, - "Loop in the log_stream system detected.", L_ERROR | (cat&LS_INTERNAL_MASK) ); + 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; } - /* Filter by level and filter hook */ - if(!( (1<levels )) return 0; - if( ls->filter ) - if( ls->filter(ls, m, cat) != 0 ) return 0; + /* Filter by level and hook function */ + if (!((1 << LS_GET_LEVEL(cat)) & ls->levels)) + return 0; + if (ls->filter && ls->filter(ls, m, cat)) + return 0; - /* pass message to substreams */ + /* 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)) + return 1; + + /* Will pass to the handler of this stream... is there any? */ + if (!ls->handler) + return 0; + + /* Upper bound on message length */ + int len = strlen(m) + strlen(stime) + strlen(sutime) + 32; + if (log_title) + len += strlen(log_title); + if (ls->name) + len += strlen(ls->name); + + /* Get a buffer and format the message */ + char *free_buf = NULL; + char *buf; + if (len <= 256) + buf = alloca(len); + else + buf = free_buf = xmalloc(len); + char *p = buf; + + /* Level (2 chars) */ + if (ls->msgfmt & LSFMT_LEVEL) { - if (ls_passmsg(depth+1, (struct log_stream*)(s->p), stime, sutime, m, cat)) - return 1; + *p++ = LS_LEVEL_LETTER(LS_GET_LEVEL(cat)); + *p++ = ' '; } - /* Prepare for handler */ - if(ls->handler) + /* Time (|stime| + |sutime| + 1 chars) */ + if (ls->msgfmt & LSFMT_TIME) { - int len = strlen(m) + strlen(stime) + strlen(sutime) + 32; - /* SHOULD be enough for all information, but beware */ - if (log_title) len += strlen(log_title); - if (ls->name) len += strlen(ls->name); - char *buf=xmalloc(len); - char *p=buf; - - /* Level (2 chars) */ - if(ls->msgfmt & LSFMT_LEVEL) - { - *p++=LS_LEVEL_LETTER(LS_GET_LEVEL(cat)); - *p++=' '; - } - - /* Time (|stime| + |sutime| + 1 chars) */ - if(ls->msgfmt & LSFMT_TIME) + const char *q = (char *)stime; + while (*q) + *p++ = *q++; + if (ls->msgfmt & LSFMT_USEC) { - char *q = (char *)stime; - - while(*q) - *p++=*q++; - if(ls->msgfmt & LSFMT_USEC) - { - q = (char *)sutime; - while(*q) - *p++=*q++; - } - *p++=' '; + q = sutime; + while (*q) + *p++ = *q++; } + *p++ = ' '; + } - /* process name, PID ( |log_title| + 6 + (|PID|<=10) chars ) */ - if((ls->msgfmt & LSFMT_TITLE) && log_title) - { - if(ls->msgfmt & LSFMT_PID) - p += sprintf(p, "[%s (%d)] ", log_title, getpid()); - else - p += sprintf(p, "[%s] ", log_title); - } + /* Process name, PID ( |log_title| + 6 + (|PID|<=10) chars ) */ + if ((ls->msgfmt & LSFMT_TITLE) && log_title) + { + if (ls->msgfmt & LSFMT_PID) + p += sprintf(p, "[%s (%d)] ", log_title, log_pid); else - { - if(ls->msgfmt & LSFMT_PID) - p += sprintf(p, "[%d] ", getpid()); - } - - /* log_stream name ( |ls->name| + 4 chars ) */ - if(ls->msgfmt & LSFMT_LOGNAME) - { - if(ls->name) - p += sprintf(p, "<%s> ", ls->name); - else - p += sprintf(p, " "); - } + p += sprintf(p, "[%s] ", log_title); + } + else + { + if (ls->msgfmt & LSFMT_PID) + p += sprintf(p, "[%d] ", log_pid); + } - /* finish the string and call the handler ( |m| + 1 chars ) */ - { - char *q = (char *)m; + /* log_stream name ( |ls->name| + 4 chars ) */ + if (ls->msgfmt & LSFMT_LOGNAME) + { + if (ls->name) + p += sprintf(p, "<%s> ", ls->name); + else + p += sprintf(p, " "); + } - while(*q) - *p++=*q++; - *p++ = '\n'; - *p++ = '\0'; - ls->handler(ls, buf, cat); - } - xfree(buf); + /* The message itself ( |m| + 1 chars ) */ + { + const char *q = m; + while (*q) + *p++ = *q++; + *p++ = '\n'; + *p++ = '\0'; + ls->handler(ls, buf, cat); } + + if (free_buf) + xfree(free_buf); return 0; } +/*** Utility functions ***/ + void msg(unsigned int cat, const char *fmt, ...) { @@ -298,6 +303,7 @@ log_init(const char *argv0) { if (argv0) { + static char log_progname[32]; strncpy(log_progname, log_basename(argv0), sizeof(log_progname)-1); log_progname[sizeof(log_progname)-1] = 0; log_title = log_progname; @@ -308,8 +314,7 @@ log_init(const char *argv0) int main(void) { - // ls_default_log.msgfmt |= LSFMT_USEC; - msg(L_INFO, "Brum!"); + msg(L_INFO, "Brum <%300s>", ":-)"); return 0; } diff --git a/ucw/log.h b/ucw/log.h index b336f2e7..bcd9ebc9 100644 --- a/ucw/log.h +++ b/ucw/log.h @@ -159,7 +159,7 @@ void ls_die(const char *fmt, ...); /* depth prevents undetected looping */ /* returns 1 in case of loop detection or other fatal error * 0 otherwise */ -int ls_passmsg(int depth, struct log_stream *ls, const char *stime, const char *sutime, +int log_pass_msg(int depth, struct log_stream *ls, const char *stime, const char *sutime, const char *msg, uns cat); /* Maximal depth of ls_passmsg recursion */