Skip to main content
added more explanation and improved code example
Source Link

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)

// 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
}
// 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;

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

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

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)

// 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
}
fixed example code [use localtime_r]
Source Link
// 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 tmtm;
 = *localtime      localtime_r(&now,&tm);

        // timestamp message commonPrinting forto boththe streamsconsole
        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 += vsprintfsprintf(cur,format,args);
    va_end(args);

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

    size_t len = cur - buf;

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

    // Printing into the file
    if (__log_filestream)
        fwrite(buf,1,len,__log_filestream);
}
// 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(&now);

        // timestamp message common for both streams
        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 += vsprintf(cur,format,args);
    va_end(args);

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

    size_t len = cur - buf;

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

    // Printing into the file
    if (__log_filestream)
        fwrite(buf,1,len,__log_filestream);
}
// 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;

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

    // Printing into the file
    if (__log_filestream)
        fwrite(buf,1,len,__log_filestream);
}
added more explanation
Source Link
 

Or, better yet, just keep concatenating to the buffer and do a single [pair] of[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

// 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(&now);

        // timestamp message common for both streams
        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 += vsprintf(cur,format,args);
    va_end(args);

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

    size_t len = cur - buf;

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

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

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

// 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(&now);

        // timestamp message common for both streams
        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 += vsprintf(cur,format,args);
    va_end(args);

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

    size_t len = cur - buf;

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

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

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

// 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(&now);

        // timestamp message common for both streams
        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 += vsprintf(cur,format,args);
    va_end(args);

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

    size_t len = cur - buf;

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

    // Printing into the file
    if (__log_filestream)
        fwrite(buf,1,len,__log_filestream);
}
fixed example code
Source Link
Loading
fixed example code
Source Link
Loading
Source Link
Loading