从Mars的Xlog组件学习日志系统

144
作者 与狼同行
2017.01.01 22:08 字数 2103

看完了微信团队对Xlog的整体介绍,迫不及待开始了研究,理论部分我是完全参考微信终端跨平台组件 mars 系列(一) - 高性能日志模块xlog 这篇文章。
看完这篇理论,文章通过各个点来阐述如何创造这样的高性能、可扩展的日志系统的想法和设计,于是我结合源码配合一起梳理一下Xlog的几个部分,无论以后自己造轮子作为借鉴或者使用Xlog,都有很多价值。

方案:
使用流式压缩方式对单行日志进行压缩,压缩加密后写进作为 log 中间 buffer的 mmap 中,当 mmap 中的数据到达一定大小后再写进磁盘文件中

从github上的官方文档来看,Xlog的初始化涉及三个语句:

  1. xlogger_SetLevel(kLevelDebug);
  2. appender_set_console_log(true);
  3. appender_open(kAppednerAsync, [logPath UTF8String], "Test");

头两句第一个是设置log级别,第二句是控制台是否打印语句的开关。
最重要的是第三句话 appender_open
Appender模块是是整个日志系统负责写日志的模块。这里直接从顶部文章搬运一下结构图片。这里appender_open是打开log目录下的日志文件,进行一些初始化操作。


E6D06D6B-F811-404D-8B98-634FA8B06C19.png
void appender_open(TAppenderMode _mode, const char* _dir, const char* _nameprefix) {
    xlogger_SetAppender(&xlogger_appender);  //设置xlogger的appender

    //创建路径文件夹
    boost::filesystem::create_directories(_dir);
    //tickcount_t用于计算每个步骤执行时间。
    tickcount_t tick;
    tick.gettickcount();
    //第一步作用是每次启动的时候会清理日志,防止占用太多用户磁盘空间
    __del_timeout_file(_dir);
    tickcountdiff_t del_timeout_file_time = tickcount_t().gettickcount() - tick;
    tick.gettickcount();
   //设置mmap文件的路径
    char mmap_file_path[512] = {0};
    snprintf(mmap_file_path, sizeof(mmap_file_path), "%s/%s.mmap2", sg_cache_logdir.empty()?_dir:sg_cache_logdir.c_str(), _nameprefix);
    //检查是否mmap文件中有数据,如果没有直接退出,如果有,清除日志缓存,同时构造LogBuffer对象。
    bool use_mmap = false;
    if (OpenMmapFile(mmap_file_path, kBufferBlockLength, sg_mmmap_file))  {
        sg_log_buff = new LogBuffer(sg_mmmap_file.data(), kBufferBlockLength, true);
        use_mmap = true;
    } else {
        char* buffer = new char[kBufferBlockLength];
        sg_log_buff = new LogBuffer(buffer, kBufferBlockLength, true);
        use_mmap = false;
    }

    if (NULL == sg_log_buff->GetData().Ptr()) {
        if (use_mmap && sg_mmmap_file.is_open())  CloseMmapFile(sg_mmmap_file);
        return;
    }
    AutoBuffer buffer;
    sg_log_buff->Flush(buffer);
    ...
    BOOT_RUN_EXIT(appender_close);
}

日志目录下的log文件为每天的日志文件,而mmap是日志缓存文件,因此会有如下策略:
这部分可以概括为:
1. 首先日志系统有一个过期的设置,日志log文件过期就自动删除
2. 每次启动清空 mmap 的日志缓存
3. 设置日志系统的Appender模块,应该可以通过自己重写appender函数,实现自己的一套方案,也即是顶部文章所说的热插拔。

题外话:

  1. 刚开始使用时发现main.mm中 setxattr(...);这个方法,以为是 mars 提供的初始化方法,后来才知道这个方法是系统库提供,为了防止该路径下的日志文件被 iCloud 同步。可以参阅官方文档: https://developer.apple.com/library/content/qa/qa1719/_index.html

关于mmap

上文中关于 appender_open 方法中有这么一句 OpenMmapFile(mmap_file_path, kBufferBlockLength, sg_mmmap_file),这个方法的实现就是使用了mmap方法

