[Python] Visualisez et identifiez les pièces lentes avec pytest

Au fur et à mesure que le nombre de tests dans un projet augmente, la rotation des CI deviendra plus lente et le stress augmentera lorsque les tests sont fréquemment effectués localement. Je me demande s'il y a 10 000 tests, mais parfois je reçois la question "Oh, il y a des cas de test lents?" C'est encore plus problématique si le code produit est responsable de la lenteur des tests. Étant donné que le framework de test de python utilise pytest, c'est un rappel que dans le cas de pytest ci-dessous, il recherche un traitement lent comme celui-ci.

J'ai principalement fait les deux choses suivantes.

① Sortie d'un cas de test avec un temps de traitement long avec l'option --durations de pytest (2) Profil avec pytest-profiling pour identifier les points de traitement lents.

Code de test

Il s'agit du code de test utilisé dans cet article. Une liste d'entiers de 1 à 10 000 000 dans l'ordre est créée par 4 modèles, et enfin comparée par assert. La lecture du sommeil dans ** setup () ** n'est incluse que pour faciliter la compréhension lors de la sortie du temps de traitement du test, et cela n'a aucun sens en termes de traitement.

Le code source peut être trouvé à ici.

test_sample.py

import time
import pytest
import sys


COUNT = 10000000

@pytest.fixture(scope='module')
def expected():
  #Création de valeurs attendues à comparer avec assert
  return [i for i in range(1, COUNT)]

@pytest.fixture(scope='function', autouse=True)
def setup():
  #Manchon qui n'a pas de sens en termes de traitement
  time.sleep(0.1)
  yield
  time.sleep(0.2)

def test_1_1(expected):
  actual = [i for i in range(1, COUNT)]
  assert expected == actual


def test_1_2(expected):
  actual = list({i for i in range(1, COUNT)})
  assert expected == actual


def test_1_3(expected):
  actual = []
  for i in range(1, COUNT):
    actual.append(i)
  assert expected == actual


def test_1_4(expected):
  actual = []
  for i in range(1, COUNT):
    # actual = actual + [i]Il faut du temps pour mourir
    actual += [i]
  assert expected == actual

Déterminez quel test est lent

Si vous ajoutez l'option --durations = N lors de l'exécution de pytest, le test le plus lent + N avant et après le traitement (setup / teardown) sera affiché dans le résultat de l'exécution. Si «N = 0» est défini, tous les résultats seront affichés.

Le résultat de l'exécution de pytest avec --durations = 0 est le suivant. Par défaut, les résultats de 0,01 s ou moins sont masqués, mais avec l'option -vv, tous les résultats sont affichés.

=========== slowest test durations =========== 
2.13s call     tests/test_sample.py::test_1_3
1.25s call     tests/test_sample.py::test_1_4
1.08s call     tests/test_sample.py::test_1_2
0.81s call     tests/test_sample.py::test_1_1
0.66s setup    tests/test_sample.py::test_1_1
0.20s teardown tests/test_sample.py::test_1_2
0.20s teardown tests/test_sample.py::test_1_4
0.20s teardown tests/test_sample.py::test_1_3
0.20s teardown tests/test_sample.py::test_1_1
0.10s setup    tests/test_sample.py::test_1_4
0.10s setup    tests/test_sample.py::test_1_2
0.10s setup    tests/test_sample.py::test_1_3
============= 4 passed in 7.40s =============

Les quatre premiers sont les résultats d'exécution de quatre cas de test. Il est rapide d'écrire en notation d'inclusion simple. Ensuite, le prétraitement (configuration) de ** test_1_1 () ** prend environ 0,66 seconde. Cela semble être l'ajout du temps de traitement de ** attendu () ** + 0,1 seconde de sommeil dans ** setup () **. Ceci est suivi de quatre démontages pour chaque processus de test et de configuration autre que ** test_1_1 () **. C'est le même que le temps de sommeil décrit dans ** setup () **.

Déterminez quel processus du test est lent

Après avoir identifié les tests lents, vous devez identifier les processus du test lents pour améliorer la vitesse. Selon Net Wisdom, il existe un moyen d'exécuter pytest et profiler en même temps. Cependant, il est nécessaire d'analyser le résultat de sortie du profil séparément en utilisant ** pstats ** ou similaire. Quand j'étudiais si ce domaine pouvait être facilement réalisé, je suis arrivé à pytest-profiling.

pytest-profiling

Vous pouvez l'installer avec pip.

