C語言回撥日誌庫的實現

ChrisZZ發表於2024-05-04

C語言回撥日誌庫的實現

Author: ChrisZZ
Link: https://www.cnblogs.com/zjutzz
Time 2024-05-04 00:00:15

0. 目的

參照 https://github.com/rxi/log.c 這一日誌庫,模仿實現. 為實際業務中的日誌庫提供參考思路。

不用 C++ 實現日誌庫, 因為業務中各個模組是 C API,不強制各個模組都用 C++(公司沒有高密度、高水平的C++演算法工程師)。C簡潔夠用。

本篇不涉及 ASCII 跳脫字元的顯示。

1. 列印檔名、行號

__FILE__ 在預編譯階段自動展開為檔名。

__LINE__ 自動在編譯階段展開為行號。

__FUNCTION__ 自動在編譯階段展開為函式名,但可能會暴露業務敏感資訊,一般不用, 或者考慮增加編譯期字串加密技術,尚未實踐。

#define LOG_DEBUG1(msg) log_log1(__FILE__, __LINE__, msg)
void log_log1(const char* file, int line, const char* msg)
{
    printf("%s:%d %s", file, line, msg);
}

2. 列印時間

localtime() 獲取時間, strftime() 修改顯示格式。

localtime 不是執行緒安全的, 多執行緒場景使用時候要加鎖保護,作為臨界區的一部分。

#nclude <time.h>

// get current time
time_t t = time(NULL);
struct tm* time = localtime(&t);

// convert it to human-readable format
char time_str[32];
size_t count = strftime(time_str, sizeof(time_str), "%Y-%m-%d %H:%M:%S", time);
time_str[count] = '\0';

// print the time str
printf("current time: %s\n", time_str);

3. 列印不定引數

類似於 printf 函式支援不定引數:先給定格式串, 再給出每個格式的替代值。

不直接用 printf 是為了同時保持列印檔名、行號、時間等資訊。

使用 va_list, va_start, va_end 來解析不定引數, 使用 vprintf 來執行 printf 風格引數的列印。

#define LOG_DEBUG2(fmt, ...) log_log2(fmt, __VA_ARGS__)
void log_log2(const char* fmt, ...)
{
    va_list args;
    va_start(args, fmt);

    vprintf(fmt, args);

    va_end(args);
}

4. 獲取時間:執行緒安全方式

使用 pthread API 裡的 mutex 來保護 localtime() 的呼叫。 臨界區儘可能最小化, 後續執行 strftime 並不是臨界區一部分。

#define LOG_DEBUG4(fmt, ...) log_log4(__FILE__, __LINE__, fmt, __VA_ARGS__)
void log_log4(const char* file, int line, const char* fmt, ...)
{
    time_t t = time(NULL);
    pthread_mutex_lock(&lock);
    struct tm* time = localtime(&t);
    pthread_mutex_unlock(&lock);

    char time_str[32];
    size_t count = strftime(time_str, sizeof(time_str), "%Y-%m-%d %H:%M:%S", time);
    time_str[count] = '\0';

    printf("%s %s:%d ", time_str, file, line);

    va_list args;
    va_start(args, fmt);
    vprintf(fmt, args);
    va_end(args);
}

5. 保持執行緒列印不被截斷

兩個執行緒同時向控制檯列印 log, 每個執行緒的列印可能沒結束就被另個執行緒截斷, 原因是 printf()vprintf() 沒有放入臨界區。

依然使用 pthread API, 這次增加 mutex 的保護範圍。

// 讓每個執行緒的列印是獨立而完整, 避免被截斷
#define LOG_DEBUG5(fmt, ...) log_log5(__FILE__, __LINE__, fmt, __VA_ARGS__)
void log_log5(const char* file, int line, const char* fmt, ...)
{
    pthread_mutex_lock(&lock);

    time_t t = time(NULL);
    struct tm* time = localtime(&t);

    char time_str[32];
    size_t count = strftime(time_str, sizeof(time_str), "%Y-%m-%d %H:%M:%S", time);
    time_str[count] = '\0';

    printf("%s %s:%d ", time_str, file, line);

    va_list args;
    va_start(args, fmt);
    vprintf(fmt, args);
    va_end(args);

    pthread_mutex_unlock(&lock);
}

6. 泛化: 回撥方式傳入列印函式

還記得用的 printf 函式嗎? 也許應該把列印動作交給呼叫者, 他:

  • 可以增加列印的內容,例如時區,hostname
  • 可以刪除列印,減小系統負載,或遮蔽演算法日誌內容,不提供給客戶

關鍵程式碼:

// 用於列印的回撥函式的型別
typedef void (PrintFn)(LogMessage* msg);

typedef struct LogContext
{
    LockFn* lock; // 鎖函式
    pthread_mutex_t* mutex; // 互斥量
    PrintFn* print;   // 用於列印的回撥函式
} LogContext;

