Logowanie w ramach pytest testów

90

Chciałbym umieścić kilka instrukcji logowania w funkcji testowej, aby zbadać niektóre zmienne stanu.

Mam następujący fragment kodu:

import pytest,os
import logging

logging.basicConfig(level=logging.DEBUG)
mylogger = logging.getLogger()

#############################################################################

def setup_module(module):
    ''' Setup for the entire module '''
    mylogger.info('Inside Setup')
    # Do the actual setup stuff here
    pass

def setup_function(func):
    ''' Setup for test functions '''
    if func == test_one:
        mylogger.info(' Hurray !!')

def test_one():
    ''' Test One '''
    mylogger.info('Inside Test 1')
    #assert 0 == 1
    pass

def test_two():
    ''' Test Two '''
    mylogger.info('Inside Test 2')
    pass

if __name__ == '__main__':
    mylogger.info(' About to start the tests ')
    pytest.main(args=[os.path.abspath(__file__)])
    mylogger.info(' Done executing the tests ')

Otrzymuję następujący wynik:

[bmaryada-mbp:/Users/bmaryada/dev/platform/main/proto/tests/tpch $]python minitest.py
INFO:root: About to start the tests 
======================================================== test session starts =========================================================
platform darwin -- Python 2.6.2 -- pytest-2.0.0
collected 2 items 

minitest.py ..

====================================================== 2 passed in 0.01 seconds ======================================================
INFO:root: Done executing the tests 

Zauważ, że tylko komunikaty logowania z '__name__ == __main__'bloku są przesyłane do konsoli.

Czy istnieje sposób, aby wymusić pytestemitowanie logowania do konsoli również z metod testowych?

superselektor
źródło
3
Możesz rzucić okiem na tę odpowiedź , opublikowaną przez twórcę py.test. Sugeruje wtyczkę pytest, która zapewnia wysoki stopień wszechstronności.
chb

Odpowiedzi:

30

U mnie działa, oto wynik, który otrzymuję: [wycinek -> przykład był nieprawidłowy]

Edycja: Wygląda na to, że musisz przekazać tę -sopcję do py.test, aby nie przechwytywał standardowego wyjścia. Tutaj (py.test nie jest zainstalowany) wystarczyło użyć python pytest.py -s pyt.py.

Na kodzie, co potrzebne jest do przekazywania -sw argscelu main:

 pytest.main(args=['-s', os.path.abspath(__file__)])

Zobacz dokumentację py.test dotyczącą przechwytywania danych wyjściowych .

TryPyPy
źródło
Przepraszam. Wkleiłem kod w pośpiechu. Usuń „assert 0 == 1” z funkcji „test_one”, aby zauważyć „problem”. Dopiero gdy wystąpi jakaś awaria (którą wymusiłem, mając fałszywe potwierdzenie), py.test wydaje się drukować informacje logowania.
superselector
Żaden problem, dowiedziałem się, jak to naprawić w wierszu poleceń, szukając sposobu programistycznego.
TryPyPy
1
można również przekierować dane wyjściowe rejestrowania do jakiegoś pliku zamiast domyślnego niejawnego stderr.
hpk42
@superselector hpk42 to py.test guy, posłuchaj. IIUC, w twoim kodzie to będzie logging.basicConfig(filename="somelog.txt", level=logging.DEBUG).
TryPyPy
115

Od wersji 3.3 pytestobsługuje rejestrowanie na żywo, co oznacza, że ​​wszystkie rekordy dziennika wysyłane podczas testów zostaną natychmiast wydrukowane na terminalu. Funkcja jest udokumentowana w sekcji Dzienniki na żywo . Rejestrowanie na żywo jest domyślnie wyłączone; aby go włączyć, ustaw log_cli = 1w pytest.iniconfig 1 . Rejestrowanie na żywo obsługuje wysyłanie do terminala i pliku; odpowiednie opcje umożliwiają dostosowanie rekordów:

terminal:

  • log_cli_level
  • log_cli_format
  • log_cli_date_format

plik:

  • log_file
  • log_file_level
  • log_file_format
  • log_file_date_format

Uwaga : log_cliflagi nie można przekazać z wiersza poleceń i należy ją ustawić pytest.ini. Wszystkie inne opcje można przekazać z wiersza poleceń lub ustawić w pliku konfiguracyjnym. Jak zauważył Kévin Barré w tym komentarzu , nadpisywanie opcji ini z wiersza poleceń można wykonać za pomocą -o/--overrideopcji. Więc zamiast deklarować log_cliw pytest.ini, możesz po prostu zadzwonić:

$ pytest -o log_cli=true ...

Przykłady

Prosty plik testowy używany do demonstracji:

# test_spam.py

import logging

LOGGER = logging.getLogger(__name__)


def test_eggs():
    LOGGER.info('eggs info')
    LOGGER.warning('eggs warning')
    LOGGER.error('eggs error')
    LOGGER.critical('eggs critical')
    assert True

