在华为的月度报告中, 发现了奇怪的问题,有一台机器在每天都会内存使用率飙到100%,偶尔的几次还会出现OOM的记录。在追踪问题的过程中,发现机器上每天的2,4,6,8点会自动运行处理日志的脚本,并统计关键字的数量。

这个脚本的过滤日志思路是, 使用 less 命令打开昨天的所有日志文件,并且读取内容,过滤其中的关键字,命令类似如下:

less yesterday*.log.gz | grep -e "xxxxx" -e "xxxxx" | sort | uniq | wc -l

关于Less, More, Cat, Zcat

这个四个命令可以分成两组:

  • less / more 的命令是为了个人类查看文件的内容设计的程序;
  • cat / zcat 是一次性输出内容到屏幕的;

两组命令的唯一区别是是否提供前后反复查看的功能。但是就是这个功能,导致了命令执行的逻辑其实是完全不同的。

less命令的执行方式将查看到的数据放入内存中(USED),所以 如果是一个10G的日志,就会占用10G的内存, 如果不够,系统就会进行交换和将旧数据换出的操作。
cat的执行模式是将数据直接输出到/dev/stdout,同时操作系统会将数据存储到Cache中,不会触发内存的告警, 由于日志中的数据其实只是进行一次过滤, 所以不需要长期的保留, 这也提高了bash处理日志文本的速度。

补充一下, Vim也是一样的, Vim会尽可能的将文件载入到内存里, 所以日志类的文件是不需要, 也不能使用Vim的.

结论

由于两个命令的处理方式不同,因此直接将命令中输出gz日志的命令换成了zcat,即可保证内存的使用不会变多, 这里同时提高的处理文本命令的效率,这个机器专门用来做这一件事情, 所以不需要考虑其他进程会影响日志处理, 造成数据的不一致。
所以在脚本中一定一定使用正确的命令和方式处理数据,才能保障性能和效率的兼顾。

最后,优化过的命令为:

zcat yesterday*.log.gz | grep -e "xxxx" -e "xxxx" | sort -u | wc -l

最后的执行时间,从原来的半个小时起步,变成了10分钟即完成。

后续的处理

已知我们的问题是不需要系统自动cache住我们过滤的日志数据,我们可以手动释放一下已经无用的cache内容:

sync && echo 3 > /proc/sys/vm/drop_caches

后面还添加了并行执行的处理命令, 但是这个并行执行的脚本确实写的非常的垃圾。 另外添加了使用python 自动填写过滤的结果到 Excel 表格。