pip install pytest-profiling

Vous pouvez également afficher le résultat du profil au format SVG, mais Graphviz est requis, veuillez donc l'installer séparément.

C'est facile à utiliser, il suffit d'ajouter l'option --profile-svg lors de l'exécution de pytest.

pytest tests/test_sample.py --profile-svg

Lorsqu'il est exécuté avec l'option --profile-svg, pytest-profiling effectue le traitement suivant.

1. Exécutez pytest et cProfile
2. Analyser les résultats du profil avec pstats
3. Convertissez le résultat de l'analyse en graphique (fichier à points) avec gprof2dot
4. Convertissez le graphique en image SVG avec la commande dot (Graphviz)

Si vous ajoutez --profile au lieu de l'option --profile-svg, il semble que le 3ème processus ci-dessus soit exécuté.

Après une série de traitements, un répertoire prof est créé et un fichier prof contenant des informations d'analyse pstats et une image SVG sont créés en dessous. Les fichiers suivants seront créés dans le répertoire prof.

prof
├ combined.prof
├ combined.svg
├ test_1_1.prof
├ test_1_2.prof
├ test_1_3.prof
└ test_1_4.prof

** test_1_1.prof ** à ** test_1_4.prof ** sont des informations d'analyse de profil pour chaque cas de test. Le nom du test est donné au nom du fichier, mais le japonais, etc. est créé en le remplaçant par un trait de soulignement. ** shared.prof ** est une information d'analyse de profil pour tous les tests effectués. ** Combiné.svg ** est converti en graphique et ensuite converti en une image SVG, qui ressemble à l'image ci-dessous.

Comment lire le graphique est expliqué dans le README de gprof2dot. Chaque nœud du graphique contient les informations suivantes.

+------------------------------+
|        function name         |
| total time % ( self time % ) |
|         total calls          |
+------------------------------+

• ** nom de la fonction **… Nom de la fonction
• ** temps total% **… Rapport entre le temps d'exécution de cette fonction et ** toutes les fonctions enfants ** et le temps d'exécution total
• ** self time% **… Le rapport entre le temps d'exécution de cette fonction uniquement et le temps de traitement total
• ** total des appels **… Nombre d'assemblées générales au cours desquelles cette fonction a été appelée (y compris les appels récursifs)

De plus, les informations suivantes sont décrites sur l'arête qui relie la fonction appelante et la fonction appelée (exprimée en tant que parent et enfant).

           total time %
              calls
parent --------------------> children

• ** temps total% **… Pourcentage du temps d'exécution transféré de l'enfant au parent
• ** appels **… Le nombre de fois qu'un parent a lu un enfant

Si vous suivez l'ordre du nœud parent le plus élevé dans l'ordre décroissant du temps total%, il semble que vous puissiez facilement identifier la partie de traitement lent.

Défi: cela ne fonctionne pas bien avec Windows

Je l'exécutais sous Windows au début, mais le fichier prof a été généré mais le fichier SVG n'a pas été créé. Si vous regardez attentivement, il semble que le système d'exploitation pris en charge n'inclut pas Windows.

Cependant, comme le fichier prof est généré, il était possible de convertir manuellement le fichier prof en SVG. Je pense que gprof2dot sera installé lorsque vous installerez pytest-profiling.

gprof2dot -f pstats prof/combined.prof > prof/tmp
dot -Tsvg -o prof/combined.svg prof/tmp

En passant, je l'ai exécuté à partir du terminal Visual Studio Code, mais j'ai eu une erreur lors de l'exécution de la commande dot. Cela ne semble pas fonctionner si le shell par défaut est PowerShell. Passer de "Select Default Shell" à cmd a bien fonctionné.

finalement

Si vous écrivez ce qui suit dans le fichier de configuration pytest et le placez sous le répertoire racine du projet, le profilage pytest sera exécuté lors de l'exécution de pytest.

pytest.ini

[pytest]
testpaths = tests
python_files = test_*.py
addopts = -vv --durations=0 --profile-svg
pytest_plugins = ['pytest_profiling']

Cependant, s'il y a de nombreux cas de test, les informations d'analyse seront compliquées, alors identifiez d'abord la partie lente du test avec l'option --durations, puis exécutez le profilage pytest uniquement pour le test correspondant afin d'identifier la partie lente du processus. Je pense que c'est plus facile de le faire. Si vous l'écrivez dans le fichier de configuration, il sera exécuté à chaque fois.