微信 xlog 源码分析

初始化

程序启动初始化xlog

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
+ (void)setup {
    NSArray *paths = NSSearchPathForDirectoriesInDomains(NSLibraryDirectory, NSUserDomainMask, YES);
    NSString *libraryDirectory = [paths firstObject];
    
    // init xlog
#if DEBUG
    xlogger_SetLevel(kLevelDebug);
    mars::xlog::appender_set_console_log(true);
#else
    xlogger_SetLevel(kLevelInfo);
    appender_set_console_log(false);
#endif
    mars::xlog::XLogConfig config;
    config.mode_ = mars::xlog::kAppenderAsync;
    config.logdir_ = [[libraryDirectory stringByAppendingString:@"/log/"] UTF8String];
    NSLog(@"dir = %s", config.logdir_.c_str());
    config.nameprefix_ = "Test";
    config.pub_key_ = "";
    config.compress_mode_ = mars::xlog::kZlib;
    config.compress_level_ = 0;
    config.cachedir_ = "";
    config.cache_days_ = 0;
    appender_open(config);
}

一堆的初始化设置

  • 设置 log level
  • 设置是否开启 控制台 日志输出
  • 设置写日志的模式为异步
    • 暂存到 mmap buffer 中，满足条件刷入文件中
    • 避免每写一条log调用一次 IO
  • 设置log日志的存储路径
  • 设置log日志的文件名前缀
  • 设置加密的公钥，不加密传空字符串
  • 设置压缩模式，zlib 或者 Zstd
    • 日志会先压缩咋存储，如果加密，先压缩再加密
  • 设置 mmap 临时文件路径，为空，使用 logdir_
  • 设置缓存天数，为 0

写日志接口

1
2
3
4
5
6
7
8
9
10
11
12
13
+ (void)logWithLevel:(TLogLevel)logLevel moduleName:(const char*)moduleName fileName:(const char*)fileName lineNumber:(int)lineNumber funcName:(const char*)funcName message:(NSString *)message {
    XLoggerInfo info;
    info.level = logLevel;
    info.tag = moduleName;
    info.filename = fileName;
    info.func_name = funcName;
    info.line = lineNumber;
    gettimeofday(&info.timeval, NULL);
    info.tid = (uintptr_t)[NSThread currentThread];
    info.maintid = (uintptr_t)[NSThread mainThread];
    info.pid = g_processID;
    xlogger_Write(&info, message.UTF8String);
}

format 后写入文件的日志格式

规则

1
level + timestamp + [pid, threadId(*is main thread)] + tag + [fileName, line, funcName] + message

示例

1
"[I][2024-03-29 +8.0 17:09:45.425][0, 105553147396480*][ViewController][ViewController.m:18, -[ViewController viewDidLoad]][Info:this is a test log!"

appender_open && xlogger_Write

mars/xlog/appender.h

定义了一系列与 appender 操作的 c 接口，内部的 XloggerAppender 是真正实现逻辑的 c++ 类。

1
2
3
4
5
6
7
8
9
10
11
12
void appender_open(const XLogConfig& _config);

void appender_flush();
void appender_flush_sync();
void appender_close();
void appender_setmode(TAppenderMode _mode);
bool appender_getfilepath_from_timespan(int _timespan, const char* _prefix, std::vector<std::string>& _filepath_vec);
bool appender_make_logfile_name(int _timespan, const char* _prefix, std::vector<std::string>& _filepath_vec);
bool appender_get_current_log_path(char* _log_path, unsigned int _len);
bool appender_get_current_log_cache_path(char* _logPath, unsigned int _len);
void appender_set_console_log(bool _is_open);

mars/xlog/src/appender.cc

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
void appender_open(const XLogConfig& _config) {
    assert(!_config.logdir_.empty());

    if (nullptr != sg_default_appender) {
        sg_default_appender->WriteTips2File("appender has already been opened. _dir:%s _nameprefix:%s",
                                            _config.logdir_.c_str(),
                                            _config.nameprefix_.c_str());
        return;
    }

    sg_default_appender = XloggerAppender::NewInstance(_config, sg_max_byte_size);
    sg_default_appender->SetConsoleLog(sg_default_console_log_open);
    if (sg_max_alive_time > 0) {
        sg_default_appender->SetMaxAliveDuration(sg_max_alive_time);
    }
    sg_release_guard = false;
    xlogger_SetAppender(&xlogger_appender);
    BOOT_RUN_EXIT(appender_release_default_appender);
}

关键的代码

1
2
3
4
5
6
//创建了 XloggerAppender 实例
sg_default_appender = XloggerAppender::NewInstance(_config, sg_max_byte_size);

//将 xlogger_appender 传递给 xloggerbase 中
xlogger_SetAppender(&xlogger_appender);

xlogger_SetAppender 定义在 mars/comm/xlogger/xloggerbase.h

xloggerbase 导出了一套 c 接口用于写日志的调用。

