Registro de eventos em Python

logging-1_abertura

O registro de eventos¹ é um recurso bastante útil pois ajuda na visualização do que está ocorrendo dentro do programa ao permitir a exibir o valor de variáveis em determinado instante ou mesmo sinalizar quais partes do código vão sendo executadas.

Em Python o módulo logging se encarrega de implementar funções e classes que permitem a utilização deste recurso e isto aqui é um roteiro bem simples de como utilizá-lo em seus programas.

(¹) Ou simplesmente logging, se preferir.

Um programa de teste

Começando com um programa de teste…

from __future__ import print_function

for i in range(1,9):
print('+' * i, ' ', end='' if i < 8 else '\n')

Que ao ser executado, exibe.

$ python program_de_teste.py
+ ++ +++ ++++ +++++ ++++++ +++++++ ++++++++

E não se preocupe com a utilidade da sequência de sinais de “+”, isto aqui é só um teste… 🙂

A configuração básica

Então, o básico para implementar um sistema de registro de eventos em um programa em Python

from __future__ import print_function
import logging

logging.basicConfig(level=logging.DEBUG,
                    format='%(asctime)s %(levelname)s: %(message)s')

logging.debug('Iniciando o programa.')
for i in range(1,9):
    print('+' * i, ' ', end='' if i < 8 else '\n')
logging.debug('Finalizando o programa.')

logging.shutdown()

O módulo é carregado através do import e sua configurado é feita pela função basicConfig() que define tanto o nível de registro — que neste caso é DEBUG — como também o formato de exibição das mensagens. Esta função funciona como um atalho ao cuidar de toda a configuração e serve para quase todos os casos.

Com a função logging.debug() é feito o registro do momento em que o laço for começa e termina e, por último, o logging.shutdown() finaliza o sistema de registro antes do término do programa.

$ python exemplo_basico.py
2018-09-20 22:51:01,553 DEBUG: Iniciando o programa.
+  ++  +++  ++++  +++++  ++++++  +++++++  ++++++++
2018-09-20 22:51:06,562 DEBUG: Finalizando o programa.

Só lembrando que as mensagens produzidas pelo módulo são enviadas para STDERR e não para STDOUT como as demais.

Níveis de registro

Os níveis de registro, ou níveis de log, servem para categorizar as mensagens de acordo com seu nível de criticidade (do mais trivial e informativo até o mais arriscado) e assim possibilitar a exibição, ou não, das mensagens de acordo com a situação em que o programa está sendo executado.

Para cada nível possui uma função específica a ser utilizada…

DEBUG

O nível mais baixo e geralmente usado quando se está diagnosticando um problema².

logging.debug("Affirmative, Dave. I read you.")

INFO

Usado para registrar a ocorrência de um determinado evento ou confirmar que tudo está correto naquele ponto do programa.

logging.info("This mission is too important for me to allow you to jeopardize it.").

WARNING

Para indicar um problema em potencial que não afeta o funcionamento do programa mas que poderá fazê-lo no futuro.

logging.warning("Without your space helmet, Dave, you're going to find that rather difficult.")

ERROR

Usado para registrar uma falha na execução do programa.

logging.error("I'm sorry, Dave. I'm afraid I can't do that.").

CRITICAL

O nível mais alto e usado para notificar a ocorrência de uma erro fatal ou motivo da interrupção do programa.

logging.critical("Dave, this conversation can serve no purpose any more. Goodbye").

 

Quando um nível específico é selecionado para exibição, os níveis posteriores também serão mostrados, assim, selecionar DEBUG significa exibir todas as mensagens, enquanto que ao escolher ERROR, apenas as mensagens dele e de CRITICAL serão visualizadas.

(²) Sim, são todas as falas do HAL e foram todas extraídas da mesma cena do filme 2001: Uma odisseia no espaço.

O formato da mensagem

Não é obrigatório visto que o módulo já tem um formato padrão, mas é interessante para complementar suas mensagens. Neste exemplo, ela foi customizada³ através argumento ‘format=’ durante a chamada da função basicConfig().

(..., format='%(asctime)s %(levelname)s: %(message)s')

Que neste caso define os seguintes atributos:

  • asctime : É a data formatada em «yyyy»-«mm»-«dd» «hh»:«mm»;«ss»,«mss» (ano com quatro algarismos; mês, dia, hora, minuto e segundo com dois algarismos e milissegundos com três algarismos).
  • levelname : O nome do nível de registro, ou seja, DEBUG, INFO, WARNING, ERROR ou CRITICAL e
  • message : A mensagem a ser impressa (aquela que é enviada pela função logging.debug(), por exemplo).

E como este é um exemplo básico, preferi inserir apenas no essencial porém é possível utilizar outros atributos para acrescentar diversos outros detalhes às mensagens.

(³) Aqui foi utilizada a sintaxe do printf mas é possível usar a do comando format() também.

Salvando em disco

Mensagens sendo exibidas diretamente no console são úteis mas rapidamente tornam-se irritantes,, a solução é redirecionar o STDERR para um arquivo ou, melhor, fazer com que o programa o faça diretamente. Isto é feito com a adição do argumento ‘filename=’ na chamada da função basicConfig().

...
logging.basicConfig(filename='registro_em_arquivo.log',
                    level=logging.DEBUG,
                    format='%(asctime)s %(levelname)s: %(message)s')
...

Assim, as mensagens passam a ser enviadas um arquivo, o “registro_em_arquivo.log”, ao invés de diretamente para a STDERR.

$ python registro_em_arquivo.py 
+ ++ +++ ++++ +++++ ++++++ +++++++ ++++++++
$ cat registro_em_arquivo.log
2018-09-22 12:37:18,536 DEBUG: Iniciando o programa.
2018-09-22 12:37:18,536 DEBUG: Finalizando o programa

O modo de criação do arquivo é o “a” — append –, portanto cada nova execução acrescentará linhas ao arquivo já existente. Este comportamento pode ser modificado através do argumento “filemode=”.

Desabilitando

Não havendo mais a necessidade de registro de eventos a partir de um determinado ponto do programa, ele pode ser desabilitado (ou redefinido) através da função logging.disable() que desabilita o registro de eventos de um determinado nível e de seus anteriores, por exemplo, para desabilitar as mensagens a partir de WARNING.

...
logging.disable(logging.WARNING)
...

Isto desligará tanto as mensagens de WARNING como também de INFO e de DEBUG, somente mensagens de ERROR e CRITICAL permanecerão sendo visualizadas. E usando logging.disable() sem parâmetros, nenhuma mensagem será exibida (é equivalente a desabilitar CRITICAL).

Finalizando…

Os programas usados aqui estão disponíveis no repositório git deste blog no GitHub, inclusive um que não citei aqui, o “hal_quotes.py”, que demonstra como fazer funções e módulos se atrelem ao logging iniciado no corpo do programa.

Até!

Anúncios