mmap的介绍
mmap是一种内存映射文件的方法,将一个文件或者其它对象映射到进程的地址空间,实现文件磁盘地址和进程虚拟地址空间中的映射关系。维持关系之后,进程就可以采用指针的方式读写操作这一段内存,而系统会自动回写脏页面到对应的文件磁盘上,即完成了对文件的操作而不必再调用read,write等系统调用函数。但内核空间对这段区域的修改也直接反映用户空间,从而可以实现不同进程间的文件共享。


A2179609-D37C-45D7-A181-1C3E225A69BB.png

文件的一般读写操作为了提高读写效率和保护磁盘,使用了页缓存机制。这样造成读文件时需要先将文件页从磁盘拷贝到页缓存中,由于页缓存处在内核空间,不能被用户进程直接寻址,所以还需要将页缓存中数据页再次拷贝到内存对应的用户空间中。这样,通过了两次数据拷贝过程,才能完成进程对文件内容的获取任务。写操作也是一样,待写入的buffer在内核空间不能直接访问,必须要先拷贝至内核空间对应的主存,再写回磁盘中(延迟写回),也是需要两次数据拷贝。

总而言之,常规文件操作需要从磁盘到页缓存再到用户主存的两次数据拷贝。而mmap操控文件,只需要从磁盘到用户主存的一次数据拷贝过程。说白了,mmap的关键点是实现了用户空间和内核空间的数据直接交互而省去了空间不同数据不通的繁琐过程。因此mmap效率更高。

而之后我们可以通过使用mmap返回的指针 bufferPtr ,然后使用指针直接写入数据。

Log接口

首先来看一下 Mars.framework 提供的log接口。

xlogger_IsEnabledFor(_level)    
xlogger_AssertP(...)              
xlogger_Assert(...)            
xlogger_VPrint(...)            
xlogger_Print(...)                
xlogger_Write(...)

如果你已经使用过 Xlogger
从iOS的案例项目中可以看到LOG_INFO,这本身就是平台适配层对Mars框架的log接口进行的一层封装,其实是调用了xlogger_Write方法,看一下具体实现。

void __xlogger_Write_impl(const XLoggerInfo* _info, const char* _log) {

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

而gs_appender就是上面所说appender函数,appender就是负责单行日志的写入。

static void __appender_async(const XLoggerInfo* _info, const char* _log) {
    ScopedLock lock(sg_mutex_buffer_async);
    if (NULL == sg_log_buff) return;

    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);

    if (!sg_log_buff->Write(log_buff.Ptr(), (unsigned int)log_buff.Length())) return;

    if (sg_log_buff->GetData().Length() >= kBufferBlockLength*1/3 || (NULL!=_info && kLevelFatal == _info->level)) {
       sg_cond_buffer_async.notifyAll();
    }

}

异步的appender方法可以归纳为:

  1. 对日志进行formater
  2. 写入日志
  3. 发送通知。

而同步的Write的方法没有最后发送通知的部分,在写入的日志的部分也稍有不同。
然后看一下LogBuffer::Write方法,根据同步模式和异步模式,Write 方法也分为了同步和异步,这里进一步查看一下异步模式的 Write 方法:

bool LogBuffer::Write(const void* _data, size_t _length) {
    size_t before_len = buff_.Length();
    size_t write_len = _length;
    //1. 先进行流式压缩
    if (is_compress_) {
        cstream_.avail_in = (uInt)_length;
        cstream_.next_in = (Bytef*)_data;

        uInt avail_out = (uInt)(buff_.MaxLength() - buff_.Length());
        cstream_.next_out = (Bytef*)buff_.PosPtr();
        cstream_.avail_out = avail_out;

        if (Z_OK != deflate(&cstream_, Z_SYNC_FLUSH)) {
            return false;
        }

        write_len = avail_out - cstream_.avail_out;
    } else {
        buff_.Write(_data, _length);
    }


    char crypt_buffer[4096] = {0};
    size_t crypt_buffer_len = sizeof(crypt_buffer);

    // 2. 在进行加密
    s_log_crypt->CryptAsyncLog((char*)buff_.Ptr() + before_len, write_len, crypt_buffer, crypt_buffer_len);
    // 3. 把压缩加密的日志写入mmap中
    buff_.Write(crypt_buffer, crypt_buffer_len, before_len);
    buff_.Length(before_len + crypt_buffer_len, before_len + crypt_buffer_len);

    s_log_crypt->UpdateLogLen((char*)buff_.Ptr(), (uint32_t)crypt_buffer_len);

    return true;
}