mars/comm/xlogger/xloggerbase.h

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
extern intmax_t xlogger_pid();
extern intmax_t xlogger_tid();
extern intmax_t xlogger_maintid();
typedef void (*xlogger_appender_t)(const XLoggerInfo* _info, const char* _log);
extern const char* xlogger_dump(const void* _dumpbuffer, size_t _len);
extern const char* xlogger_memory_dump(const void* _dumpbuffer,
                                       size_t _len);  // same as xlogger_dump, but don't write dumpbuffer to file.

TLogLevel xlogger_Level();
void xlogger_SetLevel(TLogLevel _level);
int xlogger_IsEnabledFor(TLogLevel _level);
xlogger_appender_t xlogger_SetAppender(xlogger_appender_t _appender);

typedef int (*xlogger_filter_t)(XLoggerInfo* _info, const char* _log);
void xlogger_SetFilter(xlogger_filter_t _filter);
xlogger_filter_t xlogger_GetFilter();

void        xlogger_Print(const XLoggerInfo* _info, const char* _format, ...);
void xlogger_Write(const XLoggerInfo* _info, const char* _log);

关键的是这几个

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
typedef void (*xlogger_appender_t)(const XLoggerInfo* _info, const char* _log);

xlogger_appender_t xlogger_SetAppender(xlogger_appender_t _appender) {
    if (NULL == &__xlogger_SetAppender_impl) {
        return NULL;
    }
    return __xlogger_SetAppender_impl(_appender);
}

xlogger_appender_t __xlogger_SetAppender_impl(xlogger_appender_t _appender) {
    xlogger_appender_t old_appender = gs_appender;
    gs_appender = _appender;
    return old_appender;
}

void xlogger_Write(const XLoggerInfo* _info, const char* _log) {
    if (NULL != &__xlogger_Write_impl)
        __xlogger_Write_impl(_info, _log);
}

void __xlogger_Write_impl(const XLoggerInfo* _info, const char* _log) {
    if (!gs_appender)
        return;

    if (_info) {
        XLoggerInfo* info = (XLoggerInfo*)_info;
        if (-1 == _info->pid) {
            info->pid = xlogger_pid();
        }

        if (-1 == _info->tid) {
            info->tid = xlogger_tid();
        }

        if (-1 == _info->maintid) {
            info->maintid = xlogger_maintid();
        }
    }

    if (NULL == _log) {
        if (_info) {
            XLoggerInfo* info = (XLoggerInfo*)_info;
            info->level = kLevelFatal;
        }
        gs_appender(_info, "NULL == _log");
    } else {
        gs_appender(_info, _log);
    }
}

调用栈

1
2
3
4
5
6
xlogger_Write()
   __xlogger_Write_impl
       gs_appender()
           xlogger_appender()
               sg_default_appender->Write(_info, _log);

gs_appender 外部调用 xlogger_SetAppender 传入的。

mars/xlog/src/appender.cc

1
2
3
4
5
6
void xlogger_appender(const XLoggerInfo* _info, const char* _log) {
    if (sg_release_guard) {
        return;
    }
    sg_default_appender->Write(_info, _log);
}

然后就是分析 XloggerAppender 类的细节了。

XloggerAppender

1
2
3
4
5
XloggerAppender::XloggerAppender(const XLogConfig& _config, uint64_t _max_byte_size)
: thread_async_(boost::bind(&XloggerAppender::__AsyncLogThread, this)), max_file_size_(_max_byte_size) {
    Open(_config);
}

  • 初始化赋值，创建了一个线程 XloggerAppender::__AsyncLogThread
  • 执行了 open 方法

