Logging Orientado a Aspectos (AOP)

Este documento explica como o Beyou usa Spring AOP para observabilidade: o que os dois aspectos registram, como erros esperados de cliente ficam fora do canal de erro e como a saída dos aspectos alimenta (e deliberadamente fica fora do) rastreador de erros GlitchTip.

O que o AOP cobre aqui, e o que não cobre

O pacote de AOP tem exatamente dois aspectos, e ambos fazem logging. Toda outra preocupação transversal vive em outro lugar: rate limiting e validação de JWT são filtros servlet, cache são as anotações @Cacheable do Spring, transações são @Transactional. Uma consequência que vale conhecer: rejeições por rate limit acontecem antes de o controller ser invocado, então um 429 nunca produz linha de log de aspecto. A identidade na linha também não é um aspecto: um filtro servlet coloca o id do usuário no MDC e o padrão de log o imprime, então as linhas dos aspectos o carregam sem saber que ele existe.

flowchart LR
  subgraph aspects["Os dois aspectos"]
    CL["ControllerLogging<br/>todo @RestController"]
    SL["ServiceMethodsLogging<br/>todo @Service"]
  end
  REQ["📥 Requisição"] --> CL --> SL --> DB["💾 Repository"]
  CL -.->|"[REQUEST] · [CLIENT_ERROR] · [EXCEPTION]"| LOG["📋 Logs"]
  SL -.->|"[START] · [END] · [PERFORMANCE] · [ERROR]"| LOG
  LOG -->|"stdout → Alloy → Loki"| MON["📊 Grafana"]

Os dois pointcuts usam as anotações de estereótipo padrão (@RestController, @Service), então qualquer controller ou service novo é tecido automaticamente, onde quer que more. Não há anotações próprias nem configuração explícita de AOP; o starter (renomeado spring-boot-starter-aspectj no Spring Boot 4) habilita tudo.

ServiceMethodsLogging

Quatro advices envolvem cada método de service:

Advice Nível O que emite
@Before INFO [START] Starting method: createCategory with 2 arg(s)
@AfterReturning INFO / DEBUG [END] Method finish: createCategory em INFO; o valor de retorno só em DEBUG
@Around (tempo) INFO [PERFORMANCE] Method createCategory exectued in 15 ms
@Around (exceções) WARN / ERROR Ver a seção de roteamento abaixo; sempre relança

A linha mais importante da tabela é a primeira: valores de argumentos nunca são registrados, só a contagem. Uma versão anterior registrava os objetos completos, o que colocava DTOs com senhas e e-mails no fluxo de logs; a auditoria de segurança apontou e o aspecto passou a contar. A mesma cautela vale para valores de retorno, que só se materializam em DEBUG.

Dois detalhes menores para quem for grepar: o erro de grafia "exectued" da linha de performance está no código-fonte, então grep por essa grafia; e dois advices @Around separados no mesmo pointcut significam que cada chamada de service passa por proxy duas vezes.

ControllerLogging

Dois advices envolvem cada método de controller:

Roteamento de erros esperados de cliente

Os dois aspectos dividem uma única decisão de roteamento, uma checagem estática no ServiceMethodsLogging. Seis tipos de exceção são "esperados": BusinessException (e cada subclasse de domínio), JwtNotFoundException, as três exceções de refresh token e IllegalArgumentException. Esses registram em WARN sem stack trace, porque uma senha errada ou um token expirado é uma terça-feira comum, não um incidente.

Esse roteamento também é o que mantém o rastreador de erros limpo: o GlitchTip só transforma linhas de log em eventos no nível ERROR, então o ruído esperado de cliente nunca vira alerta. Duas sutilezas valem registro:

Onde os aspectos encontram o GlitchTip

O SDK do Sentry transforma linhas de log em duas coisas: breadcrumbs (a trilha anexada a um evento) e os próprios eventos. Os aspectos são tratados de forma diferente em cada uma:

Mecânica de proxy e suas armadilhas