Jak widać, nie jest wymagana żadna dodatkowa konfiguracja; pytestustawi rejestrator automatycznie, na podstawie opcji określonych w pytest.inilinii poleceń lub przekazanych z niej.

Rejestrowanie na żywo do terminala, INFOpoziomu, fantazyjnego wyjścia

Konfiguracja w pytest.ini:

[pytest]
log_cli = 1
log_cli_level = INFO
log_cli_format = %(asctime)s [%(levelname)8s] %(message)s (%(filename)s:%(lineno)s)
log_cli_date_format=%Y-%m-%d %H:%M:%S

Uruchomienie testu:

$ pytest test_spam.py
=============================== test session starts ================================
platform darwin -- Python 3.6.4, pytest-3.7.0, py-1.5.3, pluggy-0.7.1 -- /Users/hoefling/.virtualenvs/stackoverflow/bin/python3.6
cachedir: .pytest_cache
rootdir: /Users/hoefling/projects/private/stackoverflow/so-4673373, inifile: pytest.ini
collected 1 item

test_spam.py::test_eggs
---------------------------------- live log call -----------------------------------
2018-08-01 14:33:20 [    INFO] eggs info (test_spam.py:7)
2018-08-01 14:33:20 [ WARNING] eggs warning (test_spam.py:8)
2018-08-01 14:33:20 [   ERROR] eggs error (test_spam.py:9)
2018-08-01 14:33:20 [CRITICAL] eggs critical (test_spam.py:10)
PASSED                                                                        [100%]

============================= 1 passed in 0.01 seconds =============================

Rejestrowanie na żywo do terminala i pliku, tylko komunikat i CRITICALpoziom w terminalu, fantazyjne wyjście w pytest.logpliku

Konfiguracja w pytest.ini:

[pytest]
log_cli = 1
log_cli_level = CRITICAL
log_cli_format = %(message)s

log_file = pytest.log
log_file_level = DEBUG
log_file_format = %(asctime)s [%(levelname)8s] %(message)s (%(filename)s:%(lineno)s)
log_file_date_format=%Y-%m-%d %H:%M:%S

Testowe uruchomienie:

$ pytest test_spam.py
=============================== test session starts ================================
platform darwin -- Python 3.6.4, pytest-3.7.0, py-1.5.3, pluggy-0.7.1 -- /Users/hoefling/.virtualenvs/stackoverflow/bin/python3.6
cachedir: .pytest_cache
rootdir: /Users/hoefling/projects/private/stackoverflow/so-4673373, inifile: pytest.ini
collected 1 item

test_spam.py::test_eggs
---------------------------------- live log call -----------------------------------
eggs critical
PASSED                                                                        [100%]

============================= 1 passed in 0.01 seconds =============================

$ cat pytest.log
2018-08-01 14:38:09 [    INFO] eggs info (test_spam.py:7)
2018-08-01 14:38:09 [ WARNING] eggs warning (test_spam.py:8)
2018-08-01 14:38:09 [   ERROR] eggs error (test_spam.py:9)
2018-08-01 14:38:09 [CRITICAL] eggs critical (test_spam.py:10)

1 Chociaż możesz skonfigurować pytestw setup.cfgtej [tool:pytest]sekcji, nie ulegaj pokusie, aby to zrobić, jeśli chcesz zapewnić niestandardowy format rejestrowania na żywo. Inne narzędzia do odczytu setup.cfgmogą traktować takie rzeczy jak %(message)sinterpolacja ciągów i kończyć się niepowodzeniem. Użyj, pytest.iniaby uniknąć błędów.

dudnienie
źródło
17
O notatce, która log_climusi znajdować się w pytest.ini , wygląda na to, że można użyć -oopcji nadpisania wartości z wiersza poleceń. pytest -o log_cli=true --log-cli-level=DEBUGpracuje dla mnie.
Kévin Barré
@ KévinBarré bardzo ładny komentarz i ogólnie bardzo przydatna wskazówka, dzięki! Zaktualizowałem odpowiedź.
hoefling
To zdecydowanie poprawna odpowiedź podczas korzystania z logowania. Chociaż lubię rozróżniać dzienniki, które znajdują się w testach, i te, które są w testowanym systemie, które należy rozpatrywać osobno.
CMCDragonkai
@CMCDragonkai jest niestety pytestnieco ograniczony w tej kwestii. Jednak powinno to być możliwe przy użyciu specjalnej konfiguracji rejestrowania testów w Twojej aplikacji; wyłącz propagację w swoich rejestratorach i dodaj „moduł obsługi testów”, który loguje się do określonego pliku. W ten sposób pytestrejestruje tylko rekordy pochodzące z testów, podczas gdy niestandardowa obsługa zajmuje się dziennikami SuT.
hoefling
1
@OfekAgmon, jeśli chcesz przechowywać pytestdane wyjściowe, możesz użyć --result-logargumentu (chociaż zauważ, że jest on przestarzały, tutaj są alternatywy ). Nie możesz jednak przechowywać pytestdanych wyjściowych i danych wyjściowych rejestrowania na żywo w tym samym pliku.
hoefling