XloggerAppender::Open

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
void XloggerAppender::Open(const XLogConfig& _config) {
#ifdef WIN32
    // here we make sure boost convert path is utf8 to wide on windows
    SetConvertToUseUtf8();
#endif
    config_ = _config;

    //加锁
    ScopedLock dir_attr_lock(sg_mutex_dir_attr);
    if (!config_.cachedir_.empty()) {
        //如果设置了cachedir_，创建 cachedir_
        boost::filesystem::create_directories(config_.cachedir_);
        //开启一个线程，清理cachedir_的过期数据
        thread_timeout_cache_ =
            std::make_unique<comm::Thread>(boost::bind(&XloggerAppender::__DelTimeoutFile, this, config_.cachedir_));
        thread_timeout_cache_->start_after(2 * 60 * 1000);
        //开启一个线程，将cachedir_中的文件转移到logdir_
        thread_moveold_ = std::make_unique<comm::Thread>(boost::bind(&XloggerAppender::__MoveOldFiles,
                                                                     this,
                                                                     config_.cachedir_,
                                                                     config_.logdir_,
                                                                     config_.nameprefix_));
        thread_timeout_cache_->start_after(3 * 60 * 1000);
#ifdef __APPLE__
        //iPhone上将cachedir_文件属性设置为NSFileProtectionNone
        setAttrProtectionNone(config_.cachedir_.c_str());
#endif
    }
    
    //创建线程，删除logdir_下的过期文件
    thread_timeout_log_ =
        std::make_unique<comm::Thread>(boost::bind(&XloggerAppender::__DelTimeoutFile, this, config_.logdir_));
    thread_timeout_log_->start_after(2 * 60 * 1000);
    //创建logdir_
    boost::filesystem::create_directories(config_.logdir_);
#ifdef __APPLE__
    //iPhone上将logdir_文件属性设置为NSFileProtectionNone
    setAttrProtectionNone(config_.logdir_.c_str());
#endif
    //解锁
    dir_attr_lock.unlock();

    tickcount_t tick;
    tick.gettickcount();
    
    //mmap 文件名字，cachedir_ 不为空，保存在 cachedir_， 否则保存在 logdir_， 以 nameprefix_ 为前缀
    char mmap_file_path[512] = {0};
    snprintf(mmap_file_path,
             sizeof(mmap_file_path),
             "%s/%s.mmap3",
             config_.cachedir_.empty() ? config_.logdir_.c_str() : config_.cachedir_.c_str(),
             config_.nameprefix_.c_str());
    bool use_mmap = false;
    /*
     尝试使用mmap，失败回退至内存buffer
     */
    if (OpenMmapFile(mmap_file_path, kBufferBlockLength, mmap_file_)) {
        //mmap 映射成功，根据映射关系, 选取不同的压缩方式，创建 log_buff_
        if (_config.compress_mode_ == kZstd) {
            log_buff_ = new LogZstdBuffer(mmap_file_.data(),
                                          kBufferBlockLength,
                                          true,
                                          _config.pub_key_.c_str(),
                                          _config.compress_level_);
        } else {
            log_buff_ = new LogZlibBuffer(mmap_file_.data(), kBufferBlockLength, true, _config.pub_key_.c_str());
        }
        use_mmap = true;
    } else {
        //mmap 映射失败，使用内存缓存
        char* buffer = new char[kBufferBlockLength];
        if (_config.compress_mode_ == kZstd) {
            log_buff_ =
                new LogZstdBuffer(buffer, kBufferBlockLength, true, _config.pub_key_.c_str(), _config.compress_level_);
        } else {
            log_buff_ = new LogZlibBuffer(buffer, kBufferBlockLength, true, _config.pub_key_.c_str());
        }
        use_mmap = false;
    }

    if (nullptr == log_buff_->GetData().Ptr()) {
        if (use_mmap && mmap_file_.is_open())
            CloseMmapFile(mmap_file_);
        return;
    }

    AutoBuffer buffer;
    /*
     例如发生了crash，使用mmap， log_buffer中存储的崩溃前没有写入文件的数据
     将log_buff_中的内容刷入buffer中
     */
    log_buff_->Flush(buffer);

    ScopedLock lock(mutex_log_file_);
    log_close_ = false;
    SetMode(config_.mode_);
    lock.unlock();

    //填充mark_info， 当前时间，进程id，线程 id等
    char mark_info[512] = {0};
    __GetMarkInfo(mark_info, sizeof(mark_info));
    
    //将buffer中的内容写入文件
    if (buffer.Ptr()) {
        WriteTips2File("~~~~~ begin of mmap ~~~~~\n");
        __Log2File(buffer.Ptr(), buffer.Length(), false);
        WriteTips2File("~~~~~ end of mmap ~~~~~%s\n", mark_info);
    }

    tickcountdiff_t get_mmap_time = tickcount_t().gettickcount() - tick;

    char appender_info[728] = {0};
    snprintf(appender_info, sizeof(appender_info), "^^^^^^^^^^" __DATE__ "^^^" __TIME__ "^^^^^^^^^^%s", mark_info);

    Write(nullptr, appender_info);
    char logmsg[256] = {0};
    snprintf(logmsg, sizeof(logmsg), "get mmap time: %" PRIu64, (int64_t)get_mmap_time);
    Write(nullptr, logmsg);

    Write(nullptr, "MARS_URL: " MARS_URL);
    Write(nullptr, "MARS_PATH: " MARS_PATH);
    Write(nullptr, "MARS_REVISION: " MARS_REVISION);
    Write(nullptr, "MARS_BUILD_TIME: " MARS_BUILD_TIME);
    Write(nullptr, "MARS_BUILD_JOB: " MARS_TAG);

    snprintf(logmsg, sizeof(logmsg), "log appender mode:%d, use mmap:%d", (int)config_.mode_, use_mmap);
    Write(nullptr, logmsg);

    if (!config_.cachedir_.empty()) {
        boost::filesystem::space_info info = boost::filesystem::space(config_.cachedir_);
        snprintf(logmsg,
                 sizeof(logmsg),
                 "cache dir space info, capacity:%" PRIuMAX " free:%" PRIuMAX " available:%" PRIuMAX,
                 info.capacity,
                 info.free,
                 info.available);
        Write(nullptr, logmsg);
    }

    boost::filesystem::space_info info = boost::filesystem::space(config_.logdir_);
    snprintf(logmsg,
             sizeof(logmsg),
             "log dir space info, capacity:%" PRIuMAX " free:%" PRIuMAX " available:%" PRIuMAX,
             info.capacity,
             info.free,
             info.available);
    Write(nullptr, logmsg);
}

