Monday, April 23, 2007

多服务器的日志合并统计——apache日志的cronolog轮循

作者:车东 发表于:2003-04-12 11:04 最后更新于:2007-04-13 22:04
版权声明:可以任意转载,转载时请务必以超链接形式标明文章原始出处和作者信息及本声明。
http://www.chedong.com/tech/rotate_merge_log.html
内容摘要:你完全不必耐心地看完下面的所有内容,因为结论无非以下2点:
1 用 cronolog 干净,安全地轮循apache日志
2 用 sort -m 合并排序多个日志

根据个人的使用经历:
1 先介绍apache日志的合并方法;
2 然后根据由此引出的问题说明日志轮循的必要性和解决方法,介绍如何通过cronolog对apache日志进行轮循;
中间有很多在设计日志合并过程中一些相关工具的使用技巧和一些尝试的失败经历……
我相信解决以上问题的路径不止这一条途径,以下方案肯定不是最简便或者说成本最低的,希望能和大家有更多的交流。


多服务器日志合并统计的必要性

越来越多大型的WEB服务使用DNS轮循来实现负载均衡:使用多个同样角色的服务器做前台的WEB服务,这大大方便了服务的分布规划和扩展性,但多个服务器的分布使得日志的分析统计也变得有些麻烦。如果使用webalizer等日志分析工具对每台机器分别做日志统计:
1 会对数据的汇总带来很多麻烦,比如:统计的总访问量需要将SERVER1 SERVER2...上指定月份的数字相加。
2 会大大影响统计结果中唯一访客数unique visits,唯一站点数unique sites的等指标的统计,因为这几个指标并非几台机器的代数相加。

统一日志统计所带来的好处是显而易见的,但如何把所有机器的统计合并到一个统计结果里呢?
首先也许会想:多个服务器能不能将日志记录到同一个远程文件里呢?我们不考虑使用远程文件系统记录日志的问题,因为带来的麻烦远比你获得的方便多的多……
因此,要统计的多个服务器的日志还是:分别记录=>并通过一定方式定期同步到后台=>合并=>后用日志分析工具来进行分析。

首先,要说明为什么要合并日志:因为webalizer没有将同一天的多个日志合并的功能
先后运行
webalizer log1
webalizer log2
webalizer log3
这样最后的结果是:只有log3的结果。

能不能将log1<<log2<<log3简单叠加呢?
因为一个日志的分析工具不是将日志一次全部读取后进行分析,而且流式的读取日志并按一定时间间隔,保存阶段性的统计结果。因此时间跨度过大(比如2条日志间隔超过5分钟),一些日志统计工具的算法就会将前面的结果“忘掉”。因此, log1<<log2<<log3直接文件连接的统计结果还是:只有log3的统计结果。

多台服务日志合并问题:把多个日志中的记录按时间排序后合并成一个文件

典型的多个日志文件的时间字段是这样的:
log1 log2 log3
00:15:00 00:14:00 00:11:00
00:16:00 00:15:00 00:12:00
00:17:00 00:18:00 00:13:00
00:18:00 00:19:00 00:14:00
14:18:00 11:19:00 10:14:00
15:18:00 17:19:00 11:14:00
23:18:00 23:19:00 23:14:00

日志合并必须是按时间将多个日志的交叉合并。合并后的日志应该是:
00:15:00 来自log1
00:15:00 来自log2
00:16:00 来自log1
00:17:00 来自log3
00:18:00 来自log2
00:19:00 来自log1
....

如何合并多个日志文件?
下面以标准的clf格式日志(apache)为例:
apche的日志格式是这样的:
%h %l %u %t \"%r\" %>s %b
具体的例子:
111.222.111.222 - - [03/Apr/2002:10:30:17 +0800] "GET /index.html HTTP/1.1" 200 419

最简单的想法是将日志一一读出来,然后按日志中的时间字段排序
cat log1 log2 log3 |sort -k 4 -t " "
注释:
-t " ": 日志字段分割符号是空格
-k 4: 按第4个字段排序,也就是:[03/Apr/2002:10:30:17 +0800] 这个字段
-o log_all: 输出到log_all这个文件中

