pytest débogage de la journalisation des impressions en temps réel

By | août 9, 2019
0 Comment

Expert Python

Dans de nombreuses circonstances, il est vraiment génial d’afficher le résultat d’un test en cours, sans attendre la fin.
Dans cet article, je vais décrire ma méthode pour contourner le mécanisme de capture de sortie de pytest, afin que je puisse voir mes instructions de débogage / journalisation en temps réel.

Rapide et rapide? Pas toujours

Les tests unitaires doivent être rapides afin que toute la suite de tests puisse être exécutée rapidement.

Mais quelle est la définition d’un test unitaire?
Et qu'est-ce que "rapide" et "rapidement" exactement?

Et que se passe-t-il si je n’effectue pas vraiment des tests unitaires traditionnels, mais plutôt des «unités de fonctionnalité» ou des «unités de fonctionnalité»?
Et si je suis ce que je teste réellement, c’est tout le système, avec des retards de communication, des temps de réglage du matériel, des temps d’acquisition des mesures et qui sait quelles sont toutes les autres latences du système.

Il existe de nombreux tests qui sont intéressants à exécuter à partir d’un framework de tests unitaires qui ne correspondent pas à la définition traditionnelle d’un test unitaire rapide.
J'ai des tests qui durent plusieurs minutes.
Et des suites qui durent une heure et demie ou plus.

Et pendant ce temps, je veux savoir ce qui se passe.
Les instructions de statut de débogage sont idéales pour me faire savoir ce qui se passe pendant l'exécution.
Ils fonctionnent très bien avec du code python normal non testé.
Mais lorsque je mets des instructions print ou logging en code de test, elles sont capturées et masquées.

C’est peut-être une bonne chose la plupart du temps.
Je pense que c'était une bonne décision d'en faire le comportement par défaut.

Cependant, je veux parfois le contourner.
Je vais montrer ci-dessous quelques exemples de ce dont je parle et montrer comment je le résous.

Exemple de tests lents, utilisant des instructions d'impression

Commençons par quelques tests simples qui durent plus de 3 secondes chacun.

slowTest_print.py

Si je l’exécute normalement, pytest capturera l’ensemble de la sortie, l’enregistrera jusqu’à ce que tous les tests soient terminés, et affichera la sortie des tests ayant échoué.

Je peux utiliser le drapeau ‘-s’ ou ‘–capture = no’, puis tout le résultat est signalé.
Cependant, pytest attend toujours que tous les tests soient effectués pour afficher les résultats.
Pour autant que je sache, il n’ya aucun moyen de le contourner à l’aide de déclarations «imprimées».

Mise à jour: Ceci est apparemment un problème d'environnement. OOPS. Les «-s» et «–capture = no» fonctionnent bien dans de nombreux environnements. Le seul environnement où je l’ai vu échouer est celui qui consiste à exécuter des tests de bash sur cygwin. J'aurais dû le tester dans plusieurs environnements avant de poster. OOPS. Merci à Joe de me l'avoir signalé.

Exemple de journalisation

La journalisation à l'aide du module de journalisation standard est gérée différemment par pytest.
Remplaçons les instructions print par des instructions de journalisation.

slowTest_log.py

J’ai également configuré des enregistreurs nommés distincts pour les deux tests.
L’avantage de créer des enregistreurs séparés est de rendre la sortie plus lisible.
Voici la sortie.

Eh bien, la sortie est un peu plus agréable à lire.
Cependant, pytest capture toujours la sortie des enregistreurs qui écrivent sur stdout.
Notre sortie attend toujours les 6 secondes complètes avant que quelque chose ne soit signalé, et les tests réussis ne signalent pas la sortie de leur journal.

Utiliser la journalisation et désactiver la capture fait le tour, presque

Si nous utilisons à la fois la journalisation et le drapeau ‘-s’ (ou ‘–capture = no’), nous obtenons exactement ce que je veux.
Presque.

Maintenant, la sortie sort pendant que le test est en cours. Excellent.

Qu'est-ce qui manque?

Alors, qu’en est-il du «presque»? Qu'est-ce qui manque?

Eh bien, c’est un peu difficile.
La sortie de style «… .F… F… X…» est maintenant intercalée avec la sortie de journalisation.
En fait, au début de chaque test, la sortie de journalisation est simplement ajoutée à stdout sans nouvelle ligne.

Pour être plus précis sur ce que je voudrais voir. Je vais simplement montrer ce que ma sortie idéale serait:

La seule différence serait donc d'ajouter une nouvelle ligne avant la première instruction de journalisation pour chaque test.
Si quelqu'un qui lit ceci sait comment je peux dire au module de journalisation ou à pytest d'insérer ces nouvelles lignes, j'aimerais bien l'entendre.

[ad_2]

Articles relatifs: