Little log engine in C

Question

I programmed a little log engine in C I plan to use in my project and maybe some others in future. I am very novice C programmer and would like to have feedback of some experienced ones on this. It's spawned over few files but I've joined them so it's easier to compile. Thank you.

#include <stdarg.h>
#include <syslog.h>
#include <assert.h>
#include <time.h>
#include <stdlib.h>
#include <stdio.h>
#include <unistd.h>
#include <errno.h>

#include "config.h"

/* this is log.h */
#define TPL_IDENT PACKAGE_NAME

enum tp_log_level {
    TPL_DEBUG,
    TPL_INFO,
    TPL_ERR,
    TPL_EMERG,
};

enum tp_log_mode {
    TPLM_SYSLOG,
    TPLM_FILE,
};

void tp_log_init(int mode, int level, int fd);
void tp_log_write(int level, const char *fmt, ...);
void tp_log_close(void);
/* end of log.h */

/* function from pio.c I use */
ssize_t tp_write(int fd, const void *buf, size_t len) 
{
    ssize_t ret, wlen = 0;
    const char *ptr;

    ptr = buf;
    while (wlen != len) {
        ret = write(fd, ptr, len-wlen);

        if (ret == -1)
            if (errno == EINTR)
                continue;
            else
                return -1;

        wlen += ret;
        ptr += ret;

    }
    return wlen;
}

/* start of log.c */

static int log_fd = -1;
static int log_level;
static int log_mode;

static const char *level_txt[] = { 
    "DEBUG", "INFO", "ERROR", "EMERG" 
};

static const int level_syslog[] = { 
    LOG_DEBUG, LOG_INFO, LOG_ERR, LOG_EMERG 
};

void tp_log_init(int mode, int level, int fd)
{
    assert(mode == TPLM_SYSLOG || mode == TPLM_FILE);
    assert(mode == TPLM_FILE ? fd >= 0 : 1);
    assert(level >= TPL_DEBUG && level <= TPL_EMERG);

    switch (mode) {
        case TPLM_FILE:
            log_fd = fd;
            break;
        case TPLM_SYSLOG:
            openlog(TPL_IDENT, LOG_PID|LOG_CONS, LOG_DAEMON);
            break;
    }
    log_level = level;
    log_mode = mode;
}

#define MAX_TIME_LEN 512
#define MAX_PREFIX_LEN 10
#define MAX_MSG_LEN 1024
#define MAX_POSTFIX_LEN 2

static void tp_vlog_write(int level, const char *fmt, va_list alist)
{
    int ret, len;
    time_t t;
    struct tm *tm;
    char msg[MAX_TIME_LEN+MAX_PREFIX_LEN+MAX_MSG_LEN+MAX_POSTFIX_LEN];

    assert(log_fd);
    assert(fmt);
    assert(level >= TPL_DEBUG && level <= TPL_EMERG);

    if (level < log_level)
        return;

    switch (log_mode) {
        case TPLM_FILE:

            t = time(NULL);
            tm = localtime(&t);
            if (tm == NULL) 
                abort();

            len = strftime(msg, MAX_TIME_LEN, "%a, %d %b %Y %T %z", tm);
            len += snprintf(msg+len, MAX_PREFIX_LEN, " [%s] ", 
                    level_txt[level]);

            ret = vsnprintf(msg+len, MAX_MSG_LEN, fmt, alist);
            if (ret >= MAX_MSG_LEN) 
                len += MAX_MSG_LEN-1;
            else
                len += ret;

            snprintf(msg+len, MAX_POSTFIX_LEN, "\n");
            tp_write(log_fd, msg, len+1);
            break;

        case TPLM_SYSLOG:
#ifdef HAVE_VSYSLOG
        vsyslog(level_syslog[level], fmt, alist);
#else
        vsnprintf(msg, MAX_MSG_LEN, fmt, vl);
        syslog(level_syslog[level], "%s", msg);
#endif
            break;
    }
}

void tp_log_write(int level, const char *fmt, ...)
{
   va_list vl;

   va_start(vl, fmt);
   tp_vlog_write(level, fmt, vl);
   va_end(vl);
}

void tp_log_close(void)
{
    assert(log_fd);

    switch (log_mode) {
        case TPLM_SYSLOG: 
            closelog();
            break;
        case TPLM_FILE:
            close(log_fd);
            break;
    }
}

Answer 1

As promised, here are some comments on the actual code you posted.

General:

