muduo网络库之高性能日志实现

muduo网络库之高性能日志实现

---

---

前言

在服务器端编程中，日志是必不可少的，在生产环境中应该做到Log Everything All The Time。一个多功能日志，需要有以下四个功能：1日志消息具有多个级别；2日志消息具有多个目的地；3日志消息可以配置；4可以设置运行时候的过滤器。

---

一、日志类的整体架构是什么？

一个日志库大体可以分为前端和后端两部分。前端是供应用程序使用的接口API，并生成日志消息；后端则负责把日志消息写道目的地。这两部分可能简单到只有一个回调函数：void output(const char*message,int len),其中message字符串是一条完整的日志消息，包含日志级别，时间戳，源文件位置，线程id等基本字段，以及程序输出的消息内容。

二、具体实现

1.前端部分

首先前端部分通过LogStream类进行运算符重载，将日志内容输入到LogStream成员变量FixBuffer中。然后LogStream又是Impl的内部成员，Impl是Logging的内部成员，因此muduo在设计的时候在构造函数中调用impl的构造函数，从而对日志前半部分进行格式化（日期+时间+微妙+线程id+日志级别，在通过Logging的成员函数取出Logstream对象通过输出运算符<<
向其中添加正文，最后在Logging的析构函数中进行日志的最后格式化（源文件名+行号）因此可以通过宏定义Logging的临时对象来完成日志的输入。
另外Logging获取日志内容之后如何将内容输入到我们实际想让记录的地方，就需要在析构函数中执行输出回调函数，以及发生错误时候执行flush回调函数。

代码如下（宏定义部分）：

import numpy as np
#define LOG_TRACE if(muduo::Logging::getLevel()<=muduo::Logging::TRACE)\
    muduo::Logging(__FILE__, __LINE__, muduo::Logging::TRACE, __func__).stream()
#define LOG_DEBUG if (muduo::Logging::getLevel() <= muduo::Logging::DEBUG) \
  muduo::Logging(__FILE__, __LINE__, muduo::Logging::DEBUG, __func__).stream()
#define LOG_INFO if (muduo::Logging::getLevel() <= muduo::Logging::INFO) \
  muduo::Logging(__FILE__, __LINE__).stream()
#define LOG_WARN muduo::Logging(__FILE__, __LINE__, muduo::Logging::WARN).stream()
#define LOG_ERROR muduo::Logging(__FILE__, __LINE__, muduo::Logging::ERROR).stream()
#define LOG_FATAL muduo::Logging(__FILE__, __LINE__, muduo::Logging::FATAL).stream()
#define LOG_SYSERR muduo::Logging(__FILE__, __LINE__, false).stream()
#define LOG_SYSFATAL muduo::Logging(__FILE__, __LINE__, true).stream()

构造函数以及析构函数部分

Logging::Impl::Impl(Level level, int savedErrno, const SourceFile& file, int line)
  : time_(Timestamp::now()),
    stream_(),
    level_(level),
    line_(line),
    basename_(file)
{
  formatTime();//输出响应的时间
  CurrentThread::getTid();

  //输出id到缓冲区
  stream_ << T(CurrentThread::getStringTid(), CurrentThread::getLength());
  //输入日志级别到缓冲区
  stream_ << T(LogLevelName[level], 7);
  //是否打印错误日志
  if (savedErrno != 0)
  {
    stream_ << strerror_tl(savedErrno) << " (errno=" << savedErrno << ") ";
  }
}

Logging::~Logging(){
  m_impl.finish();
  const LogStream::BUFFER& buf(stream().buffer());
  g_output(buf.get_data(), buf.length());
  if (m_impl.level_ == FATAL)
  {
    g_flush();//刷新
    abort();
  }
}

muduo在现在的PC上可以写到每s200万条消息，实现这样的指标，muduo日志库的实现有几点优化值得一提：

1:时间戳字符串中的日期和时间是分两部分进行存储，1s之内的多条日志只需要格式化微s部分即可。
2：日志消息正文前的字段是等长的，因此可以避免在运行期间求字符串长度。因为编译器认识memcpy函数，对于定长的内存复制会在编译期把他inline展开为高效的目标代码。
3： 线程id是预先格式化为字符串，在日志输出的时候只需要简单拷贝几个字节
4：在编译期间就计算好了basename，避免运行期间strschr开销。

2.后端部分

也就是写异步日志部分。多线程日志库要实现线程安全，第一种方法是加锁，第二种方法是每个线程写一个日志，但是最好是写在一个文件中这样的话便于分析。日志库部分不应该采取同步日志部分，直接向磁盘中写入数据可能阻塞很久，这样会影响心跳机制或者死锁检测触发，所以应该使用异步日志是必须的。故，需要用一个日志队列将日志前端的数据传送到后端进行处理，但这个"队列”不是现成的BlockingQueuestd::string,因此不用每次产生一个日志都通知（notify())接收方。muduo这里采用的是双缓冲技术，基本思路是准备两个buffer：A与B，前端负责将A填数据，后端则负责B中的数据写入文件。当A满了则交换A，B，如此往复。这样做的好处：1不用直接向磁盘写消息；2也避免每条日志都触发后端日志线程，减少了线程唤醒的频率降低开销。为了及时将日志文件写入消息，即便A没有满，日志库也每隔3s执行一次交换操作。

在实际实现中我们采取了四个缓冲区，这样可以进一步避免日志前端的等待数据结构如下：

    typedef muduo::detail::FixedBuffer<muduo::detail::BUFFER_LENGTH_LONG> Buffer;//设置存放内存的缓冲区
    typedef std::vector<std::unique_ptr<Buffer>>BufferVector;//存放内存指针
    typedef BufferVector::value_type BufferPtr;//定义内存缓冲区的指针
    BufferPtr currentBuffer_;//当前存储日志的容器
    BufferPtr nextBuffer_;//预备容器
    std::vector<BufferPtr>buffers_;//容器队列

