Я пытаюсь определить, как правильно использовать cProfile и pstats с асинхронным кодом.Я профилирую свой скрипт, запустив cProfile.run('loop.run_until_complete(main())', 'profile.stats').
После использования pstats для сортировки по SortKeys.TIME я получаю следующий вывод:
In [9]: sorted_stats.print_stats()
Fri Feb 15 14:40:18 2019 profile.txt
67411199 function calls (67230882 primitive calls) in 305.899 seconds
Ordered by: internal time
ncalls tottime percall cumtime percall filename:lineno(function)
3617 273.162 0.076 273.162 0.076 {method 'poll' of 'select.epoll' objects}
14094092/14093931 1.527 0.000 1.904 0.000 {built-in method builtins.isinstance}
44901 1.166 0.000 1.166 0.000 {built-in method posix.stat}
784052 1.028 0.000 1.479 0.000 /usr/lib/python3/dist-packages/soupsieve/util.py:41(lower)
32070 0.887 0.000 1.565 0.000 /usr/lib/python3/dist-packages/bs4/element.py:620(<genexpr>)
4554545 0.729 0.000 0.756 0.000 /usr/lib/python3/dist-packages/bs4/element.py:1331(descendants)
1026560 0.726 0.000 3.358 0.000 /usr/lib/python3/dist-packages/bs4/element.py:1502(search)
448385 0.716 0.000 1.411 0.000 /usr/lib/python3/dist-packages/bs4/element.py:1528(_matches)
104 0.689 0.007 4.771 0.046 /usr/lib/python3/dist-packages/bs4/builder/_lxml.py:283(feed)
255143 0.655 0.000 1.575 0.000 /usr/lib/python3/dist-packages/bs4/__init__.py:391(endData)
137377 0.520 0.000 3.692 0.000 /usr/lib/python3/dist-packages/html5lib/_tokenizer.py:49(__iter__)
8574 0.510 0.000 2.392 0.000 /usr/lib/python3.7/traceback.py:318(extract)
167700 0.494 0.000 1.061 0.000 /usr/lib/python3/dist-packages/bleach/html5lib_shim.py:199(charsUntil)
53607 0.487 0.000 0.589 0.000 /usr/lib/python3/dist-packages/bs4/builder/__init__.py:158(_replace_cdata_list_attribute_values)
299357 0.485 0.000 0.485 0.000 /usr/lib/python3/dist-packages/bs4/element.py:258(setup)
22253 0.467 0.000 5.928 0.000 /usr/lib/python3/dist-packages/bs4/element.py:592(_find_all)
448385 0.437 0.000 2.225 0.000 /usr/lib/python3/dist-packages/bs4/element.py:1461(search_tag)
83147 0.424 0.000 2.365 0.000 /usr/lib/python3/dist-packages/bs4/builder/_lxml.py:176(start)
1293015 0.418 0.000 0.556 0.000 /usr/lib/python3/dist-packages/soupsieve/css_match.py:94(is_tag)
4824419 0.409 0.000 0.409 0.000 {method 'append' of 'list' objects}
73068 0.404 0.000 0.634 0.000 /home/jess/.local/lib/python3.7/site-packages/rfc3986/normalizers.py:127(encode_component)
868978 0.403 0.000 0.773 0.000 /usr/lib/python3/dist-packages/bleach/html5lib_shim.py:192(char)
454702 0.385 0.000 0.385 0.000 {method 'match' of 're.Pattern' objects}
2326981 0.374 0.000 0.415 0.000 {built-in method builtins.hasattr}
52 0.334 0.006 5.732 0.110 /usr/lib/python3/dist-packages/html5lib/html5parser.py:196(mainLoop)
... ... ... ... ... ...
Как видите, почти все время выполнения отображается как {method 'poll' of 'select.epoll' objects}.
У меня недостаточно опыта с cProfile или asyncio, чтобы понять, как интерпретировать этот результат.Я не могу сказать, показывает ли статистика, что моя программа тратит большую часть времени выполнения в poll(), потому что (a) cProfile плохо работает с asyncio и не дает правильную статистику, (b) это нормальное поведениеи я должен просто проигнорировать первую строку или (с) это индикатор какой-то ошибки в моей программе (которая сейчас действительно ужасно медленная по причинам, которые мне еще предстоит определить) ...
Это нормально для асинхронных процессов тратить столько времени на выполнение в poll()?Есть ли лучший способ профилировать асинхронный код с помощью cProfile или чего-то еще, что даст мне более точные результаты?Или это признак того, что в моем коде может быть какая-то ошибка, вызывающая это?
ПРИМЕЧАНИЕ: для контекста код, который я профилировал, в основном выбирает 50 страниц, обрабатывает HTML, а затемделать некоторую обработку текста / языка.Часть fetch() может объяснить большую часть времени в poll().Но это при быстром интернет-соединении (> 5 МБ / с), поэтому я не думаю, что нужно тратить этот% времени на получение всего нескольких десятков text/html страниц.Похоже, что-то еще происходит, или статистика не верна ...