主要做了什么

  1. 判断是否使用了 cachedir_ ，
    • 使用了 cachedir_，创建对应的目录，
    • 清理过期的数据，文件是否过期是通过 max_alive_time_ 来判断的
    • 迁移 cachedir_ 中的文件到 logdir_ 中
  2. 创建logdir_， 清理logdir_中过期文件， 注意 Apple 平台，将logdir_文件属性设置为NSFileProtectionNone
  3. 打开 mmap 文件映射
    • 使用了 cachedir_， mmap 映射的文件就放在 cachedir_ 中，否则在 logdir_ 中
    • mmap 文件大小默认是 kBufferBlockLength = 150 * 1024， 150 KB
    • mmap 映射失败，回退， 使用内存缓存
  4. 根据选定的压缩方式，决定 log_buff_
    • kZlib 使用 LogZlibBuffer
    • kZstd 使用 LogZstdBuffer
  5. 将 log_buff_ 中的内容刷入日志文件
    • 使用 mmap 文件映射，崩溃后， 下次进入，将 mmap 文件中的内容读出，刷到文件中
    • 通过这种方式达到崩溃了也不丢日志
  6. 开启 thread_async_ 执行 XloggerAppender::__AsyncLogThread
  7. 往 log_buff_ 中写入各种帮助信息
    • “get mmap time: %”
    • MARS_URL
    • MARS_PATH
    • ….

XloggerAppender::Write

关键的写日志接口

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
void XloggerAppender::Write(const XLoggerInfo* _info, const char* _log) {
    if (log_close_)
        return;

    SCOPE_ERRNO();

    thread_local uint32_t recursion_count = 0;
    thread_local std::string recursion_str;
    recursion_count++;

    if (consolelog_open_)
        ConsoleLog(_info, _log);
#ifdef ANDROID
    else if (_info && _info->traceLog == 1)
        ConsoleLog(_info, _log);
#endif
    if (g_log_write_callback) {
        g_log_write_callback(_info, _log);
    }

    if (2 <= recursion_count && recursion_str.empty()) {
        if (recursion_count > 10)
            return;

        recursion_str.resize(kMaxDumpLength);
        XLoggerInfo info = *_info;
        info.level = kLevelFatal;

        char recursive_log[256] = {0};
        snprintf(recursive_log,
                 sizeof(recursive_log),
                 "ERROR!!! xlogger_appender Recursive calls!!!, count:%u",
                 recursion_count);

        PtrBuffer tmp((void*)recursion_str.data(), 0, kMaxDumpLength);
        log_formater(&info, recursive_log, tmp);

        if (recursion_str.capacity() >= strnlen(_log, kMaxDumpLength)) {
            recursion_str += _log;
        }

        ConsoleLog(&info, recursion_str.c_str());
    } else {
        if (!recursion_str.empty()) {
            WriteTips2File(recursion_str.c_str());
            recursion_str.clear();
        }

        if (kAppenderSync == config_.mode_)
            __WriteSync(_info, _log);
        else
            __WriteAsync(_info, _log);
    }
    recursion_count--;
}

主要逻辑：

  1. 安全检测， 如果已经调用了 close 方法，直接 return
  2. 如果打开了控制台输出，调用输出
  3. 判断是否有递归调用，出现递归调用层数大于 等于 2， 输出错误信息到控制台，大于 10， 直接 return
  4. 没有递归调用
    • 如果是同步写， 调用 __WriteSync
    • 如果是异步写， 调用 __WriteAsync

__WriteAsync

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
void XloggerAppender::__WriteAsync(const XLoggerInfo* _info, const char* _log) {
    char temp[16 * 1024] = {0};  // tell perry,ray if you want modify size.
    PtrBuffer log_buff(temp, 0, sizeof(temp));
    log_formater(_info, _log, log_buff);

    ScopedLock lock(mutex_buffer_async_);
    if (nullptr == log_buff_)
        return;

    if (log_buff_->GetData().Length() >= kBufferBlockLength * 4 / 5) {
        //log_buff_ 长度超过 4/5，写不进去了？？
        int ret = snprintf(temp,
                           sizeof(temp),
                           "[F][ sg_buffer_async.Length() >= BUFFER_BLOCK_LENTH*4/5, len: %d\n",
                           (int)log_buff_->GetData().Length());
        log_buff.Length(ret, ret);
    }
    //写入日志到 log_buff_
    if (!log_buff_->Write(log_buff.Ptr(), (unsigned int)log_buff.Length()))
        return;
    //判断是否达到写文件的条件
    if (log_buff_->GetData().Length() >= kBufferBlockLength * 1 / 3
        || (nullptr != _info && kLevelFatal == _info->level)) {
        //通知写文件
        cond_buffer_async_.notifyAll();
    }
}

