Skip to content

    Chapter 41, Intermediate

    Logging and command line with argparse

    `print` is used for debugging on your machine. In production, you need levels, destinations, and format, and that's what `logging` is for. And a useful program almost always receives arguments from the terminal.

    Code for this chapter: intermediario/cap41_logging_cli.py

    Levels and format

    The logging has five levels: DEBUG, INFO, WARNING, ERROR and CRITICAL. The basicConfig sets the minimum level and the format. Messages below the level are discarded. And I pass the values as arguments (%d), and not as an f-string, so that the message is only constructed if it is actually emitted:

    intermediario/cap41_logging_cli.pylinhas 10 a 21
    import logging
    import sys
    
    logging.basicConfig(
        stream=sys.stdout,
        level=logging.INFO,
        format="%(levelname)s %(name)s: %(message)s",
    )
    log = logging.getLogger("pedidos")
    log.debug("não aparece, nível abaixo de INFO")
    log.info("pedido recebido")
    log.warning("estoque baixo: %d unidades", 3)
    
    Output
    INFO pedidos: pedido recebido
    WARNING pedidos: estoque baixo: 3 unidades
    

    One logger per module

    The convention is logger = logging.getLogger(__name__) at the top of each module. This way the logger's name shows where the message came from, and whoever uses your library decides the level and destination without editing your code. Libraries should never call basicConfig, which is an application decision:

    intermediario/cap41_logging_cli.pylinhas 26 a 27
    logger = logging.getLogger(__name__)
    logger.info("módulo %s", __name__)
    
    Output
    INFO __main__: módulo __main__
    

    To log an exception with the full traceback, use logger.exception(...) within the except. It logs at the level ERROR and includes the call stack:

    intermediario/cap41_logging_cli.pylinhas 29 a 32
    try:
        1 / 0
    except ZeroDivisionError:
        log.exception("falha ao calcular")
    

    Structured output

    In systems with log aggregation, free text is hard to search. A formatter that emits a line of JSON per message solves this. Each logger can have its own destination:

    intermediario/cap41_logging_cli.pylinhas 37 a 58
    import json
    
    
    class FormatoJson(logging.Formatter):
        def format(self, record):
            return json.dumps(
                {
                    "nivel": record.levelname,
                    "logger": record.name,
                    "mensagem": record.getMessage(),
                },
                ensure_ascii=False,
            )
    
    
    manipulador = logging.StreamHandler(sys.stdout)
    manipulador.setFormatter(FormatoJson())
    auditoria = logging.getLogger("auditoria")
    auditoria.addHandler(manipulador)
    auditoria.propagate = False
    auditoria.setLevel(logging.INFO)
    auditoria.info("login realizado")
    
    Output
    {"nivel": "INFO", "logger": "auditoria", "mensagem": "login realizado"}
    

    Command line arguments

    The argparse converts terminal arguments, validates, generates help (--help) and error messages. I always write the function main receiving the list of arguments as a parameter, which makes it testable without opening a terminal:

    intermediario/cap41_logging_cli.pylinhas 63 a 84
    import argparse
    
    
    def criar_parser():
        parser = argparse.ArgumentParser(description="Saudação em linha de comando")
        parser.add_argument("nome", help="quem cumprimentar")
        parser.add_argument("--vezes", type=int, default=1, help="quantas vezes repetir")
        parser.add_argument("--gritar", action="store_true", help="usar maiúsculas")
        return parser
    
    
    def main(argv=None):
        args = criar_parser().parse_args(argv)
        texto = f"Olá, {args.nome}!"
        if args.gritar:
            texto = texto.upper()
        for _ in range(args.vezes):
            print(texto)
        return 0
    
    
    main(["Ana", "--vezes", "2", "--gritar"])
    
    Output
    OLÁ, ANA!
    OLÁ, ANA!
    

    When argv is None, the argparse reads sys.argv by itself. To actually run the program, the end of the file looks like this, and the exit code of the main becomes the exit code of the process:

    Final do arquivo de um programa
    if __name__ == "__main__":
        raise SystemExit(main())
    

    Invalid arguments cause the argparse to print the error and terminate with code 2, raising SystemExit. It can be captured in a test:

    intermediario/cap41_logging_cli.pylinhas 86 a 89
    try:
        criar_parser().parse_args(["Ana", "--vezes", "muitas"])
    except SystemExit as codigo:
        print("saiu com código", codigo.code)
    
    Output
    saiu com código 2
    

    For programs with multiple commands, like git add and git commit, the argparse offers subcommands:

    intermediario/cap41_logging_cli.pylinhas 91 a 100
    def parser_com_subcomandos():
        parser = argparse.ArgumentParser(prog="tarefas")
        sub = parser.add_subparsers(dest="comando", required=True)
        adicionar = sub.add_parser("adicionar")
        adicionar.add_argument("titulo")
        sub.add_parser("listar")
        return parser
    
    
    print(parser_com_subcomandos().parse_args(["adicionar", "estudar"]))
    
    Output
    Namespace(comando='adicionar', titulo='estudar')
    

    Exercise 1

    Add numbers via the command line

    Write main_soma(argv) that takes one or more numbers as arguments and returns the sum.