Logging¶
Nesta receita você configura logs JSON estruturados com correlação por request, um arquivo por nível de severidade e um endpoint HTTP para lê-los. O objetivo é que cada linha de log seja parseável, rastreável até a requisição que a originou e inspecionável sem SSH no servidor.
configure_logging instala um handler JSON no logger raiz que emite registros JSON de uma linha carregando o request ID ativo. LogUtils é uma fachada fina que adiciona métodos por nível aceitando **fields estruturados.
from tempest_fastapi_sdk import LogUtils, configure_logging
from tempest_fastapi_sdk.core import get_request_id
from src.db.models import UserModel
def risky() -> None:
"""Blow up, so the log shows a real traceback."""
raise RuntimeError("boom")
user = UserModel(email="ana@example.com")
# Imperativo — chame uma vez durante o bootstrap.
configure_logging(level="INFO", json_output=True)
# Fachada — útil para singletons de serviço.
log = LogUtils("app.users", level="INFO")
log.info("user_created", user_id=str(user.id), email=user.email)
log.warning("login_throttled", ip="1.2.3.4", attempts=5)
try:
risky()
except RuntimeError:
log.exception("risky_failed", op="reconcile") # appends traceback
# Exponha o ID de correlação fora da linha de log, se necessário.
request_id = get_request_id()
Adotando num serviço que já loga em %-style
Os métodos por nível aceitam os posicionais do logging, então call site
existente entra sem reescrita — e continua com interpolação lazy e com
o template estável que a ferramenta de log agrega:
from tempest_fastapi_sdk import LogUtils
log = LogUtils("app.email", level="INFO")
log.info("Email enviado com sucesso para %s", "ana@example.com")
log.error("Falha ao enviar para %s: %s", "bruno@x.com", "timeout")
log.error("Falha ao enviar para %s: %s", "bruno@x.com", "timeout", op="send")
A última linha mostra que os dois estilos convivem: os posicionais montam
a mensagem, e o **fields continua virando chave de topo no JSON.
funcName/lineno apontam para o seu call site, não para dentro da
fachada — o default é stacklevel=2. Quem embrulha o LogUtils numa
camada própria passa stacklevel=3 (ou mais) para atravessar os frames
extras.
Saída JSON (uma linha — formatada aqui para legibilidade):
{
"timestamp": "2026-05-16T20:14:33.412Z",
"level": "INFO",
"logger": "app.users",
"message": "user_created",
"request_id": "d83e4b0c-7c2f-4bd6-aaa1-7d4f6cf5e5e9",
"user_id": "9c1a5b2d-...",
"email": "ana@example.com"
}
O middleware aceita um nome de header customizado (RequestIDMiddleware(app, header_name="X-Correlation-ID")); o mesmo header é ecoado de volta em toda resposta.
Um conjunto de handlers, não um por módulo¶
LogUtils(__name__) é como a classe se lê, e é como ela é usada: uma linha no
topo de cada módulo. Desde a v0.280.0 é também o que ela faz bem.
# src/services/user.py
from tempest_fastapi_sdk import LogUtils
logger: LogUtils = LogUtils(__name__)
logger.info("Usuário %s criado", "u-1")
# src/services/payment.py
from tempest_fastapi_sdk import LogUtils
logger: LogUtils = LogUtils(__name__)
logger.warning("Cobrança %s expirou", "c-9")
Os dois módulos escrevem nos mesmos arquivos, através do mesmo conjunto de
handlers: o construtor configura o logger raiz, uma vez por processo, e
liga __name__ a ele por propagação. O nome do logger continua em toda linha
(campo logger), então você ainda sabe quem escreveu o quê.
Por que isso importa mais do que parece
Até a v0.279.0 o construtor chamava configure_logging(logger_name=name),
que põe propagate = False naquele logger e lhe dá handlers próprios. Medido:
7 handlers por logger (1 stdout + 6 de arquivo), então um serviço com
27 módulos abria 27 stdout e 162 de arquivo, todos nos mesmos seis caminhos — e
RotatingFileHandler não coordena rollover entre instâncias: quando o
arquivo chega no teto, várias tentam rotacionar o mesmo caminho e o
resultado é registro perdido e .1/.2 embaralhados.
Medido num processo com cinco instâncias: 7 handlers no raiz (1 stdout + 6 arquivos) e zero em cada logger de módulo.
A primeira instância decide nível e formato
"Uma vez por processo" tem consequência: a segunda chamada não
reconfigura nada, então level= e json_output= da segunda em diante são
ignorados. Isso é o que se quer num serviço — o bootstrap decide —, mas
surpreende em teste, onde cada caso quer o seu. Chame
reinitialize_logging() entre eles.
Para isolar um logger de propósito — um subsistema cujo stream você não quer misturado —, peça a forma antiga:
from tempest_fastapi_sdk import LogUtils
audit: LogUtils = LogUtils("audit", log_dir="logs/audit", scope="logger")
Arquivos por nível + 500.log isolado¶
Por padrão, o SDK escreve simultaneamente no stdout E em logs/ (um arquivo JSON por nível). Cada arquivo recebe apenas o seu próprio nível (correspondência exata — um ERROR nunca cai no warning.log), então toda severidade vira um fluxo isolado e fácil de inspecionar com grep.
from tempest_fastapi_sdk import configure_logging
# Defaults — stdout + logs/{debug,info,warning,error,critical,500}.log
configure_logging(level="INFO")
# Customizar diretório
configure_logging(level="INFO", log_dir="/var/log/myapp")
# Desligar arquivos (stdout puro — útil em serverless ou FS read-only)
configure_logging(level="INFO", file_output=False)
# Desligar stdout (sidecar coleta de disco)
configure_logging(level="INFO", stdout=False)
# Teto de crescimento: cada arquivo rotaciona em ~10 MB, guardando 5 gerações
configure_logging(level="INFO", max_bytes=10_000_000, backup_count=5)
# Sem rotação — quando o logrotate do host (ou um sidecar) é o dono da retenção
configure_logging(level="INFO", max_bytes=0)
Os arquivos rotacionam por padrão — e é por isso
FileHandler puro cresce sem teto. Num serviço com uma linha de log por
request, rodando em host de longa duração, o info.log é o que enche o
disco — e disco cheio derruba o serviço e o que mais dividir a
partição. Por isso o default é RotatingFileHandler com
max_bytes=10_000_000 e backup_count=5: ~60 MB por nível, teto duro.
O outro lado deste par já tinha o teto: o make_logs_router limita a
leitura a 20 mil registros por arquivo, adicionado depois que um serviço
com diretório de log em gigabytes respondeu com worker morto. Isto é o lado
de quem escreve.
Os arquivos rotacionados (info.log.1, info.log.2, …) não são lidos
pelo /logs: o endpoint lê os nomes exatos, então ele mostra a janela
corrente. Retenção mais longa é trabalho de coletor.
Não desligue os dois
configure_logging(stdout=False, file_output=False) lança
ValueError — silenciar todos os handlers deixa a aplicação
cega.
Log em arquivo é best-effort — nunca derruba o boot
Se o log_dir não puder ser criado ou seus arquivos não puderem ser
abertos (FS read-only, falta de permissão de escrita, container
endurecido, serverless, CI), o SDK pula os handlers de arquivo,
emite um aviso (no logger quando o stdout está ligado, senão direto no
stderr) e segue rodando só com stdout — em vez de morrer no import com
PermissionError: [Errno 13] ... 'logs'. Para abrir mão do log em
arquivo de forma explícita, passe file_output=False.
O resultado em disco:
logs/
├── debug.log # só registros DEBUG
├── info.log # só registros INFO
├── warning.log # só registros WARNING
├── error.log # só registros ERROR (um 500 também cai aqui)
├── critical.log # só registros CRITICAL
└── 500.log # só erros 500 não tratados (isolado)
Erros 500 são graves — por isso ganham arquivo próprio
O handler catch-all registrado por register_exception_handlers
marca toda exceção não tratada com o extra http_500=True. O
configure_logging(log_dir=...) roteia esses registros para um
500.log dedicado, além do error.log. Assim a falha mais
grave nunca fica soterrada no meio dos outros erros.
Isso vale para scope="root", o default. Com scope="logger" a raiz
não é configurada, o logger do SDK fica fora da árvore, e o registro
não chega a nenhum dos dois arquivos — passe
register_exception_handlers(app, logger=log.logger) para roteá-lo.
Detalhe medido em
Avisando alguém, e escolhendo para onde o registro vai.
Sempre nos logs, nunca no body
O traceback vai para os arquivos/terminal via logging — não para
o corpo da resposta. O body de um 500 é só o envelope genérico
({"detail": "Internal server error", "code": "INTERNAL_SERVER_ERROR"}).
Veja Camada HTTP para os flags log_traceback /
include_traceback.
Arquivos são sempre JSON
Os handlers de arquivo usam o JSONFormatter independente de
json_output, para que o endpoint /logs consiga parseá-los. O
json_output controla apenas o formato do stdout.
No scaffold, o diretório vem de LOG_DIR (padrão "logs"; deixe vazio para desativar o log em arquivo). Adicione logs/ ao .gitignore.
O mixin LogSettings modela a configuração inteira, rotação incluída, e
logging_kwargs() a entrega pronta para o splat — assim a tradução
campo → argumento mora num lugar só, em vez de numa chamada escrita à mão onde
os dois argumentos mais novos são justamente os que ficam de fora:
from tempest_fastapi_sdk import configure_logging
from tempest_fastapi_sdk.settings import LogSettings
class Settings(LogSettings):
"""Configuração do serviço."""
config = Settings()
configure_logging(**config.logging_kwargs())
| Variável | Padrão | O que decide |
|---|---|---|
LOG_LEVEL |
INFO |
Nível mínimo emitido. |
LOG_JSON |
True |
JSON no stdout (arquivo é sempre JSON). |
LOG_DIR |
logs |
Diretório dos arquivos; vazio desliga o log em arquivo. |
LOG_MAX_BYTES |
10000000 |
Tamanho em que cada arquivo rotaciona; 0 desliga a rotação. |
LOG_BACKUP_COUNT |
5 |
Gerações mantidas por nível. |
O orçamento de disco é LOG_MAX_BYTES * (LOG_BACKUP_COUNT + 1) por nível,
vezes os seis arquivos.
Reportando um 500 seu — error_500¶
O handler catch-all do SDK marca toda exceção não tratada com http_500=True,
que é o filtro do 500.log. Quando o seu código detecta uma falha grave
que não vira exceção — um crédito de carteira que fez rollback, uma
transferência retida no gateway —, error_500 põe o registro no mesmo arquivo:
from tempest_fastapi_sdk import LogUtils
logger: LogUtils = LogUtils(__name__)
def settle(charge_id: str) -> None:
"""Credit a wallet, escalating a rollback to the 500 stream."""
try:
raise RuntimeError("commit failed")
except RuntimeError:
logger.error_500(
"CRITICAL: crédito de carteira falhou para a cobrança %s",
charge_id,
charge_id=charge_id,
)
O registro cai no 500.log e no error.log — o arquivo isolado existe
para a falha grave não ficar soterrada, não para tirá-la do stream do nível. O
traceback vai junto sempre que houver um sendo tratado.
exc_info="auto" para o call site que às vezes está num except
logger.exception(...) exige estar dentro de um except; exc_info=True
fora de um escreve o inútil NoneType: None. Um helper chamado dos dois
lugares pede a terceira opção:
from tempest_fastapi_sdk import LogUtils
logger: LogUtils = LogUtils(__name__)
logger.error("Falha ao enviar para %s", "ana@x.com", exc_info="auto")
O default segue False, então call site existente não muda de saída.
O banco cita o valor — redact_database_errors¶
Um IntegrityError que ninguém tratou chega ao catch-all, e o traceback que
vai para o log termina no str() da exceção. No Postgres, esse texto é a
frase do servidor, e ela cita a linha:
sqlalchemy.exc.IntegrityError: (sqlalchemy.dialects.postgresql.asyncpg.IntegrityError) <class 'asyncpg.exceptions.UniqueViolationError'>: duplicate key value violates unique constraint "p_cpf_key"
DETAIL: Key (cpf)=(123.456.789-00) already exists.
[SQL: INSERT INTO p (cpf) VALUES ($1)]
[SQL parameters hidden due to hide_parameters=True]
(Background on this error at: https://sqlalche.me/e/20/gkpj)
Repare na linha dos parâmetros: hide_parameters=True estava ligado. Ele tira o
bloco de parâmetros que o SQLAlchemy anexa, mas o DETAIL é texto do
servidor, repassado pelo driver, e fica. O CPF que o cliente mandou ia para o
error.log, o 500.log, o GET /logs e o painel /admin/logs.
Por isso os três handlers de 5xx aplicam redact_database_errors antes de
logar, por default. Com o mesmo erro, a última linha do traceback vira:
tempest_fastapi_sdk.api.redaction.RedactedError: sqlalchemy.exc.IntegrityError: unique violation; constraint=p_cpf_key; table=p; columns=cpf; driver=sqlalchemy.dialects.postgresql.asyncpg.AsyncAdapt_asyncpg_dbapi.IntegrityError; database message withheld from the log
As duas saídas acima foram capturadas de um Postgres 16 real, com o
JSONFormatter do SDK, no SQLAlchemy 2.0.52. No 2.1.1 o resumo é o mesmo,
menos o driver=, que termina em
AsyncAdapt_asyncpg_dbapi.UniqueViolationError.
- Os frames ficam. Todo
File ..., line ...é o do erro original; só o texto do erro de banco muda. - Os nomes de schema ficam. Constraint, tabela e colunas vêm do
parse_integrity_error— são nomes do DDL, não dado. - O texto do servidor sai inteiro, para todo
DBAPIError, não sóIntegrityError: umDataErrortambém cita a entrada recusada. O statement SQL sai junto, porque umtext()montado com f-string carrega o literal. - Nada além do log muda. A resposta é o mesmo envelope 500, e o
on_server_errorrecebe a exceção original — o Sentry que você pluga ali continua vendo tudo, e decidir o que ele guarda é escolha sua.
Um 500 sem erro de banco na cadeia loga exatamente como antes: a função devolve o mesmo objeto.
O caminho tratado tinha o mesmo vazamento: ao converter o
IntegrityError em 409, o BaseRepository escrevia um warning com o
texto do driver. Hoje ele escreve IntegrityError on User.add: unique
violation; constraint=...; table=...; columns=..., montado por
describe_database_error — a mesma função que dá o resumo acima, pública
para o seu próprio except IntegrityError.
from fastapi import FastAPI
from tempest_fastapi_sdk import register_exception_handlers
app: FastAPI = FastAPI()
register_exception_handlers(app)
É só isso: o default já protege. Para logar a exceção crua — num ambiente
local, lendo o DETAIL de propósito —, passe redact_exception=None. Para
uma política própria, passe qualquer callable
(BaseException) -> BaseException:
from fastapi import FastAPI
from tempest_fastapi_sdk import redact_database_errors, register_exception_handlers
class PaymentGatewayError(Exception):
"""Erro do gateway, cuja mensagem carrega o número do cartão."""
def redact(error: BaseException) -> BaseException:
"""Esconde o gateway além do banco."""
if isinstance(error, PaymentGatewayError):
return RuntimeError("payment gateway failed; message withheld")
return redact_database_errors(error)
app: FastAPI = FastAPI()
register_exception_handlers(app, redact_exception=redact)
O que o resumo não diz
A exceção do driver (o UniqueViolationError do asyncpg, e o adapter do
SQLAlchemy em volta dele) sai da cadeia, porque o texto dela é a mesma
frase do servidor. O tipo dela continua no resumo, como driver=....
Dado pessoal fora de toda linha — redact=True¶
Serviço que trata dado pessoal precisa garantir que nenhuma linha de log
carregue e-mail, token ou código de verificação — inclusive as que você não
escreveu: o traceback que cita o payload, o extra= passado inteiro, a lib
de terceiro que loga o header Authorization. configure_logging resolve
isso num parâmetro:
import logging
from tempest_fastapi_sdk import RedactionPolicy, configure_logging
policy: RedactionPolicy = RedactionPolicy(extra_keys={"cpf"})
configure_logging(file_output=False, redact=policy)
log: logging.Logger = logging.getLogger("app.signup")
log.info(
"código enviado para %s",
"ana@example.com",
extra={
"cpf": "123.456.789-00",
"access_token": "eyJhbGciOiJIUzI1NiJ9.eyJzdWIiOiIxIn0.c2ln",
"plan": "free",
},
)
try:
raise ValueError("usuário ana@example.com não encontrado")
except ValueError:
log.exception("falha no login")
Saída (capturada rodando o exemplo, Python 3.11):
{"timestamp": "...", "level": "INFO", "logger": "app.signup", "message": "código enviado para [REDACTED]", "cpf": "[REDACTED]", "access_token": "[REDACTED]", "plan": "free"}
{"timestamp": "...", "level": "ERROR", "logger": "app.signup", "message": "falha no login", "exception": "Traceback (most recent call last):\n File \"...\", line ..., in <module>\nValueError: usuário [REDACTED] não encontrado"}
redact=True usa a política default; RedactionPolicy(...) acrescenta o que
é do seu domínio. O que ela faz:
- Chave sensível — todo campo de
extra=, e toda chave de dict passado como argumento ou aninhado num valor, cujo nome contém um fragmento deDEFAULT_REDACT_KEYS(password,token,secret,authorization,cookie,email,api_key, ...) tem o valor trocado inteiro. O match é por substring, em minúsculas e com-virando_:access_token,X-API-KeyeSet-Cookiecasam. - Padrão de texto — mensagem, argumentos, traceback (
exc_text),stack_infoe todo valor string passam por e-mail,Bearer <credencial>e JWT, maischave=valor/chave: valorquando a chave é sensível (?token=abcna query,{'password': 'x'}citado numa exceção). extra_keys/extra_patternsacrescentam sem repetir os defaults;keys/patternssubstituem. Padrão em string é compilado na construção.exact_keyscompara por igualdade, para nome curto que a substring pegaria demais: comRedactionPolicy(exact_keys={"code"}),"GET /invite?code=123456 status_code=200"sai"GET /invite?code=[REDACTED] status_code=200"—codesome, o status da resposta fica. Vale também paraextra=e dict aninhado.
O filtro vai em todo handler que configure_logging instala — stdout e
os seis arquivos —, e não no logger: filtro de logger não roda para registro
propagado de logger filho, filtro de handler roda. Handler que você
pendura por conta própria (Sentry, syslog) recebe o mesmo filtro assim:
import logging
import sys
from tempest_fastapi_sdk import RedactionFilter, RedactionPolicy
handler: logging.Handler = logging.StreamHandler(sys.stderr)
handler.addFilter(RedactionFilter(RedactionPolicy(extra_keys={"cpf"})))
logging.getLogger().addHandler(handler)
O que muda no registro
A redação reescreve o LogRecord no lugar: msg vira a mensagem já
renderizada e redigida, e args é limpo. Quem agrupa log pelo template
("código enviado para %s") passa a ver a mensagem final. E o match por
substring erra para o lado de esconder: email_verified e token_type
também saem como [REDACTED].
Custo
Medido com configure_logging(file_output=False) escrevendo em
/dev/null, 20 000 registros, melhor de 5 rodadas, Python 3.11: uma linha
no formato do AccessLogMiddleware (mensagem com 4 argumentos, 7 campos
de extra=) foi de ~13,5 µs para ~26 µs; um logger.exception com
traceback curto, de ~44 µs para ~66 µs. O registro é redigido uma vez,
não uma por handler. Com redact=False (o default) nenhum filtro é
instalado.
O JSONFormatter também mudou para isso funcionar: o campo exception sai
do record.exc_text quando um passo anterior já o renderizou — a mesma
precedência do logging.Formatter da stdlib — e não do exc_info de novo.
Antes, um filtro de handler que redigia o traceback era sobrescrito pelo
texto original. Em LogSettings, LOG_REDACT=true liga a política default
pelo logging_kwargs().
exc_info em todos os níveis, e o nome que o LogRecord não cede¶
debug, info, warning, error e critical aceitam exc_info como
parâmetro nomeado — bool ou "auto":
from tempest_fastapi_sdk import LogUtils
logger: LogUtils = LogUtils(__name__)
def refresh_cache(key: str) -> None:
"""Recarrega uma entrada, tolerando o cache indisponível."""
try:
raise ConnectionError("redis down")
except ConnectionError:
logger.warning("Cache miss em %s", key, exc_info="auto", op="refresh")
Até a 0.280.0 essa linha era um KeyError dormente
Só error tinha o parâmetro. Nos outros quatro níveis o exc_info=
caía no **fields, virava extra=, e o logging recusa sobrescrever
atributo reservado do LogRecord — dentro do makeRecord, depois da
checagem de nível. Medido na 0.280.0:
nível ERROR, chamada warning(exc_info=...): NÃO levanta
nível DEBUG, mesma chamada -> KeyError: "Attempt to overwrite 'exc_info'
in LogRecord"
Um serviço rodando em INFO carregava a falha adormecida até alguém subir a verbosidade — ou seja, ela detonava durante o incidente, no minuto em que o log é a única ferramenta que sobrou.
Vale para qualquer nome que o LogRecord já usa, não só exc_info:
stack_info, msg, args, levelname, name, asctime e mais. Um
campo com esse nome agora é recusado na chamada, com TypeError,
independente do nível:
from tempest_fastapi_sdk import LogUtils
logger: LogUtils = LogUtils(__name__)
try:
logger.info("pedido processado", levelname="FAKE")
except TypeError as error:
print(error)
LogUtils: reserved LogRecord attribute used as a structured field:
'levelname'. logging would raise KeyError while building the record — after
the level check, so the failure stays dormant until the verbosity goes up.
Rename the field, or pass exc_info= as the named parameter every level method
accepts.
O conjunto de nomes é lido de um LogRecord de verdade, não digitado à mão,
então ele acompanha o interpretador. Medido: 22 nomes no 3.11, 23 no
3.12 e no 3.13 — o que entra é taskName, que não existe no 3.11.
Renomeie o campo, não a intenção
Precisa de um campo estruturado com esse sentido? Prefixe:
op_name em vez de name, record_args em vez de args. O nome que o
logging reserva é da mecânica do registro, não do seu domínio.
Depois do Alembic — reinitialize_logging¶
logging.config.fileConfig() desabilita, por padrão, todo logger que já
existia. O env.py que este SDK ships chama exatamente isso, então uma
migration silencia os loggers da aplicação pelo resto do processo — os
registros são descartados antes de qualquer handler ver, o que parece problema
de configuração de log e não é.
Chame depois de qualquer código que reconfigure o sistema de logging. A função
re-habilita os loggers e limpa o latch de "raiz já configurado", então o
próximo LogUtils(...) volta a instalar handlers.
Lendo logs por HTTP — make_logs_router¶
make_logs_router monta GET /logs, que lê os arquivos JSON em disco e devolve um BasePaginationSchema[LogEntrySchema] paginado (mais recentes primeiro).
from fastapi import FastAPI
from tempest_fastapi_sdk import make_logs_router
from src.core.settings import settings
app = FastAPI()
app.include_router(
make_logs_router(log_dir="logs", token_secret=settings.TOKEN_SECRET),
)
Segredo vazio é recusado
GET /logs expõe tracebacks e metadados de request, e DELETE /logs
trunca os arquivos. Os dois exigem o header X-Token, comparado com
token_secret via make_token_dependency — ou as suas dependencies=
(ver "Atrás da sua própria auth" abaixo). Um token_secret vazio (ou só
espaço) sem dependencies= faz o make_logs_router levantar
ValueError na construção: o app não sobe, em vez de subir com /logs
aberto.
Preencha o TOKEN_SECRET com uv run tempest secrets init.
O serviço gerado pelo tempest new monta /logs só quando
TOKEN_SECRET não está vazio, porque o .env.example sai com
TOKEN_SECRET= em branco.
Para uma execução local que nada mais alcança, a recusa se desliga pelo nome, onde quem lê a chamada vê:
from fastapi import FastAPI
from tempest_fastapi_sdk import make_logs_router
app = FastAPI()
app.include_router(
make_logs_router(log_dir="logs", allow_unauthenticated=True),
)
Com token_secret preenchido, allow_unauthenticated não tem efeito: a
requisição sem X-Token continua recebendo 401.
Exemplos de consulta:
# Últimos 20 registros de todos os níveis
curl -H "X-Token: $TOKEN_SECRET" "http://localhost:8000/logs"
# Só os 500 isolados, página 1, 50 por página
curl -H "X-Token: $TOKEN_SECRET" "http://localhost:8000/logs?source=500&page_size=50"
# Erros mencionando "timeout" numa janela de tempo
curl -H "X-Token: $TOKEN_SECRET" \
"http://localhost:8000/logs?source=error&q=timeout&start=2026-05-31T00:00:00Z"
Parâmetros de query:
| Parâmetro | Valores | Descrição |
|---|---|---|
source |
all (padrão), debug, info, warning, error, critical, 500 |
Qual arquivo ler. all mescla todos os níveis; 500 retorna só os 500 isolados. |
q |
texto | Substring (case-insensitive) na mensagem. |
start / end |
ISO-8601 | Limita os registros a uma janela de tempo. Um valor sem offset (2026-05-31T00:00:00, ou só a data) é lido como UTC. |
page / page_size |
inteiros | Paginação (1-indexada). |
A leitura é limitada por arquivo
Cada request lê os 20 000 registros mais recentes de cada arquivo
selecionado (DEFAULT_MAX_RECORDS_PER_FILE), não o arquivo inteiro. O
endpoint ordena do mais novo pro mais antigo e pagina, então o que ficou de
fora não era alcançável de qualquer forma — e sem o limite um diretório de
log de vários gigabytes ia inteiro pra memória a cada request, derrubando o
worker antes de responder. Ajuste com
make_logs_router(max_records_per_file=...); quando o corte acontece, um
WARNING é logado nomeando o source.
Limpando — DELETE /logs¶
O mesmo router monta o verbo oposto, atrás do mesmo X-Token:
# Esvazia um nível
curl -X DELETE -H "X-Token: $TOKEN_SECRET" \
"http://localhost:8000/logs?source=info"
# Esvazia tudo, o 500.log incluído
curl -X DELETE -H "X-Token: $TOKEN_SECRET" \
"http://localhost:8000/logs"
A resposta nomeia o que foi esvaziado:
all aqui alcança o 500.log; na leitura, não
É a única divergência entre os dois verbos, e é deliberada. Ler all
não inclui o 500.log porque todo registro dele também está no
error.log — a página listaria o mesmo registro duas vezes. Limpar all
inclui, porque um clear que deixasse o stream de 500 para trás é o
desfecho que surpreende.
Trunca, nunca apaga
Os handlers que o configure_logging instalou seguram um descritor aberto
em cada caminho. Remover o arquivo os deixaria escrevendo num inode que
nada consegue ler de volta — o endpoint pareceria funcionar exatamente uma
vez. Arquivo ausente é criado vazio, então a pós-condição é a mesma.
Quem precisa dos caminhos fora de uma rota — um job de arquivamento, um coletor, um contador — usa o mesmo resolvedor que o router usa, em vez de recopiar o mapa de nível para nome de arquivo:
from pathlib import Path
from tempest_fastapi_sdk.api.routers.logs import resolve_log_files
paths: list[Path] = resolve_log_files("logs", "error")
every: list[Path] = resolve_log_files("logs", "all", include_http_500=True)
Atrás da sua própria auth — dependencies=¶
Serviço que já tem login próprio (Bearer JWT de admin, role, sessão) não
precisa inventar um segredo compartilhado só para os logs. Passe a
dependência que já protege o resto do painel em dependencies=, e ela vale
para GET e DELETE:
from fastapi import Depends, FastAPI
from tempest_fastapi_sdk import (
JWTUtils,
configure_logging,
make_logs_router,
make_role_dependency,
register_exception_handlers,
)
configure_logging(log_dir="logs")
tokens: JWTUtils = JWTUtils(secret="a-32-character-secret-for-tests!")
require_admin = make_role_dependency(tokens, ["admin"])
app: FastAPI = FastAPI()
register_exception_handlers(app)
app.include_router(
make_logs_router(log_dir="logs", dependencies=[Depends(require_admin)]),
)
O que cada chamada recebe, medido com esse app:
| Requisição | Resposta |
|---|---|
sem Authorization |
401 (UNAUTHORIZED) |
Bearer com roles: ["user"] |
403 (FORBIDDEN) |
Bearer com roles: ["admin"] |
200, sem X-Token nenhum |
Cada item aceita as duas grafias, Depends(require_admin) ou só
require_admin. O Depends pronto é usado como veio, não é embrulhado de
novo.
Como dependencies= convive com o X-Token
As duas peças somam, nunca se anulam:
- Só
dependencies=: elas são o gate inteiro. NenhumX-Tokené lido, e o header nem aparece no schema OpenAPI. token_secretedependencies=: a requisição precisa do header e de passar em toda dependência.- Nenhuma das duas:
ValueErrorna construção, como antes, a menos que você passeallow_unauthenticated=True. Lista vazia (dependencies=[]) não conta como gate.
Outro contrato de resposta — read_log_entries e clear_log_files¶
O router é uma casca sobre duas funções públicas. Quando o painel precisa de outra forma de resposta, chame-as direto em vez de reescrever a leitura: é nela que mora o teto por arquivo, e um leitor feito à mão que carrega o arquivo inteiro funciona no diretório novo e derruba o worker no de vários gigabytes.
As duas são síncronas (I/O de arquivo). Numa rota async, rode-as fora do
event loop com asyncio.to_thread:
import asyncio
from fastapi import APIRouter, Depends, FastAPI
from pydantic import BaseModel
from tempest_fastapi_sdk import (
JWTUtils,
LogReadResult,
clear_log_files,
make_role_dependency,
read_log_entries,
)
tokens: JWTUtils = JWTUtils(secret="a-32-character-secret-for-tests!")
require_admin = make_role_dependency(tokens, ["admin"])
class AppLogsResponseSchema(BaseModel):
messages: list[str]
truncated: bool
router: APIRouter = APIRouter(
prefix="/api/admin/metrics",
dependencies=[Depends(require_admin)],
)
@router.get("/app-logs")
async def app_logs(q: str | None = None, limit: int = 100) -> AppLogsResponseSchema:
result: LogReadResult = await asyncio.to_thread(
read_log_entries, "logs", "error", q=q
)
return AppLogsResponseSchema(
messages=[str(entry["message"]) for entry in result.entries[:limit]],
truncated=result.truncated,
)
@router.delete("/app-logs")
async def clear_app_logs() -> list[str]:
return await asyncio.to_thread(clear_log_files, "logs", "error")
app: FastAPI = FastAPI()
app.include_router(router)
Com um logger.error("payment gateway timeout") gravado, o
GET /api/admin/metrics/app-logs?q=timeout de um admin respondeu:
e o DELETE respondeu ["error.log"].
read_log_entries(log_dir, source="all", *, q, start, end, max_records_per_file)devolve umLogReadResult:entriesjá filtrados e do mais novo pro mais antigo, etruncated, que diz se o teto cortou algum arquivo. Nada casou?entriesvem[].clear_log_files(log_dir, source="all")trunca no lugar e devolve os nomes esvaziados. Em"all", o500.logentra — a mesma regra doDELETE /logs.
Recap
configure_logging(log_dir=...)→ stdout + um arquivo por nível.- Exatidão por nível: cada arquivo só recebe a sua severidade.
500.logisola erros 500 não tratados (marcadorhttp_500).make_logs_routerserve esses arquivos paginados e autenticados — peloX-Tokenou pela sua própria auth emdependencies=.read_log_entries/clear_log_filessão a leitura e a limpeza sem o router, para outro contrato de resposta.
Uma linha por request — AccessLogMiddleware¶
configure_logging formata o que você loga e RequestIDMiddleware amarra o id
de correlação, mas nada disso emite a linha por request que faz o
make_logs_router valer a leitura. Esse é o trabalho do AccessLogMiddleware:
# src/api/app.py
import logging
from fastapi import FastAPI
from tempest_fastapi_sdk import AccessLogMiddleware, RequestIDMiddleware
app: FastAPI = FastAPI()
app.add_middleware(AccessLogMiddleware, level=logging.INFO)
app.add_middleware(RequestIDMiddleware)
Cada request vira um registro cujo message é a linha familiar
(GET /api/users 200 12.4ms) e cujos detalhes vão como campos de verdade —
http_method, http_path, http_query, http_status, duration_ms,
client_ip — via extra=. É essa diferença que faz o JSONFormatter gravar
chaves em vez de uma string interpolada, e portanto que faz o GET /logs
conseguir filtrar por elas.
A ordem de registro não importa (desde a v0.277.0)
O request_id vem de duas fontes, porque nenhuma sozinha sobrevive às
duas ordens: o context var que o RequestIDMiddleware amarra, e o header
que ele carimba na resposta. Medido:
AccessLogMiddleware por dentro do RequestIDMiddleware context var: setado
header: ainda não escrito
AccessLogMiddleware por fora do RequestIDMiddleware context var: limpo
header: presente
O RequestIDMiddleware é um BaseHTTPMiddleware: carimba o header
depois que a app retorna, então o wrapper de send de um middleware
interno já rodou; e limpa o context var ao desenrolar, então um externo
não acha nada lá. Ler as duas cobre as duas.
Até a v0.276.0 isto era um !!! danger dizendo para registrar na ordem
certa. Aviso sobre passo mecânico com uma resposta certa é código não
escrito — a regra do repositório pegou o próprio SDK.
Nível: ERROR é onde a falha está¶
Resposta abaixo de 500 sai no level que você configurou (default INFO).
Resposta 5xx sai em ERROR — tanto a que a aplicação renderizou quanto a que
escapou de um handler. Achar request que falhou filtrando por nível é o motivo
de escrever essas linhas.
A exceção que escapa é o caso que mais precisa de log e o que mais falta nas
versões escritas à mão: o handler estourou antes de mandar qualquer coisa, então
não existe status para ler. O middleware registra 500, acrescenta o campo
error com o nome da classe da exceção, e re-levanta — quem decide o que o
cliente vê continua sendo o seu tratamento de erro.
Stream não é request de uma hora¶
# src/api/app.py
from fastapi import FastAPI
from tempest_fastapi_sdk import AccessLogMiddleware
app: FastAPI = FastAPI()
app.add_middleware(
AccessLogMiddleware,
exempt_paths=("/api/sse", "/api/metrics"),
)
exempt_paths casa por prefixo, então ("/api/sse",) cobre
/api/sse/stream. Uma conexão SSE aberta por uma hora sairia no log, no
fechamento, como um request que demorou uma hora.
Segredo na URL já foi logado¶
Um endpoint depreciado que recebia um token equivalente a bearer como parâmetro
de path chega ao middleware com o token na URL — recusar o request no handler
não desfaz o log. redact é a costura para isso, aplicada ao path e à query
separadamente:
# src/api/app.py
import re
from fastapi import FastAPI
from tempest_fastapi_sdk import AccessLogMiddleware
_LEGACY_TOKEN_PATH: re.Pattern[str] = re.compile(
r"^(?P<prefix>/api)?/auth/google/[^/]+$"
)
app: FastAPI = FastAPI()
def redact_path(value: str) -> str:
"""Replace the secret segment of a legacy path before it is logged."""
if _LEGACY_TOKEN_PATH.match(value):
return _LEGACY_TOKEN_PATH.sub(r"\g<prefix>/auth/google/<redacted>", value)
return value
app.add_middleware(AccessLogMiddleware, redact=redact_path)
Atrás de proxy¶
# src/api/app.py
from fastapi import FastAPI
from tempest_fastapi_sdk import AccessLogMiddleware
app: FastAPI = FastAPI()
app.add_middleware(AccessLogMiddleware, trusted_ip_header="x-real-ip")
client_ip sai de get_client_ip_from_scope. Nunca aponte
trusted_ip_header para um X-Forwarded-For cru: esse header é acrescentado
ao que o cliente mandou, então a entrada mais à esquerda é escolhida pelo
atacante — e o log passaria a atribuir requests ao endereço que ele quis. Veja
Segurança ».
Recap
AccessLogMiddlewareé ASGI puro: lê o status dohttp.response.starte deixa o caminho de exceção intocado.- O
request_identra na linha em qualquer ordem de registro: do context var quando ele é interno, do header da resposta quando é externo. 5xx(renderizado ou escapado) sai emERROR; o resto nolevelconfigurado.exempt_pathscasa por prefixo — é o que tira o SSE do log.redactreescreve path e query antes do registro existir.
Recap¶
configure_loggingescreve JSON estruturado no stdout e emlogs/, um arquivo por nível, cada arquivo com apenas o seu próprio nível.500.logfica isolado de propósito: o arquivo que você abre primeiro no incidente não vem misturado com o resto.- O id da requisição entra em toda linha, então uma reclamação de usuário vira
um
grep— é isso que separa log estruturado de log bonito. make_logs_routermontaGET /logspaginado sobre esses arquivos, mais recentes primeiro, para ler sem acesso ao disco do container.- O traceback de um 5xx não carrega o texto do banco:
redact_database_errorstroca oDETAILque cita o valor por constraint e colunas, e oon_server_errorsegue recebendo a exceção original. - Todo nível aceita
exc_info(boolou"auto"); campo estruturado que colide com atributo doLogRecordé recusado na chamada, comTypeError. - Com
redact=True(ou umaRedactionPolicy), todo handler redige e-mail,Bearer, JWT e chave sensível de mensagem,extra=, traceback estack_infoantes de o registro ser escrito.