LogContext g_ctx;   // 全域性上下文

// 註冊回撥函式的函式
void log_add_print_fn(PrintFn* print)
{
    g_ctx.print = print;
}

#define LOG_DEBUG(fmt, ...) log_log(__FILE__, __LINE__, fmt, __VA_ARGS__)
void log_log(const char* file, int line, const char* fmt, ...)
{
    if (g_ctx.lock)
    {
        g_ctx.lock(true, g_ctx.mutex);
    }

    //printf("%s %s:%d ", g_loginfo.time_str, g_loginfo.file, g_loginfo.line);
    if (g_ctx.print)
    {
        LogMessage msg;
        msg.file = file;
        msg.line = line;
        msg.fmt = fmt;

        time_t t = time(NULL);
        struct tm* time = localtime(&t);
        size_t count = strftime(msg.time_str, sizeof(msg.time_str), "%Y-%m-%d %H:%M:%S", time);
        msg.time_str[count] = '\0';

        va_start(msg.ap, fmt);
        g_ctx.print(&msg);
        va_end(msg.ap);
    }

    if (g_ctx.lock)
    {
        g_ctx.lock(false, g_ctx.mutex);
    }
}

7. 泛化: 回撥方式傳入 lock 函式

日誌庫儘可能的支援更廣泛的平臺, 不能拘泥於 pthread API, 也應當支援 MSVC 多執行緒。 支援的形式是定義出介面,而不是把具體的 MSVC 多執行緒的實現耦合進來。

對於單執行緒場景, 加鎖反而影響效能, 此時鎖函式傳入NULL值即可。

先定義鎖函式的介面:

// 鎖函式。true 為鎖住,false 為開鎖
typedef void (LockFn)(bool lock, pthread_mutex_t* mutex);

// 註冊鎖函式和互斥量
void log_set_lock(LockFn* lock, pthread_mutex_t* mutex)
{
    g_ctx.lock = lock;
    g_ctx.mutex = mutex;
}

不夠徹底, pthread_mutex_t 也應該被重構為介面而非具體實現,繼續修改得到:

typedef void (LockFn)(bool lock, void* udata);

typedef struct LogContext
{
    LockFn* lock;   // 鎖函式
    void* udata;    // 被 lock 鎖住的資料, 例如 pthread_mutex_t*
    PrintFn* print; // 用於列印的回撥函式
} LogContext;

void log_set_lock(LockFn* lock, void* udata)
{
    g_ctx.lock = lock;
    g_ctx.udata = udata;
}

這一泛化版本,使得具體的 lockFn 可以有不同實現,呼叫者自行提供即可,包括而不限於:

  • pthread API 實現的 lock
  • msvc 多執行緒 API 實現的 lock
  • C++11 多執行緒 API 實現的 lock

8. all together: 一個支援回撥的、支援執行緒安全的日誌庫實現

#if _MSC_VER
#define _CRT_SECURE_NO_WARNINGS
#endif

#include <stdio.h>
#include <stdarg.h>
#include <time.h>
#include <stdbool.h>

typedef struct LogMessage
{
    const char* file;   // 檔名
    int line;           // 行號
    const char* fmt;    // 格式串
    va_list ap;         // 格式串的不定引數
    char time_str[32];  // 時間
} LogMessage;

// 用於列印的回撥函式的型別
typedef void (PrintFn)(LogMessage* msg);

// 鎖函式。true 為鎖住,false 為開鎖
typedef void (LockFn)(bool lock, void* udata);

typedef struct LogContext
{
    LockFn* lock;   // 鎖函式
    void* udata;    // 被 lock 鎖住的資料, 例如 pthread_mutex_t*
    PrintFn* print; // 用於列印的回撥函式
} LogContext;

LogContext g_ctx;   // 全域性上下文

// 註冊回撥函式的函式
void log_add_print_fn(PrintFn* print)
{
    g_ctx.print = print;
}

// 註冊鎖函式和互斥量
void log_set_lock(LockFn* lock, void* udata)
{
    g_ctx.lock = lock;
    g_ctx.udata = udata;
}

// 使用標準輸出執行列印的函式
void stdout_print_fn(LogMessage* msg)
{
    printf("%s %s:%d ", msg->time_str, msg->file, msg->line);
    vprintf(msg->fmt, msg->ap);
}

#define LOG_DEBUG(fmt, ...) log_log(__FILE__, __LINE__, fmt, __VA_ARGS__)
void log_log(const char* file, int line, const char* fmt, ...)
{
    if (g_ctx.lock)
    {
        g_ctx.lock(true, g_ctx.udata);
    }

    //printf("%s %s:%d ", g_loginfo.time_str, g_loginfo.file, g_loginfo.line);
    if (g_ctx.print)
    {
        LogMessage msg;
        msg.file = file;
        msg.line = line;
        msg.fmt = fmt;

        time_t t = time(NULL);
        struct tm* time = localtime(&t);
        size_t count = strftime(msg.time_str, sizeof(msg.time_str), "%Y-%m-%d %H:%M:%S", time);
        msg.time_str[count] = '\0';

        va_start(msg.ap, fmt);
        g_ctx.print(&msg);
        va_end(msg.ap);
    }

    if (g_ctx.lock)
    {
        g_ctx.lock(false, g_ctx.udata);
    }
}

