3

有太多日志采集工具了。但是可以做到在繁忙的机器上低负载地采集海量日志的工具并不多。很多日志采集器是用python/perl/ruby这些语言写的。下面一个简单的测试,说明python的效率是不适合日志采集工具的。

被采集的日志:ftp://ita.ee.lbl.gov/traces/NASA_access_log_Jul95.gz 数据被复制了3遍,大小是588M

这里只测试了文件读取,按行切分的效率。并不涉及多文件同时监控,以及发送效率。测试数据被缓存在file cache里了,所以不涉及磁盘读取效率的问题。
python版本:

lines = 0
with open('/tmp/messages') as f:
    for line in f:
        lines += 1
print(lines)

python的速度:

5675143

real    0m1.097s
user    0m1.005s
sys     0m0.092s

python构造string的速度实在是太慢了。
粗糙的c的版本(fgets比较慢,快的实现方式应该直接用read syscall和SIMD指令)

#include <stdio.h>
#include <string.h>

int main ( ) {
    char buff[4096];
    int lines;
    FILE *fp;

    fp = fopen( "/tmp/messages", "r" );
    if ( fp == NULL ) {
        perror( "Cannot open file" );
        return 1;
    }

    while ( fgets(buff,4096,fp) != NULL ) {
        lines += 1;
    }

    printf("%d\n", lines);
    fclose( fp );
    return 0;
}

c的速度:

5675143

real    0m0.464s
user    0m0.375s
sys     0m0.089s

再来看看go的版本

package main
import (
    "fmt"
    "os"
    "bufio"
)
func main() {
    fi, err := os.Open("/tmp/messages")
    if err != nil {
        panic(err)
    }
    defer func() {
        if err := fi.Close(); err != nil {
            panic(err)
        }
    }()
    scanner := bufio.NewScanner(fi)
    lines := 0
    for scanner.Scan() {
        scanner.Bytes()
        lines += 1
    }
    fmt.Println(lines)
    if err := scanner.Err(); err != nil {
        panic(err)
    }
}

go版本的速度

5675143

real    0m0.548s
user    0m0.437s
sys     0m0.119s

最简单的命令呢?

wc -l /tmp/messsages

这个是最快的

5675142 /tmp/messages

real    0m0.231s
user    0m0.150s
sys     0m0.081s

具体go的时间花在哪里了:

540ms of 540ms total (  100%)
      flat  flat%   sum%        cum   cum%
     200ms 37.04% 37.04%      200ms 37.04%  syscall.Syscall
     190ms 35.19% 72.22%      190ms 35.19%  runtime.indexbytebody
     100ms 18.52% 90.74%      520ms 96.30%  bufio.(*Scanner).Scan
      20ms  3.70% 94.44%      210ms 38.89%  bufio.ScanLines
      10ms  1.85% 96.30%      530ms 98.15%  main.main
      10ms  1.85% 98.15%      210ms 38.89%  os.(*File).Read
      10ms  1.85%   100%       10ms  1.85%  runtime.usleep
         0     0%   100%      200ms 37.04%  os.(*File).read
         0     0%   100%      530ms 98.15%  runtime.goexit
         0     0%   100%      530ms 98.15%  runtime.main
         0     0%   100%       10ms  1.85%  runtime.mstart
         0     0%   100%       10ms  1.85%  runtime.mstart1
         0     0%   100%       10ms  1.85%  runtime.sysmon
         0     0%   100%      200ms 37.04%  syscall.Read
         0     0%   100%      200ms 37.04%  syscall.read

大部分时间是花在了 indexbytebody,也就是查找 \n 的byte遍历过程上了。这个可以解释为什么go版本比wc要慢,wc的实现是经过高度优化的汇编指令。另外syscall.Read导致的goroutine切换成本也偏高,每次调用syscall之前都有一次保存goroutine stack的操作。这个可以解释为什go的版本比纯c的要慢,因为syscall有开销。

简单的结论是go比python快得多,但是仍然有自己的开销。go不适合在最求极致性能的情况下使用,因为无法用尽所有的优化手段。但是把go当作更快的python来使还是可以的。
可以参考这篇文章:http://zhen.org/blog/sequence-high-performance-sequential-semantic-log...

可惜的是heka(https://github.com/mozilla-services/heka)虽然是 go 写的,在实际的测试中发现速度其实很慢,可能跟其内部设计比较复杂有关系。像logsend(https://github.com/ezotrank/logsend)这样的专门工具可能性能会好一些。


taowen
4.1k 声望1.4k 粉丝

Go开发者们请加入我们,滴滴出行平台技术部 taowen@didichuxing.com