Return to Revisions

You're doing printf and fprintf twice for the same arguments.

So, it's replicating code.

*printf is somewhat heavyweight. So, I'd do sprintf [or snprintf] to a buffer (e.g):

len = sprintf(buf,...);

And then do:

fwrite(buf,1,len,stdout);
if (__log_filestream)
    fwrite(buf,1,len,__log_filestream);

The overhead of using the buffer is less than calling a printf function twice. I'd repeat the same buffering for the vprintf/vfprintf

Or, better yet, just keep concatenating to the buffer and do a single [pair of] fwrite at the end. This is [yet] better performance.

And, this is especially helpful if there are multiple threads doing logging because the given log message will come out on a single line (e.g.):

threadA timestamp | threadA message
threadB timestamp | threadB message

With two separate writes to a stream, two threads could intersperse partial parts of their message [not nearly as nice]:

threadA timestamp
threadB timestamp
threadA message
threadB message

Note that this is enough to guarantee that we see nice/whole lines. But, it doesn't prevent a race for the ordering of two lines for each stream. That is, we could have [on stdout]:

threadA line
threadB line

But, it might not prevent [on the logfile stream]:

threadB line
threadA line

So, we could wrap the fwrite calls in a mutex. Or, we could just wrap the calls in a flockfile(stdout) / funlockfile(stdout) pairing (See: FORCE_SEQUENTIAL in the example below)

If this function is the only function writing to the logfile and/or stdout, you might get even better performance by using write instead of fwrite [YMMV]

Here's how I would refactor the code [and, if you're paranoid, you could use snprintf]:

// The function
void
log(int lvl,const char *format,...)
{
    va_list args;
    char buf[1000];
    char *cur = buf;

    // If lvl < 0 the prefix will not be used
    if (lvl >= lINFO) {
        time_t now = time(NULL);
        struct tm tm;
        localtime_r(&now,&tm);

        // Printing to the console
        cur += sprintf(cur,"[%d-%02d-%02d %02d:%02d:%02d %s] [%s] : ",
            tm.tm_year + 1900,tm.tm_mon + 1,tm.tm_mday,
            tm.tm_hour,tm.tm_min,tm.tm_sec,
            __log_name,parse_lvl(lvl));
    }

    va_start(args, format);
    cur += sprintf(cur,format,args);
    va_end(args);

    *cur++ = '\n';
    *cur = 0;

    size_t len = cur - buf;

    // lock [either] stream to force both streams to come out "atomically" in
    // the same order
#ifdef FORCE_SEQUENTIAL
    flockfile(stdout);
#endif

    // Printing to the console
    fwrite(buf,1,len,stdout);

    // Printing into the file
    if (__log_filestream)
        fwrite(buf,1,len,__log_filestream);

#ifdef FORCE_SEQUENTIAL
    funlockfile(stdout);
#endif
}