Feature image

It is a good time to be a software engineer in 2024. The amount of tools a developer has at their fingertips to write robust software is truly incredible. Break points and other debugging tools make working through bugs and runtime issues significatly easier since it gives us visual access to the stack. Unfortunately, most of the software we write is destined for production where many of these tools cannot be utilized. As any parent can tell you, eventually your kids grow up and move out into the world where you can no longer monitor them as you once had. Same goes for the software we write. To counteract this, engineers still rely heavily upon logs that write the activity of their software to different files that can be reviewed at a later date if needed.

I was recently working through

Building Low Latency Applications With C++

Author: Sourav Ghosh

and found a really cool example of a Logger class that is pretty plug and play for a bunch of software projects where one might need to log their C++. Of course, there are a bunch of great libraries that can do this, but the one I will be going through below is lightweight and customizable to the developers needs. What follows largely comes from the book referenced above, but with some of my own modifications to modernize the abstractions where I thought relevant.

Imagine you want to log anytime your utility class has its execute() invoked along with the current state of the utility class. We want a logger class that is both so simple you can easily call log() to write to a specific log file, but flexible enough to take any arbitrary number of arguments to help construct the log entry

C++
1    class UtilityClass {
2        int flag_ = 1;
3        int timesInvoked_ = 0;
4        Logger logger_;
5
6        UtilityClass() : logger_("utility_class.log");
7    };

Our utility class will hold onto a Logger member variable that is initailized within the constructor. Our logger class will need an initial string argument that informs the logger where it needs to store the logs written to it. Once this is good to go though, writting logs is pretty simple

C++
1    UtilityClass::execute() {
2        logger_->log("%:% %() invoked. flag=%, timesInvoked=% \n", __FILE__, __LINE__, __FUNCTION__, flag_, ++timesInvoked_);
3    }

Thats it. We lay out the text we want to be logged and then pass an arbitrary amount of other arguments to the log function that will replace each instace of %. Our final example will look something like this within our log

utilityclass.cpp, 12, execute() invoked. flag=true, timesInvoked=1

This text will live within the .log file we setup when constructing our Logger class. Let us now see how we implement the Logger class.

We will start with defining our Logger constructor and private members

C++
 1    class Logger {
 2
 3        explicit Logger(const std::string &file_name) : file_name_(file_name) {
 4            file_.open(file_name);
 5            ASSERT(file_.is_open(), "Could not open log file:" + file_name);
 6            logger_thread = std::thread(&Logger::flush, this);
 7        }
 8
 9         // Deleted default, copy & move constructors and assignment-operators.
10        Logger() = delete;
11
12        Logger(const Logger &) = delete;
13
14        Logger(const Logger &&) = delete;
15
16        Logger &operator=(const Logger &) = delete;
17
18        Logger &operator=(const Logger &&) = delete;
19
20        private:
21            const std::string file_name_;
22            std::ofstream file_;
23
24            std::queue<LogElement> queue_;
25            std::atomic<bool> running_;
26            std::thread *logger_thread_;
27    };

Our constructor takes in the file name and attempts to open an ofstream file that it has ownership over. Assuming this works, we next start up a thread that runs a function called flush which we will get to shortly. We do not want our Logger class being copied or moved and therefore delete those constructors. Our private member variables include a queue to asynchronously take in new items to write to our log file, an atomic boolean to track if the log should still be running, and our thread to handle writing logs on a backend thread that doesnt bog down any critical processes.

Before we proceed any further, there are a couple of data structures we will need to define that our logger class will use to handle the different data types it might be passed to log.

C++
 1    enum class LogType : int8_t {
 2        CHAR = 0,
 3        INTEGER = 1,
 4        LONG_INTEGER = 2,
 5        LONG_LONG_INTEGER = 3,
 6        UNSIGNED_INTEGER = 4,
 7        UNSIGNED_LONG_INTEGER = 5,
 8        UNSIGNED_LONG_LONG_INTEGER = 6,
 9        FLOAT = 7,
10        DOUBLE = 8
11    };
12
13    struct LogElement {
14        LogType type_ = LogType::CHAR;
15        union {
16        char c;
17        int i;
18        long l;
19        long long ll;
20        unsigned u;
21        unsigned long ul;
22        unsigned long long ull;
23        float f;
24        double d;
25        } u_;
26    };

We first construct an enum to represent the different primitive types supported by our logger class. We also construct a LogElement struct that holds two values. The first is the enum of the primitive type stored by the LogElement and the second is a union that stores the actual primitive value. It should be noted an std::variant is a more modern solution to getting similar behavior, but with a performance hit I do not find acceptable in C++.

We can now look at the implementation details of our flush function.