#if __GNUC__
#include <pthread.h>
#include <unistd.h>

// 使用 pthread 的 mutex 來實現鎖函式
void pthread_lock_fn(bool lock, void* mutex)
{
    if (lock)
    {
        pthread_mutex_lock((pthread_mutex_t*)mutex);
    }
    else
    {
        pthread_mutex_unlock((pthread_mutex_t*)mutex);
    }
}

// 使用 LOG_DEBUG 的示例執行緒函式
void* f(void* args)
{
    pthread_t thread_id = pthread_self();
    int* mode = (int*)args;
    for (int i = 0; i < 100; i++)
    {
        int j = (*mode) * 100 + i;
        LOG_DEBUG("hello %d in thread %lu\n", j, (unsigned long)thread_id);
    }
    return NULL;
}

int mutex_lock_example()
{
    // 定義區域性的 mutex
    pthread_mutex_t mutex;
    pthread_mutex_init(&mutex, NULL);

    // 註冊回撥函式. 如果不註冊,則看不到任何輸出
    log_add_print_fn(stdout_print_fn);

    // 設定鎖, 如果不設定,在多執行緒時的列印會被截斷,獲取時間時會發生 data race
    log_set_lock(pthread_lock_fn, &mutex);

    pthread_t t1, t2;
    int mode1 = 1;
    pthread_create(&t1, NULL, f, &mode1);
    int mode2 = 2;
    pthread_create(&t2, NULL, f, &mode1);

    pthread_join(t1, NULL);
    pthread_join(t2, NULL);

    pthread_mutex_destroy(&mutex);

    return 0;
}
#endif

#if _MSC_VER

#include <windows.h>

void msvc_lock_fn(bool lock, void* critical_section)
{
    if (lock)
    {
        EnterCriticalSection((CRITICAL_SECTION*)critical_section);
    }
    else
    {
        LeaveCriticalSection((CRITICAL_SECTION*)critical_section);
    }
}

DWORD WINAPI f3(LPVOID lpParameter)
{
    int mode = *static_cast<int*>(lpParameter);
    DWORD thread_id = GetCurrentThreadId();
    for (int i = 0; i < 100; i++)
    {
        int j = mode * 100 + i;
        LOG_DEBUG("hello %d in thread %lu\n", j, (unsigned long)thread_id);
    }
    return 0;
}

int msvc_lock_example()
{
    CRITICAL_SECTION cs;
    InitializeCriticalSection(&cs);

    log_add_print_fn(stdout_print_fn);
    log_set_lock(msvc_lock_fn, &cs);

    int mode1 = 1;
    int mode2 = 2;

    HANDLE hThread1, hThread2;
    DWORD threadID1, threadID2;

    hThread1 = CreateThread(
        NULL,
        0,
        f3,
        &mode1,
        0,
        &threadID1
    );

    hThread2 = CreateThread(
        NULL,
        0,
        f3,
        &mode2,
        0,
        &threadID2
    );

    WaitForSingleObject(hThread1, INFINITE);
    WaitForSingleObject(hThread2, INFINITE);

    CloseHandle(hThread1);
    CloseHandle(hThread2);

    DeleteCriticalSection(&cs);
    return 0;
}
#endif

#define USE_CPP11 1

#if USE_CPP11
#include <mutex>
#include <thread>

void f2(int mode)
{
    std::thread::id thread_id = std::this_thread::get_id();
    for (int i = 0; i < 100; i++)
    {
        int j = mode * 100 + i;
        {
            LOG_DEBUG("hello %d in thread %lu\n", j, thread_id);
        }
    }
}

void cpp11_lock_fn(bool lock, void* mutex)
{
    if (lock)
    {
        static_cast<std::mutex*>(mutex)->lock();
    }
    else
    {
        static_cast<std::mutex*>(mutex)->unlock();
    }
}

int cpp11_lock_example()
{
    std::mutex mutex;

    log_add_print_fn(stdout_print_fn);
    log_set_lock(cpp11_lock_fn, &mutex);

    int mode1 = 1;
    std::thread t1(f2, mode1);

    int mode2 = 2;
    std::thread t2(f2, mode2);

    t1.join();
    t2.join();

    return 0;
}
#endif

int main()
{
#if __GNUC__
   mutex_lock_example();
#endif

#if _MSC_VER
    msvc_lock_example();
#endif

#if USE_CPP11
    cpp11_lock_example();
#endif

    return 0;
}

相關文章