Search code examples
csyslog

Syslog API: How to get subsecond timestamps in C (works in Python3)


I have two test programs that write to syslog, one in C and one in Python3. Here is some sample output (from /var/log/messages):

Dec  9 11:27:55.000 0c6e58933c36 c-logtest[206]: hello
Dec  9 11:27:55.000 0c6e58933c36 c-logtest[206]: world
Dec  9 11:27:59.584 0c6e58933c36 py-logtest[208]: hello
Dec  9 11:27:59.590 0c6e58933c36 py-logtest[208]: world

The milliseconds are always 000 for the c-logtest program, while evidently works for py-logtest. What am I doing wrong?


c-logtest.c:

#include <syslog.h>
#include <unistd.h> //usleep

int main() {
    openlog("c-logtest", LOG_CONS | LOG_NDELAY, LOG_USER);

    syslog(LOG_INFO, "hello");
    usleep(5000);
    syslog(LOG_INFO, "world");

    closelog();
    return 0;
}

py-logtest.py

#!/usr/bin/env python3

import time
import logging
import logging.handlers

logger = logging.getLogger('')
handler = logging.handlers.SysLogHandler(address = '/dev/log')
handler.setFormatter(logging.Formatter('py-logtest %(message)s'))
logger.addHandler(handler)
logger.setLevel(logging.INFO)

logger.info("hello")
time.sleep(0.005)
logger.info("world")

I'm using syslog-ng, which I've configured to produce millisecond resolution timestamps, by adding this to syslog-ng.conf:

options{ frac-digits(3); };

Tip: It is possible to reproduce this in an isolated manner with docker run --rm -it fedora bash, and from there, install and configure syslog-ng, run the two programs, and tail -F /var/log/messages.


Solution

  • According to this thread glibc implementation of syslog API does not generate sub-second timestamps precision.

    What you can do is probably use keep-timestamp(no) syslog-ng option. It will make syslog-ng ignore the timestamp sent along with the message and use time of message reception instead. Whether this is acceptable or not depends on your use case. In most of the cases when syslog runs locally this probably should not be a problem. There is the following warning in the documentation though:

    To use the S_ macros, the keep-timestamp() option must be enabled (this is the default behavior of syslog-ng PE).