Logging compatibly with logrotate

Question

I am writing a Linux daemon that writes a log. I'd like the log to be rotated by logrotate. The program is written in C.

Normally, my program would open the log file when it starts, then write entries as needed and then, finally, close the log file on exit.

What do I need to do differently in order to support log rotation using logrotate? As far as I have understood, my program should be able to reopen the log file each time logrotate has finished it's work. The sources that I googled didn't, however, specify what reopening the log file exactly means. Do I need to do something about the old file and can I just create another file with the same name? I'd prefer quite specific instructions, like some simple sample code.

I also understood that there should be a way to tell my program when it is time to do the reopening. My program already has a D-Bus interface and I thought of using that for those notifications.

Note: I don't need instructions on how to configure logrotate. This question is only about how to make my own software compatible with it.

Answer 1

Although man logrotate examples use the HUP signal, I recommend using USR1 or USR2, as it is common to use HUP for "reload configuration". So, in logrotate configuration file, you'd have for example

/var/log/yourapp/log {
    rotate 7
    weekly
    postrotate
        /usr/bin/killall -USR1 yourapp
    endscript
}

The tricky bit is to handle the case where the signal arrives in the middle of logging. The fact that none of the locking primitives (other than sem_post(), which does not help here) are async-signal safe makes it an interesting issue.

The easiest way to do it is to use a dedicated thread, waiting in sigwaitinfo(), with the signal blocked in all threads. At exit time, the process sends the signal itself, and joins the dedicated thread. For example,

#define  ROTATE_SIGNAL  SIGUSR1

static pthread_t        log_thread;
static pthread_mutex_t  log_lock = PTHREAD_MUTEX_INITIALIZER;
static char            *log_path = NULL;
static FILE *volatile   log_file = NULL;

int log(const char *format, ...)
{
    va_list  args;
    int      retval;

    if (!format)
        return -1;
    if (!*format)
        return 0;

    va_start(args, format);
    pthread_mutex_lock(&log_lock);
    if (!log_file)
        return -1;
    retval = vfprintf(log_file, format, args);
    pthread_mutex_unlock(&log_lock);
    va_end(args);

    return retval;
}

void *log_sighandler(void *unused)
{
    siginfo_t info;
    sigset_t  sigs;
    int       signum;

    sigemptyset(&sigs);
    sigaddset(&sigs, ROTATE_SIGNAL);

    while (1) {

        signum = sigwaitinfo(&sigs, &info);
        if (signum != ROTATE_SIGNAL)
            continue;

        /* Sent by this process itself, for exiting? */
        if (info.si_pid == getpid())
            break;

        pthread_mutex_lock(&log_lock);
        if (log_file) {
            fflush(log_file);
            fclose(log_file);
            log_file = NULL;
        }
        if (log_path) {
            log_file = fopen(log_path, "a");
        }
        pthread_mutex_unlock(&log_lock);
    }

    /* Close time. */
    pthread_mutex_lock(&log_lock);
    if (log_file) {
        fflush(log_file);
        fclose(log_file);
        log_file = NULL;
    }
    pthread_mutex_unlock(&log_lock);

    return NULL;
}

/* Initialize logging to the specified path.
   Returns 0 if successful, errno otherwise. */
int log_init(const char *path)
{
    sigset_t          sigs;
    pthread_attr_t    attrs;
    int               retval;

    /* Block the rotate signal in all threads. */
    sigemptyset(&sigs);
    sigaddset(&sigs, ROTATE_SIGNAL);
    pthread_sigmask(SIG_BLOCK, &sigs, NULL);

    /* Open the log file. Since this is in the main thread,
       before the rotate signal thread, no need to use log_lock. */
    if (log_file) {
        /* You're using this wrong. */
        fflush(log_file);
        fclose(log_file);
    }
    log_file = fopen(path, "a");
    if (!log_file)
        return errno;

    log_path = strdup(path);

    /* Create a thread to handle the rotate signal, with a tiny stack. */
    pthread_attr_init(&attrs);
    pthread_attr_setstacksize(65536);
    retval = pthread_create(&log_thread, &attrs, log_sighandler, NULL);
    pthread_attr_destroy(&attrs);
    if (retval)
        return errno = retval;

    return 0;       
}

void log_done(void)
{
    pthread_kill(log_thread, ROTATE_SIGNAL);
    pthread_join(log_thread, NULL);
    free(log_path);
    log_path = NULL;
}

The idea is that in main(), before logging or creating any other threads, you call log_init(path-to-log-file), noting that a copy of the log file path is saved. It sets up the signal mask (inherited by any threads you might create), and creates the helper thread. Before exiting, you call log_done(). To log something to the log file, use log() like you would use printf().

I'd personally also add a timestamp before the vfprintf() line, automatically:

    struct timespec  ts;
    struct tm        tm;

    if (clock_gettime(CLOCK_REALTIME, &ts) == 0 &&
        localtime_r(&(ts.tv_sec), &tm) == &tm)
        fprintf(log_file, "%04d-%02d-%02d %02d:%02d:%02d.%03ld: ",
                          tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday,
                          tm.tm_hour, tm.tm_min, tm.tm_sec,
                          ts.tv_nsec / 1000000L);

This YYYY-MM-DD HH:MM:SS.sss format has the nice benefit that it is close to a worldwide standard (ISO 8601) and sorts in the correct order.

Answer 2

There are several common ways:

1. you use logrotate and your program should be able to catch a signal (usually SIGHUP) as a request to close and reopen its log file. Then logrotate sends the signal in a postrotate script
2. you use logrotate and your program is not aware of it, but can be restarted. Then logrotate restarts your program in a postrotate script. Cons: if the start of the program is expensive, this may be suboptimal

3. you use logrotate and your program is not aware of it, but you pass the copytruncate option to logrotate. Then logrotate copies the file and then truncates it. Cons: in race conditions you can lose messages. From rotatelog.conf manpage

   ... Note that there is a very small time slice between copying the file and truncating it, so some logging data might be lost...

4. you use rotatelogs, an utility for httpd Apache. Instead of writing directly to a file, you programs pipes its logs to rotatelogs. Then rotatelogs manages the different log files. Cons: your program should be able to log to a pipe or you will need to install a named fifo.

But beware, for critical logs, it may be interesting to close the files after each message, because it ensures that everything has reached the disk in case of an application crash.

Answer 3

Normally, my program would open the log file when it starts, then write entries as needed and then, finally, close the log file on exit.

What do I need to do differently in order to support log rotation using logrotate?

No, your program should work as if it doesn't know anything about logrotate.

Do I need to do something about the old file and can I just create another file with the same name?

No. There should be only one log file to be opened and be written. Logrotate will check that file and if it becomes too large, it does copy/save the old part, and truncate the current log file. Therefore, your program should work completely transparent - it doesn't need to know anything about logrotate.