Formatted Console Log with Datetime

[ElusiveTau]

I'm working on a C++11 project that uses console logging (cout) at the moment. I created the following Log method to perform printf-style formatting:

// Uses sprintf, use _CRT_SECURE_NO_WARNINGS preprocessor directive

#include <cstdio>
#include "Windows.h"

using namespace std;

bool Log(const char* msg, ...)
{
#define MSGMAXLEN 500
    if (msg && strlen(msg) >= MSGMAXLEN) { return false; } // Or log but truncate

    // Get the current datetime
    char logMsg[500] = {};
    SYSTEMTIME now;
    GetLocalTime(&now);
    sprintf(logMsg, "%02d/%02d/%02d %02d:%02d:%02d.%03d: %s",
        now.wYear, now.wMonth, now.wDay,
        now.wHour, now.wMinute, now.wSecond, now.wMilliseconds,
        msg
    );

    // Pass variable arguments with format string to vprintf
    va_list argptr;
    va_start(argptr, msg);
    int successfulWrite = vfprintf(stdout, logMsg, argptr);
    va_end(argptr);
    if (successfulWrite >= 0) { return true; }

    return false;
}

int main()
{
    Log("#%d Hello %s!\n", 1, "Alice");
    return 0;
}

I don't use variadic arguments extensively and this usage was based off a stack overflow answer. It seems to be working but I was wondering if there is anything to look out for.

[kigar64551]

Variadic functions, as implemented in C/C++, are not type-safe at all!

Specifically, vfprintf() requires that the given va_list contains one argument for each type specifier in the given format string. Furthermore, the type of each argument in the va_list needs to match the type of the corresponding type specifier in the format string. There is, unfortunately, no way the check this. You need to trust the caller of your Log() function to do it properly, every time! And, if the caller does wrong, then undefined behavior (including crashes and possible security vulnerabilities) will be the consequence.

If you use C++ (rather than plain C), as you say, it would be much preferable to implement a C++ (i.e. object-oriented) solution 😏

For example, something like this:

#include <iostream>
#include <chrono>
#include <iomanip>
#include <sstream>

// ------------------
// Logging interface
// ------------------

class ILoggable {
public:
	virtual void display(std::stringstream &buffer) const = 0;
};

static std::tm get_date_time(const bool local_time) {
	const time_t now = time(NULL);
	std::tm date;
	if ((local_time ? localtime_s(&date, &now) : gmtime_s(&date, &now)) != 0) {
		memset(&date, 0, sizeof(std::tm));
	}
	return date;
}

void log(const ILoggable *const obj) {
	const std::tm date = get_date_time(false);
	std::stringstream buffer;
	buffer << std::put_time(&date, "[%Y-%m-%d %H:%M:%S] ");
	obj->display(buffer);
	std::cout << buffer.str() << std::endl;
}

// ------------------
// An example class
// ------------------

class MyClass : public ILoggable {
public:
	MyClass(const int id, const char *const name) : m_id(id), m_name(name) {}

	virtual void display(std::stringstream &buffer) const {
		buffer << m_id << " Hello " << m_name << "!";
	}
private:
	const int m_id;
	const std::string m_name;
};

// ------------------
// Main
// ------------------

int main()
{
	MyClass instance1(1, "Alice");
	MyClass instance2(2, "Bob");
	log(&instance1);
	log(&instance2);
}

[ElusiveTau]

There is, unfortunately, no way the check this. You need to trust the caller of your Log() function to do it properly, every time! And, if the caller does wrong, then undefined behavior (including crashes and possible security vulnerabilities) will be the consequence.

Thanks for the note! At the time of composing the OP, my GoogleTest tests kept crashing in the middle of a call to Log. Turns out, one of my format strings had "% s" (space character) instead of the intended "%s" specifier.

I'd use a logging library if I could but I'm not the project lead. I'm of the opinion that we should pick a logging library and stop muddling around with our own implementation but so it goes.

[mbozzi]

There might be compiler-specific functionality to type-check format strings, for example by applying the attribute [[gnu::format(printf, 1, 2)]] to Log.

Look for "format" in the GCC docs:
https://gcc.gnu.org/onlinedocs/gcc-3.2.3/gcc/Function-Attributes.htm

I think Clang has a similar feature but MSVC does not.

[mbozzi]

After a closer look it seems like the code is prone to overflowing the 500-byte format string logMsg; the time stamp is taking up some of those bytes.

You could fix the overflow by using snprintf:

bool Log(const char* msg, ...)
{
    if (!msg) return false;

    int constexpr format_string_buffer_size = 500;
    char format_string[format_string_buffer_size];

    SYSTEMTIME now;
    GetLocalTime(&now);

    // Format the time stamp followed by msg into format_string
    int n = snprintf(format_string, format_string_buffer_size, "%02d/%02d/%02d %02d:%02d:%02d.%03d: %s",
        now.wYear, now.wMonth, now.wDay, now.wHour, now.wMinute, now.wSecond, now.wMilliseconds, msg);
    if (n < 0) return false; // encoding error

    if (n >= format_string_buffer_size) 
    { // The format string is truncated arbitrarily.
      // For example, "%d %n %s" may be truncated to "%d %", which contains an invalid format-specifier;
      // the best option is to fail.
      return false;
    }

    // Pass variable arguments with format string to vprintf
    va_list argptr;
    va_start(argptr, msg);
    int successfulWrite = vprintf(format_string, argptr);
    va_end(argptr);

    return successfulWrite >= 0;
}

It might be a bit simpler to call printf twice - once for the timestamp, again for the user's message.

[seeplus]

snprintf() returns the number of characters that would have been written if the given size was big enough. There is a special case that if size is 0 then (buff can be NULL) nothing is written and the return value is the size of the required buffer (add 1 for null terminator). You can then allocate required memory and re-call snprintf(). Consider something like (not tried)

int n = snprintf(NULL, 0, "%02d/%02d/%02d %02d:%02d:%02d.%03d: %s",
        now.wYear, now.wMonth, now.wDay, now.wHour, now.wMinute, now.wSecond, now.wMilliseconds, msg);

if (n < 0 ) return false;

std::string buff (n + 1, 0);

n = snprintf(buff.data(), buff.size(), "%02d/%02d/%02d %02d:%02d:%02d.%03d: %s",
        now.wYear, now.wMonth, now.wDay, now.wHour, now.wMinute, now.wSecond, now.wMilliseconds, msg);

if (n < 0 || n >= buff.size()) return false;

[kigar64551]

If you are willing to dynamically allocate the buffer, you can just use asprintf():
https://man7.org/linux/man-pages/man3/asprintf.3.html
https://pubs.opengroup.org/onlinepubs/9799919799/functions/asprintf.html

AFAIK, in MSVC that function is still lacking 🙄, but ports readily exist:
https://raw.githubusercontent.com/lordmulder/asprintf-msvc/refs/heads/master/asprintf_msvc.c

But then, in C++, I'd recommend just going with std::stringstream, which in contrast to any *printf() variant, actually is type-safe.

(See my example logger implementation above)

[seeplus]

If the OP could move to C++20 rather than sticking with using C++11 then there's std::format()