记nodejs在pm2下使用log4js cluster模式的日志打印丢失问题

我使用pm2的cluster集群模式管理node服务，使用log4js打印日志。最近公司业务量上升，与此同时问题订单也随之增多。但多次在排查异常订单时找不到订单的正常日志，在基本排除程序本身问题后我将目光投在了日志打印插件log4js身上。

1：这是我目前的log4js的配置

log4js.configure({ appenders: { out: { type: 'stdout' }, info: { type: 'dateFile', filename: 'info', pattern: '-yyyy-MM-dd.log', layout: { type: 'pattern', pattern: '%d{yyyy-MM-ddThh:mm:ss.SSSO} %p %c - [%m]' } }, }, categories: { default: { appenders: ['out','info'], level: 'all' }, }, pm2: true, disableClustering: true });

我在网上也找到了很多博客，看到很多人都是这么写的。这么写可以解决cluster集群模式下只有一个进程输出的问题。但是在翻了log4js的源码之后我发现，如果设置了disableClustering为true之后，每个cluster进程都会单独向文件输出日志。

log4js.configure()配置的源码如下：

当你设置了disableClustering为true时log4js会做如上处理。然后当你getLogger时：

 

执行getLogger()函数时，会执行isMaster()方法，判断当前进程是不是主进程。isMaster函数执行时，如果disableClustering为true的话则认为当前进程是主进程。则会将sendLogEventToAppender作为打印日志时的执行函数。真正将日志打印到文件中。这个函数的具体执行大家可以自己去看下源码。里面逻辑很简单，就不再赘述。

这样就会发生多个进程同时向一个文件写入的情况，在某种情况下就会出现日志丢失情况。 我司遇到的问题就是在这种情况下发生的。而且官方文档也有提到这种模式会发生一些莫名其妙的问题（说的应该就是日志丢失吧）。log4js官方文档

好。到了这里，我们的node程序在pm2的cluster模式在使用log4js丢日志的原因基本是确定了。就是disableClustering的锅。那我们就要去解决它，怎么解决？

1：将disableClustering去掉。在配置中将disableClustering去掉之后，运行4个进程后发现，只有一个进程能正常打印日志，其它三个进程日志全部丢失。继续看官方文档发现下面一段话。

在log4js的配置中设置pm2为true时需要下载pm2-intercom参加才能保持日志的正常打印。ok，下载pm2-intercom。使用ab发起10个并发请求，打印结果如下。

ok。看起来一起完美。你以为结束了？当然不可能。

按照当前设置将服务发到测试环境，一跑，同样的代码，同样的设置，同样发起10个请求，只有3个打印出来了。试了好几次都是这样。so，还是在丢日志。

为什么呢？不可能啊！是不是电脑有问题？是不是pm2版本问题？是不是Node版本问题？是不是Log4js版本问题?在各种尝试了n次，将所有环境全部统一之后我发现，还是这样。so，老老实实看源码吧。

前面的一堆就不再说了，直接到关键代码。log4js下打印日志会有可能有两条路径。如下：

pm2下使用cluster模式时，其实所有的进程都是cluster，只有pm2主进程是master进程。但是pm2内部对进程做了标志。例如，启动4个cluster进程，则会有一个标志字段（默认是NODE_APP_INSTANCE）记录它的内部标志， 0、1、2、3。当标志位为0时，log4js就认为它是主进程（通过isPM2Master函数）。则此时master进程负责执行sendLogEventToAppender函数打印日志，cluster进程负责执行workerDispatch将日志发送给主进程（其实这时发送给的是pm2主进程）。

到了这里我们可以看到的结果就是，如果是cluster进程，则日志会发送给master进程，现在让我们来看pm2-intercom插件。我先是在github上找了一下它的源码发现没找到，后来问了log4js的官方人员后得到的结果是源码丢了！源码丢了！丢了！ 原因不知道，结果就是找不到了。。issues地址

后来找到了一份貌似是第三方的pm2-intercom源码。pm2-intercom源码 找到源码看了一下。发现pm2-intercom会通过pm2的api连接到pm2，并接收到所有的消息：

上面是pm2官方的文档pm2文档 。pm2-intercom接收消息代码如下：

通过打印日志发现，所有cluster进程发送的消息都会被pm2-intercom接收。然后通过pm2-intercom转发出去。如下：

然后我发现在执行async.forEachLimit函数往别的进程广播时因为设置了4，所有最后执行下来。只会想pm2 list列表中的前4个进程推送消息，所有往后的进程都接收不到。 此时！ 终于找到了为什么我在本地调试时为什么能接收到消息，而到了测试环境就不行。因为测试环境跑了很多服务。我的程序远在4之外。

此时，问题的原因已经找到了。通过在async.forEachLimit函数里面加上next（）函数执行，发现果然所有的进程都能接收到消息。测试环境也已经可以接收到消息。

但是，这种方式有几个弊端：

1：所有的进程都能接收到消息，所有的主进程都会打印日志，所有可能你的日志会在不同的程序之间串。

2：往所有的进程发送日志，很没有效率。

所以最好可以根据自己的需求往特定的进程发送消息。

如你有一个进程专门记录日志，则可以都往那一个上面发。或者每个程序的master进程记录日志，则可以使用packet中的name来进行区分做分发。具体的实现可以自行定义。

至此，多进程打印日志的问题算是找到了。我也将修改代码发布到线上观察后续的结果。希望能解决问题。哈哈。

谨以此篇记录我踩的这些坑，如有错漏欢迎指教。