《Linux多线程服务端编程》——高效的多线程日志

什么是日志？我也问过自己。字面意思，记录东西的。
之前面试的时候，面试官问过我，一般程序出了问题怎么调试。最常见的莫过于断点，或者我们在编程的时候条件判断响应的输出。但是这个东西在代码量小的时候是可以的，如果我们的东西很大呢，分布式的呢，几十万行的代码，也都断点吗？
日志其实就是输出的加强版，我把运行过程的信息记录下来，这样我只需要查看日志就能知道干了什么事，发生了什么。
正式开始，以上仅代表个人观点哈哈哈。

日志是什么

日志分两种：

1. 诊断日志：文本的、供人阅读的日志，用来故障诊断和追踪，也可用于性能分析。用来追踪蛛丝马迹，破案。（别藏了，我都在监控视频里看见你了，铁证如山，就是你在运行时偷懒导致出错的）
2. 交易日志：记录状态变更，通过回放日志可以逐步恢复每一次修改后的状态。

编程中主要的是第一种，我们谈第一种。
那既然要发现错误，日志应该记录什么，自己想一下先：时间肯定要的，啥时候发生的；地点肯定要的，哪块出了问题；谁肯定要的，哪个线程出了毛病。
好，看下：

1. 收到的每条信息的id；
2. 收到的每条外部消息的全文；
3. 发出的每条消息的全文，每条消息都有全局唯一的id；
4. 关键内部状态的变更等

其实就是日志里要存的消息是关键信息，要能通过这信息找到问题的根源。

概述

一个日志库大体分为前端和后端两部分。前端是供应用程序使用的接口，并生成日志消息；后端负责把日志消息写到目的地。
多线程程序中，前端和后端与单线程差异不大，每个线程有自己的前端，程序共用一个后端。所以前端的日志需要能够高效的发回后端。典型的多生产者单消费者问题。前端的要求是要快，后端的要求是要多。
说到底，日志其实也是输出。选择什么样的输出模式呢？一种是printf式，一种是C++stream<<风格。我是比较喜欢stream风格的，用起来简单自然。难得和大神老师想法一致（哈哈哈，英雄所见略同）。

功能需求

有四个功能块：

1. 日志消息有多个级别，如trace，debug，info，warn，error，fatal等。
2. 日志消息可能有多个目的地，如文件、socket等
3. 日志消息的格式可配置
4. 可以设置运行时过滤器，控制不同组件的日志消息的级别和目的地

主要还是日志的输出级别功能。不同的需求要求不同的级别，不同的级别输出不同的风格。日志输出级别运行时要可以调节，同一个执行文件可以方便地调整为上述的级别。
分布式服务系统的日志文件目的地就是本地文件，本来就是可能网络错误才写的日志，往网络里不是自寻死路。
一个服务端的运行时间可能是很长的，数据自然也会很多。那输出的日志也会很多，所以日志文件的滚动是必要的。打个比方就是比如我这个东西一天之内没有事情就没有问题了。那我就可以滚动删除24小时前的日志。或是写满1G，就换个文件。

这是作者举的例子，日志的文件名。
往文件写日志的一个常见问题是，程序崩溃，那么崩溃时的日志其实是问题的关键，但是由于崩溃，没有来得及写进日志。flush硬盘是一种方法，但是费时费力。muduo采用了：一是定期将缓冲日志flush到硬盘，二是每条日志都带有cookie（这不是曲奇，这是哨兵，他会告诉你，这个东西在哪里，就像我们浏览网站可以后退到上一个网站就是这个的功劳）告诉你函数地址。这样core dump文件中查找cookie，找到消息的位置。
日志消息的格式是固定的，如果每一次都需要解析日志格式，那也是很大的开销，格式固定不仅写起来方便，读起来也方便。不会说比对的时候，还需要一个一个挨着配对。

这个是日志消息格式：

1. 每个消息占一行，方便快速检索
2. 时间戳精确到微秒。消息通过gettimeofday获取。
3. 始终使用GMT时区（Z）。这个是我没有想到的，之前在libevent里面也有看到过时间调整，但是没有这么具象。分布式系统跨州时，统一时区会省掉很多麻烦。
4. 打印线程id，这个我们提到过，便于检查各个之间的交互。
5. 打印日志级别，如果排查error，直接看error级别就可以。
6. 打印源文件和行号，直接去该位置改BUG就行了。

性能需求

日志其实也是额外的开销，如果有问题自然有用，如果没问题删去日志自然可以优化效率。为什么需要日志就不说了，所以不能删。那我们自然就要提高日志的效率，让日志不至于影响关键进程的效率。所以，日志性能需求大概需要：