主要逻辑：

  1. 根据 XLoggerInfo 将 _log 格式化， 形式是 level + timestamp + [pid, threadId(*is main thread)] + tag + [fileName, line, funcName] + message
  2. 当 log_buff_ 的长度 大于等于 4/5 时， 该条日志不会写入， 被替换成一条 fatal 的信息日志
  3. 将格式化的日志写入log_buff_中
  4. 如果当前log_buff_日志长度大于 1/3，或者当前是一条等级为 kLevelFatal 的日志。条件变量通知 XloggerAppender::__AsyncLogThread, 将 log_buff_ 的日志刷到文件里。

XloggerAppender::__AsyncLogThread

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
void XloggerAppender::__AsyncLogThread() {
    while (true) {
        ScopedLock lock_buffer(mutex_buffer_async_);

        if (nullptr == log_buff_)
            break;
        //将 buffer 内容写入文件
        AutoBuffer tmp;
        log_buff_->Flush(tmp);
        lock_buffer.unlock();

        if (nullptr != tmp.Ptr())
            __Log2File(tmp.Ptr(), tmp.Length(), true);

        if (log_close_)
            break;
        //等待 15 分钟
        cond_buffer_async_.wait(15 * 60 * 1000);
    }
}

线程启动时机 open -> SetMode async -> thread start

主要逻辑：

  1. white 循环死循环，等待条件变量
  2. 进入循环
    • 加锁
    • log_buff_ 内容 flush 到 tmp 中
    • 调用 __Log2File 将 tmp 写入文件
    • 如果 已经 close， 跳出循环，结束线程
    • 没有 close， 继续等待下一次唤醒

__WriteSync

1
2
3
4
5
6
7
8
9
10
11
void XloggerAppender::__WriteSync(const XLoggerInfo* _info, const char* _log) {
    char temp[16 * 1024] = {0};  // tell perry,ray if you want modify size.
    PtrBuffer log(temp, 0, sizeof(temp));
    log_formater(_info, _log, log);

    AutoBuffer tmp_buff;
    if (!log_buff_->Write(log.Ptr(), log.Length(), tmp_buff))
        return;

    __Log2File(tmp_buff.Ptr(), tmp_buff.Length(), false);
}
  1. 格式化
  2. 写入 log_buff_
  3. log_buff_ 写入文件

选择异步还是同步

文件写入模式，分异步和同步，变量定义见 appender.h 里 kAppednerXX， Release版本一定要用 kAppednerAsync， Debug 版本两个都可以，但是使用 kAppednerSync 可能会有卡顿。
当日志写入模式为异步时，调用接口会把内存中的日志写入到文件。appender_flush_sync 为同步 flush，flush 结束后才会返回。 appender_flush 为异步 flush，不等待 flush 结束就返回。

__Log2File

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
void XloggerAppender::__Log2File(const void* _data, size_t _len, bool _move_file) {
    if (nullptr == _data || 0 == _len || config_.logdir_.empty()) {
        return;
    }

    ScopedLock lock_file(mutex_log_file_);

    if (config_.cachedir_.empty()) {
        //cachedir_ 为空， 打开 logdir_
        /*
         打开 logFile
         1. 处理文件切换， 如果 max_file_size_ > 0, 分割多个文件，单个文件 max_file_size_ 大小
         2. 判断是否需要切换文件，打开正确的文件
         */
        if (__OpenLogFile(config_.logdir_)) {
            //调用 fwrite 将长度_len 的 _data 写入到 logfile_ 中
            __WriteFile(_data, _len, logfile_);
            if (kAppenderAsync == config_.mode_) {
                //如果是异步写入，关闭 log 文件
                __CloseLogFile();
            }
        }
        return;
    }

 
    struct timeval tv;
    gettimeofday(&tv, nullptr);
    
    /*
     cachedir_ 不为空，根据缓存策略，判断是否写入 cachedir_ 或者直接写入 logfile_
     获取操作的文件路径
     内部处理文件切换逻辑
     */
    char logcachefilepath[1024] = {0};
    __MakeLogFileName(tv, config_.cachedir_, config_.nameprefix_.c_str(), LOG_EXT, logcachefilepath, 1024);
    //判断可以写入 cachedir_， 写入到 cachedir_
    bool cache_logs = __CacheLogs();
    if ((cache_logs || boost::filesystem::exists(logcachefilepath)) && __OpenLogFile(config_.cachedir_)) {
        __WriteFile(_data, _len, logfile_);
        if (kAppenderAsync == config_.mode_) {
            __CloseLogFile();
        }

        if (cache_logs || !_move_file) {
            return;
        }
        //移动文件，从 cachedir_ 移动到 logdir_
        char logfilepath[1024] = {0};
        __MakeLogFileName(tv, config_.logdir_, config_.nameprefix_.c_str(), LOG_EXT, logfilepath, 1024);
        if (__AppendFile(logcachefilepath, logfilepath)) {
            if (kAppenderSync == config_.mode_) {
                __CloseLogFile();
            }
            //移动完成后，删除 cachedir_ 中的旧文件
            boost::filesystem::remove(logcachefilepath);
        }
        return;
    }

    //不满足写入 cachedir_， 写入 logdir_
    bool write_success = false;
    bool open_success = __OpenLogFile(config_.logdir_);
    if (open_success) {
        write_success = __WriteFile(_data, _len, logfile_);
        if (kAppenderAsync == config_.mode_) {
            __CloseLogFile();
        }
    }

    if (!write_success) {
        if (open_success && kAppenderSync == config_.mode_) {
            __CloseLogFile();
        }

        if (__OpenLogFile(config_.cachedir_)) {
            __WriteFile(_data, _len, logfile_);
            if (kAppenderAsync == config_.mode_) {
                __CloseLogFile();
            }
        }
    }
}

