C++开发基础之自定义异步日志库实现及性能测试

1. 前言

在软件开发中，日志记录是一个必不可少的部分。通过日志，我们可以记录系统的运行状态、错误信息以及调试数据。然而，当系统的日志量很大时，日志写入操作可能会影响系统的性能，尤其是在 I/O 操作较为频繁的情况下。因此，构建一个异步日志系统成为提升性能的重要手段。

在这篇博客中，我们将实现一个 C++ 异步日志库，支持日志级别分类和自定义文件路径、文件名等功能。同时，我们还会进行性能测试，评估异步日志系统的写入效率。

---

2. 异步日志系统的基本功能设计

1. 日志级别与日志结构

首先，我们需要定义日志的几种级别，并将其与日志消息、时间戳等信息封装在一起：

// 日志级别
enum class LogLevel {
    INFO,
    WARNING,
    ERROR,
    EXCEPTION
};

// 日志项
struct LogEntry {
    std::string message;
    LogLevel level;
    std::string timestamp;
};

我们定义了四种常见的日志级别：INFO（信息）、WARNING（警告）、 ERROR（错误）和EXCEPTION（异常）。每条日志都包含一条消息、日志级别和时间戳。

2. 获取当前时间和日期

为了记录日志的时间，我们需要获取当前系统时间并将其转换为标准的可读格式：

#include <chrono>
#include <ctime>
#include <sstream>
#include <iomanip>

// 获取当前时间的时间戳
std::string GetCurrentTimestamp() {
    auto now = std::chrono::system_clock::now();
    std::time_t now_time = std::chrono::system_clock::to_time_t(now);
    std::tm tm;
    localtime_s(&tm, &now_time);  
    std::stringstream ss;
    ss << std::put_time(&tm, "%Y-%m-%d %H:%M:%S");
    return ss.str();
}

// 获取当前日期，用于日志文件命名
std::string GetCurrentDate() {
    auto now = std::chrono::system_clock::now();
    std::time_t now_time = std::chrono::system_clock::to_time_t(now);
    std::tm tm;
    localtime_s(&tm, &now_time);
    std::stringstream ss;
    ss << std::put_time(&tm, "%Y-%m-%d");
    return ss.str();
}

GetCurrentTimestamp() 函数用于获取精确到秒的时间戳，而 GetCurrentDate() 用于生成日志文件的日期，以便我们根据日期创建日志文件。

3. 异步写入日志实现

接下来，我们构建一个 MyLogger 类，负责处理日志的异步写入。为了避免阻塞主线程，我们将日志写入操作放在单独的线程中处理，并使用 std::queue 存储待写入的日志。

#include <iostream>
#include <fstream>
#include <string>
#include <thread>
#include <mutex>
#include <queue>
#include <condition_variable>

class MyLogger {
public:
    MyLogger(const std::string& output_dir)
        : output_dir_(output_dir), stop_flag_(false) {
        StartLoggingThread();
    }

    ~MyLogger() {
        StopLoggingThread();
    }

    // 记录日志
    void Log(const std::string& message, LogLevel level) {
        std::lock_guard<std::mutex> lock(queue_mutex_);
        log_queue_.emplace(LogEntry{ message, level, GetCurrentTimestamp() });
        condition_.notify_one();  // 通知日志线程有新日志
    }

private:
    std::string output_dir_;
    std::queue<LogEntry> log_queue_;
    std::mutex queue_mutex_;
    std::condition_variable condition_;
    bool stop_flag_;
    std::thread logging_thread_;

    // 启动日志线程
    void StartLoggingThread() {
        logging_thread_ = std::thread([this]() {
            while (!stop_flag_ || !log_queue_.empty()) {
                std::unique_lock<std::mutex> lock(queue_mutex_);
                condition_.wait(lock, [this]() {
                    return !log_queue_.empty() || stop_flag_;
                    });

                while (!log_queue_.empty()) {
                    LogEntry entry = log_queue_.front();
                    log_queue_.pop();
                    lock.unlock();
                    WriteLogToFile(entry);
                    lock.lock();
                }
            }
            });
    }

    // 停止日志线程
    void StopLoggingThread() {
        {
            std::lock_guard<std::mutex> lock(queue_mutex_);
            stop_flag_ = true;
        }
        condition_.notify_one();
        if (logging_thread_.joinable()) {
            logging_thread_.join();
        }
    }

    // 写入日志到文件
    void WriteLogToFile(const LogEntry& entry) {
        std::string filename = output_dir_ + "/log_" + GetCurrentDate() + ".txt";
        std::ofstream log_file(filename, std::ios_base::app);
        if (log_file.is_open()) {
            log_file << "[" << entry.timestamp << "] "
                << LogLevelToString(entry.level) << ": "
                << entry.message << std::endl;
        }
    }
};

4. 调用示例

我们可以创建一个 MyLogger 实例，并随时向其中添加日志：

// MyLogApp.cpp : 此文件包含 "main" 函数。程序执行将在此处开始并结束。
//

#include <iostream>
#include "MyLogger.h"
#include <string>
#include <thread>
#include <filesystem>

namespace fs = std::filesystem;

