How logging works in chimer, writing a small C++ logging library
As I work on and manage a deployment of the chimer web server (I.e., the website you are on right now), I needed a way to write logs to a configurable location so I that I can get debug information, usage statistics, and errors/warnings if anything unexpected happens. There are many off the shelf logging libraries for C++… or any other language for that matter. Some examples for C++ are spdlog and Boost.Log. However, I was feeling adventurous and wanted to write my own as a learning exercise.
I took a lot of inspiration from my experience with logging in C# applications and designed something that is similar to the .NET High Performance Logging pattern. This pattern splits logging conceptually into two parts: the logger object which contains the log sink and delegate functions which contain the log messages and information on how those messages should be formatted.
The logger
The logger class is an incredibly simple structure. It can be configured to write to different sinks (e.g., a file, the terminal, etc.) depending on the concrete implementation chosen, and can be configured to log up to a certain level (critical, error, warning, info, debug, or trace).
/// File: logger.hpp
/// Creator: nathan@nathanieljwright.com
/// Copyright (C) 2024 Nathaniel Wright. All Rights Reserved.
#pragma once
#include "log_level.hpp"
#include <string_view>
namespace chimer::logging
{
class logger
{
private:
log_level m_level;
public:
logger(log_level level);
virtual ~logger();
log_level get_log_level() const noexcept;
virtual void log(log_level level, std::string_view message) = 0;
};
} // namespace chimer::logging
Logging delegates
For each log message that I want to write, there is a corresponding logger delegate that has to be defined. Delegates contain a user defined format function and the desired log level for when this format function should be called. Each time the log message is asked to be written, the logger's log level is compared against the log level of the delegate. Only if logging is possible at the configured level will the delegate's message generating function be called. This saves the program from spending time formatting a message and allocating a std::string to store it when it would just be thrown away if the configured logging level was too high. To see this in action, take a look at the operator() method in the code shown below.
Another useful outcome of these delegates having to be defined is that log messages used in multiple places will have the exact same format string in each place that it's used. Many other logging libraries encourage putting the informational string in each place the logger is called (e.g., log->info("Hello, world")). This is error prone if one ever wants the information string to match in multiple places. Yes, you can have a place in the source code full of const strings that are used instead of typing it out each time, but this starts looking more and more like the logger delegate approach.
/// File: logger_delegate.hpp
/// Creator: nathan@nathanieljwright.com
/// Copyright (C) 2024 Nathaniel Wright. All Rights Reserved.
#pragma once
#include "log_level.hpp"
#include "logger.hpp"
#include <functional>
#include <memory>
#include <type_traits>
template <typename T>
concept DerivedFromLogger = std::is_base_of_v<chimer::logging::logger, T>;
namespace chimer::logging
{
template <typename R, typename... GenArgs> class logger_delegate
{
public:
using log_generator = std::function<R(GenArgs...)>;
logger_delegate(log_level level, log_generator gen) : m_gen(std::move(gen)), m_level(level)
{
}
template <DerivedFromLogger T, typename... Args> inline void operator()(T &logger, Args &&...args) const
{
if (m_level <= logger.get_log_level()) [[likely]]
{
logger.log(m_level, m_gen(std::forward<Args>(args)...));
}
}
template <DerivedFromLogger T, typename... Args>
inline void operator()(const std::shared_ptr<T> &logger, Args &&...args) const
{
operator()(*logger.get(), std::forward<Args>(args)...);
}
private:
log_generator m_gen;
log_level m_level;
};
} // namespace chimer::logging
Example Usage
Here's an example of definining and then using a logger delegate. The console_logger is configured to be able to output the desired message, but if it weren't, the lambda specified would never be called. Because of this, no string would need to be allocated.
/// File: chimer_logging_example.cpp
/// Creator: nathan@nathanieljwright.com
/// Copyright (C) 2024 Nathaniel Wright. All Rights Reserved.
#include "chimer/logging/console_logger.hpp"
#include "chimer/logging/logger_delegate.hpp"
#include <fmt/core.h>
using namespace chimer::logging;
logger_delegate<std::string, int> log_count_info(log_level::info, [](auto count) {
// This will get called, formats and allocates a string
return fmt::format("The current count is {}", count);
});
logger_delegate<std::string, int> log_count_trace(log_level::trace, [](auto count) {
// This will never get called.
return fmt::format("The current count is {}", count);
});
int main()
{
// Create a logger that will write to the terminal
auto logger = console_logger(log_level::info);
for (int i = 0; i < 10; i++)
{
// Call the logger_delegate
log_count_info(logger, i);
log_count_trace(logger, i);
}
return 0;
}
2024-10-26T21:35:39-0700 [info] The current count is 0
2024-10-26T21:35:39-0700 [info] The current count is 1
2024-10-26T21:35:39-0700 [info] The current count is 2
2024-10-26T21:35:39-0700 [info] The current count is 3
2024-10-26T21:35:39-0700 [info] The current count is 4
2024-10-26T21:35:39-0700 [info] The current count is 5
2024-10-26T21:35:39-0700 [info] The current count is 6
2024-10-26T21:35:39-0700 [info] The current count is 7
2024-10-26T21:35:39-0700 [info] The current count is 8
2024-10-26T21:35:39-0700 [info] The current count is 9