C++
 1    auto flushQueue() noexcept {
 2      while (running_) {
 3
 4        while (!queue_.empty()) {
 5            auto next = queue_.front();
 6            queue_.pop();
 7            switch (next->type_) {
 8            case LogType::CHAR:
 9              file_ << next->u_.c;
10              break;
11            case LogType::INTEGER:
12              file_ << next->u_.i;
13              break;
14            case LogType::LONG_INTEGER:
15              file_ << next->u_.l;
16              break;
17            case LogType::LONG_LONG_INTEGER:
18              file_ << next->u_.ll;
19              break;
20            case LogType::UNSIGNED_INTEGER:
21              file_ << next->u_.u;
22              break;
23            case LogType::UNSIGNED_LONG_INTEGER:
24              file_ << next->u_.ul;
25              break;
26            case LogType::UNSIGNED_LONG_LONG_INTEGER:
27              file_ << next->u_.ull;
28              break;
29            case LogType::FLOAT:
30              file_ << next->u_.f;
31              break;
32            case LogType::DOUBLE:
33              file_ << next->u_.d;
34              break;
35          }
36        }
37        file_.flush();
38
39        using namespace std::literals::chrono_literals;
40        std::this_thread::sleep_for(10ms);
41      }
42    }

This function will run on a while true loop, confirming with the atomic boolean that it should continue to loop after each iteration. This is fine since, as stated earlier, this function runs on a background thread spun up within the constructor. Each iteration involves pulling all the items from the queue one at a time, checking the type, and writing the correct union value to our ofstream file. Once the queue is cleared, we flush the file and put the thread to sleep for 10ms.

Next is the most challenging part of our logger class which is the actual log function. Because we want to be able to take an arbitrary number of arguments that can be inserted in place of the % symbol in the string, we will need to utilize a template variadic pack.

C++
 1  template<typename T, typename... A>
 2    auto log(const char *s, const T &value, A... args) noexcept {
 3      while (*s) {
 4        if (*s == '%') {
 5          if (*(s + 1) == '%') { // to allow %% -> % escape character.
 6            ++s;
 7          } else {
 8            pushValue(value); // substitute % with the value specified in the arguments.
 9            log(s + 1, args...); // pop an argument and call self recursively.
10            return;
11          }
12        }
13        pushValue(*s++);
14      }
15    }

Our log function takes a pointer to the beginning of the string we want our log to write to and an arbitrary number of templated arguments. A while loop allows us to iterate the string one memory address at a time until we reach our null terminated string value. We check each character to see if it is a % that requires work to grab the next templated argument to place within our string. We have an edge case where we are actually escaping a % by having two of them in a row. Each iteration of our while loop will end in us calling the pushValue() method. If our character is not a %, then we stay within the scope of the current function and continue to the next loop. If our character matches %, then we will call pushValue() with the next templated argument, which will insert that templated value in our log, and then we call log() again with args… to ensure our log function gets the next templated argument. Our pushValue function is overloaded to handle all the primitive types supported by our LogType enum

C++
 1    auto pushValue(const char value) noexcept {
 2      pushValue(LogElement{LogType::CHAR, {.c = value}});
 3    }
 4
 5    auto pushValue(const int value) noexcept {
 6      pushValue(LogElement{LogType::INTEGER, {.i = value}});
 7    }
 8
 9    auto pushValue(const long value) noexcept {
10      pushValue(LogElement{LogType::LONG_INTEGER, {.l = value}});
11    }
12
13    auto pushValue(const long long value) noexcept {
14      pushValue(LogElement{LogType::LONG_LONG_INTEGER, {.ll = value}});
15    }
16
17    auto pushValue(const unsigned value) noexcept {
18      pushValue(LogElement{LogType::UNSIGNED_INTEGER, {.u = value}});
19    }
20
21    auto pushValue(const unsigned long value) noexcept {
22      pushValue(LogElement{LogType::UNSIGNED_LONG_INTEGER, {.ul = value}});
23    }
24
25    auto pushValue(const unsigned long long value) noexcept {
26      pushValue(LogElement{LogType::UNSIGNED_LONG_LONG_INTEGER, {.ull = value}});
27    }
28
29    auto pushValue(const float value) noexcept {
30      pushValue(LogElement{LogType::FLOAT, {.f = value}});
31    }
32
33    auto pushValue(const double value) noexcept {
34      pushValue(LogElement{LogType::DOUBLE, {.d = value}});
35    }
36
37    auto pushValue(const char *value) noexcept {
38      while (*value) {
39        pushValue(*value);
40        ++value;
41      }
42    }
43
44    auto pushValue(const std::string &value) noexcept {
45      pushValue(value.c_str());
46    }
47
48    auto pushValue(const LogElement &log_element) noexcept {
49      queue_.push(log_element);
50    }

The last overloaded function takes the actual LogElement we converted all the other primitive types to and adds it to the queue_. From here, our flushQueue() method running on its own thread will periodically take all LogElement values in the queue_ and add to them our log file.

Finally, we utilize a destructor on our Logger to clean up

C++
 1   ~Logger() {
 2      while (queue_.size()) {
 3        using namespace std::literals::chrono_literals;
 4        std::this_thread::sleep_for(1s);
 5      }
 6      running_ = false;
 7      logger_thread_->join();
 8
 9      file_.close();
10    }

We wait for the flushQueue method to clean up any items left in our queue_, then we join our threads and close our file.

The end result is a light logging class that we can use anywhere in our project. A big note of warning, our implementation is not entirely thread safe as it currently sits. Two different places in our code writing to the same log file at the same time could lead to characters being inter-mixed. Additional locks or synchronizations techniques can be included to prevent such issues from occuring.

Happy logging