Python中的asyncio性能分析
1. 工具
1.1 cProfile
一般對分析python性能的工具都會用cprofile。
但是這玩意對多線程和asyncio的支持并不友好,如果用它對asyncio分析,會發(fā)現(xiàn)CPU都耗費在了poll上面,無法確定到底耗費在哪些協(xié)程上。
例如:
會出現(xiàn)python - What is correct way to use cProfile with asyncio code? - Stack Overflow這樣的問題。
用法:
python3 -m cProfile -o test.prof test2.py
運行完會生成一個test.prof文件,本文第2節(jié)介紹如何通過可視化工具查看這個文件。
也可以通過cprofilev來查看。
pip install cprofilev
cprofilev -f ./test.prof
瀏覽器中打開運行上方代碼后生成的ip和端口號,如下:
2.1 yappi
這個工具可以測多線程、asycio等多種場景。
其實,CPython本身就自帶三個調優(yōu)工具,它們分別是cProfile,Profile和hotshot。
這三個工具對多線程的Python程序的性能剖析支持得都不好,開發(fā)者必須想辦法分別對線程進行profile,然后再把結果合并。
而yappi的出現(xiàn)就是為了解決Python多線程程序的profile問題。
安裝:
pip install yappi
下面先通過一個簡單案例介紹使用yappi庫,這是對多線程程序進行profile的代碼例子。
需要注意的是,yappi.set_clock_type函數(shù)的參數(shù),如果是cpu,代表統(tǒng)計的是在CPU上執(zhí)行的時間,如果是wall,代表統(tǒng)計的是持續(xù)的時間。
import yappi if __name__ == "__main__": # yappi.set_clock_type("wall") yappi.set_clock_type("cpu") yappi.start() for i in range(10): t = threading.Thread(target=sum, args=(100, i,), name="hello"+str(i)) t.start() main_thread = threading.currentThread() for t in threading.enumerate(): if t is not main_thread: t.join() yappi.get_func_stats().print_all() yappi.get_thread_stats().print_all()
你可以按上面這個例子改造你自己多線程程序,然后運行,就會得到如下的分析結果。
Clock type: CPU Ordered by: totaltime, desc name ncall tsub ttot tavg ..ns/2.7/lib/python2.7/threading.py:752 Thread.run 10 0.000137 2.428557 0.242856 ..thub/Asgard/samples/yappi/yappi_sample.py:16 sum 10 0.000089 2.428420 0.242842 ..ub/Asgard/samples/yappi/funcs.py:5 consumer_time 10 0.414581 2.428331 0.242833 ..s/2.7/lib/python2.7/random.py:238 Random.randint 109362 0.729320 1.926393 0.000018 ..2.7/lib/python2.7/random.py:175 Random.randrange 109362 0.860899 1.197073 0.000011 ../2.7/lib/python2.7/threading.py:726 Thread.start 10 0.000224 0.001801 0.000180 ..7/lib/python2.7/threading.py:656 Thread.__init__ 10 0.000283 0.001404 0.000140 ..s/2.7/lib/python2.7/threading.py:603 _Event.wait 10 0.000152 0.001217 0.000122 ..7/lib/python2.7/threading.py:309 _Condition.wait 12 0.000423 0.001210 0.000101 ..2.7/lib/python2.7/threading.py:866 Thread.__stop 10 0.000255 0.000956 0.000096 ..s/2.7/lib/python2.7/threading.py:911 Thread.join 10 0.000257 0.000761 0.000076 ..ersions/2.7/lib/python2.7/threading.py:542 Event 10 0.000068 0.000587 0.000059 ../python2.7/threading.py:400 _Condition.notifyAll 10 0.000143 0.000580 0.000058 ..ons/2.7/lib/python2.7/threading.py:242 Condition 20 0.000169 0.000523 0.000026 ..7/lib/python2.7/threading.py:561 _Event.__init__ 10 0.000153 0.000519 0.000052 ..lib/python2.7/threading.py:373 _Condition.notify 10 0.000191 0.000403 0.000040 ..b/python2.7/threading.py:260 _Condition.__init__ 20 0.000286 0.000354 0.000018 ../python2.7/threading.py:300 _Condition._is_owned 22 0.000156 0.000292 0.000013 ..ib/python2.7/threading.py:709 Thread._set_daemon 10 0.000111 0.000242 0.000024 ...7/lib/python2.7/threading.py:1152 currentThread 21 0.000137 0.000205 0.000010 ..s/2.7/lib/python2.7/threading.py:64 Thread._note 54 0.000201 0.000201 0.000004 ...7/lib/python2.7/threading.py:59 Thread.__init__ 40 0.000135 0.000135 0.000003 ..2.7/threading.py:297 _Condition._acquire_restore 12 0.000087 0.000130 0.000011 ..hon2.7/threading.py:294 _Condition._release_save 12 0.000071 0.000108 0.000009 ../2.7/lib/python2.7/threading.py:570 _Event.isSet 20 0.000061 0.000061 0.000003 ..b/python2.7/threading.py:1008 _MainThread.daemon 10 0.000037 0.000037 0.000004 ..ns/2.7/lib/python2.7/threading.py:1183 enumerate 1 0.000016 0.000021 0.000021 name id tid ttot scnt Thread 3 123145399676928 0.087168 37 Thread 1 123145391263744 0.087128 138 Thread 8 123145420709888 0.087124 140 Thread 9 123145424916480 0.087121 40 Thread 2 123145395470336 0.087109 27 Thread 6 123145412296704 0.087088 92 Thread 5 123145408090112 0.087084 125 Thread 7 123145416503296 0.087072 51 Thread 4 123145403883520 0.087069 139 Thread 10 123145429123072 0.087030 132 _MainThread 0 140735541031744 0.023092 13
上半部分是函數(shù)調用統(tǒng)計。
- ncall: 調用次數(shù)
- tsub: 不包含子函數(shù)所占用的CPU時間
- ttot: 包含子函數(shù)所占用的CPU時間
- tavg: 包含子函數(shù)時平均占用CPU時間
下半部分是所有線程的統(tǒng)計結果。
- tid 線程
- idttot 線程總的CPU占用時間
- scnt 線程被調度到CPU上的次數(shù)
再看一個例子:
通過運行下方例子就會輸出每個函數(shù)/協(xié)程所占用的時間,并生成一個test.prof文件:
import asyncio import sys import yappi test_time = 5 # 測試時間 async def exit(): await asyncio.sleep(5) yappi.get_func_stats().print_all() yappi.stop() stats = yappi.convert2pstats(yappi.get_func_stats()) stats.dump_stats("test.prof") asyncio.get_event_loop().stop() sys.exit(0) async def do_something(num): for i in range(num): i = i+1 await asyncio.sleep(0) async def test1(): await do_something(10000) async def test2(): await do_something(100000) async def main(): asyncio.get_event_loop().create_task(exit()) while True: await test1() await test2() yappi.set_clock_type("cpu") yappi.start() loop = asyncio.get_event_loop() with yappi.run(): loop.run_until_complete(main())
輸出如下圖:
2. 可視化
2.1 SnakeViz
可以針對上面工具生成的prof文件進行分析,然后生成分析結果可以直觀地看到cpu時間都耗費在哪里了。
使用方法:
pip install snakeviz snakeviz test.prof
就會自動打開一個網(wǎng)頁來展示分析的情況。
2.2 gprof2dot
gprof2dot可以將prof文件生成一個圖片。
安裝:
apt-get install graphviz pip install gprof2dot
運行:
gprof2dot -f pstats test.prof | dot -Tpng -o output.png
生成的圖片如下圖所示
總結
以上為個人經(jīng)驗,希望能給大家一個參考,也希望大家多多支持腳本之家。
相關文章
Python 基于FIR實現(xiàn)Hilbert濾波器求信號包絡詳解
今天小編就為大家分享一篇Python 基于FIR實現(xiàn)Hilbert濾波器求信號包絡詳解,具有很好的參考價值,希望對大家有所幫助。一起跟隨小編過來看看吧2020-02-02