可以看到步骤这个异步LogBuffer中Write方法几乎是重中之重,涉及到了数据流的压缩、加密和写入。

关于流式压缩

看到了 Write 方法中出现这里的压缩部分:

 if (Z_OK != deflate(&cstream_, Z_SYNC_FLUSH)) {
            return false;
  }

这里deflate是压缩数据流的算法. 任何需要流式压缩的地方都可以用。它是由Huffman 编码 和 LZ77压缩 两个算法组成。

  1. Huffman 编码:huffman编码是一种可变长编码( VLC:variable length coding))方式,于1952年由huffman提出。依据字符在需要编码文件中出现的概率提供对字符的唯一编码,并且保证了可变编码的平均编码最短,被称为最优二叉树,有时又称为最佳编码。

  2. LZ77:LZ77压缩算法靠查找重复的序列. 这里使用术语:”滑动窗口”, 它的意思是:在任何的数据点上, 都记录了在此之前的字符. 32k的滑动窗口表示压缩器(解压器)能记录前32768个字符. 当下一个需要压缩的字符序列能够在滑动窗口中找到, 这个序列会被两个数字代替: 一个是距离,表示这个序列在窗口中的起始位置离窗口的距离, 一个是长度, 字符串的长度.

举例 : 将字符串“Blah blah b ”压缩为“Blah b[D=5,L=5] ”

根据顶部文章的介绍,如之上的代码所示,的确是单行日志压缩,作为日志系统,应该避免造成CPU负担,因此避免了多个日志同时压缩的方式。

关于加密

这次开源没有提供具体的加密算法,但是对单行日志进行了编码。
先来说一下解码的部分,刚开始使用 Mars 的 Xlogger 组件,看着输出的xlog格式的文件却不知道如何解码,github也没介绍怎么解码,后来看了一下源码,在 mars/log/crypt/ 目录下有一个
decode_mars_log_file 的python文件,把Xlog格式的加密文件,放到该目录下,跑一下脚本,就会生成解码后的log文件。

至于加密的部分,如下图所示,加密部分的代码会将其日志变为如下格式,拥有日志头信息和尾部,然后再变为二进制格式,然后最终写入到xlog格式的文件中。


6E0EE9E2-7896-449F-AFD9-60341BC892FD.png


下面以同步模式的日志加密为例子:

void LogCrypt::CryptSyncLog(const char* const _log_data, size_t _input_len, char* _output, size_t& _output_len) {
    uint16_t seq = __GetSeq(false);
    uint32_t len = std::min(_input_len, _output_len - GetHeaderLen() - GetTailerLen());

    memcpy(_output + GetHeaderLen(), _log_data, len);
    _output[GetHeaderLen() + len] = kMagicEnd;
    _output[0] = kMagicSyncStart;

    memcpy(_output + 1, &seq, sizeof(seq));

    struct timeval tv;
    gettimeofday(&tv, 0);
    time_t sec = tv.tv_sec;
    tm tm_tmp = *localtime((const time_t*)&sec);

    char hour = (char)tm_tmp.tm_hour;

    memcpy(_output+3, &hour, sizeof(hour));
    memcpy(_output+4, &hour, sizeof(hour));
    memcpy(_output+5, &len, sizeof(len));

    _output_len = GetHeaderLen() + GetTailerLen() + len;
}

于是把xlog对单行日志从压缩到加密后写进作为 log 中间 buffer的 mmap 的部分,大致梳理了一下,源码还有很多细枝末节的地方,主体算是梳理完毕。

UI组件知识杂谈