但这样的效率比较低,要知道。如果一个服务已经需要使用负载均衡,其服务的单机日志条数往往都超过了千万级,大小在几百M,这样要同时对多个几百M的日志进行排序,机器的负载可想而之……
其实有一个优化的途径,要知道:即使单个日志本身已经是一个“已经按照时间排好序“的文件了,而sort对于这种文件的排序合并提供了一个优化合并算法:使用 -m merge合并选项,
因此:合并这样格式的3个日志文件log1 log2 log3并输出到log_all中比较好方法是:
sort -m -t " " -k 4 -o log_all log1 log2 log3
注释:
-m: 使用 merge优化算法

注意:合并后的日志输出最好压缩以后再发给webalizer处理
有的系统能处理2G的文件,有的不能。有的程序能处理大于2G的文件,有的不能。尽量避免大于2G的文件,除非确认所有参与处理的程序和操作系统都能处理这样的文件。所以输出后的文件如果大于2G,最好将日志gzip后再发给webalizer处理:大于2G的文件分析过程中文件系统出错的可能性比较大,并且gzip后也能大大降低分析期间的I/O操作。

日志的按时间排序合并就是这样实现的。

日志的轮循机制

让我们关心一下数据源问题:webalizer其实是一个按月统计的工具,支持增量统计:因此对于大型的服务,我可以按天将apache的日志合并后送给 webalizer统计。WEB日志是如何按天(比如每天子夜00:00:00)截断呢?
如果你每天使用crontab:每天0点准时将日志备份成access_log_yesterday
mv /path/to/apache/log/access_log /path/to/apache/log/access_log_yesterday
的话:你还需要:马上运行一下:apache restart 否则:apache会因为的日志文件句柄丢失不知道将日志记录到哪里去了。这样归档每天子夜重启apache服务会受到影响。
比较简便不影响服务的方法是:先复制,后清空
cp /path/to/apache/log/access_log /path/to/apache/log/access_log_yesterday
echo >/path/to/apache/log/access_log

严肃的分析员会这样做发现一个问题:
但cp不可能严格保证严格的0点截断。加入复制过程用了6秒,截断的access_log_yesterday日志中会出现复制过程到00:00:06期间的日志。对于单个日志统计这些每天多出来几百行日志是没有问题的。但对于多个日志在跨月的1天会有一个合并的排序问题:
[31/Mar/2002:59:59:59 +0800]
[31/Mar/2002:23:59:59 +0800]
[01/Apr/2002:00:00:00 +0800]
[01/Apr/2002:00:00:00 +0800]

