由于业务需要,对EDM发出的邮件日志进行分析处理,我要做的是预处理,把posfix杂乱无章的日志中找到我需要的数据.
我用javamail发的邮件,发送邮件时获取到是一个messageId,形如:2135546465.103503.1400232891548.JavaMail.root@hostname
但是直接通过这个messageid是不能拿到发送邮件的status的,因为日志中是这么记录的:
May 16 17:34:53 c1202 postfix/cleanup[23641]: 00020127E4D: message-id=<2135546465.103503.1400232891548.JavaMail.root@hostname>May16 17:34:53 c1202 postfix/error[23571]: 00020127E4D: to=, relay=none, delay=0.1, delays=0.08/0/0/0.01, dsn=4.4.2, status=deferred (delivery temporarily suspended: lost connection with 163mx01.mxmail.netease.com[220.181.14.139] while sending DATA command)
这个日志已经把没有用的行过滤掉了,只剩这两行是有用的.这两行的关联ID是00020127E4D,也就是说我要先通过
2135546465.103503.1400232891548.JavaMail.root@hostname
获取到00020127E4D,然后再通过00020127E4D获取到第二行中的status.
Q:为什么不直接grep 邮件名?
A:因为发送邮件服务器是共用的,不能通过邮件名就确认这封邮件是由我的EDM服务发出,而messageid是EDM服务发出时的标志ID,所以需要通过messageid找到关联ID,再找到发送结果那么折腾.
#假设同一条mailid的记录在最近10行内
mailTmp=`grep -A 10 "${line}" "${logFile2}"`
#获取mailid,例如582664BDA66
mailid=`echo "${mailTmp}"| fgrep -m 1 "${line}" | awk '{print $6}'|sed 's/://g'`
#获取发送结果,可能会有重试多条,只读第一条.
sendStatus=`echo "${mailTmp}" | fgrep "${mailid}"| fgrep "postfix/smtp" | fgrep -m 1 "to=" | sed 's/.*status=//g'`
获取到status的核心代码就是这三行.再加个外层while循环从文件中读取messageid输入line的样子.
版本一:
需求能实现,但速度很慢,每秒最高得出3条status结果.
版本二:
maillog的日志是并发写入的,虽然对同一封邮件发出写入的日志顺序是固定的,但同一个mailid可能要读1000行才能找到这关键的两行数据.
改进:
1. 为了减少第一条语句的搜索,过滤掉无用的行,例如postfix/qmgr,postfix/smtpd等行,我不关注的信息.
2. 根据mailid预先排序,把关联的mailid放在一起,这样更加能够减轻第一条grep的搜索.
结果:
每秒3条速度提升到每秒5条,还不错,但还是太慢了,因为第一天的日志有19W条...这样算下去要10个小时才能弄完.
版本三:
每秒5条,没想到什么好办法提升了,就想着能不能并发呢?开N个线程,那每秒不就可以处理N*5条了吗?
改进:
尝试使用shell下面的并发,找了一下资料,参考一位疑似TX员工分享的代码: http://my.oschina.net/sanpeterguo/blog/133304
我使用的服务器是8核CPU,为了尽量不影响原有的服务,我把线程开了5个.
结果:
果然很有效,开了5个线程,能把速度提升到每秒处理12~17个.
版本四:
grep有多个用法,其中有grep/fgrep/egrep,后面两个只不过是第一个带参数的alias,但网上说用fgrep会更快,fgrep是fix string grep,不解析pattern,搜索会更快.
还有的说法在grep前加LANC=C,即用的时候为LANC=C grep XXXX,我试了,几乎没影响.
改进:
使用fgrep
结果:
略微有效,现在每秒稳定在15~18个了.
版本五:
其实我这里非常需要用到一个数据结构,map,字典结构,要是我可以预先把日志里所有的messageId->status处理好,然后我直接查就可以了,但是没找到shell下面map结构的工具...据说bash 4.2有,但用起来也很复杂,如果用python/java来写就实在太简单了,但我想挑战shell,用shell实现这个需求,而且用grep来匹配字符串效率是最高的,尝试用map失败.
版本六:
由于用了多线程对同一个文件进行grep,那文件的写性能肯定很影响效率啊!
尝试一: 把mail.log文件读到内存里,即logFile3=`cat ${logFile2}`,然后再用echo "${logFile3}" |grep XXX这样去筛选.
结果: 一运行就报错了...不给这样用..也不知道为啥,报的是参数过长...mail.log文件有88MB,不行.
于是我想能不能搞个linux下的ramdisk,这样肯定能大大提升mail.log的读性能啊!
google了一下资料发现,linux下ramdisk原生就是支持的,就在ls -al /dev/ram*,预设了一些,但是用的时候,ramdisk大小是固定的,一旦分配了,重启前就不能改变了.这样不好,这台机器上的主要服务不是我现在用的日志分析小程序,不能独占那么多内存,而且日志大小每天都不一样,不能直接分配一个较大的内存来这样用.
然后我再找到了/dev/shm,这是默认是内存的一半大小,用于共享内存使用的.用的是tmpfs,更重要的是动态的,如果你不放东西进去 ,他占用内存就是0,如果你较大的东西进去再删掉,内存能释放掉让给其它程序使用.
而且/dev/shm是可以安全使用的,很多服务器会用这个目录来当一些临时文件的存储,更有甚者把/tmp挂载到/dev/shm下面!非常满足我的需求!
改进:
把mail.log放到/dev/shm
结果:
分析日志提升到每秒55条了~!YES!大喜~
以上就是我分析日志从每秒处理3个结果到每秒处理55个结果过程, 性能足足提升了16倍啊!现在仅需一个小时就可以把19W条messageid分析完了,不错的结果.或许还有改进的空间,继续折腾吧.
版本七:
过了一天,过滤后的日志变大了,从88MB涨到400MB,按版本六的速度只有15TPS了,于是只好用JAVA实现一下,把messageId跟status放到MAP里,直接命中查询,无论日志有多少,速度都稳定在800TPS了,郁闷~