• don't define multiple variables on the same line.

• is there a good reason to redefine log levels in tp_log_level rather than use the levels Syslog defines?

• you have two arrays, level_txt and level_syslog that are dependent upon the values of tp_log_level but nothing ties these together. In such a small program, this is unlikely to be a problem, but this sort of loose dependency tends to break with time - someone appends (or even inserts!) a value to one part without adjusting the other. Do you really need to log the level text, "DEBUG" etc? Syslog doesn't. Why complicate the job? If you just use syslog constants, both these arrays could be discarded. If you really must use them, make a structure holding a level and a text and make an array of these; then at least you only have one dangling dependency...

• I personally don't have any dogmatic objection to multiple returns. Some coding standards object to them on the grounds that they make functions unclear. I would argue the contrary: they can, if used well, make functions clearer.

---

In tp_write

• why using raw write (as opposed to stdio)? The fact that you test for interrupted writes makes me think that you intend to log to a socket or a serial port etc... Is that so?

• you should get compiler warnings about comparisons and conversions between size_t and ssize_t. Since the function only has two return values, -1 and len, and the caller knows the value of len anyway, it seems unnecessary to return anything but an int: 0 for success, and -1 for failure. That way you can avoid using a ssize_t and the warnings it generates.

• you need braces in the if/else statements: the compiler has to assume that the else belongs to the inner if. Using braces even when not strictly necessary is generally considered good practice. But they can be ugly...

• might be better coded as:

  ssize_t tp_write(int fd, const void *buf, size_t len)
  {
      const char *p = buf;
      const char *end = p + len;
  
      while (p < end) {
          ssize_t ret = write(fd, p, (size_t) (end - p));
          if (ret > 0) {
              p += ret;
          }
          else if (errno != EINTR) {
              return -1;
          }
      }
      return 0;
  }
  

---

In tp_log_init

• mode would be more logically of type tp_log_mode

• I don't use asserts much. You are relying on the asserts to find problems that the subsequent code does not handle (eg. the switch has no default). But another approach is to allow the code to fail if the parameters are wrong by falling back on syslog. This works even when NDEBUG is defined (asserts disabled):

  void tp_log_init(enum tp_log_mode mode, enum tp_log_level level, int fd)
  {
      log_level = level;
      if (mode == TPLM_FILE) {
          if (fd >= 0) {
              log_fd = fd;
              log_mode = TPLM_FILE;
              return;
          }
          /* print an error or abort() if you like */
      }
      openlog(TPL_IDENT, LOG_PID|LOG_CONS, LOG_DAEMON);
      log_mode = TPLM_SYSLOG;
  }
  

---

In tp_vlog_write

• MAX_TIME_LEN and MAX_MSG_LEN seem generous for a log message. Remember that msg is on the stack and if you are in a restricted environment, 1500 bytes might be too much. ctime uses 26 bytes for the time/date, so I doubt your time format needs 512.

• level seems like it should be a enum tp_log_level

• the switch could be done with if/else

• I would extract the creation of a time string into a separate function. Also, why abort if localtime fails? This makes your code more fragile than it needs to be - just don't call strftime() if tm == NULl.

• your assert(log_fd) fails if log_fd == 0. This should apply to the TPLM_FILE mode only.

• as I said before, printing the level text seems unnecessary. If you need it, use strcpy instead of snprintf.

• printing "\n" could be done with strcpy(msg+len, "\n")

• Personally, I have no objection to the use of varargs in this code. @Lundin is right that it is not type-safe, but sometimes it has its uses. This seems a legitimate use to me.

---

In tp_log_close

• your assert fails if log_fd == 0.
• if/else would be clearer.

Answer 2

Overall, the program is fairly well-written and clear. One particular good thing is that you have grasped the concept of private encapsulation in C, by placing the static keyword in all the right places. You also use const correctness for your function parameters. All of that is excellent program design, so keep using it! Below are my comments regarding various issues in the code:

Bugs found:

• Always use header guards or you will get all kind of strange linker or compiler problems.

Coding style, major issues:

• You should add comments to each function declaration in the header file, explaining what the function does and what's the nature of the parameters.
• Never declare multiple variables on the same line, there is never a reason to do so and it can lead to subtle bugs such as int* x, y;, x is a pointer, y is not. Instead, declare every variable on a line of its own.

