1. 22 Dec 2013

    gperftools-httpd分析server性能杂记

    前记

    Redis 相信很多人很熟悉了:广泛使用key-value store,提供方便的访问Hash,List,Set等接口。Redis的通讯协议简洁,高效,并且客户端成熟。

    最近在写一个程序shenfeng/pedis,C++实现的一个Redis协议的server,封装facebook 的rocksdb,提供基于磁盘的List,Hash API(比如RPUSH,LRANGE,HSET,HGET,参见Redis的文档)。

    rocksdb继承于Gogole 的leveldb,是一个磁盘key-value lib,并提供了Merge-Operator 的支持,为实现高效率的基于磁盘List, Hash API创造了条件。

    pedis将是推荐系统的基础服务,提供以下功能:

    1. 存储每个user的历史行为:user和item的关系
    2. 快速提取user的行为:用户的历史决定了这个用户,是个性化算法的基础
    3. 定期dump <用户,行为>矩阵,用于离线模型训练

    曾用redis来存储用户的历史行为,无奈存储了10亿左右<用户,行为>对后,内存消耗大(20G),向公司要机器困难(相比于写code),嗨,公司对个性化推荐这块不舍得资源投入。无奈之余,花周末时间,写个pedis从根上解决内存资源少的问题。

    由于Redis的协议比较简单,今天周末,在家用C++实现了协议的Decode和Encode(有限状态机的方式,redis_proto.hpp),网络库采用的Redis的ae.c,server已经能跑起来了。用reids提供的redis-benchmark工具测试了一下性能,和redis-server相差不大,在i7-2600上,每秒能搞定200k次get,set请求。

    一时兴起,按照前一篇bloggperftools 初探 - gperftools-httpd介绍的方法,用gperftools跑了一下我的code和redis code:

    profile脚本

    # 启动redis-server,会启动一个http server,监听在9999端口,使得可以用pprof分析性能
    export LD_PRELOAD=/home/feng/workspace/gperftools-httpd-read-only/libghttpd-preload.so
    ./src/redis-server
    
    # 发出1千万get请求,50个长连接
    ./src/redis-benchmark -p 7389 -t get -n 10000000
    
    # 分析性能,生成svg调用关系和cost图
    google-pprof ./src/redis-server 'http://localhost:9999/pprof/profile'

    profile 结果

    1. 点击查看redis-server的profile结果
    2. 点击查看pedis-server的profile结果

    几个比较有意思的观察:

    1. redis-server, pedis-server每秒都可以处理200k次请求
    2. redis-server的结果中,epoll_ctlepoll_wait耗时都比较多,各7%-8%。但这是在每秒用户程序收发20万次请求的情况下。但正常的程序,很少有每秒这么大量的首发,所以epoll很难成为系统的瓶颈。
    3. 仔细观察pedis-server的结果,仅epoll_ctl耗时较多,epoll_ctl难觅踪影。原因是我做了一个特别的优化,在绝大部分情况下,可以省掉epoll_ctl的调用,并且可以降低latency(稍后会整理一个Pull Request,提给Redis)
    4. 没有竞争的锁,开销小。 pedis-server图中,有__pthread_之类条目,因为pedis-server将会是多线程的,每个写会加锁,但这个测试,server是单线程的,所以锁没有竞争。
    5. 两个程序中耗时最多的都是 __write_nocancel,50%左右,它是write(2),把数据包copy到TCP buffer里
    6. __read_nocancel也很耗时,占10%左右。它是read(2),从TCP buffer拷贝数据到用户程序的buffer

    redis-server中epoll_ctl耗时

    epoll_ctl

    pedis-server中epoll_ctl难觅踪影,epoll_wait耗时

    epoll_ctl

  2. 10 Dec 2013

    gperftools 初探 - gperftools-httpd

    相信每一个对性能感兴趣的程序员都会好奇自己的程序的瓶颈在什么地方,哪段代码是热点,哪段代码用了最多的内存。 ### 初识 pprof 前段时间,用go写了一些code,受Russ CoxProfiling Go Programs。在它的帮助下,优化程序很方便,profile线上实际运行的服务,得到真实的情况。

    gperftools初探

    最近的一个项目:实时推荐,是用C++写的。靠着7年多以来,几乎每天都写代码的经验,这个程序在没有特别做优化的情况下,能在20m左右,根据用户的行为行为,算出推荐结果。20ms左右的时间,倒是没有优化的必要。 趁着项目逐渐稳定,也多出了一点闲暇时间,我也想研究一下工具。首先感兴趣的是 : >Fast, multi-threaded malloc() and nifty performance analysis tools

    很喜欢的介绍。试着用它跑了最近写的一个C++的线程池 , 通过submit两百万递归计算斐波那契数列第19项的jobs给线程池,来观察有多少CPU时间是花在计算上:

    CPUPROFILE=/tmp/profile  ./threadpool
    google-pprof  ./threadpool /tmp/profile

    使用方便,只需要在编译时链接 -lprofiler,运行时加一个环境变量。在计算fib(19)这个函数上,占用了近95%的CPU时间。这样对自己的程序,能有个直观的认识

    gperftools-httpd初探

    有了profile threadpool的甜头,很急切的想知道在线上跑的推荐程序是什么样的。在sa的帮助下,装上了相应的packages。

    在gperftools 的wiki最后有这样一句话: > Russ Cox’s gperftools-httpd, a simple http server based on thttpd that enables remote profiling via google-perftool’s pprof.

    原来这也是Russ Cox写的。他也是go的作者之一。膜拜。

    迅速checkout code,make。 它的使用也很简单,make完后,会生成libghttpd-preload.so的文件。在程序运行前,export几个环境变量就ok:

    export GHTTPPORT=8780  #http端口号,gperftools-httpd会启一个轻量的HTTP服务器,来处理 profile请求
    export LD_PRELOAD=/${DIR}/libghttpd-preload.so # DIR 为文件夹名
    # start the  program

    线上处理着真实的请求,profile线上程序(overhead可以忽略不计):

    google-pprof ./rcmd_server http://localhost:8780/pprof/profile
    web  # 通过浏览器查看

    这样,清楚了这个程序的瓶颈在什么地方,需要优化时,也就有了方向。 hot spot

  3. 24 Nov 2013

    go1.2 map的GC性能提升

    几天前,线上Golang程序 GC调优一例 介绍了为特定程序优化gc的一个例子,从里面可以看出,go在做map的gc时,性能不太理想(50万的map,在i7-2600s上停顿8ms)

    今天时星期天,天气不错!下午出去跑步,上午在家玩一会儿程序。,实际测试这个情况有没有改变。

    和上次一样的程序,同一台机器:

    gc32(1): 2+0+0 ms, 61 -> 30 MB 15457 -> 3198 (357463-354265) objects, 0(0) handoff, 0(0) steal, 0/0/0 yields
    gc33(1): 2+0+0 ms, 61 -> 30 MB 15470 -> 3198 (369735-366537) objects, 0(0) handoff, 0(0) steal, 0/0/0 yields
    gc34(1): 2+0+0 ms, 61 -> 30 MB 15183 -> 3192 (381720-378528) objects, 0(0) handoff, 0(0) steal, 0/0/0 yields

    gc时间由原来的8ms,减少到2ms。

    GOGCTRACE 参数废弃,替换为GODEBUG

    搜索代码树,找不到GOGCTRACE字样了,现在由GODEBUG环境变量接管。具体代码在:

    static struct {
            int8*   name;
            int32*  value;
    } dbgvar[] = {
            {"gctrace", &runtime·debug.gctrace},
            {"schedtrace", &runtime·debug.schedtrace},
            {"scheddetail", &runtime·debug.scheddetail},
    };
    GOGCTRACE=1 go run gc.go  # go1.2以前,GOGCTRACE环境变量控制 详细信息打印
    GODEBUG='gctrace=1' go run gc.go  # go1.2rc5 由GODEBUG控制

    commit 追溯

    好奇提升的原因,追了一会儿代码。

    go的gc的代码集中在src/pkg/runtime/mgc0.c里。

    # github 上,对golang code的镜像。相比于官方用hg管理,git对于我更友好一点
    git clone :jnwhiteh/golang.git  
    git log src/pkg/runtime/mgc0.c   # 查看 src/pkg/runtime/mgc0.c 的修改记录

    这次map gc性能的提升,可能是Keith Randall的这个commit 对 的修复造成的,commit message:

    runtime: record type information for hashtable internal structures. Remove all hashtable-specific GC code

    大量内存数据,造成GC时的长时间停顿,使我头疼。这也是我日常需要面对的:加载大量数据,在有限的时间内(几十ms),进行在线算法计算,返回结果,比如推荐,搜索等。这使我不得不用C++来完成的程序的编写。欣喜的看到这次进步。map应用非常频繁的数据,这次提升,非常有意义。期待go语言gc的继续进步!

  4. 15 Nov 2013

    Apache Thrift的一另类用法 - dump/load数据文件

    Apache Thrift 一般被用做跨语言的服务的开发。它在这方面很好用,高效且方便,我现在服务的美团大量的使用了它。

    最近在做Deal的推荐系统,需要加载Deal的详细信息到内存。修改代码到程序跑起来的时间长短影响着开发效率,当然是越快越好,不希望每次修改代码后,编译,重启都需要去向数据库要一遍所有Deal的信息,毕竟C++的编译已经很耗时(这是我喜欢go的一个原因,它编译迅速。但go对需要加载几百万用户的上亿行为到内存,20ms左右算出推荐结果的场景有些力不从心)。一个可行的办法是把Deal信息dump到本地文件,重启时,快速的load这个文件。

    Thrift的一个功能是把数据按照预定义的protocol,dump成与程序语言无关bytes,通过网络传输给另外的进程,对方以同样的protocol,load这些bytes,还原为原来的数据。通过网络这部分可以换成文件。

    简单示例:定义数据格式,生成code

    // Thrift 定义文件 data.thrift
    struct DealTiny {
        1: required i32 dealid,
        2: required i32 classid,
        3: required i32 mttypeid,
        4: required i32 bizacctid,
        5: required bool isonline,
        6: required i32 geocnt,
    }
    
    struct DealsTiny {
        1: required list<DealTiny> deals
    }

    通过下面的命令,生成需要的c++,和py code

    # 生成py的code。python从数据库load数据,并保持为文件
    thrift -gen py data.thrift
    
    # 生成c++的code。线上服务是c++写的,它需要load py 生成的数据文件
    thrift -gen cpp data.thrift

    dump 数据文件的python code 片段

    def dump_deals():
        deals = DealsTiny() 
        # 从db load数据
    
        # 用Thrift dump deals为bytes
        itransport = TTransport.TMemoryBuffer()
        prof = TBinaryProtocol.TBinaryProtocolAcceleratedFactory()
        ipro = prof.getProtocol(itransport)
        deals.write(ipro)
    
        # 写入文件
        buf = itransport.getvalue()
        with open("deals_info.bin", 'w') as f:
            f.write(buf)

    load 数据文件的C++ code 片段

    int load_deals(std::string file, DealsTiny &deals) {
        // mmap文件到内存
        int fd = open(file.c_str(), O_RDONLY);
        if (fd < 0) {
            perror(file.c_str());
            return fd;
        }
        const long size = get_file_size(file);
        unsigned char *buffer = (unsigned char*)mmap(NULL, size, PROT_READ, MAP_PRIVATE | MAP_POPULATE, fd, 0);
        close(fd);
        if (buffer == MAP_FAILED) {
            perror("mmap");
            return -1;
        }
    
        // 用Thrift load数据文件。
        shared_ptr<TTransport> itransport(new TMemoryBuffer(buffer, size));
        TBinaryProtocol ipro(itransport);
        deals.read(&ipro);
    
        munmap(buffer, size);
        return 1;
    }

    Thrift的BinaryProtocol很高效,用这种方式load数据文件方便,且快,很喜欢。

  5. 13 Nov 2013

    线上Golang程序 GC调优一例

    Golang 是一个很有意思的语言,第一次看它介绍时,就很喜欢。半年前加入美团,有机会用它写了几个线上程序。其中一个程序Router,每天需要转发几千万的请求。由于需要根据请求内容决定route路径,它需要加载几十万deal(美团单)的信息到内存供查询。问题来了,用map装的几十万数据让gc很辛苦。

    Deal数据

    // Deal的定义
    type DealTiny struct {
            Dealid    int32
            Classid   int32
            Mttypeid  int32
            Bizacctid int32
            Isonline  bool
            Geocnt    int32
    }

    gc停顿

    用go写一个简单的Web程序,设置GOGCTRACE环境变量为1后启动程序,用wrk压力测试,观察控制台打出的gc停顿时间。

    GOGCTRACE=1 go run gc.go  # 设置环境变量,go gc时会打印详细信息
    
    wrk http://localhost:8080/ -d 10s  # 压力测试,发送大量请求,让程序“忙”起来,触发gc

    测试程序主要部分code:

    func main() {
            const SIZE = 500000 // 50万
            m := make(map[int32]DealTiny, SIZE)
            for i := 0; i < SIZE; i++ { // 把数据放进内存
                    m[rand.Int31()] = DealTiny{}
            }
            http.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) {
                    // 模拟内存分配,做一些计算
                    n := rand.Intn(4096) + 1024
                    buffer := make([]int, n)
                    for i := 0; i < n; i++ {
                            buffer[i] = rand.Intn(1024)
                    }
                    c := 0
                    for i := 0; i < n; i++ {
                            if buffer[i] > 512 {
                                    c += 1
                            }
                    }
                    fmt.Fprintf(w, "n: %d, more than 512 count: %d", n, c)
            })
            log.Fatal(http.ListenAndServe(":8080", nil))
    }

    程序在控制台的部分输出

    # go 1.1.1; Linux 3.2.0; CPU Intel(R) Core(TM) i7-2600 CPU 3.40GHz
    
    gc83(1): 8+0+0 ms, 62 -> 31 MB 19455 -> 3211 (1291202-1287991) objects, 0(0) handoff, 0(0) steal, 0/0/0 yields
    gc84(1): 8+0+0 ms, 62 -> 31 MB 19087 -> 3213 (1307079-1303866) objects, 0(0) handoff, 0(0) steal, 0/0/0 yields
    gc85(1): 8+0+0 ms, 62 -> 31 MB 18935 -> 3212 (1322802-1319590) objects, 0(0) handoff, 0(0) steal, 0/0/0 yields

    gc停顿时间为8ms,且线上CPU比测试机主频低,且是虚拟机,停顿时间比8ms长一些。这么长的停顿时间,显然是不能接受的。需要想办法优化。

    查看go的代码 发现,gc时,需要一个一个的扫描map的key和value,自然是相当贵的。

    go没有像jvm那样多的可以调整的参数,并且不是分代回收。优化gc的方式仅仅只能是通过优化程序。但go有一个优势:有真正的array(而仅仅是an array of referece)。go的gc算法是mark and sweep,array对此是友好的:整个array一次性被处理。可以用一个array用open addressing的方式实现map,以此优化gc(也会减少内存的使用,后面可以看到)

    // DealMap 为array backend hash table
    dm := NewDealMap(SIZE)
    for i := 0; i < SIZE; i++ {
        dm.Put(DealTiny{Dealid: rand.Int31()})
    }

    此次,gc日志为

    gc80(1): 0+0+0 ms, 25 -> 12 MB 7235 -> 803 (507340-506537) objects, 0(0) handoff, 0(0) steal, 0/0/0 yields
    gc81(1): 0+0+0 ms, 25 -> 12 MB 7184 -> 803 (513722-512919) objects, 0(0) handoff, 0(0) steal, 0/0/0 yields
    gc82(1): 0+0+0 ms, 25 -> 12 MB 7340 -> 803 (520260-519457) objects, 0(0) handoff, 0(0) steal, 0/0/0 yields

    可以看出,gc回收非常迅速(0ms),并且内存使用也由原来gc后的31M 减少到12M。优化效果是很明显的。

    DealMap的实现

    type DealMap struct {
        table   []DealTiny
        buckets int
        size    int
    }
    
    // round 到最近的2的倍数
    func minBuckets(v int) int {
        v--
        v |= v >> 1
        v |= v >> 2
        v |= v >> 4
        v |= v >> 8
        v |= v >> 16
        v++
        return v
    }
    
    func hashInt32(x int) int {
        x = ((x >> 16) ^ x) * 0x45d9f3b
        x = ((x >> 16) ^ x) * 0x45d9f3b
        x = ((x >> 16) ^ x)
        return x
    }
    
    func NewDealMap(maxsize int) *DealMap {
        buckets := minBuckets(maxsize)
        return &DealMap{size: 0, buckets: buckets, table: make([]DealTiny, buckets)}
    }
    
    // TODO rehash策略
    func (m *DealMap) Put(d DealTiny) {
        num_probes, bucket_count_minus_one := 0, m.buckets-1
        bucknum := hashInt32(int(d.Dealid)) & bucket_count_minus_one
        for {
            if m.table[bucknum].Dealid == 0 { // insert, 不支持放入ID为0的Deal
                m.size += 1
                m.table[bucknum] = d
                return
            }
            if m.table[bucknum].Dealid == d.Dealid { // update
                m.table[bucknum] = d
                return
            }
            num_probes += 1 // Open addressing with Linear probing 
            bucknum = (bucknum + num_probes) & bucket_count_minus_one
        }
    }
    
    func (m *DealMap) Get(id int32) (DealTiny, bool) {
        num_probes, bucket_count_minus_one := 0, m.buckets-1
        bucknum := hashInt32(int(id)) & bucket_count_minus_one
        for {
            if m.table[bucknum].Dealid == id {
                return m.table[bucknum], true
            }
            if m.table[bucknum].Dealid == 0 {
                return m.table[bucknum], false
            }
            num_probes += 1
            bucknum = (bucknum + num_probes) & bucket_count_minus_one
        }
    }