主要的就是

  • 打开文件，准备写入 __OpenLogFile
  • 写入文件 __WriteFile
  • 写入文件完成，关闭文件 __CloseLogFile

__OpenLogFile

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
bool XloggerAppender::__OpenLogFile(const std::string& _log_dir) {
    if (config_.logdir_.empty())
        return false;

    struct timeval tv;
    gettimeofday(&tv, nullptr);

    if (nullptr != logfile_) {
        //已打开文件
        time_t sec = tv.tv_sec;
        tm tcur = *localtime((const time_t*)&sec);
        tm filetm = *localtime(&openfiletime_);

        if (filetm.tm_year == tcur.tm_year && filetm.tm_mon == tcur.tm_mon && filetm.tm_mday == tcur.tm_mday) {
            //文件打开时间是今天，返回 true
            return true;
        }
        //关闭文件
        fclose(logfile_);
        logfile_ = nullptr;
    }
    
    uint64_t now_tick = gettickcount();
    time_t now_time = tv.tv_sec;

    openfiletime_ = tv.tv_sec;

    char logfilepath[1024] = {0};
    __MakeLogFileName(tv, _log_dir, config_.nameprefix_.c_str(), LOG_EXT, logfilepath, 1024);

    if (now_time < last_time_) {
        //当前时间小于 last_time_, 这咋出现的？
        logfile_ = fopen(last_file_path_, "ab");
        //打开失败，将错误输出到控制台
        if (nullptr == logfile_) {
            __WriteTips2Console("open file error:%d %s, path:%s", errno, strerror(errno), last_file_path_);
        }

#ifdef __APPLE__
        assert(logfile_);
#endif
        return nullptr != logfile_;
    }
    //打开文件
    logfile_ = fopen(logfilepath, "ab");

    if (nullptr == logfile_) {
        __WriteTips2Console("open file error:%d %s, path:%s", errno, strerror(errno), logfilepath);
    }
    
    if (0 != last_time_ && (now_time - last_time_) > (time_t)((now_tick - last_tick_) / 1000 + 300)) {
        /*
         
         系统时间差 gapA = now_time - last_time_
         cpu 时钟 gapB = (now_tick - last_tick_) / 1000
         gapA - gapB > 300 secs
         
         为啥会出现这种情况？
         系统休眠，tick 会停止，唤醒后，tick 继续。 但是时间应该是同步到网络，因此出现 gapA > gapB 的情况。
         
         出现了记录一下，将信息写入文件。
         */
        
        struct tm tm_tmp = *localtime((const time_t*)&last_time_);
        char last_time_str[64] = {0};
        strftime(last_time_str, sizeof(last_time_str), "%Y-%m-%d %z %H:%M:%S", &tm_tmp);

        tm_tmp = *localtime((const time_t*)&now_time);
        char now_time_str[64] = {0};
        strftime(now_time_str, sizeof(now_time_str), "%Y-%m-%d %z %H:%M:%S", &tm_tmp);

        char log[1024] = {0};
        snprintf(log,
                 sizeof(log),
                 "[F][ last log file:%s from %s to %s, time_diff:%ld, tick_diff:%" PRIu64 "\n",
                 last_file_path_,
                 last_time_str,
                 now_time_str,
                 now_time - last_time_,
                 now_tick - last_tick_);

        AutoBuffer tmp_buff;
        log_buff_->Write(log, strnlen(log, sizeof(log)), tmp_buff);
        __WriteFile(tmp_buff.Ptr(), tmp_buff.Length(), logfile_);
    }
    //将 logfilepath 保存在 last_file_path_ 中
    memcpy(last_file_path_, logfilepath, sizeof(last_file_path_));
    //更新 last_tick_ 和 last_time_
    last_tick_ = now_tick;
    last_time_ = now_time;

#ifdef __APPLE__
    assert(logfile_);
#endif
    return nullptr != logfile_;
}

主要逻辑

