Técnicas

Logging

Registro estruturado com níveis, campos, arquivo e formato JSON.

Por que não usar out#

out serve para falar com quem está olhando o terminal agora. Log serve para responder perguntas depois: o que aconteceu às 3h da manhã?

A diferença prática está em três coisas que out não tem: nível, campos estruturados e destino configurável.

Os seis níveis#

dataforge

adopt Arcane.Logging as Log

registro := Log.logger("pedidos", "DEBUG")

registro.debug("iniciando o processamento")
registro.info("pedido recebido", {"id": 1042, "cliente": "Ana"})
registro.warn("estoque baixo", {"produto": "P02", "restam": 3})
registro.error("pagamento recusado", {"id": 1042, "codigo": 402})

Nível	Quando
`TRACE`	detalhe fino, normalmente desligado
`DEBUG`	o que ajuda a investigar
`INFO`	eventos normais que valem registrar
`WARN`	algo estranho, mas o programa segue
`ERROR`	uma operação falhou
`FATAL`	o programa não continua

O nível do logger é um piso: com WARN, tudo abaixo é descartado sem custo. Uma linha muda a verbosidade do sistema inteiro.

Campos estruturados#

dataforge

registro.info("pedido recebido", {"id": 1042, "cliente": "Ana"})

saída

23:59:01 INFO  [pedidos] pedido recebido id=1042 cliente=Ana

Compare com out $"pedido {id} do cliente {nome}". A diferença aparece na hora de procurar: com campos, grep 'id=1042' acha tudo daquele pedido. Com texto interpolado, a estrutura se perdeu na formatação.

Contexto fixo#

dataforge

servico := Log.logger("api", "INFO")
servico.with_context({"servico": "checkout", "versao": "1.2"})
servico.info("requisicao recebida", {"rota": "/pagar"})

Esses campos passam a aparecer em toda linha daquele logger. Você escreve uma vez o que é constante.

JSON para máquina#

dataforge

maquina := Log.logger("api", "INFO")
maquina.as_json(yes)
maquina.info("evento", {"usuario": 7, "acao": "login"})

saída

{"time": "...", "level": "INFO", "logger": "api", "message": "evento", "usuario": 7, "acao": "login"}

Uma linha de configuração troca o público-alvo do log de humano para máquina — o formato que Elasticsearch, Loki e CloudWatch esperam.

Arquivo#

dataforge

arquivo := Log.logger("disco", "INFO")
arquivo.to_file("app.log", yes)     # yes = anexar
arquivo.info("linha gravada")
arquivo.close()

O close garante que o buffer foi para o disco. Em programa que roda continuamente, combine com defer.

Guardar em memória#

dataforge

auditoria := Log.logger("auditoria", "INFO")
auditoria.keep(yes)
...
erros := auditoria.records() >> sift r: r["level"] is "ERROR"

Útil em teste: você verifica que o log certo foi emitido, sem ler stdout.

Registrar e repassar#

dataforge

action camada_media():
    monitor:
        camada_baixa()
    handle e:
        registro.error("falha na camada baixa", {"motivo": e.message})
        propagate e.message

A camada do meio anota o que sabe e repassa. O anti-padrão oposto é engolir: handle e: registro.error("falhou") faz o chamador achar que deu certo.