O Sol diz: Identifique a função de gargalo com Python cProfile!

9 min

python
language: ja bn en es hi pt ru zh-cn zh-tw

Nós!
Ugh!
Venham!
Miau!

Olá, sou um inútil.
Recentemente, tem sido muito divertido ouvir o canal de Masahiro Sakurai, ex-funcionário do HAL Laboratory, como se fosse um rádio enquanto mexo no PC.
Na verdade, as memórias de quando eu mexia no 3DS voltaram, e os Nintendo Directs do presidente Iwata que eu assistia na época eram sempre divertidos. Revisando, figuras como Toshio Ikeda da Fujitsu, por exemplo, mostram uma paixão incrível em documentários, e é um mundo inacreditável que eles viajassem para os EUA tantas vezes naquela época. Naquela época, havia a Guerra do Vietnã, e as sombras do pós-Segunda Guerra Mundial ainda pairavam, então de onde vinha toda aquela energia?

Introdução

Eu não estava muito ciente da velocidade de execução de linguagens de script, mas ao executar o cuckooget que estou desenvolvendo, acabei me preocupando com isso.
Em parte, é possível executar código Rust dentro do interpretador usando PyO3/maturin com código escrito em Rust.
Simplificando, funções escritas em Rust são transformadas em bibliotecas Python e executadas através de arquivos binários compilados a partir do código Rust. A razão é simples: para processos que envolvem cálculos de CPU, parece que executá-los com este arquivo binário seria mais rápido. No final, ficou mais rápido, mas há um grande erro nisso.
Primeiro, a medição foi feita sem realizar um teste de benchmark com código puramente Python.
Mesmo nas "Notas sobre Programação em C" escritas por Rob Pike, conhecido como o pai do Go,

Regra 1: Você não pode saber onde um programa gastará seu tempo. Os gargalos ocorrem em lugares surpreendentes. Portanto, não faça suposições nem otimizações de velocidade até que você tenha clareza sobre onde está o gargalo.

Se é assim, a medição deve ser feita. Se este é o princípio para a linguagem C de baixo nível, é impensável que não se aplique às camadas de nível superior.

Às vezes esqueço essas coisas, então sinto profundamente que algo como a filosofia UNIX, que envolve verificações regulares, é necessário para me disciplinar.

Dito isso, sou humano e, embora eu saiba, acabo tendendo a puxar valores atípicos...

Medição com cProfile

No início, eu estava usando um método primitivo com import time, start_time = time.time() e, após o término da execução da função, end_time = time.time() seguido de print(f"exec time {start_time - end_time}"). Mas pensei: 'Estou usando um computador, por que ser tão ineficiente?!' Então, procurei algo que pudesse exibir o tempo de execução para cada função.
Parece que existe algo chamado cProfile como parte da biblioteca padrão. O site abaixo é fácil de entender.
Analisando o desempenho do código com Python cProfile

No meu caso, verifiquei da seguinte forma.

python3 -m cProfile -o profile.pstats ./main.py https://soulminingrig.com/ site

Com isso, o tempo de execução das funções executadas por ./main.py é armazenado em um arquivo binário chamado profile.pstats.

Verificando os resultados da execução da função

No site anterior, eles usavam um arquivo executável Python, mas é mais fácil entrar no modo de linha de comando do pstats para verificar.

python3 -m pstats profile.pstats

Isso entra no modo de linha de comando do pstats, e os resultados da saída podem ser verificados da seguinte forma.

profile.pstats% stats 5
Thu Nov  7 20:24:10 2024    profile.pstats

         48488696 function calls (47625490 primitive calls) in 51.151 seconds

   Random listing order was used
   List reduced from 3017 to 5 due to restriction <5>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     1586    0.001    0.000    0.001    0.000 /home/haturatu/.local/lib/python3.12/site-packages/aiohttp/client_reqrep.py:909(__del__)
       80    0.000    0.000    0.001    0.000 /usr/lib/python3.12/copy.py:247(_reconstruct)
        4    0.000    0.000    0.005    0.001 /usr/lib/python3.12/encodings/__init__.py:71(search_function)
        3    0.000    0.000   98.745   32.915 /usr/lib/python3.12/asyncio/base_events.py:651(run_until_complete)
     1103    0.001    0.000    0.003    0.000 /usr/lib/python3.12/re/_parser.py:312(_class_escape)

Você pode verificar outros comandos com help.

profile.pstats% help

Documented commands (type help <topic>):
========================================
EOF  add  callees  callers  help  quit  read  reverse  sort  stats  strip

No meu caso, eu usei stats 100 para gerar a saída, abri-a com vim em outro terminal, copiei e colei, e depois quit.
Em relação a este arquivo de texto salvo após colar no vim, vamos analisá-lo com awk e sort.

No caso de tottime

$ awk '{ print $2","$6 }' bench | sort | column -t -s "," | tail 
0.009    /usr/lib/python3.12/re/_compiler.py:243(_optimize_charset)
0.010    /usr/lib/python3.12/concurrent/futures/_base.py:428(result)
0.012    /usr/lib/python3.12/asyncio/base_events.py:627(run_forever)
0.013    /usr/lib/python3.12/re/__init__.py:280(_compile)
0.018    /usr/lib/python3.12/re/_compiler.py:37(_compile)
0.022    /usr/lib/python3.12/concurrent/futures/_base.py:497(set_running_or_notify_cancel)
0.030    /home/haturatu/git/devgit/async_web_mirror.py:186(download_and_save_image)
0.031    /usr/lib/python3.12/re/_parser.py:512(_parse)
0.061    /usr/lib/python3.12/concurrent/futures/_base.py:537(set_result)
tottime  filename:lineno(function)

De alguma forma, parece que apenas tottime é suficiente como informação para um benchmark por função, por enquanto.

O gargalo do Beautiful Soup 4 é apenas uma impressão?

O que estava lento em outros ambientes parecia ser search_tag em element.py, que é chamado por bs4.
O que me chamou a atenção foi aqui:

        if ((not self.name)
            or call_function_with_tag_data
            or (markup and self._matches(markup, self.name))
            or (not markup and self._matches(markup_name, self.name))):

É difícil acreditar que o gargalo esteja na operação or...
No entanto, existem apenas 7 lugares em element.py onde or é avaliado, e três deles estão sendo usados aqui.
Algo aqui cheira mal.

Bem, o assunto acabou virando bs4, então é isso por enquanto.
Até a próxima.

Related Posts