O Spring AOP é baseado em proxy (CGLIB), o que traz o alerta clássico: um método chamando outro método da mesma classe passa por fora do proxy, então nem o logging nem @Cacheable nem @Transactional disparam na chamada interna. O scheduler de snapshots documenta essa armadilha explicitamente no próprio código. Os aspectos também envolvem os beans do serviço de cache, então uma leitura cacheada carrega os proxies dos aspectos mais o interceptor de cache.

Referência de prefixos de log

Prefixo Fonte Nível Significado
[REQUEST] Aspecto de controller INFO Assinatura completa com duração, só no sucesso
[CLIENT_ERROR] Aspecto de controller WARN Erro esperado de cliente, sem stack trace
[EXCEPTION] Aspecto de controller ERROR Falha inesperada, stack trace completo
[START] Aspecto de service INFO Entrada do método com contagem de argumentos
[END] Aspecto de service INFO / DEBUG Saída do método; valor de retorno só em DEBUG
[PERFORMANCE] Aspecto de service INFO Duração ("exectued", conforme o código)
[ERROR] Aspecto de service ERROR Falha inesperada, stack trace completo
[LOG] Services de domínio varia A convenção manual dentro do código de negócio

Esses prefixos são o que as consultas do Loki e o dashboard Beyou Logs filtram.

De quem é cada linha

Cada linha carrega o id do usuário para quem a requisição era:

2026-08-21T08:31:33.536Z  INFO 1 --- [backend] [mcat-handler-61] [userId=3f1c9a2e-…] b.b.backend.AOP.ServiceMethodsLogging : [PERFORMANCE] Method history exectued in 12 ms

O valor vem do MDC, preenchido durante toda a requisição pelo UserContextLogFilter, e é impresso pelo logging.pattern.correlation, o espaço que o próprio Spring Boot reserva para identidade por requisição dentro dos seus padrões default de console e arquivo. O filtro é um filtro servlet comum, não um elo da cadeia de segurança, ordenado depois do FilterChainProxy do Spring Security para o principal já existir, e antes do filtro de rate limit para que uma rejeição 429 seja atribuível mesmo que nenhum aspecto a veja. Linhas sem usuário em contexto, entre elas as de inicialização e as do scheduler de snapshots, imprimem anonymous em vez de um campo vazio, então uma consulta de log tem um único formato de linha para interpretar, não dois.

O id é uma chave substituta, e nada que o usuário escreveu viaja com ele. É isso que o torna seguro num canal onde os aspectos se recusam a registrar argumentos de propósito: o id diz qual conta, o banco diz quem. A integração Logback do Sentry copia o MDC para breadcrumbs e eventos, então o mesmo id chega ao GlitchTip e responde se um incidente é uma conta ou todas elas.

Dois tipos de linha ainda aparecem como anonymous numa requisição autenticada, ambos porque não existe id para anexar naquele ponto, e não por esquecimento. O TokenService.validateToken é registrado pelo aspecto de service de dentro do SecurityFilter, antes de o token ter sido transformado em usuário. O stream SSE do agente retoma numa thread do reactor onde nenhum filtro de requisição roda, e é por isso que o AiAgentService recebe o id do usuário e o registra ele mesmo.

Lacunas honestas

Área Estado atual Nota
IDs de correlação Id de usuário, sem request id Cada linha carrega [userId=…], então a atividade de um usuário é uma consulta só. Nada separa duas requisições simultâneas do mesmo usuário, o que ainda depende de nome de thread e timestamps
Tempo de requisições falhas [REQUEST] só no sucesso Um endpoint que lança exceção não deixa registro de duração
Higiene de mensagens de exceção Registradas sem escape e sem limite Um controller sanitiza suas mensagens na origem contra forja de log; o advice em si não, então o mesmo buraco existe para qualquer outra mensagem
Cobertura de testes Um teste de regressão de PII O ControllerLogging tem um guarda provando que argumentos nunca vazam; o ServiceMethodsLogging e o roteamento WARN/ERROR não têm testes dedicados
Logging estruturado Texto puro Logs em JSON deixariam as consultas do Loki mais firmes que grep de prefixo