我们采用Linux的syslog来记录产品的debug log。调用其中的一个可执行文件,执行完命令之后,查看debug log的信息,居然从某一条log之后的log都丢失了。多次尝试后,发现每次都在某条固定的log之后的log都丢失了。这篇博文就让我们一起来探个究竟。

一. 问题发现

    在发现真正问题之前我做了以下尝试:

    (1) 进程是否在固定log之后某种逻辑退出?或者在固定log打印之后的语句中会产生信号导致进程终止? 在程序末尾打印一个消息到屏幕,可以看到程序正常运行,并退出。
    (2) 是否debug log对象发生了改变,或者debug level在运行中发生了改变? 同样在程序中打印这些信息,发现并无异常。

    (3) gdb调试查看程序走的分支逻辑

    如上方法均未发现问题,其实还有一种想法:syslog会不会丢弃一些log信息?但一开始是被我排除的,当时原因有二:第一在Redhat4/5上均不会出现这个问题;第二Redhat 6平台上的产品已经发布了至少一年了,要是debug log总是缺少应该不会等到我来发现吧。然而,正是由于一些惯有的思维,或者是一些看似有理却不严谨的推断,导致真相姗姗来迟

    接着,我优先查看了/var/log/messages文件, 看到了如下的错误信息,而6292正是我之前执行的进程ID。

imuxsock begins to drop messages from pid 6292 due to rate-limiting
    那么很显然,于是很快利用google神器,找到了原因,这个是和Redhat 6中的rsyslog的机制有关系,并且这些机制可配置。

二. Redhat 6.3中rsyslog的Rate Limit配置

    所谓Rate limit就是指,在某个固定的时间段内,syslog最多允许打印的log信息数量(多出的log信息将被丢弃)。在Redhat 6中,由配置文件/etc/rsyslog.conf中以下两个配置项决定:

    $SystemLogRateLimitInterval [Number1]: Number1 为设定的限制的时间间隔大小

    $SystemLogRateLimitBurst [Number2]: Number2 为在设定的限制的时间间隔内,最多输出的log信息数量。

    在设定完后,则表示在每一个Number1时间间隔内,如果超过Number2个数的log信息将会被去除。默认Number1为5秒钟,Number2为200.但如果我们不希望,在打印的log时有丢失,则可以在/etc/rsyslog.conf中添加或者设置

$SystemLogRateLimitInterval 0
    当然设置完成后,一定要记得重新启动rsyslog服务(用命令:service rsyslog restart)哦~~~

Note:rsyslog 5.7.1之后的版本才添加了此功能,而Redhat 6.3采用的是rsyslog 5.8.10 。


参考:

1. https://bugzilla.redhat.com/show_bug.cgi?format=multiple&id=753363

2. http://lists.adiscon.net/pipermail/rsyslog/2011-April/028307.html

3. http://www.rsyslog.com/tag/rate-limiting/

4. http://www.rsyslog.com/changelog-for-5-7-1-v5-devel/


GitHub 加速计划 / li / linux-dash
10.39 K
1.2 K
下载
A beautiful web dashboard for Linux
最近提交(Master分支:2 个月前 )
186a802e added ecosystem file for PM2 4 年前
5def40a3 Add host customization support for the NodeJS version 4 年前
Logo

旨在为数千万中国开发者提供一个无缝且高效的云端环境,以支持学习、使用和贡献开源项目。

更多推荐