파이썬을 쓰다보면 코드 길이와 복잡도가 증가할 수록 어디서 느려지는지 원인을 찾기 쉽지 않은 경우가 있습니다. 이러한 상황에서 원인을 찾기 수월하게 해주는 몇가지 profiling 툴에 대해 몇 가지 소개하고 그 사용법을 안내합니다.
이게 왜 필요했냐? 그래서 이걸로 뭘 했냐?
사건의 발단입니다.
새 기능을 구현하기 위해 코드를 Python 넘겨받았습니다. 그런데 한번 돌릴때마다 3 ~ 5초정도 걸렸는데요. 구현할 프로젝트 시스템 특성상 데이터를 넣으면 real-time 으로 결과가 바로 나와야 하는데, script 한번 실행하는데 수 초가 걸리면 서비스도 힘들뿐더러 개발 단계에서도 반복 테스트를 할텐데 시간이 오래 걸릴 수 밖에 없습니다.
C# .NET 개발할때는 당연히 VS 내장 프로파일러나 dotTrace 같은 툴로 프로파일링 했지만, python은 생소해서 알아보게 되었습니다. 후에 사용한 툴을 소개하겠지만, 이러한 프로파일링 툴을 사용하여 코드를 분석 후 최적화를 진행한 결과 3초 이상 걸리던 python script 실행시간을 10배 이상 줄이는데 성공했습니다.
노가다의 시작: time() function?
가장 간단한 방법입니다. 툴 설치하기도 귀찮고, 간단하게 빠른 구현을 원하고자 하면 다음의 방법이 베스트 솔루션일 수 있습니다. time 함수를 사용하여 코드 사이에 시작 시간과 끝나는 시간을 측정하여 해당 코드의 실행시간을 출력합니다.
import time
start_time = time.time()
main()
print("--- %s seconds ---" % (time.time() - start_time))코드를 실행하면 다음과 같이 실행시간이 출력될 것입니다.
--- 0.764891862869 seconds ---코드가 단순하고 간단할때는 이러한 솔루션이 방법이겠지만, 코드 길이와 복잡도가 증가할때 시간이 남고 잉여롭지 않는 한은 이러한 방법을 쓰는건 무리일 수 있습니다.
따라서 VizTracer와 cProfile을 이용한 call graph (DOT) 시각화 방법을 설치부터 사용까지를 단계별로 소개하겠습니다.
VizTracer
https://github.com/gaogaotiantian/viztracer
군더기가 없는 깔끔한 프로파일러입니다. 설치 후 terminal 에서 python 코드에 대해 바로 프로파일링을 돌리고 그 결과를 standalone 웹 페이지나 JSON 파일로 출력하여 전용 뷰어 결과 파일을 열어서 확인 할 수 있습니다.
구현중인 멀티 쓰레딩과 멀티 프로세스 프로파일링 기능을 지원하니 안성맞춤이라 판단하고 사용했습니다. 또한 개발중인 코드에 수정을 가하지 않고 프로파일링을 수행 후 그 결과를 웹 페이지로 output 되므로 웹 브라우저로 바로 열어서 확인 할 수 있어서 편리하게 사용했습니다.
설치는 다음과 같이 command line 에 입력하고 진행합니다. python 코드를 프로파일링 할 것이므로 당연하겠지만, 선행 작업으로 python 설치가 요구됩니다.
$ pip install viztracer설치 완료 후 다음의 명령어를 command line 에 입력하면 바로 프로파일링이 자동으로 수행되고 그 결과를 파일로 출력합니다. argument가 없으면 자동으로 result.json 파일로 결과가 출력됩니다.
$ viztracer my_script.pyInline code 에서는 다음과 같이 사용할 수 있습니다. 일부분의 코드에 대해 프로파일링을 수행하고자 하는 경우 이러한 방법이 도움될 수 있습니다.
from viztracer import VizTracer
tracer = VizTracer()
tracer.start()
# Something happens here
tracer.stop()
tracer.save() # also takes output_file as an optional argument결과를 standalone 웹 페이지 파일로 생성하려면 다음과 같이 명령어를 수정하고 입력합니다. -o result.html 인자를 추가하여 실행하면 결과로 result.html 파일이 생성됩니다.
$ viztracer -o result.html my_script.py수행 후 생성된 result.html 파일을 firefox 이나 chrome 같은 브라우저로 실행하면 다음과 같이 프로파일링 결과를 바로 확인 할 수 있습니다. GUI 환경에서 따로 추가적인 작업 없이 파일만 열면 바로 결과를 확인 할 수 있습니다.
다음은 python script 를 프로파일링 하고 확인한 웹 페이지를 보여주고 있습니다.
JSON으로 생성한 결과의 확인은 다음의 명령어를 입력합니다.
$ vizviewer result.json그러면 terminal 에 다음과 같음과 같은 메시지가 출력된 후 브라우저가 자동으로 실행됩니다.
Running vizviewer
You can also view your trace on http://localhost:9001
Press Ctrl+C to quit브라우저가 자동으로 실행되지 않으면 수동으로 print 된 주소로 접속하면 됩니다. GUI를 지원하지 않는 환경이 있을 수 있습니다. 그럴때는 JSON 결과 파일을 내려 받은 후 다음 Perfetto 웹 사이트에 접속하여 파일을 업로드하여 그 결과를 확인 할 수 있습니다.
사이드바 부분을 확인하면 open trace file 메뉴를 확인하면 됩니다.
프로파일링을 수행하면서 circular buffer가 꽉 찼다는 오류 메시지를 확인 할 수 있습니다. 그런 경우 파일 실행 시간이 길거나 call 이 무지막하게 이뤄지고 있어 프로파일러가 다 담지 못하는 상황이 발생할 수 있습니다.
Circular buffer is full, you lost some early data, but you still have the most recent data.
If you need more buffer, use "viztracer --tracer_entries <entry_number>"
Or, you can try the filter options to filter out some data you don't need
use --quiet to shut me up이 경우 에러 메시지에 언급된 것처럼 다음과 같이 tracer_entries, max_stack_depth 사이즈를 조정해주면 됩니다. 기본값은 1,000,000 입니다. 필요에 따라 사이즈를 늘리면 되지면 프로파일링 결과를 분석할때 내용이 많아 시간이 들 수 있습니다.
$ viztracer -o result.html -tracer_entries -max_stack_depth 30 5000000 my_script.pystack 깊이의 경우 실행하는 script 의 복잡도에 에 따라 적절히 조절하면 됩니다. 또한 min_duration 인자를 추가하여 특정 실행 시간 이상만 기록하도록 할 수 있습니다.
VizTracer를 사용하면서 매번 command line을 칠때마다 argument 를 입력하기 번거로운 경우가 있습니다. 이 경우 설정 파일을 생성하여 VizTracer 실행 시 자동으로 해당 configuration 파일을 참조하여 프로파일링을 수행합니다.
.viztracerrc 파일을 프로파일링을 수행할 파일의 경로에 생성하고 다음과 같이 필요한 설정을 넣고 실행하면 됩니다.
[default]
output_file = result.html
max_stack_depth = 30
min_duration = 0.3ms
tracer_entries = 10000000cProfile – call graph profiling visualization
어떤 function을 얼만큼 호출했으며, 걸린 시간이 어느정도인지 프로파일링을 돌릴 수 있는 툴입니다. 여기서는 이를 확장하여 call graph를 시각화에 그치지 않고 얼만큼 call 이 수행되었고, 그 비중까지 시각화하는 방법을 알아보겠습니다.
다음은 command line에서 cProfile로 프로파일링을 돌렸을 때 출력되는 결과를 보여주고 있습니다.
$python3 -m cProfile my_script.py
Ordered by: standard name
ncalls tottime percall cumtime percall filename:lineno(function)
6 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:100(acquire)
6/1 0.000 0.000 0.008 0.008 <frozen importlib._bootstrap>:1022(_find_and_load)
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:1053(_handle_fromlist)
6 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:125(release)
6 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:165(__init__)
6 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:169(__enter__)
6 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:173(__exit__)
6 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:179(_get_module_lock)
....
....앞서 cProfile 수행 결과를 pstats 파일로 저장 할 수 있도록 argument를 추가 후 실행합니다.
$ python3 -m cProfile -o profile.pstats i_hate_python.py그러면 프로파일링을 수행한 python script 가 위치한 경로에 profile.pstats 파일이 생성되었을 것입니다. 이제 이 파일을 DOT 으로 변환하는 방법을 알아보겠습니다.
시각화 하려면 먼저 시각화 라이브러리 graphviz 를 설치해야합니다. call graph 시각화 툴인 doxygen을 사용한다면 설치 했을 라이브러리 입니다. Ubuntu 리눅스를 기준으로 다음의 command 를 입력하고 설치합니다.
$ sudo apt-get install graphviz그리고 profiling 결과를 DOT로 변환할 라이브러리를 설치합니다. 라이브러리는 gprof2dot 사용할 것입니다. 다음의 command 를 입력하여 설치를 진행합니다.
$ pip install gprof2dot또는 다음과 같이 Git Clone으로 설치할 수 있습니다.
$ git clone https://github.com/jrfonseca/gprof2dot설치 완료하면 사용 방법은 간단합니다. 앞서 프로파일링으로 출력된 결과 파일은 profile.stats 와 함께 다음과 같이 command 를 입력하고 실행합니다.
$ gprof2dot -f pstats profile.pstats | dot -Tsvg -o callgraph.svgGit 으로 설치한 경우 다음과 같이 입력하여 명령어를 실행합니다. Git으로 Clone 한 폴더에 있는 python script 를 실행해야 하므로 명령어는 다음과 같습니다. 개발 환경에 맞게 수정 후 실행하면 됩니다.
$ python3 ./gprof2dot/gprof2dot.py -f profile.pstats | dot -Tsvg -o callgraph.svg실행이 완료되면 같은 경로에 callgraph.svg 파일이 생성되어 있습니다. 기본적으로 SVG 벡터 이미지 파일로 생성됩니다. 프로파일링 크기에 따라 DOT 생성 시간이 걸릴 수 있습니다.
열어서 확인하면 다음과 같이 DOT call graph 에 call 이 많은 순으로 색상이 결정됩니다. 다음은 dummy python script 에 대해 프로파일링을 수행하고 시각화한 DOT를 보여주고 있습니다.
Python 의 라이브러리 import 에서 시간을 꽤 잡아먹는것을 확인 할 수 있습니다.
지금까지 VizTracer 와 cProfile의 시각화 방법에 대해 알아보았습니다. VizTracer의 경우 결과 분석 UI가 직관적이므로 원하는 부분을 수월하게 분석할 수 있고, gprof2dot 를 통한 시각화는 어떤 부분에서 병목이 발생하는지 한 눈에 확인 할 수 있어, 병목이 발생한 부분을 바로 찾을 수 있는 이점이 있습니다.
툴 마다 각각의 이점이 있으니 필요에 따라 사용하면 되겠습니다. 또한 앞서 언급한 툴의 Git 저장소에 사용 메뉴얼에 고급유저를 위한 사용법이 있으니 참고하시기 바랍니다.
2023/05/22 추가
괜찮은 프로파일러를 발견해서 추가로 링크 겁니다
https://github.com/ionelmc/python-hunter
Reference
- https://docs.python.org/3/library/profile.html
- https://viztracer.readthedocs.io/en/latest/
- https://stackoverflow.com/questions/582336/how-do-i-profile-a-python-script
- https://stackoverflow.com/questions/50558849/python-how-to-trace-function-execution-order-in-large-project