• Avoid multiple return statements inside functions, and also avoid continue. There are a few odd cases where they make sense, but most often they just indicate muddy program design or spaghetti code. Consider rewriting the whole function as:

  ssize_t tp_write(int fd, const void *buf, size_t len)
  {
      ssize_t ret;
      ssize_t wlen = 0;
      const char *ptr;
  
      ptr = buf;
      for(wlen=0; wlen < len; wlen+=ret)
      {
          ret = write(fd, ptr, len-wlen);
  
          if (ret == -1 && errno != EINTR)
          {
              wlen = -1;
          }
  
          ptr += ret;
      }
  
      return wlen;
  }
  

Coding style, minor issues:

• I would separate standard C header #includes from non-standard ones, with a blank line, just as you have already separated library headers and user headers.
• Treat enums as unique variable types, not as integers. With a typedef you can achieve something that is essentially an unique type.

• Use for loops whenever doing trivial iterations. tp_write you could have been made more redable if you had written:

  for(wlen=0; wlen<len; wlen+=ret)

• Consider using a special coding style to indicate constants. It is very common to declare constant variables using only upper case letters, ie LEVEL_TXT rather than level_txt.

• Keep all #defines at the top of the file, or at least high up. Programmers expect to find everything pre-processor related in the beginning of the file.

• Never use if, for etc statements without following {}. This is a certain way to create subtle bugs. (Not all programmers may agree on this, but at least the MISRA-C coding standard does so).

Program design:

• Avoid va_lists like the plague! Not only are they error prone with no type safety, not only are they hard to read, but there is never an actual reason to use them in C. It is a completely superfluous feature of the language. Back in the days when dinosaurs walked the earth, different programming languages competed over who had the most features (of questionable value). This is such a remain from those dinosaurs. I've programmed C for almost two decades without ever needing va_lists in any program, and then I've programmed everything from the most low-level real time systems to PC desktop fluff, and everything in between.

Answer 3

The only thing that really sticks out to me is where you use the return value of snprintf etc without checking that it's valid in tp_vlog_write(). If snprintf returns a negative value you risk that the logging library introduces weird bugs in the host application. You don't want that!

Otherwise there's not much to pick on in this code.

Answer 4

I think you are in danger of reinventing the wheel. Syslog does what you need, including allowing you to filter the messages that actually get logged (see setlogmask). According to my man-page, it even has a logopt parameter in the openlog call that allows you to specify LOG_PERROR, telling Syslog to duplicate messages to stderr (which you can of course redirect to a file). Is there a reason why you might need messages not to go to the system logs?

If that really wont do, then I'd look at writing a drop-in replacement for syslog and having your initialisation function setup a function pointer with the same prototype as syslog(3). For example:

void (*tp_syslog)(int priority, const char *message, ...);
void (*tp_closelog)(void);

static FILE *log_file;
static int log_maskpri;

static void log_close(void)
{
    if (log_file != NULL) {
        fclose(log_file);
        log_file = NULL;
    }
}

static size_t logdate(char *msg, size_t len)
{
    time_t t = time(NULL);
    struct tm *tm = localtime(&t);
    return tm ? strftime(msg, len, "%a, %d %b %Y %T %z", tm) : 0;
}

static void log_write(int priority, const char *message, ...)
{
    if (LOG_MASK(priority) & log_maskpri) {
        char date[100];
        size_t len = logdate(date, sizeof date);
        fwrite(date, len, 1, log_file);
        //fwrite(get_prio(priority), 10, 1, log_file);

        va_list va;
        va_start(va, message);
        vfprintf(log_file, message, va);
        va_end(va);
    }
}

void tp_log_init(const char *path, int mask)
{
    if (path) {
        if ((log_file = fopen(path, "a")) != NULL) {
            tp_syslog = log_write;
            tp_closelog = log_close;
            log_maskpri = mask;
            return;
        }
        perror(path);
    }
    /* setup syslog if a log file was not specified or could not be opened */
    tp_syslog = syslog;
    tp_closelog = closelog;
    openlog("myident", LOG_PID|LOG_CONS, LOG_DAEMON);
    setlogmask(mask);
}

Note that I used stdio instead of raw file writes - why not? I also cheated in not printing the priority (level) name - is it useful? I also didn't redefine syslog's constants (log priorities, etc).

You can call the log functions as normal:

tp_log_init("/path/to/logfile", LOG_UPTO(LOG_ERR));

tp_syslog(LOG_EMERG, "hello %d", 100);
tp_closelog();

I'll write some comments on your code as it stands tomorrow (in a separate answer).