最后更新于 .

最近在grahite上看到响应时间变得很长,虽说之前没有特意去优化性能,但是感觉也不应该这么差才对。

QQ20150406 1

我们的服务器框架用的就是我之前开源的 maple,每个命令字都对应一个入口函数,如下:

@app.route(2)
def login(request):
    logger.error("login: %s", request.gw_box)
    uid = request.box.get_json()["uid"]
    request.login_client(uid)
    time.sleep(1)
    request.write_to_client(dict(
        ret=0,
        body="login %s" % uid
    ))

所以只要找到一种方法分析这个函数对应的内部调用情况就可以了。

很方便的,python内置了cProfile类来完成我们想要的功能,我给封装成为一个装饰器,用起来更方便一些,当然在django和flask中也可以直接用。

def monitor_profile(func):
    import cProfile
    import functools
    @functools.wraps(func)
    def func_wrapper(*args, **kwargs):
        def tmpfunc():
            return func(*args, **kwargs)
        # 直接用run是不行的
        cProfile.runctx("tmpfunc()", globals(), locals(), "%s.stat" % func.__name__)
    return func_wrapper

执行到对应的函数后,就会将统计写到函数名对应的stat文件中,比如 login.stat。

相应的,我也封装了一个分析工具:

import sys
import argparse
import pstats

def build_parser():
    parser = argparse.ArgumentParser()
    parser.add_argument('-f', '--file', help='stat filename', action='store', required=True)
    parser.add_argument('-s', '--sort', help='sort type: cumulative, time', action='append')
    parser.add_argument('-p', '--percent', help='sort type', action='store', default=0.5, type=float)
    parser.add_argument('-d', '--dir', help='show directory', action='store_true')
    return parser

def main():
    args = build_parser().parse_args()
    p = pstats.Stats(args.file)

    sort_keys = args.sort or ('cumulative', 'time')

    if not args.dir:
        p = p.strip_dirs()

    p.sort_stats(*sort_keys).print_stats(args.percent)


if __name__ == '__main__':
    main()

用起来非常简单,执行一下:

python stat.py -f login.stat -p0.1

输出结果如下:

Mon Apr  6 11:16:02 2015    login.stat

         442 function calls (439 primitive calls) in 1.002 seconds

   Ordered by: cumulative time, internal time
   List reduced from 107 to 11 due to restriction

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    1.002    1.002 :1()
        1    0.000    0.000    1.002    1.002 worker.py:40(tmpfunc)
        1    0.000    0.000    1.002    1.002 worker.py:46(login)
        1    1.000    1.000    1.000    1.000 {time.sleep}
        1    0.000    0.000    0.001    0.001 request.py:73(write_to_client)
        1    0.000    0.000    0.001    0.001 __init__.py:1176(error)
        1    0.000    0.000    0.001    0.001 __init__.py:1260(_log)
        3    0.000    0.000    0.000    0.000 box.py:41(__init__)
        1    0.000    0.000    0.000    0.000 request.py:146(login_client)
        1    0.000    0.000    0.000    0.000 __init__.py:1281(handle)
        1    0.000    0.000    0.000    0.000 __init__.py:1313(callHandlers)

可以明显看到时间消耗在 time.sleep 上。

好了,上面只是一个简单的示例,接下来看今天解决的问题的真实情况。

下面两张图分别是牌桌内有2人和7人的情况下的调用图。

2人:

QQ20150406 3

7人:

QQ20150406 2

 

异常的部分均使用颜色加亮了,可以看出几个端倪:

  1. 随着人数变多,有些部分的请求翻了几倍
  2. 读取数据库和redis的调用量太大

既然知道了是与存储通信的问题,那么接下来就来看看是哪些地方调用了 get_db_user,get_user_from_db。

cProfile 提供了一个方法:

#如果想知道有哪些函数调用了bar,可使用
p.print_callers(0.5, "bar")

所以通过这种方法拿到:

4EF1E801 22DE 45B1 BC10 9CF9154FB56B

CBF7C01C C2D2 4164 A5C7 673B38B11EB4

 

所以接下来就去看下上面的代码中这些数据库调用是否是必要就可以了。

基本就是这样了。

另外之前也出现过python内存泄漏的定位,可惜没有写下来文档,只记得是用 objgraph,不过用起来也比较简单,等下次遇到再说吧。

Pingbacks

Pingbacks已关闭。

评论

  1. 李坤

    李坤 on #

    博主。你好,看了你出神入化的VIM使用技巧,真的很佩服,羡慕,我找了你很多原来的文章,都没有找到困惑我得一个问题。我得问题是这样的,希望你看到的时候能回答我一下:我用gvim,在gvim中执行命令 :!make ,按道理说这个make命令应该在我当前目录下寻找makefile 并执行,但是他总会去我得默认目录下找makefile 而非 当前目录下,找了2天也没能找到解决方案。希望博主能帮忙解决这个问题。现在只能打开一个cmd,一个gvim来写代码,虽然也不麻烦,但是心里还是比较烦。如果解决不了,你也可以教我一下如何在:!下连续执行两条命令,这样我也可以使用这个命令 :!cd %:p;make

    Reply

  2. 朱念洋

    朱念洋 on #

    "将当前文件所在目录设置为当前目录nmap cd :call SetCurDir()function! SetCurDir() execute "lcd %:p:h" echohl WarningMsg | echo "Succ to lcd to ".getcwd() | echohl Noneendfunction我一般先手动敲个cd

    Reply

    1. 李坤

      李坤 on #

      受你的启发,我可以仿照你这个写一个make的函数,然后make的时候先进入当前目录,很nice的方法,谢谢,不过我觉得肯定有可以设置的地方,我这个不知道哪里设置错了可能谢谢啦

      Reply

    2. 李坤

      李坤 on #

      博主 按照你这个思路,搞了很久还是不行哦。另外 我在Gvim下 先执行!cd “我得目录” & make 这种方法,可以执行到make命令,但是路径还是cmd默认路径,我怀疑是不是 这个想法本身就不能实现的,g++之类的命令本身都是可以加路径的,所以可以做到,但是make是不可以加参数指定路径的了,求指点,我QQ 339496143

      Reply

      1. 朱念洋

        朱念洋 on #

        不会吧,我一直是这么用啊。。还有就是make也是可以加路径的:make -C dir

        Reply

  3. 依云

    依云 on #

    咦那个高亮行的插件是什么,mark(script_id=2666)么?

    Reply

    1. 朱念洋

      朱念洋 on #

      对,Mark,哈哈

      Reply

发表评论