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
原文地址:http://blog.csdn.net/hfty290/article/details/42843303