Registro em testes pytest

94

Eu gostaria de colocar algumas instruções de log na função de teste para examinar algumas variáveis ​​de estado.

Eu tenho o seguinte snippet de código:

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 ')

Eu obtenho a seguinte saída:

[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 

Observe que apenas as mensagens de registro do '__name__ == __main__'bloco são transmitidas para o console.

Existe uma maneira de forçar pytesta emissão de registro para o console a partir de métodos de teste também?

superseletor
fonte
3
Você pode dar uma olhada nesta resposta , postada pelo criador de py.test. Ele sugere um plugin pytest que fornece um alto grau de versatilidade.
chb

Respostas:

30

Funciona para mim, aqui está o resultado que recebo: [recorte -> exemplo estava incorreto]

Edit: Parece que você tem que passar a -sopção para py.test para que não capture stdout. Aqui (py.test não instalado), dava para usar python pytest.py -s pyt.py.

Para o seu código, tudo que você precisa é passar -sem argsque main:

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

Consulte a documentação py.test sobre a captura de saída .

TryPyPy
fonte
Desculpa. Colei o código às pressas. Remova o 'assert 0 == 1' da função 'test_one' para notar o 'problema'. Somente quando há alguma falha (que forcei por ter uma declaração falsa), o py.test parece imprimir as informações de registro.
superseletor de
Sem problemas, descobri como consertar na linha de comando, procurando uma forma programática.
TryPyPy
1
você também pode redirecionar a saída de registro para algum arquivo em vez do stderr implícito padrão.
hpk42
@superselector hpk42 é o cara do py.test, ouça. IIUC, no seu código seria logging.basicConfig(filename="somelog.txt", level=logging.DEBUG).
TryPyPy
128

Desde a versão 3.3, pytestsuporta registro ao vivo, o que significa que todos os registros de log emitidos nos testes serão impressos no terminal imediatamente. O recurso está documentado na seção Live Logs . O registro ao vivo é desabilitado por padrão; para habilitá-lo, defina log_cli = 1na configuração pyproject.toml1 ou pytest.ini2 . O registro ao vivo suporta a emissão para o terminal e arquivo; as opções relevantes permitem a personalização de registros:

terminal:

  • log_cli_level
  • log_cli_format
  • log_cli_date_format

Arquivo:

  • log_file
  • log_file_level
  • log_file_format
  • log_file_date_format

Nota : a log_clibandeira não pode ser passada da linha de comando e deve ser definida em pytest.ini. Todas as outras opções podem ser passadas da linha de comando ou definidas no arquivo de configuração. Como apontado por Kévin Barré em este comentário , substituindo opções ini de linha de comando pode ser feito através da -o/--overrideopção. Então, ao invés de declarar log_cliem pytest.ini, você pode simplesmente chamar:

$ pytest -o log_cli=true ...

Exemplos

Arquivo de teste simples usado para demonstrar:

# 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

Como você pode ver, nenhuma configuração extra é necessária; pytestirá configurar o logger automaticamente, com base nas opções especificadas pytest.iniou transmitidas na linha de comando.

Registro ao vivo para terminal, INFOnível, saída extravagante

Configuração em pyproject.toml:

[tool.pytest.ini_options]
log_cli = true
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"

A configuração idêntica no legado 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

Executando o teste:

$ 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 =============================

Registro ao vivo no terminal e arquivo, apenas mensagem e CRITICALnível no terminal, saída extravagante no pytest.logarquivo

Configuração em pyproject.toml:

[tool.pytest.ini_options]
log_cli = true
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"

A configuração idêntica no legado 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

Execução de teste:

$ 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 pyproject.toml suportado desde a versão 6.0 e é a melhor opção IMO. Consulte PEP 518 para obter as especificações.

2 Embora você também possa configurar pytestem setup.cfgna [tool:pytest]seção, não fique tentado a fazer isso quando quiser fornecer um formato de registro ao vivo personalizado. Outras ferramentas de leitura setup.cfgpodem tratar coisas como %(message)sinterpolação de string e falhar. A melhor escolha é usar pyproject.tomlmesmo assim, mas se você for forçado a usar o formato legado do estilo ini, atenha-se a pytest.inipara evitar erros.

roubar
fonte
21
Sobre a nota que log_clideve estar no pytest.ini , parece que você pode usar a -oopção para substituir o valor da linha de comando. pytest -o log_cli=true --log-cli-level=DEBUGfunciona para mim.
Kévin Barré
@KévinBarré comentário muito bom e uma dica muito útil em geral, obrigado! Atualizou a resposta.
hoefling 02 de
Esta é definitivamente a resposta correta ao usar o registro. Embora eu goste de diferenciar os logs que estão dentro dos testes e os logs que estão dentro do sistema em teste, que devem ser considerados separadamente.
CMCDragonkai
@CMCDragonkai, infelizmente, pytesté um tanto limitado quanto a isso. No entanto, isso deve ser possível com configuração de registro especial para testes em seu aplicativo; desative a propagação em seus registradores e adicione um "manipulador de teste" que registra em um arquivo especificado. Dessa forma, pytestapenas registra os registros provenientes dos testes, enquanto o manipulador personalizado cuida dos registros do SuT.
hoefling
1
@OfekAgmon se quiser armazenar a pytestsaída, você pode usar o --result-logargumento (embora observe que ele está obsoleto, aqui estão as alternativas ). No pytestentanto, você não pode armazenar a saída e a saída do registro ao vivo no mesmo arquivo.
hoefling