Log4js多进程陷阱与避免

Log4js多进程陷阱与避免

基于log4js 0.6.14版本

    Log4js总共三篇博客

    《Log4js原理解析》http://write.blog.csdn.net/postedit/42844085

    《Log4js配置详解》http://blog.csdn.net/hfty290/article/details/42843737

    《Log4js多进程陷阱与避免》http://blog.csdn.net/hfty290/article/details/42843303

    在node之中由于单个进程内存存在1.4GB的上限，因此在一些大型的系统中，通常使用cluster的方式来运行。在cluster环境，也就是多进程环境中，在使用log4js时其实有一个陷阱，可能很多人都遇见过，让人错愕。

    在单进程环境中大家会使用file或者datefile类型的Appender实例来写日志，并且为了日志的自动清除还设置了滚动方式，按照文件大小或者日期进行滚动。但是这两种类型的Appender在达到滚动阈值时，先进性rename，然后创建一个新的文件，把后面的内容写入到新的文件中。

    例如：在datefile按照天进行滚动的环境中，日志文件名为cheese.log

rename cheese.log cheese.log.2015-01-17
create file cheese.log
write cheese.log

    在单进程环境中，这完全没有问题，但是在多进程环境就会有问题。问题就出在每个进程都要执行上面的rename与create操作。在多进程写同一个文件时，实际上只要有一个进程执行rename与create操作就行了。

    例如：

<span style="font-size:12px;">进程A先被触发，执行换天备份日志操作：
rename cheese.log cheese.log.2015-01-17
create file cheese.log
write cheese.log
在后面的某个时间，进程B也被触发了，再次执行换天备份日志操作：
rename cheese.log cheese.log.2015-01-17
create file cheese.log
write cheese.log</span><span style="font-size: 11pt;">
</span>

    看出来了吧，在被执行了第二次之后，2015-01-16上的数据其实丢失了，cheese.log.2015-01-17文件内容只是进程A备份到进程B备份，这段时间的日志。现在问题说清楚了，我们来想想解决方案。

    问题的关键出在多个进程在不同时候执行了换天备份操作，那么如果能够保证只有一个进程执行换天备份就没问题了。

    在log4js中提供了两种这种类型的Appender，分别是clustered与multiprocess，都是在master进程上开启监听，worker进程将日志简单地发送给master，日志的写入备份等操作都有master进程进行。但是这种方式有一个缺点，日志通过网络传输，node是先缓冲到本地数组，然后提供给socket缓冲区，假如网络写入速度比日志写入速度慢，那么以为着进程的内存占用会越来越多，最终可想而知了。

    另外一种更好地方式是使用datefile类型的Appender，但是设置alwaysIncludePattern属性为true，也就是说每次写日志直接写在 cheese.log.2015-01-17这样的文件上，换天的时候写到新的日志文件即可。这种方式就去掉了rename日志的过程，从而避免多进程导致的日志rename混乱。

    关于clustered、multiprocess、datefile类型的Appender具体配置，请看另一篇博客《log4js配置详解》中“datefile配置”，“multiprocess配置”，“cluster配置”的三个小节。

    Log4js总共三篇博客

    《Log4js原理解析》http://write.blog.csdn.net/postedit/42844085

    《Log4js配置详解》http://blog.csdn.net/hfty290/article/details/42843737

    《Log4js多进程陷阱与避免》http://blog.csdn.net/hfty290/article/details/42843303