1
2
3
4
5
6
7
bool XloggerAppender::__OpenLogFile(const std::string& _log_dir) {
    char logfilepath[1024] = {0};
    __MakeLogFileName(tv, _log_dir, config_.nameprefix_.c_str(), LOG_EXT, logfilepath, 1024);
    //打开文件
    logfile_ = fopen(logfilepath, "ab");
    return nullptr != logfile_;
}
  • 获取 log 文件路径
    • __MakeLogFileName 内部处理了文件切换的逻辑，判断需要切换文件，就生成新的文件名
  • 打开文件

__MakeLogFileName

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
void XloggerAppender::__MakeLogFileName(const timeval& _tv,
                                        const std::string& _logdir,
                                        const char* _prefix,
                                        const std::string& _fileext,
                                        char* _filepath,
                                        unsigned int _len) {
    long index = 0;
    std::string logfilenameprefix = __MakeLogFileNamePrefix(_tv, _prefix);
    if (max_file_size_ > 0) {
        // max_file_size_ > 0, 表示 log 会分开写入多个文件，每个文件限制 max_file_size_ 大小
        index = __GetNextFileIndex(logfilenameprefix, _fileext);
    }

    std::string logfilepath = _logdir;
    logfilepath += "/";
    logfilepath += logfilenameprefix;

    if (index > 0) {
        char temp[24] = {0};
        snprintf(temp, 24, "_%ld", index);
        logfilepath += temp;
    }

    logfilepath += ".";
    logfilepath += _fileext;

    strncpy(_filepath, logfilepath.c_str(), _len - 1);
    _filepath[_len - 1] = '\0';
}

主要逻辑：

log 文件名生

  • 如果 max_file_size_ > 0, log 会分开写入多个文件，每个文件限制 max_file_size_ 大小
    • 文件命名会包含 index， index 递增。当前文件大小达到 max_file_size_， index ++

__GetNextFileIndex

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
long XloggerAppender::__GetNextFileIndex(const std::string& _fileprefix, const std::string& _fileext) {
    std::vector<std::string> filename_vec;
    //读取logdir_目录下的文件，这些文件以 _fileprefix 开头，扩展名为 _fileext
    //如果cachedir_被使用， 将 cachedir_ 目录下的文件也读入 filename_vec
    __GetFileNamesByPrefix(config_.logdir_, _fileprefix, _fileext, filename_vec);
    if (!config_.cachedir_.empty()) {
        __GetFileNamesByPrefix(config_.cachedir_, _fileprefix, _fileext, filename_vec);
    }

    long index = 0;  // long is enought to hold all indexes in one day.
    if (filename_vec.empty()) {
        return index;
    }
    // high -> low
    std::sort(filename_vec.begin(), filename_vec.end(), __string_compare_greater);
    std::string last_filename = *(filename_vec.begin());
    std::size_t ext_pos = last_filename.rfind("." + _fileext);
    std::size_t index_len = ext_pos - _fileprefix.length();
    if (index_len > 0) {
        std::string index_str = last_filename.substr(_fileprefix.length(), index_len);
        if (strutil::StartsWith(index_str, "_")) {
            index_str = index_str.substr(1);
        }
        index = atol(index_str.c_str());
    }
    
    //上面根据文件 index 倒叙排列
    //获取最新 index 文件大小

    uint64_t filesize = 0;
    std::string logfilepath = config_.logdir_ + "/" + last_filename;
    if (boost::filesystem::exists(logfilepath)) {
        filesize += boost::filesystem::file_size(logfilepath);
    }
    if (!config_.cachedir_.empty()) {
        logfilepath = config_.cachedir_ + "/" + last_filename;
        if (boost::filesystem::exists(logfilepath)) {
            filesize += boost::filesystem::file_size(logfilepath);
        }
    }
    //如果 index 对应的文件大小 大于 max_file_size_ ,返回 index +1, 代表需要创建新文件
    //否则，继续在当前 index 文件写入
    
    return (filesize > max_file_size_) ? index + 1 : index;
}

主要逻辑：

  • 将 cache 和 log 目录下， 对应的 log 文件递减排序， 栈顶部是最新写入的 log 文件
  • 判断是否需要切分到下个文件，如果需要切分，index+1， 否则返回当前 index

__WriteFile

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
bool XloggerAppender::__WriteFile(const void* _data, size_t _len, FILE* _file) {
    if (nullptr == _file) {
        assert(false);
        return false;
    }

    long before_len = ftell(_file);
    if (before_len < 0)
        return false;

    if (1 != fwrite(_data, _len, 1, _file)) {
        int err = ferror(_file);

        __WriteTips2Console("write file error:%d", err);

        ftruncate(fileno(_file), before_len);
        fseek(_file, 0, SEEK_END);

        char err_log[256] = {0};
        snprintf(err_log, sizeof(err_log), "\nwrite file error:%d\n", err);

        AutoBuffer tmp_buff;
        log_buff_->Write(err_log, strnlen(err_log, sizeof(err_log)), tmp_buff);

        fwrite(tmp_buff.Ptr(), tmp_buff.Length(), 1, _file);

        return false;
    }

    return true;
}