要知道[01/Apr/2002:00:00:00 这个字段是不可以进行“跨天排序”的。因为日期中使用了dd/mm/yyyy,月份还是英文名,如果按照字母排序,很有可能是这样的结果:排序导致了日志的错误
[01/Apr/2002:00:00:00 +0800]
[01/Apr/2002:00:00:00 +0800]
[01/Apr/2002:00:00:00 +0800]
[01/Apr/2002:00:00:00 +0800]
[01/Apr/2002:00:00:00 +0800]
[01/Apr/2002:00:00:00 +0800]
[01/Apr/2002:00:00:00 +0800]
[31/Mar/2002:59:59:59 +0800]
[31/Mar/2002:59:59:59 +0800]
[31/Mar/2002:23:59:59 +0800]
[31/Mar/2002:59:59:59 +0800]
[31/Mar/2002:23:59:59 +0800]

这些跨天过程中的非正常数据对于webalizer等分析工具来说简直就好像是吃了一个臭虫一样,运行的结果是:它可能会把前一个月所有的数据都丢失!因此这样的数据会有很多风险出现在处理上月最后一天的数据的过程中。

问题的解决有几个思路:
1 事后处理:
。所以一个事后的处理的方法是:用grep命令在每月第1天将日志跨月的日志去掉,比如:
grep -v "01/Apr" access_log_04_01 > access_log_new

修改SORT后的日志:所有跨天的数据去掉。也许对日志的事后处理是一个途径,虽然sort命令中有对日期排序的特殊选项 -M(注意是:大写M),可以让指定字段按照英文月份排序而非字母顺序,但对于apache日志来说,用SORT命令切分出月份字段很麻烦。(我尝试过用 "/"做分割符,并且使用“月份” “年:时间”这两个字段排序)。虽然用一些PERL的脚本肯定可以实现,但最终我还是放弃了。这不符合系统管理员的设计原则:通用性。并且你需要一直问自己:有没有更简单的方法呢?
还有就是将日志格式改成用TIMESTAMP(象SQUID的日志就没有这个问题,它的日志本身就是使用TIMESTAMP做时间时间戳的),但我无法保证所有的日志工具都能识别你在日期这个字段使用了特别的格式。

2 优化数据源:
最好的办法还是优化数据源。将数据源保证按天轮循,同一天的日志中的数据都在同一天内。这样以后你无论使用什么工具(商业的,免费的)来分析日志,都不会因为日志复杂的预处理机制受到影响。

首先可能会想到的是控制截取日志的时间:比如严格从0点开始截取日志,但在子夜前1分钟还是后一分钟开始截取是没有区别的,你仍然无法控制一个日志中有跨 2天记录的问题,而且你也无法预测日志归档过程使用的时间。
因此必须要好好考虑一下使用日志轮循工具的问题,这些日志轮循工具要符合:
1 不中断WEB服务:不能停apache=>移动日志=>重启apache
2 保证同一天日志能够按天轮循:每天一个日志00:00:00-23:59:59
3 不受apache重启的影响:如果apache每次重启都会生成一个新的日志是不符合要求的
4 安装配置简单

首先考虑了apache/bin目录下自带的一个轮循工具:rotatelogs 这个工具基本是用来按时间或按大小控制日志的,无法控制何时截断和如何按天归档。
然后考虑logrotate后台服务:logrotate是一个专门对各种系统日志(syslogd,mail)进行轮循的后台服务,比如SYSTEM LOG,但其配置比较复杂,放弃,实际上它也是对相应服务进程发出一个-HUP重启命令来实现日志的截断归档的。

在apache的FAQ中,推荐了经过近2年发展已经比较成熟的一个工具cronolog:安装很简单:configure=>make=> make install

他的一个配置的例子会让你了解它有多么适合日志按天轮循:对httpd.conf做一个很小的修改就能实现:
TransferLog "|/usr/sbin/cronolog /web/logs/%Y/%m/%d/access.log"
ErrorLog "|/usr/sbin/cronolog /web/logs/%Y/%m/%d/errors.log"

然后:日志将写入
/web/logs/2002/12/31/access.log
/web/logs/2002/12/31/errors.log
午夜过后:日志将写入
/web/logs/2003/01/01/access.log
/web/logs/2003/01/01/errors.log
而2003 2003/01 和 2003/01/01 如果不存在的话,将自动创建

所以,只要你不在0点调整系统时间之类的话,日志应该是完全按天存放的(00:00:00-23:59:59),后面日志分析中: [31/Mar/2002:15:44:59这个字段就和日期无关了,只和时间有关。

测试:考虑到系统硬盘容量,决定按星期轮循日志
apache配置中加入:
#%w weekday
TransferLog "|/usr/sbin/cronolog /path/to/apache/logs/%w/access_log"

重启apache后,除了原来的CustomLog /path/to/apche/logs/access_log继续增长外,系统log目录下新建立了 3/目录(测试是在周3),过了一会儿,我忽然发现2个日志的增长速度居然不一样!
分别tail了2个日志才发现:
我设置CustomLog使用的是combined格式,就是包含(扩展信息的),而TransferLog使用的是缺省日志格式,看了apache的手册才知道,TransferLog是用配置文件中离它自己最近的一个格式作为日志格式的。我的httpd.conf里写的是:
LogFormat ..... combined
LogFormat ... common
...
CustomLog ... combined
TransferLog ...

所以TrasferLog日志用的是缺省格式,手册里说要让TRANSFER日志使用指定的格式需要:
LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\""
TransferLog "|/usr/local/sbin/cronolog /path/to/apache/logs/%w/access_log"

重启,OK,日志格式一样了。
这样的设置结果其实是同时在logs目录下分别记录2个日志access_log和%w/access_log,能不能只记录%w/下的日志那?
查apache手册,更简单的方法:直接让CustomLog输出到cronolog归档日志,并且还能指定格式。
CustomLog "|/usr/local/sbin/cronolog /path/to/apache/logs/%w/access_log" combined

最后是一个日志同步的问题。

任务:每天凌晨找到前1天的日志,另存一个文件准备发送到服务器上。
比如我要保留前1周的日志:每天复制前1天的日志到指定目录,等待日志服务器来抓取:
/bin/cp -f /path/to/apache/logs/`date -v-1d +%w`/access_log /path/for/backup/logs/access_log_yesterday

在FREEBSD上使用以下命令
date -v-1d +%w
注释:
-v-1d: 前1天,而在GNU/Linux上这个选项应该是date -d yesterday
+%w: weekday,由于使用的都是标准时间函数库,所有工具中的WEEKDAY定义都是一样的 0-6 => 周日-周六

注意:
写到CRONTAB里的时候"%"前面需要加一个"\"转义:每天0点5分进行一次日志归档,
另外一个问题就是在cront中需要用:rm -f {} ; 而不是rm -f {}\;
5 0 * * * /bin/cp /path/to/logs/`date -v-1d +\%w`/access_log /path/to/for_sync/logs/access_yesterday
37 10 * * * /usr/bin/find /home/apache/logs/ -name access_log -mtime +1 -exec /bin/rm -f {} ;

首次开始cronolog日志统计是周3,一周以后日志又将轮循回3/access_log
但这次日志是追加到3/access_log还是重新创建一个文件呢?>>access_log or >access_log?
我测试的结果是日志将被追加:
[01/Apr/2002:23:59:59 +0800]
[01/Apr/2002:23:59:59 +0800]
[08/Apr/2002:00:00:00 +0800]
[08/Apr/2002:00:00:00 +0800]

肯定是不希望每次日志还带着上周的数据的并重复统计一次的(虽然对结果没影响),而且这样%w/下的日志不是也越来越多了吗?
解决方法1 把每天的cp改成mv
解决方法2 每天复制完成后:删除6天以前的access_log日志
find /path/to/apache/logs -name access_log -mtime +6 -exec rm -f {}\;
多保留几天的日志还是有必要的:万一日志分析服务器坏了一天呢?

以下是把apache安装在/home/apache下每天统计的一个脚本文件:
#!/bin/sh

#backup old log
/bin/cp -f /home/apache/logs/`date -d yesterday +%w`/access_log /home/apache/logs/access_log_yesterday

#remove old log
/usr/bin/find /home/apache/logs -name access_log -mtime +6 -exec rm -f {}\;

#analysis with webalizer
/usr/local/sbin/webalizer

总结:
1 用 cronolog 干净,安全地轮循日志
2 用 sort -m 排序合并多个日志


参考资料:

日志分析统计工具:
http://directory.google.com/Top/Computers/Software/Internet/Site_Management/Log_Analysis/

Apche的日志设置:
http://httpd.apache.org/docs/mod/mod_log_config.html

Apache的日志轮循:
http://httpd.apache.org/docs/misc/FAQ.html#rotate

Cronolog
http://www.cronolog.org

Webalizer
http://www.mrunix.net/webalizer/
Webalzer的Windows版
http://www.medasys-lille.com/webalizer/

AWStats的使用简介
http://www.chedong.com/tech/awstats.html

No comments :