int main()
{
    // 指定日志文件的输出路径
    std::string log_output_dir = "./logs";
    if (!fs::exists(log_output_dir)) {
        fs::create_directory(log_output_dir);
    }

    // 创建Logger实例
    MyLogger logger(log_output_dir);

    // 记录不同级别的日志
    logger.Log("This is an INFO message", LogLevel::INFO);
    logger.Log("This is a WARNING message", LogLevel::WARNING);
    logger.Log("This is an ERROR message", LogLevel::ERROR);
    logger.Log("This is an EXCEPTION message", LogLevel::EXCEPTION);
    // 等待一会，保证日志异步写入
    std::this_thread::sleep_for(std::chrono::seconds(1));
}

在这个示例中，日志会被写入当前日期命名的文件中，例如 log_2024-09-06.txt。异步线程将自动处理日志写入，主线程不会因 I/O 操作而被阻塞。

[2024-09-06 15:07:02] INFO: This is an INFO message
[2024-09-06 15:07:02] WARNING: This is a WARNING message
[2024-09-06 15:07:02] ERROR: This is an ERROR message
[2024-09-06 15:07:02] EXCEPTION: This is an EXCEPTION message

---

3、日志库的性能测试

为了评估日志系统的性能，我们设计了一个简单的 Benchmark 测试。测试内容包括单次日志写入和批量日志写入的耗时。

1. 测试代码

我们使用 std::chrono 进行时间测量，并定义 LoggerBenchmark 类来测试性能：

#pragma once
#include "MyLogger.h"

class MyLoggerBenchmark 
{
public:
    MyLoggerBenchmark(MyLogger& logger) : logger_(logger) {}
    // 单次日志写入测试
    void SingleLogTest();
    // 批量日志写入测试
    void BulkLogTest(int num_logs);
private:
    MyLogger& logger_;
};

#pragma once

#include "MyLoggerBenchmark.h"

// 单次日志写入测试
void MyLoggerBenchmark::SingleLogTest() {
    auto start = std::chrono::high_resolution_clock::now();
    logger_.Log("Single log test message", LogLevel::INFO);
    auto end = std::chrono::high_resolution_clock::now();
    auto duration = std::chrono::duration_cast<std::chrono::microseconds>(end - start).count();
    std::cout << "Single log write took " << duration << " microseconds." << std::endl;
}

// 批量日志写入测试
void MyLoggerBenchmark::BulkLogTest(int num_logs) {
    std::vector<std::string> messages;
    for (int i = 0; i < num_logs; ++i) {
        messages.push_back("Bulk log test message #" + std::to_string(i + 1));
    }

    auto start = std::chrono::high_resolution_clock::now();
    for (const auto& msg : messages) {
        logger_.Log(msg, LogLevel::INFO);
    }
    auto end = std::chrono::high_resolution_clock::now();
    auto duration = std::chrono::duration_cast<std::chrono::milliseconds>(end - start).count();
    std::cout << "Bulk log write of " << num_logs << " logs took " << duration << " milliseconds." << std::endl;
    std::cout << "Average log write time: " << duration * 1000.0 / num_logs << " microseconds." << std::endl;
}

2. Benchmark 调用示例

// MyLogApp.cpp : 此文件包含 "main" 函数。程序执行将在此处开始并结束。
//

#include <filesystem>
#include "MyLoggerBenchmark.h"

using namespace std;
namespace fs = std::filesystem;

int main()
{
    // 指定日志文件的输出路径
    std::string log_output_dir = "./logs";
    if (!fs::exists(log_output_dir)) {
        fs::create_directory(log_output_dir);
    }

    // 创建Logger实例
    MyLogger logger(log_output_dir);
    MyLoggerBenchmark benchmark(logger);
    // 单条日志写入测试
    benchmark.SingleLogTest();
    // 批量日志写入测试
    benchmark.BulkLogTest(100000);  // 写入 100000 条日志
    // 等待日志线程完成写入
    std::this_thread::sleep_for(std::chrono::seconds(2));
}

3. Benchmark 结果

我们通过批量写入 100000 条日志来测量日志系统的性能。输出如下：
日志文件记录

[2024-09-06 15:35:37] INFO: Single log test message
[2024-09-06 15:35:37] INFO: Bulk log test message #1
[2024-09-06 15:35:37] INFO: Bulk log test message #2
[2024-09-06 15:35:37] INFO: Bulk log test message #3
[2024-09-06 15:35:37] INFO: Bulk log test message #4
[2024-09-06 15:35:37] INFO: Bulk log test message #5
[2024-09-06 15:35:37] INFO: Bulk log test message #6
[2024-09-06 15:35:37] INFO: Bulk log test message #7
[2024-09-06 15:35:37] INFO: Bulk log test message #8
[2024-09-06 15:35:37] INFO: Bulk log test message #9
[2024-09-06 15:35:37] INFO: Bulk log test message #10
...
[2024-09-06 15:35:37] INFO: Bulk log test message #100000

控制台输出

Single log write took 2895 microseconds.
Bulk log write of 100000 logs took 1817 milliseconds.
Average log write time: 18.17 microseconds.

从结果中可以看出，异步日志系统在批量写入时效率较高，每条日志的平均写入时间大约为 18.17 微秒。

---

4. 总结

在本文中，我们实现了一个简单的 C++ 异步日志库，支持自定义日志文件命名、日志级别分类以及异步日志写入操作。通过测试，我们验证了异步日志系统在大量日志写入时的性能优势。