每个容器大小为4MB，至少可以放1000条日志消息，std::unique_ptr具备移动语义，而且可以自己管理生命周期。

再来看前端具体的发送代码也就是，回调函数output的具体实现：

    //前端不断的存放日志
    void AsyLogging::append(const char* logline,int len){
        MUtexLockGuard guard(mutex_);//对多线程临界区访问要加锁
        if(currentBuffer_->avail()>len){
            currentBuffer_->append(logline,len);
        }
        else{
            buffers_.push_back(std::move(currentBuffer_));
            if(nextBuffer_){
                currentBuffer_=std::move(nextBuffer_);
            }
            else{
                currentBuffer_.reset(new Buffer);
            }
            currentBuffer_->append(logline,len);
            condition_.notify();//通知后端消费者进程
        }
    }

前端来一条日志如果当前缓冲区大小足够则直接append，这里拷贝一条日志消息不会造成多大开销，因为其他部分都是对指针的操作。如果当前缓冲区大小都不够了，则将当前缓冲区移入数组，并将另外一个块准备好的缓冲区作为当前缓冲区，然后追加日志消息后端开始写日志。如果前端写日志很快一下子把两块缓冲区都使用完了，那么只好重新分配一块缓冲区，这种情况很少见。

后端具体实现：

    //后端消费者线程
    void AsyLogging::threadFunc(){
        assert(running_==true);
        latch_.CountDown();

        LogFile output(basename_,rollSize_,false,flushInterval_,100);
        BufferPtr newBuffer1(new Buffer);
        BufferPtr newBuffer2(new Buffer);
        newBuffer1->clear();
        newBuffer2->clear();
        BufferVector buffersToWrite;
        buffersToWrite.reserve(16);

        //一直在运行
        while(running_){

            assert(newBuffer1 && newBuffer1->length() == 0);
            assert(newBuffer2 && newBuffer2->length() == 0);
            assert(buffersToWrite.empty());

            //获取生产者数据同时对生产者的缓冲区进行补充
            {   
                MUtexLockGuard guard(mutex_);
                if(buffers_.empty()){
                    
                    condition_.waitForSeconds(flushInterval_);//进行超时等待
                }
                //等待完毕后
                buffers_.push_back(std::move(currentBuffer_));
                //交换之后bufferToWrite有数据，buffers_没有数据了
                buffersToWrite.swap(buffers_);

                //重新对生存者缓冲区进行补充
                currentBuffer_=std::move(newBuffer1);
                if(!nextBuffer_){
                    nextBuffer_=std::move(newBuffer2);
                }
            }

            assert(!buffersToWrite.empty());

            if(buffersToWrite.size()>25){
                char buf[256];
                snprintf(buf, sizeof buf, "Dropped log messages at %s, %zd larger buffers/n",
                        Timestamp::now().to_string().c_str(),
                        buffersToWrite.size()-2);
                fputs(buf, stderr);
                output.append(buf, static_cast<int>(strlen(buf)));//错误信息写入日志
                buffersToWrite.erase(buffersToWrite.begin()+2, buffersToWrite.end());//只保留最开始的两个
            }

            //正式开始写日志,只有一消费者进程不需要加锁
            for(auto&buffer:buffersToWrite){
                output.append(buffer->get_data(),buffer->length());
            }

            if(buffersToWrite.size()>2){
                buffersToWrite.resize(2);
            }


            //是否使用了newBuffer1缓冲区
            if(!newBuffer1){
                assert(!buffersToWrite.empty());
                newBuffer1=std::move(buffersToWrite.back());
                buffersToWrite.pop_back();
                newBuffer1->reset();
            }

            //是否使用了newBuffer2缓冲区
            if(!newBuffer2){
                assert(!buffersToWrite.empty());
                newBuffer2=std::move(buffersToWrite.back());
                buffersToWrite.pop_back();
                newBuffer1->reset();
            }
            buffersToWrite.clear();
            output.flush();//缓冲区刷新到磁盘
            
            printf("-------------------------%s---------------------------------\n","一次刷新结束");
        }
        output.flush();

        
    }

需要注意的是后端pthread_cond_waittime,在等待期间会释放掉互斥锁避免一直卡住进程。后端也提出了日志堆积的处理方式：如果是同步写日志的话不需要担心，因为阻塞IO就限制了前端的写入速度。但是如果是异步日志的话，是有可能造成日志堆积的，这个时候就需要丢弃后面多余的日志保存开始的两个日志，这样可以防止日志库本身引起程序故障，将来或许可以加入网络报警功能，通知人工介入快速修复。

最后输出到目标文件中：

        void LogFile::append_unlocked(const char* logline, int len){
            m_appendfile->append(logline,len);
            if(m_appendfile->m_bytes>rollSize_){
                rollFile();
            }
            else{
                count_++;
                if(count_>checkEveryN_){
                    count_ = 0;
                    time_t now=time(NULL);
                    //天数发生了改变
                    time_t thisPeriod_ = now / kRollPerSeconds_ * kRollPerSeconds_;
                    if (thisPeriod_ != startOfPeriod_)
                    {
                        rollFile();
                    }
                    //到时间刷新了
                    if(now-lastFlush_>flushInterval_){
                        lastFlush_ = now;
                        flush();
                    }
                }
            }

        }

这里主要是对于文件的大小以及日期到达临界值时候进行日志的翻滚！

---

总结

`muduo的日志类关键是搞清楚类之间的关系，分析前后端之间如何交互数据，以及如何高效交互数据