1. 每秒写几千上万条日志时没有明显损失
2. 能应对一个进程写大量日志
3. 不阻塞正常进程
4. 多线程中不会出现竞争

就是我们之前说的，日志是辅助，不能影响正常的进程工作。

这是作者提到的优化措施，具体到源码的时候再细细分析原因，现在看一下概念了解就好。

多线程异步日志

一个多线程程序的每个进程最好只写一个日志，如果每个进程写一个日志会很麻烦，需要切换文件。而且我们之前也分析过，多线程写多个文件不一定能提高效率。
所以我们可以做个缓存区的东西，所有的都往这个里面写就好了，然后它统一整理到日志文件。这个叫“异步日志”，之前我们聊过同步异步，简单理解就是阻塞非阻塞。异步日志其实就是非阻塞日志，非阻塞原因就是不要耽误正经事。
我们用一个“队列”来将日志前端的数据传送到后端（日志线程），但不必写一条就发一条（有点像TCP，打包发送）。

重点：
此处开始重点逻辑。
强调三次
哈哈哈，别害怕，没有很难。muduo日志库采用双缓冲技术，基本思路是：两块bufferA、B，前端负责往A里写日志，后端将B中的日志写入文件。之所以用两个，其实就是可以交换，A写满之后换给B，B便可以继续接收前端的日志，而A里面的写入文件。这样就可以省去等待时间，不会说写满了等待读取完毕，然后继续写。而且日志不影响整体流程，只是事后用来分析的，所以不必追求实时性，写满一块buffer再唤醒线程写入后端即可。每隔一段时间，即使写不满也换。保证每次都效率较高。
代码实现

首先看一下，声明一个buffer结构，然后声明两个迭代器，一个锁，一个条件变量。
看下发送端代码实现：

整个逻辑还是很清晰的，先加锁，如果当前buffer还有空间，那么直接把日志消息拷贝到当前buffer即可。否则，当前buffer已满，送入到bufers，然后将另一个块内存移用到当前缓冲，追加日志消息，并通知后端写入。
中间有个操作时如果写的太快，两个内存都满了，那就再分配一块新的内存。
再看后端实现：

首先是两块备用buffer，等待条件触发，这里面有个不同是，条件变量是用if的，不是用while。她的条件一个是触发，一个是超时。当条件满足时，先将curbuffer移入buffers，并将备用的一块内存移为当前内存。然后把buffers和bufferstowrite交换。后面的就可以不加锁将towrtie的内容安全写进文件。最后临界区内操作还有一个就是将另一个备份buffer替换nextbuffer，这样便始终有一个空闲预备buffer可以调用。
图示：

可以看到3s内bufferA其实并未写满，超时后后端醒来将curbuffer送入buffers，将newbuf1换为curbuffer，然后buffers和bufferwrite交换，写入文件，写完之后再把newbuffer1重新备份上。

1.8s时，A就已经写满，于是缓冲送入buffers，将nextbuffer移为当前buffer，唤醒后端写入。唤醒后端后，先将curbuffer送入buffers，然后把newbuffer1移用为当前buffer，交换buffers和towrite，然后newbuffer2替换nextbuffer，就是保证前端有两个缓冲可用，然后结束后后端有两个备份。

这是最后一种情况，工作太密集，两块buffer不够用，A满了之后换成B，然后后端也接到了通知，但是还没有处理，B就也已经被填满，此时前端就出现了无缓存可用的情况，于是我们之前看源码的时候的那块新分配代码就会出场，创建一个新的内存，之后后端终于介入，将当前的E也填入，后端将new1、2换给前端，然后将ABE写入文件，之后重新填充后端的两个备份。
E释放，避免造成page fault。
其实就是一个时刻都有备份的问题，不会导致日志到来时无缓存可存的情况，四个内存的交换使得前端始终可以写日志而不会出现等待或丢失的情况。最后作者提出了个优化方向。可以一起思考一下。

总结

这篇博文耗时比较长，中间断断续续有别的事情。所以总结一下，其实日志就是为了记录过程中的蛛丝马迹留待后续检查使用。日志的信息因此需要能找到具体的发生时间地点等。日志的格式固定，查写都方便。最主要的是日志的非阻塞实现。我们通过利用缓存区的操作实现异步写入。其实就是前端和后端的交互，我们通过四块缓存的交换实现了较为平滑的交互。其实就是前端时刻有写的地方，后端备好两块用于替换。

加油。下一章就要开始源码了。