- Agile 2
- Alta disponibilidad 1
- Alternativas cloud 1
- Aop 1
- Arquitectura 3
- Arquitectura distribuida 2
- Automatizacion 3
- Azure devops 1
- Base de datos 1
- Buenas practicas 19
- Cloud 1
- Colas 7
- Competing consumers 1
- Convenciones 11
- Copilot 1
- Diseno 6
- Docker 2
- Docker compose 1
- Documentacion 1
- Eda 11
- Equipos 1
- Escalabilidad 1
- Flujo de negocio 1
- Flujo de trabajo 3
- Flyway 1
- Git 4
- Gradle 3
- Herramientas digitales 1
- Ia 1
- Iam 1
- Infraestructura 2
- Java 14
- Jerarquia tecnica 1
- Jpa 1
- Jsonb 1
- Kafka 7
- Kubernetes 1
- Liderazgo en software 1
- Lineamientos 1
- Log 1
- Logging 3
- Microservicios 3
- Mongodb 1
- Monitoreo 1
- Nosql 3
- Observabilidad 4
- Open source 1
- Plugins 3
- Postgresql 1
- Privacidad 1
- Programacion funcional 1
- Programacion reactiva 4
- Rabbitmq 6
- Rotacion de talento 1
- Saga 2
- Scrum 2
- Security 1
- Seguridad 1
- Self hosting 1
- Sistemas legados 1
- Spring boot 3
- Spring mvc 2
- Sql 3
- Streams 1
- Threadlocal 1
- Trazabilidad 2
- Versionado 2
- Web 1
- Webflux 2
- Websockets 1
- Zero trust 1
Trazabilidad
2 artículos
Observabilidad sin Ruido: Diseñando un Sistema de Logs con AOP en Arquitecturas DDD — Parte II
- Mauricio ECR
- Arquitectura
- 18 May, 2026
La primera parte de este artículo construyó el argumento conceptual: por qué los logs dispersos se convierten en deuda técnica, cómo AOP permite centralizar la observabilidad sin contaminar la lógica
Observabilidad sin Ruido: Diseñando un Sistema de Logs con AOP en Arquitecturas DDD — Parte II
- Mauricio ECR
- Arquitectura
- 18 May, 2026
La primera parte de este artículo construyó el argumento conceptual: por qué los logs dispersos se convierten en deuda técnica, cómo AOP permite centralizar la observabilidad sin contaminar la lógica de negocio, qué información debe registrarse en cada capa de una arquitectura DDD, y cómo los campos estructurados convierten un archivo de texto en una fuente de inteligencia operacional. Lo que quedó pendiente fue la demostración concreta: cómo se construye ese sistema, qué decisiones se toman en cada pieza, y por qué cada una de ellas importa.
Eso es exactamente lo que ocupa esta segunda parte. El objetivo es preciso: que al terminar de leerla, un desarrollador con experiencia en Spring pueda reproducir el sistema completo en su proyecto. No como una lista de pasos a seguir ciegamente, sino con el entendimiento de por qué cada componente existe, qué problema resuelve y qué ocurriría si se omitiera o se implementara de otra manera.
El stack es Java 21, Spring Boot 3.5.x, Gradle. Las dependencias que habilitan el sistema son spring-boot-starter-aop, que trae AspectJ y el soporte de proxies de Spring, y jackson-datatype-jsr310, que permite serializar correctamente los tipos de fecha y hora de Java 8 en los logs. Lombok está presente por conveniencia, pero no es estructuralmente necesario. Ninguna dependencia adicional es requerida.
El proyecto de ejemplo
Para que cada decisión técnica tenga contexto real, el sistema de logs se implementa sobre un proyecto concreto: una API REST que registra usuarios. Es un caso de uso deliberadamente simple, lo suficiente para que el flujo sea fácil de seguir, pero con la estructura completa de una arquitectura DDD: entrada HTTP, caso de uso, validaciones de dominio, persistencia, y manejo de errores.
El proyecto tiene esta estructura:
src/main/java/com/app_247/blog/id202603212000art/
│
├── Id202603212000artApplication.java ★ [LOG]
│
├── applications/
│ └── aop/
│ ├── aspect/
│ │ └── MethodLoggingAspect.java ★ [LOG]
│ └── config/
│ ├── JacksonConfig.java ★ [LOG]
│ └── LoggingAopProperties.java ★ [LOG]
│
├── domain/
│ ├── model/
│ │ ├── exception/
│ │ │ ├── BusinessException.java
│ │ │ └── DomainValidationException.java
│ │ └── usuario/
│ │ ├── gateway/
│ │ │ └── IUsuarioGateway.java
│ │ └── Usuario.java
│ └── usecase/
│ └── registrarusuario/
│ ├── dto/
│ │ ├── RegistrarUsuarioIn.java
│ │ └── RegistrarUsuarioOut.java
│ ├── enricher/
│ │ └── UsernameEnricher.java
│ ├── validator/
│ │ ├── EdadValidator.java
│ │ ├── EmailDominioValidator.java
│ │ └── NombreValidator.java
│ └── RegistrarUsuarioUseCase.java
│
└── infrastructure/
├── drivenadapters/
│ └── jpa/
│ └── usuario/
│ ├── adapter/
│ │ └── UsuarioPersistenciaAdapter.java
│ ├── entity/
│ │ └── UsuarioEntity.java
│ ├── mapper/
│ │ └── UsuarioPersistenciaMapper.java
│ └── repository/
│ └── UsuarioJpaRepository.java
└── entrypoints/
└── api/
└── registrarusuario/
├── dto/
│ ├── RegistrarUsuarioRequest.java
│ └── RegistrarUsuarioResponse.java
├── mapper/
│ └── RegistrarUsuarioApiMapper.java
├── RegistrarUsuarioController.java
└── util/
└── Exception/
└── GlobalExceptionHandler.java
src/main/resources/
└── application.properties ★ [LOG]
Las clases marcadas con ★ [LOG] son las que forman el sistema de observabilidad. Todo lo demás es la lógica del negocio y la infraestructura del proyecto, que no tiene ninguna instrucción de log y no necesita tenerla.
El flujo de una solicitud
Antes de abrir cualquier clase del sistema de logs vale la pena recorrer el flujo completo de una solicitud de registro de usuario. Es el flujo que el aspecto va a observar, y entenderlo con claridad hace que cada decisión de implementación tenga sentido inmediato.
El cliente envía un POST /api/v1/usuarios con un cuerpo JSON que contiene nombre, email y edad. A partir de ahí, la solicitud atraviesa estas capas en orden:
RegistrarUsuarioController es el punto de entrada. Recibe el request HTTP, lo valida con Bean Validation (@Valid), y usa RegistrarUsuarioApiMapper para convertir el RegistrarUsuarioRequest en un RegistrarUsuarioIn, que es el DTO que entiende el dominio. Luego invoca el caso de uso y convierte el resultado de vuelta a un RegistrarUsuarioResponse para la respuesta HTTP. El controlador no tiene lógica de negocio: solo traduce entre el mundo HTTP y el mundo del dominio.
RegistrarUsuarioUseCase es donde ocurre la orquestación. Recibe el RegistrarUsuarioIn y ejecuta la secuencia de negocio: primero llama a NombreValidator, EdadValidator y EmailDominioValidator para validar que los datos cumplan las reglas del dominio. Luego consulta el gateway para verificar que el email no esté ya registrado. Si todo es válido, usa UsernameEnricher para generar el nombre de usuario a partir del email, construye el objeto Usuario y lo persiste a través del gateway. Finalmente construye y retorna el RegistrarUsuarioOut.
Es importante notar que NombreValidator, EdadValidator, EmailDominioValidator y UsernameEnricher son clases con métodos estáticos, sin estado, sin anotaciones de Spring. El UseCase los llama directamente como utilidades. No son beans y el aspecto no los ve, lo cual es correcto: su comportamiento queda capturado por la observación del UseCase que los invoca.
IUsuarioGateway es la interfaz del puerto de salida. El dominio la define; la infraestructura la implementa. El UseCase solo conoce la interfaz, nunca la implementación concreta.
UsuarioPersistenciaAdapter es la implementación del gateway. Está anotado con @Component, es un bean de Spring, y es aquí donde realmente ocurre la interacción con la base de datos. Usa UsuarioPersistenciaMapper para convertir entre el modelo de dominio Usuario y la entidad JPA UsuarioEntity, y delega en UsuarioJpaRepository para las operaciones sobre H2.
GlobalExceptionHandler intercepta cualquier excepción que no haya sido manejada antes de llegar al cliente. Para DomainValidationException devuelve un 422 con el detalle del campo que falló. Para BusinessException devuelve un 409 con el código de error. Para errores de validación de Bean Validation devuelve un 400 con el mapa de campos y mensajes.
Con ese recorrido claro, el flujo completo se puede representar así:
POST /api/v1/usuarios
│
▼
RegistrarUsuarioController ← @RestController ★ interceptado
│ toCommand()
▼
RegistrarUsuarioApiMapper ← @Component (MapStruct)
│ RegistrarUsuarioIn
▼
RegistrarUsuarioUseCase ← @Service ★ interceptado
│
├── NombreValidator.validar() ← clase plana, NO interceptada
├── EdadValidator.validar() ← clase plana, NO interceptada
├── EmailDominioValidator.validar() ← clase plana, NO interceptada
│
├── gateway.existeEmail()
│ └── UsuarioPersistenciaAdapter#existeEmail ← @Component ★ interceptado
│ └── UsuarioJpaRepository (Spring Data)
│
├── UsernameEnricher.generarUsername() ← clase plana, NO interceptada
│
└── gateway.guardar()
└── UsuarioPersistenciaAdapter#guardar ← @Component ★ interceptado
└── UsuarioJpaRepository (Spring Data)
│
▼ RegistrarUsuarioOut
RegistrarUsuarioController
│ toResponse()
▼
RegistrarUsuarioApiMapper
│
▼
RegistrarUsuarioResponse → HTTP 201
Este flujo es el que el aspecto va a observar en tiempo de ejecución. Cada clase marcada con ★ interceptado genera sus propios registros de INPUT, OUTPUT y TIMING sin que ninguna de ellas sepa que está siendo observada. Las clases planas que no son beans simplemente no aparecen en los logs, y eso es correcto: su comportamiento está implícito en la observación de las capas que las contienen.
La arquitectura del sistema de logs
Con el flujo del proyecto claro, el sistema de logs se puede describir con precisión. Son tres piezas con responsabilidades distintas que operan juntas:
LoggingAopProperties es la configuración. Define qué interceptar: qué paquetes, qué clases, qué métodos, en qué nivel de log y a partir de qué tiempo de ejecución emitir una advertencia. No sabe nada del aspecto ni de Jackson.
MethodLoggingAspect es el motor. Intercepta cada método elegible, mide el tiempo, serializa los argumentos y resultados, y emite los registros según las reglas que encontró en las propiedades. No sabe nada de la lógica de negocio del proyecto.
JacksonConfig proporciona el ObjectMapper que el aspecto usa para convertir objetos Java en texto JSON. Está configurado para manejar correctamente los tipos de fecha de Java 8, que sin esta configuración se serializarían como arrays de números en lugar de strings ISO.
La relación entre las tres piezas es deliberadamente asimétrica: LoggingAopProperties no sabe nada del aspecto, y el aspecto no sabe nada de Jackson más allá de que tiene un ObjectMapper disponible. Cada pieza tiene una responsabilidad única y bien delimitada.
LoggingAopProperties: el contrato de configuración
Todo el comportamiento del sistema de logs se controla desde application.properties a través de LoggingAopProperties. Esta clase es un @ConfigurationProperties que mapea el prefijo logging.aop a una estructura de objetos en memoria:
@Data
@ConfigurationProperties(prefix = "logging.aop")
public class LoggingAopProperties {
private boolean enabled = true;
private String basePackage = "com.app_247.blog.id202603212000art";
private List<PatternConfig> patterns = List.of();
@Data
public static class PatternConfig {
private String packageRegex = ".*";
private String classRegex = ".*";
private String methodRegex = ".*";
private String logLevel = "INFO";
private long warnThresholdMs = 500L;
}
}
La estructura interna PatternConfig representa una regla de interceptación. Tiene tres expresiones regulares que se evalúan contra el paquete, el nombre simple de la clase y el nombre del método. Si las tres hacen match, la regla aplica y sus otros dos campos determinan el comportamiento: logLevel controla en qué nivel se emiten los registros normales de esa capa, y warnThresholdMs define el umbral de tiempo a partir del cual el registro de timing se eleva automáticamente a WARN independientemente del nivel configurado.
Los valores por defecto de las tres regex son ".*", que en regex significa "cualquier cosa". Esto garantiza que una PatternConfig construida sin configuración explícita intercepta todo, lo cual es un default seguro para desarrollo pero que en producción se reemplaza por reglas precisas.
Para que Spring Boot cargue esta clase al arrancar, la clase principal de la aplicación debe registrarla explícitamente:
@SpringBootApplication
@EnableConfigurationProperties(LoggingAopProperties.class)
public class Id202603212000artApplication {
public static void main(String[] args) {
SpringApplication.run(Id202603212000artApplication.class, args);
}
}
@EnableConfigurationProperties es el mecanismo que le indica a Spring Boot que debe crear un bean de tipo LoggingAopProperties y enlazarlo con el prefijo logging.aop del archivo de propiedades. Sin esta anotación, la clase existe pero nunca se puebla: el aspecto recibiría una instancia con todos los valores por defecto y sin ningún patrón configurado, lo que significa que no interceptaría nada. Es un error silencioso difícil de diagnosticar si no se conoce el mecanismo.
La configuración del proyecto de ejemplo define tres patrones, uno por cada capa que se quiere observar:
logging.aop.enabled=true
logging.aop.base-package=com.app_247.blog.id202603212000art
# UseCase
logging.aop.patterns[0].package-regex=com\\.app_247\\.blog\\.id202603212000art\\.domain\\.usecase.*
logging.aop.patterns[0].class-regex=.*UseCase
logging.aop.patterns[0].method-regex=.*
logging.aop.patterns[0].log-level=INFO
logging.aop.patterns[0].warn-threshold-ms=300
# Adapter de persistencia
logging.aop.patterns[1].package-regex=com\\.app_247\\.blog\\.id202603212000art\\.infrastructure\\.drivenadapters.*
logging.aop.patterns[1].class-regex=.*Adapter
logging.aop.patterns[1].method-regex=.*
logging.aop.patterns[1].log-level=DEBUG
logging.aop.patterns[1].warn-threshold-ms=100
# Controller
logging.aop.patterns[2].package-regex=com\\.app_247\\.blog\\.id202603212000art\\.infrastructure\\.entrypoints.*
logging.aop.patterns[2].class-regex=.*Controller
logging.aop.patterns[2].method-regex=.*
logging.aop.patterns[2].log-level=INFO
logging.aop.patterns[2].warn-threshold-ms=500
Tres decisiones de diseño visibles en esta configuración merecen atención. Primera: el adapter de persistencia tiene log-level=DEBUG mientras que el UseCase y el Controller tienen log-level=INFO. Esto significa que en producción con nivel INFO configurado, los logs del adapter son invisibles por defecto y solo aparecen cuando se activa DEBUG dinámicamente para diagnosticar un problema. La lógica es que saber que el UseCase llamó al adapter y cuánto tardó ya es información suficiente en condiciones normales; el detalle de qué exactamente se guardó o consultó es información de diagnóstico que solo se necesita ocasionalmente.
Segunda: el umbral de WARN del adapter es de 100ms, mucho más estricto que los 300ms del UseCase y los 500ms del Controller. Esto refleja una expectativa operacional: una operación de base de datos que tarde más de 100ms en este proyecto es una señal de alerta, mientras que el UseCase puede acumular ese tiempo y más en su orquestación sin que sea necesariamente un problema.
Tercera: los patrones se evalúan en orden y se aplica el primero que haga match. Si en el futuro existiera una clase que fuera a la vez un UseCase y un Adapter, lo cual no debería ocurrir en una arquitectura DDD bien diseñada pero podría ocurrir en un proyecto en transición, el patrón 0 ganaría porque aparece primero. Esta semántica de primer match es predecible y fácil de razonar.
JacksonConfig: el ObjectMapper para los logs
El aspecto necesita convertir los argumentos y resultados de los métodos en texto para escribirlos en el log. Jackson es la herramienta natural para esto en un proyecto Spring, pero la configuración por defecto tiene un problema concreto con los tipos de fecha de Java 8.
Sin configuración adicional, un LocalDateTime como 2026-05-18T15:47:05.875 se serializa como un array de números: [2026,5,18,15,47,5,875000000]. En un log de producción eso es ilegible. La solución es registrar el módulo JavaTimeModule y deshabilitar la serialización de fechas como timestamps:
@Configuration
public class JacksonConfig {
@Bean
public ObjectMapper objectMapper() {
ObjectMapper mapper = new ObjectMapper();
mapper.registerModule(new JavaTimeModule());
mapper.disable(SerializationFeature.WRITE_DATES_AS_TIMESTAMPS);
return mapper;
}
}
El resultado es que LocalDateTime aparece en los logs como "2026-05-18T15:47:05.8756894", que es exactamente lo que se ve en la salida de consola de referencia.
Una pregunta legítima es por qué esta configuración vive en el paquete applications/aop/config y no en un paquete de configuración general de la aplicación. La respuesta es de propiedad: este ObjectMapper existe para el sistema de logs, no para la aplicación en general. En el futuro, cuando se incorpore el sistema de enmascaramiento que se documentará en la tercera parte de esta serie, este mapper recibirá configuración adicional específica para logs que no debe afectar a las respuestas HTTP. Mantenerlo en el paquete del sistema de logs hace explícita esa propiedad desde el principio.
MethodLoggingAspect: el motor de la interceptación
Con la configuración clara y el ObjectMapper disponible, el aspecto puede construirse. MethodLoggingAspect es un @Component anotado con @Aspect que recibe por inyección las propiedades y el mapper:
@Slf4j
@Aspect
@Component
@RequiredArgsConstructor
@ConditionalOnProperty(prefix = "logging.aop", name = "enabled", havingValue = "true", matchIfMissing = true)
public class MethodLoggingAspect {
private final ObjectMapper objectMapper;
private final LoggingAopProperties properties;
private final ConcurrentHashMap<String, Optional<PatternConfig>> matchCache = new ConcurrentHashMap<>();
@ConditionalOnProperty con matchIfMissing = true significa que el aspecto está activo por defecto aunque la propiedad logging.aop.enabled no aparezca en el archivo de configuración. Solo se desactiva si la propiedad está explícitamente en false. Esto es un default sensato: en un proyecto nuevo donde todavía no se ha configurado nada, el sistema de logs funciona.
El matchCache es un ConcurrentHashMap de instancia, no estático. Esto es deliberado: si en algún escenario de pruebas o de recarga de contexto se creara una nueva instancia del aspecto, el cache empieza vacío y se reconstituye limpiamente. Un cache estático compartiría estado entre instancias del aspecto, lo que en tests de integración puede producir comportamientos inesperados difíciles de reproducir.
El pointcut y el filtro inicial
El pointcut captura todos los beans anotados con los estereotipos principales de Spring, excluyendo el propio paquete del aspecto:
@Around("(within(@org.springframework.stereotype.Service *) " +
"|| within(@org.springframework.stereotype.Component *) " +
"|| within(@org.springframework.web.bind.annotation.RestController *)" +
"|| within(@org.springframework.stereotype.Repository *)) " +
"&& !within(com.app_247.blog.id202603212000art.aop..*)")
public Object logMethod(ProceedingJoinPoint joinPoint) throws Throwable {
Usar within con estereotipos en lugar de una expresión de paquete tiene una implicación directa en DDD que ya se mencionó al describir el flujo: los validadores y enrichers del dominio, que son clases planas sin anotaciones de Spring, no son interceptados. El aspecto solo ve lo que Spring gestiona, y eso es exactamente lo correcto.
Lo primero que hace el advice una vez que captura una invocación es extraer la información del método y aplicar el filtro de paquete base:
MethodSignature signature = (MethodSignature) joinPoint.getSignature();
Method method = signature.getMethod();
String packageName = method.getDeclaringClass().getPackageName();
String className = method.getDeclaringClass().getSimpleName();
String methodName = method.getName();
if (!packageName.startsWith(properties.getBasePackage())) {
return joinPoint.proceed();
}
Este filtro descarta en una comparación de strings todas las invocaciones que provienen de beans de Spring propios del framework o de librerías de terceros. Es el filtro más barato posible y elimina la gran mayoría de las invocaciones que el pointcut captura pero que no son de la aplicación.
Las invocaciones que pasan ese filtro enfrentan la evaluación de patrones, protegida por el cache:
String cacheKey = packageName + "." + className + "#" + methodName;
Optional<PatternConfig> matchedPattern = matchCache.computeIfAbsent(
cacheKey,
k -> findMatchingPattern(packageName, className, methodName));
if (matchedPattern.isEmpty()) {
return joinPoint.proceed();
}
Si ningún patrón hace match, la invocación pasa sin ningún registro. Si hay match, el PatternConfig resultante determina todo el comportamiento posterior: nivel de log, umbral de tiempo, y por extensión qué tan visible es esa capa en producción.
La firma comprimida
Cada registro incluye una firma que identifica el método observado. La firma completa de un método en este proyecto puede ocupar una línea entera de log por sí sola. El aspecto la comprime preservando solo la inicial de cada segmento del paquete excepto el último:
private String compressPackage(String packageName) {
if (packageName == null || packageName.isBlank()) return "";
String[] segments = packageName.split("\\.");
if (segments.length == 1) return packageName;
StringBuilder sb = new StringBuilder();
for (int i = 0; i < segments.length - 1; i++) {
sb.append(segments[i].charAt(0)).append('.');
}
sb.append(segments[segments.length - 1]);
return sb.toString();
}
El resultado para com.app_247.blog.id202603212000art.infrastructure.drivenadapters.jpa.usuario.adapter es c.a.b.i.i.d.j.u.adapter. El último segmento se preserva completo porque es el que aporta contexto: adapter, usecase, entrypoints. Los segmentos anteriores son el prefijo que cualquier desarrollador del proyecto reconoce por su inicial. La firma completa que aparece en cada registro queda así:
c.a.b.i.i.d.j.u.adapter.UsuarioPersistenciaAdapter#guardar
Legible, compacta, y suficientemente precisa para ubicar el método en el árbol de archivos sin ambigüedad.
Los cuatro tipos de registro
El advice @Around tiene visibilidad completa sobre la invocación: puede ejecutar código antes, durante y en el camino de error. Esa visibilidad se materializa en cuatro tipos de registro con marcadores visuales distintos que permiten identificarlos de un vistazo en la consola:
private static final String INPUT_MARKER = ">>> [INPUT] |";
private static final String OUTPUT_MARKER = "<<< [OUTPUT] |";
private static final String TIMING_MARKER = "*** [TIMING] |";
private static final String ERROR_MARKER = "!!! [ERROR] |";
private static final String PROPAGATED_MARKER = "!!! [ERROR-PROPAGATED] |";
Los marcadores no son decorativos. En una consola con decenas de líneas por segundo, la diferencia visual entre >>>, <<<, *** y !!! permite al ojo localizar inmediatamente qué tipo de evento está leyendo sin procesar el texto completo de cada línea.
INPUT
El registro INPUT captura los argumentos del método en el momento de la invocación. La lógica recorre los parámetros usando reflexión para asociar cada valor con el nombre del parámetro declarado:
private void logInput(
String methodSignature,
MethodSignature signature,
Object[] args,
PatternConfig pattern) {
Parameter[] parameters = signature.getMethod().getParameters();
if (parameters.length == 0) {
logAtLevel(pattern, "{} {} args: (none)", methodSignature, INPUT_MARKER);
return;
}
Map<String, Object> inputMap = new LinkedHashMap<>();
IntStream.range(0, parameters.length)
.forEach(i -> inputMap.put(
parameters[i].getName(),
formatArg(args[i])));
logAtLevel(pattern, "{} {} args: {}", methodSignature, INPUT_MARKER, inputMap);
}
LinkedHashMap preserva el orden de inserción, que coincide con el orden de declaración de los parámetros. El resultado en el log es un mapa legible donde cada clave es el nombre exacto del parámetro y cada valor es la representación JSON del argumento. Para que los nombres de los parámetros estén disponibles en tiempo de ejecución a través de parameter.getName(), el proyecto debe compilarse con la opción -parameters. En Spring Boot esto está habilitado por defecto desde la versión 3.2, así que en este stack no requiere ninguna configuración adicional.
La serialización de cada argumento pasa por formatArg:
private String formatArg(Object arg) {
if (arg == null) return "null";
try {
return objectMapper.writeValueAsString(arg);
} catch (Exception e) {
e.printStackTrace();
return arg.toString();
}
}
Si Jackson no puede serializar el objeto, el método cae de vuelta a toString() como último recurso. Esto evita que un argumento no serializable rompa el flujo de logging y, por extensión, el flujo de negocio. El aspecto es un observador: nunca debe interferir con la ejecución que está observando.
OUTPUT
El registro OUTPUT captura el valor de retorno una vez que el método completa su ejecución normalmente:
private void logOutput(
String methodSignature,
Class<?> returnType,
Object result,
PatternConfig pattern) {
if (void.class.equals(returnType) || Void.class.equals(returnType)) {
logAtLevel(pattern, "{} {} return: void", methodSignature, OUTPUT_MARKER);
return;
}
logAtLevel(pattern, "{} {} return: {}",
methodSignature, OUTPUT_MARKER, formatArg(result));
}
El caso especial es cuando el tipo de retorno es void: no hay nada que serializar, pero sí vale la pena registrar que el método completó su ejecución. Un registro OUTPUT ausente en un flujo donde se esperaba puede ser la primera pista de que algo no terminó correctamente.
TIMING
El registro TIMING es el más rico en información operacional. Se emite siempre, tanto en el flujo normal como en el flujo de error, lo que garantiza que siempre hay una métrica de tiempo disponible independientemente de cómo terminó la ejecución:
private void logTiming(
String methodSignature,
Instant start,
Instant end,
long elapsedMs,
PatternConfig pattern) {
String startStr = formatInstant(start);
String endStr = formatInstant(end);
String elapsedFormatted = formatElapsed(elapsedMs);
if (elapsedMs >= pattern.getWarnThresholdMs()) {
log.warn("{} {} start: {} | end: {} | elapsed: {} ⚠️ superó umbral de {}ms",
methodSignature, TIMING_MARKER,
startStr, endStr,
elapsedFormatted,
pattern.getWarnThresholdMs());
return;
}
logAtLevel(pattern, "{} {} start: {} | end: {} | elapsed: {}",
methodSignature, TIMING_MARKER, startStr, endStr, elapsedFormatted);
}
La lógica del umbral merece atención: si elapsedMs supera warnThresholdMs, el registro se emite en WARN directamente con log.warn(), ignorando el nivel configurado en el patrón. Esto significa que aunque el adapter tenga log-level=DEBUG y en producción sus logs normales sean invisibles, un TIMING que supere el umbral siempre aparece en INFO y superior. La lentitud es siempre visible, independientemente del nivel de verbosidad configurado para esa capa.
El tiempo se formatea de forma legible según su magnitud:
private String formatElapsed(long elapsedMs) {
if (elapsedMs < 1_000) {
return elapsedMs + "ms";
} else if (elapsedMs < 60_000) {
return "%.3fs".formatted(elapsedMs / 1_000.0);
} else {
long minutes = elapsedMs / 60_000;
long seconds = (elapsedMs % 60_000) / 1_000;
long millis = elapsedMs % 1_000;
return "%dm %ds %dms".formatted(minutes, seconds, millis);
}
}
Menos de un segundo se muestra en milisegundos: 120ms. Entre un segundo y un minuto se muestra con tres decimales: 1.234s. Por encima de un minuto se desglosa en componentes: 2m 3s 456ms. Esta progresión hace que el número sea siempre legible en la unidad que le corresponde, sin que el ojo tenga que convertir 120000ms a 2 minutos mentalmente.
Los instantes de inicio y fin se formatean con precisión de milisegundos:
private static final DateTimeFormatter FORMATTER =
DateTimeFormatter.ofPattern("HH:mm:ss.SSS");
private String formatInstant(Instant instant) {
return LocalDateTime
.ofInstant(instant, ZoneId.systemDefault())
.format(FORMATTER);
}
El resultado en el log es start: 15:47:05.750 | end: 15:47:05.870 | elapsed: 120ms. Con esos tres valores en cada registro TIMING es posible reconstruir la línea de tiempo completa de una transacción sin necesidad de ninguna herramienta externa: basta con ordenar los registros por hora de inicio y la secuencia de etapas queda visible.
ERROR y ERROR-PROPAGATED
El manejo de errores es donde el diseño del aspecto muestra su complejidad más interesante. El problema a resolver es este: cuando una excepción sube por el stack, cada capa interceptada la captura en su bloque catch, lo que sin ningún mecanismo de control produciría un registro ERROR en cada capa que la excepción atraviesa. En el flujo del proyecto de ejemplo, una BusinessException lanzada en el UseCase sería logueada como ERROR tanto en el UseCase como en el Controller, duplicando la información y contaminando los dashboards con falsos positivos.
La solución usa dos ThreadLocal que trabajan juntos:
private static final ThreadLocal<Throwable> loggedExceptionHolder = new ThreadLocal<>();
private static final ThreadLocal<Integer> depthHolder =
ThreadLocal.withInitial(() -> 0);
depthHolder cuenta cuántos métodos interceptados están activos simultáneamente en el stack del hilo actual. Se incrementa al entrar a cada método interceptado y se decrementa al salir, tanto en el flujo normal como en el flujo de error. loggedExceptionHolder almacena una referencia a la excepción que ya fue logueada como ERROR origen.
La lógica en el bloque de error funciona así:
} catch (Throwable ex) {
Instant endInstant = Instant.now();
long elapsed = endInstant.toEpochMilli() - startInstant.toEpochMilli();
if (loggedExceptionHolder.get() == null) {
loggedExceptionHolder.set(ex);
logException(methodSignature, ex, elapsed, ERROR_MARKER);
} else {
logException(methodSignature, ex, elapsed, PROPAGATED_MARKER);
}
logTiming(methodSignature, startInstant, endInstant, elapsed, pattern);
int currentDepth = depthHolder.get() - 1;
depthHolder.set(currentDepth);
if (currentDepth == 0) {
loggedExceptionHolder.remove();
depthHolder.remove();
}
throw ex;
}
La primera capa interceptada que captura la excepción encuentra loggedExceptionHolder vacío, la registra con ERROR_MARKER y la almacena en el holder. Cada capa superior que captura la misma excepción encuentra el holder poblado y la registra con PROPAGATED_MARKER en nivel DEBUG. En la consola, el ERROR aparece exactamente una vez, en el punto donde se originó el problema, y las capas superiores emiten un DEBUG discreto que confirma la propagación sin duplicar el ruido.
La limpieza de los ThreadLocal ocurre cuando depthHolder llega a cero, es decir, cuando el método más externo del stack interceptado termina su manejo del error. Este punto de limpieza es crítico: los hilos en un servidor web son reutilizados de un request al siguiente a través de un pool. Si los ThreadLocal no se limpian, el hilo llega al siguiente request con valores residuales del request anterior. El efecto concreto sería que la primera excepción del nuevo request encontraría loggedExceptionHolder ya poblado y se registraría como ERROR-PROPAGATED en lugar de ERROR, perdiendo el origen real del error. Es un bug silencioso que solo aparece bajo carga, cuando los hilos se reutilizan frecuentemente, y que es extremadamente difícil de reproducir en desarrollo.
La razón por la que depthHolder es necesario además de loggedExceptionHolder es precisamente esta: no basta con saber que hay una excepción registrada; hay que saber cuándo es seguro limpiarla. Sin el contador de profundidad, el aspecto no puede distinguir entre el momento en que la excepción está siendo propagada por capas internas, donde el holder debe mantenerse, y el momento en que salió completamente del stack interceptado, donde el holder debe limpiarse.
El método que emite el registro de error diferencia los dos casos:
private void logException(
String methodSignature,
Throwable ex,
long elapsedMs,
String marker) {
if (marker.equals(PROPAGATED_MARKER)) {
log.debug("{} {} exception: {} - {} | elapsed: {}",
methodSignature,
marker,
ex.getClass().getSimpleName(),
ex.getMessage(),
formatElapsed(elapsedMs));
} else {
log.error("{} {} exception: {} - {} | elapsed: {}",
methodSignature,
marker,
ex.getClass().getSimpleName(),
ex.getMessage(),
formatElapsed(elapsedMs));
}
}
El ERROR origen siempre se emite en nivel ERROR, independientemente del nivel configurado en el patrón. La propagación se emite en DEBUG para que en producción con nivel INFO sea completamente invisible. Si se necesita ver la cadena de propagación para diagnosticar un problema, basta con activar DEBUG dinámicamente.
El flujo completo bajo la lupa
Con todos los componentes descritos, vale la pena recorrer la salida de consola real del proyecto para el flujo feliz y para el flujo de error. No como validación de que el código funciona, sino como lectura del sistema contando su propia historia.
Flujo feliz: registro exitoso de un usuario
La solicitud llega al Controller con nombre, email y edad. El aspecto captura la invocación antes de que el método ejecute su primera línea y emite el INPUT con los argumentos serializados:
INFO : c.a.b.i.i.e.a.registrarusuario.RegistrarUsuarioController#registrar
>>> [INPUT] | args: {request={"nombre":"Juan Perez","email":"[email protected]","edad":25}}
El Controller mapea el request a un RegistrarUsuarioIn e invoca el UseCase. El aspecto intercepta esa invocación también y emite el INPUT del UseCase con el comando ya mapeado:
INFO : c.a.b.i.d.u.registrarusuario.RegistrarUsuarioUseCase#ejecutar
>>> [INPUT] | args: {command={"nombre":"Juan Perez","email":"[email protected]","edad":25}}
Dentro del UseCase ocurren las validaciones de dominio: NombreValidator, EdadValidator y EmailDominioValidator se invocan secuencialmente. Son clases planas sin anotaciones de Spring, no son beans, y el aspecto no las ve. Su comportamiento queda implícito en el contexto del UseCase que las llama. Si alguna lanzara una excepción, aparecería en el log del UseCase como un ERROR, no en un log propio del validador.
Superadas las validaciones, el UseCase llama a gateway.existeEmail(). Spring resuelve esa llamada hacia UsuarioPersistenciaAdapter, que sí es un bean y sí está interceptado:
DEBUG : c.a.b.i.i.d.j.u.adapter.UsuarioPersistenciaAdapter#existeEmail
>>> [INPUT] | args: {email="[email protected]"}
DEBUG : c.a.b.i.i.d.j.u.adapter.UsuarioPersistenciaAdapter#existeEmail
<<< [OUTPUT] | return: false
WARN : c.a.b.i.i.d.j.u.adapter.UsuarioPersistenciaAdapter#existeEmail
*** [TIMING] | start: 15:47:05.750 | end: 15:47:05.870 | elapsed: 120ms ⚠️ superó umbral de 100ms
Tres registros para una sola llamada al adapter. El INPUT muestra exactamente qué email se consultó. El OUTPUT confirma que no existe. El TIMING revela que la operación tardó 120ms, superando el umbral de 100ms configurado para esta capa, lo que eleva automáticamente el registro a WARN aunque el nivel configurado para el adapter sea DEBUG. Este WARN es visible en producción con nivel INFO aunque todos los demás registros del adapter sean invisibles. La lentitud siempre se ve.
El UseCase continúa: genera el username, construye el objeto Usuario y llama a gateway.guardar(). El adapter es interceptado de nuevo:
DEBUG : c.a.b.i.i.d.j.u.adapter.UsuarioPersistenciaAdapter#guardar
>>> [INPUT] | args: {usuario={"id":null,"nombre":"Juan Perez","email":"[email protected]","edad":25,"username":"juanperez","fechaRegistro":"2026-05-18T15:47:05.8756894"}}
DEBUG : c.a.b.i.i.d.j.u.adapter.UsuarioPersistenciaAdapter#guardar
<<< [OUTPUT] | return: {"id":1,"nombre":"Juan Perez","email":"[email protected]","edad":25,"username":"juanperez","fechaRegistro":"2026-05-18T15:47:05.8756894"}
DEBUG : c.a.b.i.i.d.j.u.adapter.UsuarioPersistenciaAdapter#guardar
*** [TIMING] | start: 15:47:05.877 | end: 15:47:05.939 | elapsed: 62ms
El INPUT del guardar muestra el objeto completo antes de persistirse, con id en null porque todavía no ha pasado por la base de datos. El OUTPUT muestra el mismo objeto con el id asignado por H2 ya presente. El TIMING marca 62ms, dentro del umbral de 100ms, así que se emite en DEBUG normal.
El UseCase completa su ejecución y retorna el RegistrarUsuarioOut. El aspecto lo captura:
INFO : c.a.b.i.d.u.registrarusuario.RegistrarUsuarioUseCase#ejecutar
<<< [OUTPUT] | return: {"id":1,"nombre":"Juan Perez","email":"[email protected]","username":"juanperez","fechaRegistro":"2026-05-18T15:47:05.8756894"}
INFO : c.a.b.i.d.u.registrarusuario.RegistrarUsuarioUseCase#ejecutar
*** [TIMING] | start: 15:47:05.748 | end: 15:47:05.940 | elapsed: 192ms
El OUTPUT del UseCase no incluye el campo edad porque RegistrarUsuarioOut no lo tiene: ese DTO de salida solo expone lo que el contrato del caso de uso devuelve. El TIMING del UseCase registra 192ms totales de orquestación, que incluyen las validaciones, las dos llamadas al adapter y la construcción de objetos intermedios.
Finalmente el Controller recibe el resultado, lo mapea a RegistrarUsuarioResponse y retorna:
INFO : c.a.b.i.i.e.a.registrarusuario.RegistrarUsuarioController#registrar
<<< [OUTPUT] | return: {"id":1,"nombre":"Juan Perez","email":"[email protected]","username":"juanperez","fechaRegistro":"2026-05-18T15:47:05.8756894","mensaje":"Usuario registrado exitosamente"}
INFO : c.a.b.i.i.e.a.registrarusuario.RegistrarUsuarioController#registrar
*** [TIMING] | start: 15:47:05.747 | end: 15:47:05.944 | elapsed: 197ms
El OUTPUT del Controller incluye el campo mensaje que RegistrarUsuarioResponse agrega al mapear desde el RegistrarUsuarioOut. El TIMING del Controller registra 197ms de extremo a extremo, 5ms más que el UseCase, que es exactamente el overhead del Controller en mappers y serialización de la respuesta HTTP.
Con esos once registros, sin ninguna línea de log escrita en ninguna clase del proyecto, el sistema cuenta su historia completa: qué llegó, por qué capas pasó, cuánto tardó cada una, y qué salió.
Flujo de error: email duplicado
La misma solicitud llega por segunda vez. El Controller y el UseCase emiten sus INPUT normalmente, idénticos a los del flujo feliz. El adapter consulta si el email existe:
DEBUG : c.a.b.i.i.d.j.u.adapter.UsuarioPersistenciaAdapter#existeEmail
>>> [INPUT] | args: {email="[email protected]"}
DEBUG : c.a.b.i.i.d.j.u.adapter.UsuarioPersistenciaAdapter#existeEmail
<<< [OUTPUT] | return: true
DEBUG : c.a.b.i.i.d.j.u.adapter.UsuarioPersistenciaAdapter#existeEmail
*** [TIMING] | start: 15:47:12.883 | end: 15:47:12.887 | elapsed: 4ms
Esta vez el OUTPUT es true. El adapter completó su ejecución normalmente: encontró el email, retornó el resultado, el aspecto registró el TIMING. Hasta aquí no hay ningún error. El error ocurre en el UseCase, que recibe el true y lanza la BusinessException:
ERROR : c.a.b.i.d.u.registrarusuario.RegistrarUsuarioUseCase#ejecutar
!!! [ERROR] | exception: BusinessException - El email ya está registrado | elapsed: 4ms
INFO : c.a.b.i.d.u.registrarusuario.RegistrarUsuarioUseCase#ejecutar
*** [TIMING] | start: 15:47:12.883 | end: 15:47:12.887 | elapsed: 4ms
Dos registros para el camino de error del UseCase. El ERROR captura el tipo de excepción y su mensaje, que en este caso es suficientemente descriptivo para entender qué ocurrió sin necesidad de un stacktrace. El TIMING se emite de todas formas: 4ms desde que entró el comando hasta que la excepción salió del UseCase. Nótese que no hay OUTPUT: el método no completó normalmente, así que el aspecto nunca llega al código que lo emite. La ausencia del OUTPUT es en sí misma información.
La excepción sube al Controller. El aspecto la intercepta, encuentra loggedExceptionHolder ya poblado por el UseCase, y la registra como propagación:
DEBUG : c.a.b.i.i.e.a.registrarusuario.RegistrarUsuarioController#registrar
!!! [ERROR-PROPAGATED] | exception: BusinessException - El email ya está registrado | elapsed: 5ms
INFO : c.a.b.i.i.e.a.registrarusuario.RegistrarUsuarioController#registrar
*** [TIMING] | start: 15:47:12.883 | end: 15:47:12.888 | elapsed: 5ms
El ERROR-PROPAGATED se emite en DEBUG, invisible en producción con nivel INFO. El TIMING del Controller registra 5ms de extremo a extremo, 1ms más que el UseCase, que es el overhead del propio Controller antes de invocar el UseCase.
Desde el Controller la excepción sigue subiendo hasta el GlobalExceptionHandler, que la captura y construye la respuesta de error apropiada. El handler no está interceptado por el aspecto porque no tiene ninguno de los estereotipos del pointcut que coincida con un patrón configurado, así que su ejecución es completamente silenciosa desde el punto de vista del sistema de logs. El cliente recibe un HTTP 409 con el detalle del error.
Lo que este flujo demuestra es la distinción que se anticipó en la primera parte: un ERROR en el log del aspecto no siempre significa un fallo del sistema. Una BusinessException por email duplicado es una condición esperada del negocio. En un dashboard de monitoreo, filtrar por ERROR en los logs del aspecto va a incluir estos casos junto con los errores reales de infraestructura. La forma de separar ambos tipos es observar de dónde viene el ERROR: si viene de un UseCase lanzando una excepción de negocio, es ruido operacional esperado; si viene de un adapter fallando al conectar con la base de datos, es un problema genuino que requiere atención. El campo de la firma en el registro, que incluye la capa y la clase, es la clave para hacer esa distinción.
Producción sin redespliegue
Hay un escenario que todo sistema productivo enfrenta eventualmente: un comportamiento anómalo que no se reproduce en desarrollo y que requiere ver el detalle de las capas internas para diagnosticarse. En el modelo tradicional, la respuesta era subir el nivel de log a DEBUG, redesplegar, reproducir el problema, bajar el nivel, redesplegar de nuevo. En sistemas con tráfico real ese ciclo puede tomar horas y el volumen de logs generado puede saturar la infraestructura de observabilidad.
El diseño de este sistema evita ese ciclo de dos formas complementarias. La primera es estructural: los logs del adapter están en DEBUG por configuración, así que en producción con nivel INFO son completamente invisibles sin ningún costo operativo. No hay nada que desactivar porque nunca estuvieron activos. La segunda es dinámica: Spring Boot Actuator expone un endpoint que permite cambiar el nivel de log de cualquier paquete en tiempo de ejecución sin reiniciar la aplicación.
Para activarlo basta con incluir Actuator en las dependencias y exponer el endpoint de loggers en la configuración:
management.endpoints.web.exposure.include=loggers
management.endpoint.loggers.enabled=true
Con eso disponible, activar DEBUG para el paquete de los adapters en un ambiente productivo es una llamada HTTP:
POST /actuator/loggers/com.app_247.blog.id202603212000art.infrastructure.drivenadapters
Content-Type: application/json
{"configuredLevel": "DEBUG"}
A partir de ese momento, todos los registros del adapter que estaban silenciados aparecen en el log en tiempo real. Cuando el diagnóstico termina, una segunda llamada restaura el nivel a INFO y el silencio vuelve. Sin redespliegue, sin ventana de mantenimiento, sin riesgo de introducir cambios mientras se investiga un problema.
Este mecanismo refleja una filosofía más amplia que vale la pena nombrar explícitamente: el sistema de observabilidad debe poder adaptarse al momento sin modificar el sistema que está observando. La configuración por niveles y los patrones por capa son precisamente el mecanismo que hace eso posible.
Lo que se gana con este diseño
Vale la pena hacer explícito el inventario de lo que este sistema aporta, porque no todo es inmediatamente visible en el código.
La consistencia es quizás el beneficio más silencioso. Cada método interceptado produce exactamente el mismo formato de registro, con los mismos marcadores, la misma estructura de tiempo y la misma firma comprimida. No importa quién escribió la clase ni cuándo: el sistema de logs tiene siempre el mismo aspecto. En un equipo donde varias personas trabajan en paralelo sobre distintas partes del proyecto, esa consistencia es la diferencia entre un log que se puede leer y uno que requiere interpretación caso a caso.
La herencia automática es el segundo beneficio. Cada nueva clase que se añada al proyecto y que cumpla con los patrones configurados, un nuevo UseCase, un nuevo adapter, un nuevo Controller, hereda la observabilidad completa sin que nadie tenga que recordar añadir ninguna instrucción de log. El sistema crece y la observabilidad crece con él.
La separación de responsabilidades es el tercero. La lógica de negocio no sabe que está siendo observada. Los validadores de dominio no importan ninguna librería de logging. El UseCase no tiene ninguna instrucción de log. Si en el futuro el equipo decide cambiar el formato de los registros, añadir un campo nuevo a cada entrada, o integrar el sistema con OpenTelemetry, ese cambio ocurre en un único lugar: MethodLoggingAspect. Ninguna clase de negocio necesita ser modificada.
La granularidad controlable es el cuarto beneficio. El sistema tiene tres niveles de visibilidad configurables de forma independiente: los logs del Controller y el UseCase son INFO y siempre visibles, los logs del adapter son DEBUG y silenciosos en producción, y los WARN de latencia son siempre visibles independientemente del nivel de su capa. Esta estratificación permite operar en producción con un volumen de logs manejable mientras se mantiene la capacidad de activar el detalle completo en segundos cuando se necesita.
Mirando hacia adelante
Lo construido en este artículo es un sistema completo y funcional, pero no es un punto de llegada. Hay líneas naturales de evolución que vale la pena tener en el horizonte.
La más inmediata es el enmascaramiento de datos sensibles, que será el tema de la tercera parte de esta serie. El sistema actual serializa los argumentos y resultados tal como son: un email aparece en el log como texto plano, un número de identificación aparece completo. En muchos contextos eso es inaceptable desde el punto de vista de privacidad y cumplimiento regulatorio. La solución es extender el ObjectMapper que usa el aspecto con un introspector personalizado que lea anotaciones declaradas en el modelo de dominio y aplique estrategias de enmascaramiento antes de escribir el registro. El modelo de dominio declara qué es sensible; el sistema de logs lo respeta automáticamente.
Más allá del enmascaramiento, la integración con OpenTelemetry es otra extensión natural. Los registros estructurados que produce este sistema, con sus marcadores de capa y sus métricas de tiempo, son completamente compatibles con el modelo de spans de OpenTelemetry. Los mismos puntos de interceptación del aspecto que hoy emiten registros de texto podrían emitir spans instrumentados que una plataforma como Jaeger o Zipkin renderiza como árboles de llamadas con tiempos y metadatos. La transición no requeriría cambios en ninguna clase de negocio: solo en el aspecto.
La generación de métricas de aplicación a través de Micrometer desde los mismos puntos de intercepción es otra línea de evolución que elimina la duplicación entre el sistema de logs y el sistema de métricas. Hoy, para saber la latencia promedio de un adapter externo se necesita parsear los registros TIMING. Con Micrometer integrado en el aspecto, ese mismo dato podría alimentar un contador o un histograma directamente, sin pasar por texto. Una única fuente de verdad para logs y métricas, gestionada desde el mismo componente transversal.
Lo que todo esto ilustra, más allá de los detalles técnicos, es que un sistema de observabilidad diseñado con los mismos principios que se aplican a la lógica de negocio, separación de responsabilidades, consistencia, configurabilidad, no es una carga que el equipo arrastra sino una ventaja que el equipo usa. El código del proyecto queda limpio, la observabilidad queda centralizada, y la capacidad de entender qué está pasando en producción en cualquier momento queda disponible sin adivinar y sin redesplegar.
Anexo: Código fuente completo
Las clases que siguen son exactamente las que forman el sistema de logs. Todo lo demás, los validadores, los mappers, las entidades JPA, el handler de excepciones, es lógica del proyecto de ejemplo que no tiene ninguna relación con el sistema de observabilidad y que se puede reemplazar por la lógica propia de cualquier proyecto sin afectar el funcionamiento del aspecto.
Estructura de carpetas
src/main/java/com/app_247/blog/id202603212000art/
│
├── Id202603212000artApplication.java ★
│
└── applications/
└── aop/
├── aspect/
│ └── MethodLoggingAspect.java ★
└── config/
├── JacksonConfig.java ★
└── LoggingAopProperties.java ★
src/main/resources/
└── application.properties ★
Cinco artefactos. Tres en el paquete applications/aop, uno en la raíz de la aplicación y uno en recursos. Todo el sistema de observabilidad vive en esas cinco piezas.
Grupo 1 — Propiedades de configuración
LoggingAopProperties.java
package com.app_247.blog.id202603212000art.applications.aop.config;
import java.util.List;
import org.springframework.boot.context.properties.ConfigurationProperties;
import lombok.Data;
@Data
@ConfigurationProperties(prefix = "logging.aop")
public class LoggingAopProperties {
/** Habilita o deshabilita el aspecto completo */
private boolean enabled = true;
/** Paquete raíz de la aplicación, primer filtro antes de evaluar regex */
private String basePackage = "com.app_247.blog.id202603212000art";
/** Lista de patrones de interceptación */
private List<PatternConfig> patterns = List.of();
@Data
public static class PatternConfig {
/** Regex que debe cumplir el paquete completo */
private String packageRegex = ".*";
/** Regex que debe cumplir el nombre simple de la clase */
private String classRegex = ".*";
/** Regex que debe cumplir el nombre del método */
private String methodRegex = ".*";
/** Nivel de log: TRACE, DEBUG, INFO, WARN, ERROR */
private String logLevel = "INFO";
/** Umbral en ms a partir del cual se emite un WARN de tiempo */
private long warnThresholdMs = 500L;
}
}
Grupo 2 — Configuración de Jackson
JacksonConfig.java
package com.app_247.blog.id202603212000art.applications.aop.config;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import com.fasterxml.jackson.databind.ObjectMapper;
import com.fasterxml.jackson.databind.SerializationFeature;
import com.fasterxml.jackson.datatype.jsr310.JavaTimeModule;
@Configuration
public class JacksonConfig {
@Bean
public ObjectMapper objectMapper() {
ObjectMapper mapper = new ObjectMapper();
mapper.registerModule(new JavaTimeModule());
mapper.disable(SerializationFeature.WRITE_DATES_AS_TIMESTAMPS);
return mapper;
}
}
Grupo 3 — El aspecto
MethodLoggingAspect.java
package com.app_247.blog.id202603212000art.applications.aop.aspect;
import java.lang.reflect.Method;
import java.lang.reflect.Parameter;
import java.time.Instant;
import java.time.LocalDateTime;
import java.time.ZoneId;
import java.time.format.DateTimeFormatter;
import java.util.LinkedHashMap;
import java.util.Map;
import java.util.Optional;
import java.util.concurrent.ConcurrentHashMap;
import java.util.stream.IntStream;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.reflect.MethodSignature;
import org.springframework.boot.autoconfigure.condition.ConditionalOnProperty;
import org.springframework.stereotype.Component;
import com.app_247.blog.id202603212000art.applications.aop.config.LoggingAopProperties;
import com.app_247.blog.id202603212000art.applications.aop.config.LoggingAopProperties.PatternConfig;
import com.fasterxml.jackson.databind.ObjectMapper;
import lombok.RequiredArgsConstructor;
import lombok.extern.slf4j.Slf4j;
@Slf4j
@Aspect
@Component
@RequiredArgsConstructor
@ConditionalOnProperty(prefix = "logging.aop", name = "enabled", havingValue = "true", matchIfMissing = true)
public class MethodLoggingAspect {
private final ObjectMapper objectMapper;
private final LoggingAopProperties properties;
// -------------------------------------------------------------------------
// Marcadores visuales
// -------------------------------------------------------------------------
private static final String INPUT_MARKER = ">>> [INPUT] |";
private static final String OUTPUT_MARKER = "<<< [OUTPUT] |";
private static final String TIMING_MARKER = "*** [TIMING] |";
private static final String ERROR_MARKER = "!!! [ERROR] |";
private static final String PROPAGATED_MARKER = "!!! [ERROR-PROPAGATED] |";
private static final DateTimeFormatter FORMATTER =
DateTimeFormatter.ofPattern("HH:mm:ss.SSS");
// -------------------------------------------------------------------------
// ThreadLocal: registra la excepción que ya fue logueada como ERROR origen
// evita que capas superiores la vuelvan a loguear como ERROR
// -------------------------------------------------------------------------
private static final ThreadLocal<Throwable> loggedExceptionHolder =
new ThreadLocal<>();
// -------------------------------------------------------------------------
// ThreadLocal: contador de profundidad de métodos interceptados activos
// permite saber cuándo estamos en el método más externo del stack
// -------------------------------------------------------------------------
private static final ThreadLocal<Integer> depthHolder =
ThreadLocal.withInitial(() -> 0);
// -------------------------------------------------------------------------
// Cache de matching por firma de método
// Key: "com.app_247...RegistrarUsuarioUseCase#ejecutar"
// Value: PatternConfig que hizo match, o empty si no hubo match
// -------------------------------------------------------------------------
private final ConcurrentHashMap<String, Optional<PatternConfig>> matchCache =
new ConcurrentHashMap<>();
// -------------------------------------------------------------------------
// Pointcut: limitado a beans Spring, excluye el propio paquete aop
// -------------------------------------------------------------------------
@Around("(within(@org.springframework.stereotype.Service *) " +
"|| within(@org.springframework.stereotype.Component *) " +
"|| within(@org.springframework.web.bind.annotation.RestController *)" +
"|| within(@org.springframework.stereotype.Repository *)) " +
"&& !within(com.app_247.blog.id202603212000art.aop..*)")
public Object logMethod(ProceedingJoinPoint joinPoint) throws Throwable {
MethodSignature signature = (MethodSignature) joinPoint.getSignature();
Method method = signature.getMethod();
String packageName = method.getDeclaringClass().getPackageName();
String className = method.getDeclaringClass().getSimpleName();
String methodName = method.getName();
// Filtro rápido por paquete base antes de evaluar regex
if (!packageName.startsWith(properties.getBasePackage())) {
return joinPoint.proceed();
}
// Cache de matching: evita re-evaluar regex en invocaciones repetidas
String cacheKey = packageName + "." + className + "#" + methodName;
Optional<PatternConfig> matchedPattern = matchCache.computeIfAbsent(
cacheKey,
k -> findMatchingPattern(packageName, className, methodName));
if (matchedPattern.isEmpty()) {
return joinPoint.proceed();
}
PatternConfig pattern = matchedPattern.get();
// Firma comprimida:
// c.a.b.i.d.u.registrarusuario.RegistrarUsuarioUseCase#ejecutar
String methodSignature = "%s.%s#%s".formatted(
compressPackage(packageName),
className,
methodName);
// Incrementar profundidad al entrar en un método interceptado
depthHolder.set(depthHolder.get() + 1);
logInput(methodSignature, signature, joinPoint.getArgs(), pattern);
Instant startInstant = Instant.now();
Object result;
try {
result = joinPoint.proceed();
} catch (Throwable ex) {
Instant endInstant = Instant.now();
long elapsed = endInstant.toEpochMilli() - startInstant.toEpochMilli();
if (loggedExceptionHolder.get() == null) {
// Primera captura → origen del error
loggedExceptionHolder.set(ex);
logException(methodSignature, ex, elapsed, ERROR_MARKER);
} else {
// Ya fue logueada más abajo → propagación
logException(methodSignature, ex, elapsed, PROPAGATED_MARKER);
}
logTiming(methodSignature, startInstant, endInstant, elapsed, pattern);
// Decrementar profundidad al salir con excepción
int currentDepth = depthHolder.get() - 1;
depthHolder.set(currentDepth);
// Limpiar ThreadLocals solo cuando salimos del método más externo
if (currentDepth == 0) {
loggedExceptionHolder.remove();
depthHolder.remove();
}
throw ex;
}
Instant endInstant = Instant.now();
long elapsed = endInstant.toEpochMilli() - startInstant.toEpochMilli();
// Decrementar profundidad al salir en flujo normal
depthHolder.set(depthHolder.get() - 1);
logOutput(methodSignature, method.getReturnType(), result, pattern);
logTiming(methodSignature, startInstant, endInstant, elapsed, pattern);
return result;
}
// -------------------------------------------------------------------------
// Compresión de paquete
// com.app_247.blog.id202603212000art.domain.usecase.registrarusuario
// → c.a.b.i.d.u.registrarusuario
// -------------------------------------------------------------------------
private String compressPackage(String packageName) {
if (packageName == null || packageName.isBlank()) return "";
String[] segments = packageName.split("\\.");
if (segments.length == 1) return packageName;
StringBuilder sb = new StringBuilder();
for (int i = 0; i < segments.length - 1; i++) {
sb.append(segments[i].charAt(0)).append('.');
}
sb.append(segments[segments.length - 1]);
return sb.toString();
}
// -------------------------------------------------------------------------
// Busca el primer patrón configurado que haga match con el método
// -------------------------------------------------------------------------
private Optional<PatternConfig> findMatchingPattern(
String packageName,
String className,
String methodName) {
return properties.getPatterns()
.stream()
.filter(pattern -> packageName.matches(pattern.getPackageRegex())
&& className.matches(pattern.getClassRegex())
&& methodName.matches(pattern.getMethodRegex()))
.findFirst();
}
// -------------------------------------------------------------------------
// Log INPUT
// -------------------------------------------------------------------------
private void logInput(
String methodSignature,
MethodSignature signature,
Object[] args,
PatternConfig pattern) {
Parameter[] parameters = signature.getMethod().getParameters();
if (parameters.length == 0) {
logAtLevel(pattern, "{} {} args: (none)", methodSignature, INPUT_MARKER);
return;
}
Map<String, Object> inputMap = new LinkedHashMap<>();
IntStream.range(0, parameters.length)
.forEach(i -> inputMap.put(
parameters[i].getName(),
formatArg(args[i])));
logAtLevel(pattern, "{} {} args: {}", methodSignature, INPUT_MARKER, inputMap);
}
// -------------------------------------------------------------------------
// Log OUTPUT
// -------------------------------------------------------------------------
private void logOutput(
String methodSignature,
Class<?> returnType,
Object result,
PatternConfig pattern) {
if (void.class.equals(returnType) || Void.class.equals(returnType)) {
logAtLevel(pattern, "{} {} return: void", methodSignature, OUTPUT_MARKER);
return;
}
logAtLevel(pattern, "{} {} return: {}",
methodSignature, OUTPUT_MARKER, formatArg(result));
}
// -------------------------------------------------------------------------
// Log TIMING
// -------------------------------------------------------------------------
private void logTiming(
String methodSignature,
Instant start,
Instant end,
long elapsedMs,
PatternConfig pattern) {
String startStr = formatInstant(start);
String endStr = formatInstant(end);
String elapsedFormatted = formatElapsed(elapsedMs);
if (elapsedMs >= pattern.getWarnThresholdMs()) {
log.warn("{} {} start: {} | end: {} | elapsed: {} ⚠️ superó umbral de {}ms",
methodSignature, TIMING_MARKER,
startStr, endStr,
elapsedFormatted,
pattern.getWarnThresholdMs());
return;
}
logAtLevel(pattern, "{} {} start: {} | end: {} | elapsed: {}",
methodSignature, TIMING_MARKER, startStr, endStr, elapsedFormatted);
}
// -------------------------------------------------------------------------
// Log ERROR / PROPAGATED
// El marcador se recibe como parámetro para distinguir origen de propagación
// Siempre se emite en ERROR independiente del nivel configurado en el patrón
// -------------------------------------------------------------------------
private void logException(
String methodSignature,
Throwable ex,
long elapsedMs,
String marker) {
if (marker.equals(PROPAGATED_MARKER)) {
// Solo informativo — el error real ya fue logueado en el origen
log.debug("{} {} exception: {} - {} | elapsed: {}",
methodSignature,
marker,
ex.getClass().getSimpleName(),
ex.getMessage(),
formatElapsed(elapsedMs));
} else {
// Origen del error — siempre visible
log.error("{} {} exception: {} - {} | elapsed: {}",
methodSignature,
marker,
ex.getClass().getSimpleName(),
ex.getMessage(),
formatElapsed(elapsedMs));
}
}
// -------------------------------------------------------------------------
// Emisión de log según nivel configurado en el patrón
// -------------------------------------------------------------------------
private void logAtLevel(PatternConfig pattern, String message, Object... args) {
switch (pattern.getLogLevel().toUpperCase()) {
case "TRACE" -> log.trace(message, args);
case "DEBUG" -> log.debug(message, args);
case "WARN" -> log.warn(message, args);
case "ERROR" -> log.error(message, args);
default -> log.info(message, args);
}
}
// -------------------------------------------------------------------------
// Helpers
// -------------------------------------------------------------------------
private String formatInstant(Instant instant) {
return LocalDateTime
.ofInstant(instant, ZoneId.systemDefault())
.format(FORMATTER);
}
private String formatElapsed(long elapsedMs) {
if (elapsedMs < 1_000) {
return elapsedMs + "ms";
} else if (elapsedMs < 60_000) {
return "%.3fs".formatted(elapsedMs / 1_000.0);
} else {
long minutes = elapsedMs / 60_000;
long seconds = (elapsedMs % 60_000) / 1_000;
long millis = elapsedMs % 1_000;
return "%dm %ds %dms".formatted(minutes, seconds, millis);
}
}
private String formatArg(Object arg) {
if (arg == null) return "null";
try {
return objectMapper.writeValueAsString(arg);
} catch (Exception e) {
e.printStackTrace();
return arg.toString();
}
}
}
Grupo 4 — Bootstrap
Id202603212000artApplication.java
package com.app_247.blog.id202603212000art;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.boot.context.properties.EnableConfigurationProperties;
import com.app_247.blog.id202603212000art.applications.aop.config.LoggingAopProperties;
@SpringBootApplication
@EnableConfigurationProperties(LoggingAopProperties.class)
public class Id202603212000artApplication {
public static void main(String[] args) {
SpringApplication.run(Id202603212000artApplication.class, args);
}
}
Grupo 5 — Configuración de la aplicación
application.properties
spring.application.name=id202603212000art
# ================================
# SERVER
# ================================
server.port=8080
# ================================
# H2 DATABASE
# ================================
spring.datasource.url=jdbc:h2:mem:usuariosdb;DB_CLOSE_DELAY=-1;DB_CLOSE_ON_EXIT=FALSE
spring.datasource.driver-class-name=org.h2.Driver
spring.datasource.username=sa
spring.datasource.password=
# H2 Console (http://localhost:8080/h2-console)
spring.h2.console.enabled=true
spring.h2.console.path=/h2-console
# ================================
# JPA / HIBERNATE
# ================================
spring.jpa.database-platform=org.hibernate.dialect.H2Dialect
spring.jpa.hibernate.ddl-auto=create-drop
# ================================
# JACKSON
# ================================
spring.jackson.serialization.write-dates-as-timestamps=false
spring.jackson.time-zone=America/Bogota
# ================================
# AOP LOGGING
# ================================
logging.aop.enabled=true
logging.aop.base-package=com.app_247.blog.id202603212000art
# UseCase
logging.aop.patterns[0].package-regex=com\\.app_247\\.blog\\.id202603212000art\\.domain\\.usecase.*
logging.aop.patterns[0].class-regex=.*UseCase
logging.aop.patterns[0].method-regex=.*
logging.aop.patterns[0].log-level=INFO
logging.aop.patterns[0].warn-threshold-ms=300
# Adapter de persistencia
logging.aop.patterns[1].package-regex=com\\.app_247\\.blog\\.id202603212000art\\.infrastructure\\.drivenadapters.*
logging.aop.patterns[1].class-regex=.*Adapter
logging.aop.patterns[1].method-regex=.*
logging.aop.patterns[1].log-level=DEBUG
logging.aop.patterns[1].warn-threshold-ms=100
# Controller
logging.aop.patterns[2].package-regex=com\\.app_247\\.blog\\.id202603212000art\\.infrastructure\\.entrypoints.*
logging.aop.patterns[2].class-regex=.*Controller
logging.aop.patterns[2].method-regex=.*
logging.aop.patterns[2].log-level=INFO
logging.aop.patterns[2].warn-threshold-ms=500
Con esas cinco piezas el sistema está completo. LoggingAopProperties define las reglas, JacksonConfig provee el serializador, MethodLoggingAspect aplica la observabilidad, Id202603212000artApplication registra las propiedades en el contenedor, y application.properties conecta la configuración con el comportamiento deseado para cada capa. Cualquier proyecto que adopte estas cinco piezas y ajuste los patrones a su propia estructura de paquetes tiene el sistema funcionando desde el primer arranque, sin ninguna modificación en las clases de negocio.
Observabilidad sin Ruido: Diseñando un Sistema de Logs con AOP en Arquitecturas DDD
- Mauricio ECR
- Arquitectura
- 01 Mar, 2026
Hay una tensión que todo equipo de desarrollo enfrenta tarde o temprano: la necesidad de saber qué está pasando dentro del sistema sin que esa necesidad contamine el código que lo hace funcionar. Los
Observabilidad sin Ruido: Diseñando un Sistema de Logs con AOP en Arquitecturas DDD
- Mauricio ECR
- Arquitectura
- 01 Mar, 2026
Hay una tensión que todo equipo de desarrollo enfrenta tarde o temprano: la necesidad de saber qué está pasando dentro del sistema sin que esa necesidad contamine el código que lo hace funcionar. Los logs son la herramienta más inmediata para satisfacer esa necesidad, pero también son, cuando no se gestionan con criterio, una de las fuentes más frecuentes de deuda técnica, acoplamiento silencioso y dolores de cabeza en producción.
Lo que se propone en este artículo es un modelo de observabilidad para sistemas construidos con Java 21, Spring Boot 3.5.x, Gradle y arquitectura DDD. El objetivo no es solo definir dónde va cada logger.info(), sino construir un esquema en el que la observabilidad sea una preocupación transversal completamente separada de la lógica de negocio, implementada mediante Programación Orientada a Aspectos (AOP) y sostenida por convenciones que cualquier miembro del equipo pueda seguir sin ambigüedad.
El problema que queremos resolver
Antes de hablar de la solución vale la pena entender con precisión el problema. En la mayoría de los proyectos, los logs nacen de forma orgánica: el desarrollador que escribe un caso de uso añade un par de líneas de debug para entender qué está pasando durante el desarrollo, y esas líneas se quedan ahí. Llega otro desarrollador, añade las suyas, y así sucesivamente. El resultado, algunos meses después, es un codebase donde la lógica de negocio está entrelazada con instrucciones de log que nadie revisa, que no siguen ningún formato consistente, que en algunos métodos son excesivas y en otros brillan por su ausencia, y que en más de una ocasión exponen datos sensibles de los usuarios en texto plano.
El problema no es que los desarrolladores sean descuidados. El problema es estructural: cuando la responsabilidad de loguear está distribuida en cada clase del sistema, es inevitable que el resultado sea inconsistente. La única forma de garantizar consistencia es centralizar esa responsabilidad en un mecanismo que opere de forma transversal, sin depender de que cada desarrollador recuerde seguir una convención.
Eso es, en esencia, lo que ofrece la Programación Orientada a Aspectos.
AOP: observar sin intervenir
La idea central de AOP es simple aunque su implementación puede ser sofisticada: existen preocupaciones en un sistema, como la seguridad, las transacciones o el logging, que no pertenecen a ningún módulo en particular pero que afectan a todos. En lugar de dispersar el código que gestiona esas preocupaciones por todo el sistema, AOP permite encapsularlo en un componente separado llamado aspecto, que el framework inyecta de forma transparente en los puntos de ejecución que se le indiquen.
En el contexto de Spring, esto funciona a través de proxies. Cuando el contenedor de inversión de control crea un bean, puede envolverlo en un proxy que intercepta las llamadas a sus métodos. Ese proxy ejecuta el aspecto antes, después o alrededor de la llamada real. El método original no sabe que está siendo observado; simplemente hace su trabajo.
Para que este mecanismo funcione hay una condición que no siempre es obvia: los objetos deben ser beans de Spring. Si una clase no está gestionada por el contenedor, Spring no puede envolverla en un proxy y el aspecto no puede interceptarla. Este detalle tiene una implicación directa en cómo se diseña la observabilidad en una arquitectura DDD, y es precisamente el punto de partida para resolver uno de los dilemas más frecuentes en este tipo de proyectos.
La capa de dominio y el dilema del logging
En una arquitectura DDD estricta, la capa de dominio es la más interna y la más pura. No debe tener dependencias de infraestructura, no debe saber si está siendo ejecutada en una API REST o en un job batch, y definitivamente no debería importar librerías de logging. Esta pureza es lo que la hace testeable, portable y mantenible.
Pero esa misma pureza genera una pregunta legítima: ¿qué pasa con los servicios de dominio? Un servicio que valida si un cliente tiene crédito suficiente, que aplica reglas de descuento, que verifica el stock disponible, ¿no merece ser observado? Si algo falla en esa lógica, ¿cómo sabremos qué ocurrió?
La respuesta convencional suele ser una de dos: o se acepta contaminar el dominio con un logger, o se ignora completamente ese nivel de detalle y se espera que las excepciones cuenten la historia. Ninguna de las dos opciones es satisfactoria.
La salida está en un detalle de implementación que a veces pasa desapercibido: cuando los servicios de dominio y los casos de uso se registran como beans en el contenedor de Spring a través de la capa de aplicación, aunque el dominio no sabe nada de Spring, el contenedor sí los gestiona. Y si el contenedor los gestiona, AOP puede interceptarlos. El dominio sigue siendo puro porque no tiene ninguna dependencia en infraestructura. El aspecto lo observa desde afuera, a través del proxy, sin que el servicio de dominio sea consciente de ello.
Este es uno de esos casos donde las restricciones de una arquitectura, entendidas a fondo, abren posibilidades que no eran evidentes a primera vista.
Una sola responsabilidad por capa
Con ese fundamento claro, los puntos de observabilidad se organizan siguiendo la misma lógica que organiza la arquitectura: cada capa tiene su propio contrato de logging.
Los entry points, que son los controladores REST o cualquier otro mecanismo de entrada al sistema, son el primer y último punto que el aspecto intercepta en el flujo de una solicitud. Aquí se registra el request entrante con los datos de entrada saneados y, cuando el flujo termina, el response saliente con el tiempo total que tomó la operación. Es la vista más amplia del sistema: saber qué llegó y qué salió.
Los casos de uso aportan el siguiente nivel de granularidad. El aspecto registra el inicio y el fin de la orquestación, con el DTO de entrada ya mapeado y el resultado antes de que sea transformado para la respuesta. Esto permite correlacionar exactamente qué datos entran al corazón del sistema y qué produce como resultado.
Los servicios de dominio representan el nivel más detallado. Aquí el aspecto registra el resultado de cada validación, cada regla de negocio, cada decisión que toma el dominio. Este nivel de detalle, sin embargo, no necesita estar activo permanentemente en producción. Se emite en nivel DEBUG, lo que significa que en un ambiente productivo es invisible pero puede activarse dinámicamente en cuestión de segundos si se necesita diagnosticar un problema sin reiniciar la aplicación.
Finalmente, los driven adapters, que son las implementaciones de los puertos hacia el mundo exterior, tienen un requerimiento adicional que los diferencia de todas las demás capas: la latencia. No basta con saber que se hizo una llamada a un servicio externo o que se ejecutó una consulta a la base de datos; hay que saber cuánto tardó. Esa información es la que permite distinguir entre un problema de lógica interna y un problema de dependencia externa, una diferencia que en producción puede significar horas de diagnóstico incorrecto.
El tiempo como dato de primera clase
Medir el tiempo solo en las llamadas externas es un primer paso, pero insuficiente. Para entender verdaderamente el comportamiento de un sistema bajo carga es necesario conocer cuánto tarda cada etapa del flujo. Un total de 800 milisegundos en una solicitud puede ser perfectamente aceptable o completamente inaceptable dependiendo de dónde se origina ese tiempo.
Por eso cada punto de observabilidad debe registrar dos métricas de tiempo: durationMs, que mide cuánto tardó esa etapa específica, y elapsedMs, que mide el tiempo acumulado desde que llegó la solicitud hasta ese punto. Con ambas métricas en cada registro, reconstruir la línea de tiempo de una transacción en una herramienta de observabilidad es trivial.
A esto se suma un campo stage en cada registro, que identifica la capa que lo generó: ENTRY_POINT, USE_CASE, DOMAIN_SERVICE, EXTERNAL_CALL o REPOSITORY. Este campo convierte los logs de texto plano en datos estructurados sobre los que se pueden construir dashboards, alertas y análisis de performance sin necesidad de parsear mensajes de texto.
El valor de este diseño se hace evidente con un ejemplo concreto. Imaginemos una solicitud de creación de orden de compra que tarda 800 milisegundos en total. Sin el campo stage y sin durationMs por etapa, la única conclusión disponible es que la solicitud fue lenta. Con esos campos, el análisis revela en segundos que 600 de esos 800 milisegundos los consumió la API externa de cobertura logística, mientras que la lógica de dominio tomó menos de 15 milisegundos. La optimización correcta es evidente: no hay que tocar el dominio, hay que atacar la dependencia externa.
Privacidad por diseño, no por convención
Uno de los aspectos más delicados del logging es la privacidad. Cada vez que un sistema registra información existe el riesgo de que datos sensibles terminen en un archivo de log, en una herramienta de indexación o en el radar de una auditoría de seguridad. La respuesta habitual a este riesgo es la convención: "no logueen datos personales". El problema con las convenciones es que dependen de que cada desarrollador las recuerde y las aplique correctamente en cada caso.
Un enfoque más robusto es que la privacidad se declare en el modelo de datos, no en el código que loguea.
Para materializar esto se definen dos anotaciones que se aplican directamente sobre los campos del modelo de dominio. La primera, @NoLog, indica que un campo nunca debe aparecer en ningún log bajo ninguna circunstancia: omisión total. Se usa para campos como imágenes en Base64, documentos adjuntos, o cualquier objeto cuyo tamaño o naturaleza lo hace inadecuado para un registro. La segunda, @Confidential, indica que el campo contiene datos personales y que su valor debe enmascararse antes de escribirse. El aspecto aplica una función de máscara según el tipo configurado: una dirección de correo como [email protected] se convierte en j***@mail.com, un número de identificación se convierte en ***, un teléfono muestra solo los últimos cuatro dígitos.
Lo elegante de este diseño es que las reglas de privacidad viven donde tienen sentido: en el modelo de dominio, junto a la definición del dato. Cuando un desarrollador crea un campo en un modelo y lo anota con @Confidential, esa anotación se respeta automáticamente en todos los logs del sistema, sin necesidad de recordar actualizar ningún otro componente. La privacidad deja de ser una convención y se convierte en una propiedad del dato.
Más allá de las anotaciones, hay categorías de información que nunca deben aparecer en logs independientemente de si están anotadas: credenciales, tokens de autenticación, datos completos de tarjetas de crédito, cookies de sesión, datos biométricos. La regla práctica que sintetiza todos estos casos es directa: si el dato permite suplantar la identidad de un usuario o acceder a un sistema, no va en el log.
Trazabilidad: el hilo que conecta todo
Un log aislado tiene valor limitado. El valor real emerge cuando se pueden correlacionar todos los eventos de una transacción, desde que llega la solicitud hasta que sale la respuesta, incluyendo cada llamada externa y cada decisión de dominio que ocurrió en el camino.
El mecanismo que hace posible esta correlación es el message-id, un identificador único que se asigna a cada solicitud en el momento en que entra al sistema. Si el cliente lo envía en el header X-Message-Id, se reutiliza; si no viene, el sistema genera uno automáticamente. Este identificador se almacena en el MDC de SLF4J, que es un mapa de contexto asociado al hilo de ejecución. Todos los logs emitidos durante esa solicitud lo incluyen automáticamente.
El resultado es que en cualquier herramienta de observabilidad, filtrar por message-id produce exactamente la secuencia completa de eventos de una transacción, ordenada por tiempo, con cada etapa identificada por su stage y con sus métricas de duración. Lo que antes requería correlacionar manualmente decenas de líneas de log dispersas ahora es una consulta de una sola condición.
Este mecanismo presenta un desafío particular en operaciones asíncronas. Cuando Spring lanza un hilo para ejecutar una tarea marcada con @Async, ese hilo nuevo no hereda el MDC del hilo padre. El message-id y el tiempo de inicio de la solicitud se pierden, y los logs del hilo asíncrono quedan huérfanos sin correlación. La solución es un decorador de tareas que captura el MDC completo del hilo padre en el momento en que se lanza la tarea y lo restaura en el hilo hijo antes de ejecutarla. Este decorador se configura una sola vez en el executor del pool de hilos y aplica a todas las operaciones asíncronas del sistema sin ningún esfuerzo adicional por parte del desarrollador.
El mismo principio se extiende a arquitecturas de microservicios. Cuando el sistema hace una llamada HTTP a otro servicio, el message-id debe viajar en el header de la petición saliente. El microservicio receptor lo extrae, lo almacena en su propio MDC, y todos sus logs quedan correlacionados con la misma transacción origen. Esto se configura una sola vez en el cliente HTTP como un interceptor, y a partir de ahí todas las llamadas salientes propagan el identificador automáticamente. En una plataforma de observabilidad centralizada, una sola búsqueda por message-id puede reconstruir el árbol completo de llamadas entre servicios.
El flujo completo bajo la lupa
Para ilustrar cómo se manifiesta todo esto en la práctica, vale la pena recorrer un flujo real. Tomemos la creación de una orden de compra como caso de uso: el cliente envía los datos de la orden con sus productos, dirección de entrega e información personal; el sistema valida que el cliente esté activo, verifica el stock, homologa los códigos externos de los productos a los códigos internos del catálogo, consulta una API externa para validar la cobertura logística en la dirección indicada, persiste la orden en base de datos y devuelve el número de orden generado.
Sin escribir una sola línea de log en ninguno de esos componentes, el aspecto genera automáticamente doce registros a lo largo del flujo. El primero captura el request entrante con los datos saneados: el correo del cliente enmascarado, el número de identificación reemplazado por asteriscos, los documentos adjuntos simplemente omitidos. El segundo marca el inicio del caso de uso. Los registros tres, cuatro y cinco corresponden a los servicios de dominio: la validación del cliente, la validación de stock y la homologación de productos; estos se emiten en DEBUG y son invisibles en producción a menos que se activen dinámicamente. Los registros siete y ocho capturan la llamada a la API de cobertura logística con su latencia exacta. Los registros nueve y diez hacen lo mismo con la operación de base de datos. El registro once cierra el caso de uso con el tiempo total de orquestación. El doce emite el response saliente con el tiempo total de la solicitud de punta a punta.
El análisis de esos doce registros revela de inmediato la distribución del tiempo: cuatro milisegundos de overhead en los mappers de entrada, diez milisegundos en validaciones de dominio, doscientos diez milisegundos en la API de cobertura logística, cuarenta y cinco milisegundos en base de datos. Sin ningún profiler, sin instrumentación adicional, el sistema cuenta su propia historia con precisión quirúrgica.
El mismo flujo en un escenario de error muestra otra dimensión del diseño. Si el stock es insuficiente, el servicio de dominio lanza una excepción de negocio controlada. El aspecto la captura a nivel DEBUG en el servicio de dominio y la deja subir. El @ControllerAdvice la intercepta y emite un registro en nivel WARN, no ERROR, porque una validación fallida es una condición esperada del negocio, no un fallo del sistema. Sin stacktrace completo, solo el mensaje de negocio y el message-id. En cambio, si la API externa de cobertura logística devuelve un timeout, el adapter emite un registro en nivel ERROR con stacktrace completo y la latencia exacta que revela los cinco segundos de espera antes del fallo.
Esta distinción entre WARN y ERROR no es cosmética. En los dashboards de monitoreo permite separar el ruido normal del negocio de los fallos reales que requieren atención inmediata. Un equipo de operaciones que recibe alertas solo para registros ERROR puede confiar en que cada alerta representa un problema genuino del sistema, no una validación fallida que el usuario debe corregir.
Producción sin sorpresas
Hay un escenario que todo sistema productivo enfrenta eventualmente: un comportamiento anómalo que no se reproduce en desarrollo y que requiere ver el detalle de la lógica interna para diagnosticarse. En el modelo tradicional, la respuesta a este escenario era subir el nivel de log a DEBUG, redesplegar, esperar, bajar el nivel, redesplegar de nuevo. Un proceso lento, arriesgado y que en sistemas con tráfico real puede generar un volumen de logs suficiente para saturar la infraestructura de observabilidad.
Dos mecanismos complementarios evitan ese ciclo. El primero es la jerarquía de niveles ya descrita: los logs de DOMAIN_SERVICE se emiten en DEBUG, así que en producción con nivel INFO son completamente invisibles y no generan ningún costo operativo. El segundo es el cambio dinámico de nivel a través de un endpoint interno que delega en la API de loggers de Spring Boot Actuator. Activar DEBUG para un paquete específico, observar el comportamiento, y volver a INFO es una operación de segundos sin ningún redespliegue.
Este diseño refleja una filosofía más amplia: las herramientas de observabilidad deben poder adaptarse al momento sin modificar el sistema observado.
Lo que también importa, aunque no se vea en el código
Hay una dimensión del logging que no suele documentarse pero que es igualmente crítica: saber qué no loguear. Las anotaciones @NoLog y @Confidential cubren los datos que el modelo declara explícitamente como sensibles, pero hay categorías de información que nunca deben aparecer en logs independientemente de cualquier anotación.
Los tokens de autenticación son el ejemplo más obvio. Un JWT completo, una API key o un refresh token en un log es esencialmente una credencial expuesta que puede ser extraída por cualquiera con acceso a la plataforma de observabilidad, que en muchas organizaciones incluye a un número considerable de personas. Lo mismo aplica para contraseñas, PINs, datos completos de tarjetas de crédito, cookies de sesión y datos biométricos.
La lista no es exhaustiva ni puede serlo, porque los datos sensibles dependen del contexto de cada sistema. Lo que sí puede establecerse como hábito es hacerse la pregunta antes de que un dato llegue a un registro. Y en la duda, la respuesta correcta es siempre la omisión.
De los logs a la inteligencia operacional
Un sistema de logs bien diseñado no es solo un mecanismo de diagnóstico reactivo. Es la materia prima de la inteligencia operacional. Los campos estructurados que este esquema produce, stage, durationMs, elapsedMs, event, adapter, permiten derivar métricas sin instrumentación adicional en el código.
La latencia promedio por adapter externo permite monitorear el SLA de cada dependencia. La tasa de registros con event=BUSINESS_EXCEPTION agrupada por tipo de excepción permite entender qué reglas de negocio fallan con más frecuencia y orientar decisiones de producto. El tiempo total por endpoint permite construir alertas que disparen cuando la latencia supera el percentil 99 histórico. La correlación entre EXTERNAL_CALL_START sin su correspondiente EXTERNAL_CALL_END permite detectar llamadas que nunca respondieron.
Y quizás el beneficio más silencioso de todos: cada nueva funcionalidad que se añada al sistema hereda automáticamente la observabilidad con el mismo nivel de detalle y el mismo formato estructurado, simplemente por seguir la arquitectura. No hay nada que recordar, nada que configurar, nada que pueda olvidarse.
Mirando hacia adelante
Lo descrito en este artículo establece una base sólida, pero no es un punto de llegada. Hay líneas de evolución naturales que vale la pena tener en el horizonte.
La integración con sistemas de tracing distribuido como OpenTelemetry lleva la correlación entre microservicios un paso más allá, al construir árboles de spans que representan visualmente la jerarquía de llamadas, con tiempos y metadatos, en una interfaz diseñada específicamente para ese propósito. Los logs estructurados que produce este esquema son compatibles con ese modelo y pueden complementarlo sin contradicción.
La generación automática de métricas de aplicación a través de Micrometer desde los mismos puntos de intercepción del AOP es otra extensión natural, ya que evita la duplicación entre el sistema de logs y el sistema de métricas, manteniendo una única fuente de verdad para ambos tipos de datos.
El mismo patrón de aspectos transversales también puede extenderse a otros dominios de preocupación: auditoría de cambios de estado, registro de accesos a datos sensibles para cumplimiento regulatorio, o validación automática de contratos entre capas.
Lo que todo esto ilustra, más allá de los detalles técnicos, es que la observabilidad no tiene por qué ser un ciudadano de segunda clase en la arquitectura de un sistema. Cuando se diseña con la misma intención que se diseña la lógica de negocio, cuando se le aplican los mismos principios de separación de responsabilidades y consistencia, se convierte en una ventaja operacional genuina: el equipo gana la capacidad de entender qué está pasando en producción en cualquier momento, con el nivel de detalle que necesita, sin adivinar y sin contaminar el código que hace que el sistema funcione.
La implementación concreta de este diseño, con el código de cada artefacto, los aspectos completos, el sanitizador de datos y el ejemplo funcional del flujo de orden de compra, se documenta en detalle en la segunda parte de este artículo.