主要就是调用 fwrite 写文件。

__CloseLogFile

1
2
3
4
5
6
7
8
9
void XloggerAppender::__CloseLogFile() {
    if (nullptr == logfile_)
        return;

    openfiletime_ = 0;
    fclose(logfile_);
    logfile_ = nullptr;
}

调用 fclose 关闭文件。

1
2
3
4
if (kAppenderAsync == config_.mode_) {
    //如果是异步写入，关闭 log 文件
    __CloseLogFile();
}

上面看到异步写入，写入之后关闭了文件。

压缩和加密是怎么做的

我们选定 zlib 压缩模式， 关联的 logbuffer 就是 LogZlibBuffer

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
class LogZlibBuffer : public LogBaseBuffer {
 public:
    LogZlibBuffer(void* _pbuffer, size_t _len, bool _is_compress, const char* _pubkey);
    ~LogZlibBuffer();

 public:
    virtual size_t Compress(const void* src, size_t inLen, void* dst, size_t outLen);
    virtual void Flush(AutoBuffer& _buff);

 private:
    bool __Reset();
    char __GetMagicSyncStart();
    char __GetMagicAsyncStart();

 private:
    z_stream cstream_;
};

}  // namespace xlog
}

LogZlibBuffer 继承自 LogZlibBuffer， 重写了 compress 和 flush 方法 。

因此 LogZlibBuffer 调用 write 方法写入的时候做了压缩和加密，看代码

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
bool LogBaseBuffer::Write(const void* _data, size_t _length) {
    if (NULL == _data || 0 == _length) {
        return false;
    }
    if (buff_.Length() == 0) {
        if (!__Reset())
            return false;
    }

    size_t before_len = buff_.Length();
    size_t write_len = _length;

    if (is_compress_) { //压缩
        //计算剩余空间
        uInt avail_out = (uInt)(buff_.MaxLength() - buff_.Length() - log_crypt_->GetTailerLen());
        //压缩后的长度
        write_len = Compress(_data, _length, buff_.PosPtr(), avail_out);
        if (write_len == (size_t)-1) {
            return false;
        }
    } else {
        //不压缩，直接写入
        buff_.Write(_data, _length);
    }
    
    //计算已经加密的长度
    before_len -= remain_nocrypt_len_;

    std::string out_buffer;
    //之前未加密的长度
    size_t last_remain_len = remain_nocrypt_len_;
    //加密 之前未为加密的数据+新写入的长度
    log_crypt_->CryptAsyncLog((char*)buff_.Ptr() + before_len,
                              write_len + remain_nocrypt_len_,
                              out_buffer,
                              remain_nocrypt_len_);
    
    //加密后的数据写入 buffer， 从 before_len 位置开始写入
    buff_.Write(out_buffer.data(), out_buffer.size(), before_len);
    //更新 buffer 长度
    before_len += out_buffer.size();
    buff_.Length(before_len, before_len);
    
    //更新 buffe 头部的长度标识
    log_crypt_->UpdateLogLen((char*)buff_.Ptr(), (uint32_t)(out_buffer.size() - last_remain_len));

    return true;
}


写入的时候，先压缩再加密， 保存到内部的 buff_ 中。

看一下 log_crypt_->UpdateLogLen

1
2
3
4
void LogCrypt::UpdateLogLen(char* _data, uint32_t _add_len) {
    uint32_t currentlen = (uint32_t)(GetLogLen(_data, GetHeaderLen()) + _add_len);
    memcpy(_data + GetHeaderLen() - sizeof(uint32_t) - sizeof(char) * 64, &currentlen, sizeof(currentlen));
}

上面说到 buffer 头部格式

1
2
|magic start(char)|seq(uint16_t)|begin hour(char)|end hour(char)|length(uint32_t)|crypt key(char*64)|

崩溃了， mmap 写入文件，下次重新进入，重新 mmap 也能拿到之前数据长度。

看一下 flush

1
2
3
4
5
6
7
8
9
10
11
12
13
void LogBaseBuffer::Flush(AutoBuffer& _buff) {
    if (log_crypt_->GetLogLen((char*)buff_.Ptr(), buff_.Length()) == 0) {
        __Clear();
        return;
    }

    __Flush();
    
    _buff.Write(buff_.Ptr(), buff_.Length());

    __Clear();
}

主要逻辑：

将 logBuffer 中存的 header + 压缩加密的数据， 读取到 AutoBuffer 中。
读取完毕，清理 logBuffer。

总结

  1. xlog 使用了 mmap 技术来解决崩溃丢日志的问题
  2. 支持压缩，加密
  3. 支持单文件和根据大小切分多文件
  4. 支持同步写异步写，release 模式要开启异步模式
微信 xlog 源码分析
https://yxibng.github.io/2024/03/29/微信 xlog 源码分析/
作者
yxibng
发布于
2024年3月29日
许可协议