Esta skill proporciona las mejores prcticas para implementar logging efectivo mediante Wide Events (eventos amplios) y Canonical Log Lines. El objetivo es transformar el debugging de arqueologa a analytics, permitiendo observabilidad real en aplicaciones distribuidas modernas.
Los logs tradicionales estn diseados para una era de monolitos y servidores nicos. En sistemas modernos, una sola request puede tocar 15 servicios, 3 bases de datos, 2 caches y una cola de mensajes. Los logs tradicionales fallan porque:
- Emiten mltiples lneas por request (17+ lneas para una sola request exitosa)
- Carecen de contexto de negocio
- Usan formatos inconsistentes para el mismo dato (user-123, user_id=user-123, {"userId": "user-123"})
- Estn optimizados para escribir, no para consultar
- No permiten correlacionar eventos entre servicios
Logs emitidos como pares clave-valor (generalmente JSON) en lugar de strings planos.
// Mal
"Payment failed for user 123"
// Bien
{"event": "payment_failed", "user_id": "123"}
Nmero de valores nicos que puede tener un campo. Los campos de alta cardinalidad son los ms valiosos para debugging.
- Alta cardinalidad:
user_id,request_id,trace_id(millones de valores nicos) - Baja cardinalidad:
http_method,environment,status_code(pocos valores nicos)
Nmero de campos en un evento de log. Ms dimensiones significa ms preguntas que puedes responder sobre tus datos.
Un nico evento rico en contexto emitido por request por servicio. En lugar de 13 lneas de log para una request, emites 1 lnea con 50+ campos conteniendo todo lo necesario para debugging.
Sinnimo de wide event, popularizado por Stripe. Una lnea de log por request que sirve como registro autoritativo de lo que ocurri.
Cambio de mentalidad crtico: En lugar de loggear lo que tu cdigo est haciendo, loggea lo que ocurri con esta request.
Para cada request, emitir UN wide event por servicio con todo el contexto que pueda ser til para debugging. No solo lo que sali mal, sino la imagen completa de la request.
{
"request_id": "req_8bf7ec2d",
"trace_id": "abc123def456",
"span_id": "span_xyz",
"parent_span_id": "span_parent",
"method": "POST",
"path": "/api/checkout",
"query_params": {},
"status_code": 500,
"duration_ms": 1247,
"timestamp": "2025-01-15T10:23:45.612Z",
"client_ip": "192.168.1.42",
"user_agent": "Mozilla/5.0...",
"content_type": "application/json",
"request_size_bytes": 2400,
"response_size_bytes": 48291
}
```
### User Context
```json
{
"user_id": "user_456",
"session_id": "sess_abc123",
"subscription_tier": "premium",
"account_age_days": 847,
"lifetime_value_cents": 284700,
"organization_id": "org_123",
"team_id": "team_456",
"role": "admin",
"country": "US",
"locale": "en-US",
"timezone": "America/New_York",
"feature_flags": {"new_checkout_flow": true, "express_payment": false},
"ab_test_cohort": "checkout_v2"
}
```
### Business Context
```json
{
"order_id": "order_789",
"cart_id": "cart_xyz",
"cart_total_cents": 15999,
"item_count": 3,
"item_skus": ["SKU-123", "SKU-456"],
"payment_method": "card",
"payment_provider": "stripe",
"payment_intent_id": "pi_abc123",
"coupon_code": "SAVE20",
"discount_cents": 3200,
"shipping_method": "express",
"shipping_cents": 999,
"currency": "USD",
"is_gift": false
}
```
### Infrastructure Context
```json
{
"service_name": "checkout-service",
"service_version": "2.4.1",
"deployment_id": "deploy_789",
"git_sha": "a1b2c3d4",
"region": "us-east-1",
"availability_zone": "us-east-1a",
"host": "checkout-pod-abc123",
"container_id": "container_xyz",
"k8s_namespace": "production",
"k8s_pod": "checkout-7d4f8b9c6-abc12",
"cloud_provider": "aws",
"environment": "production"
}
```
### Error Context
```json
{
"error_type": "PaymentError",
"error_code": "card_declined",
"error_message": "Card declined by issuer",
"error_retriable": false,
"error_stack": "Error: Card declined...",
"stripe_decline_code": "insufficient_funds",
"retry_count": 3,
"last_retry_at": "2025-01-15T10:23:44.000Z",
"upstream_service": "stripe-api",
"upstream_latency_ms": 1089
}
```
### Performance Context
```json
{
"db_query_count": 3,
"db_query_time_ms": 145,
"cache_hits": 2,
"cache_misses": 1,
"external_call_count": 2,
"external_call_time_ms": 1089,
"memory_used_mb": 256,
"cpu_time_ms": 45
}
```
## Implementacin
### Middleware para Wide Events
```typescript
// middleware/wideEvent.ts
export function wideEventMiddleware() {
return async (ctx, next) => {
const startTime = Date.now();
// Inicializar el wide event con contexto de request
const event: Record<string, unknown> = {
request_id: ctx.get('requestId'),
timestamp: new Date().toISOString(),
method: ctx.req.method,
path: ctx.req.path,
service: process.env.SERVICE_NAME,
version: process.env.SERVICE_VERSION,
deployment_id: process.env.DEPLOYMENT_ID,
region: process.env.REGION,
};
// Hacer el evento accesible a los handlers
ctx.set('wideEvent', event);
try {
await next();
event.status_code = ctx.res.status;
event.outcome = 'success';
} catch (error) {
event.status_code = 500;
event.outcome = 'error';
event.error = {
type: error.name,
message: error.message,
code: error.code,
retriable: error.retriable ?? false,
};
throw error;
} finally {
event.duration_ms = Date.now() - startTime;
// Emitir el wide event UNA SOLA VEZ al final
logger.info(event);
}
};
}
```
### Enriquecimiento en Handlers
```typescript
app.post('/checkout', async (ctx) => {
const event = ctx.get('wideEvent');
const user = ctx.get('user');
// Agregar contexto de usuario
event.user = {
id: user.id,
subscription: user.subscription,
account_age_days: daysSince(user.createdAt),
lifetime_value_cents: user.ltv,
};
// Agregar contexto de negocio mientras procesas
const cart = await getCart(user.id);
event.cart = {
id: cart.id,
item_count: cart.items.length,
total_cents: cart.total,
coupon_applied: cart.coupon?.code,
};
// Procesar pago y capturar mtricas
const paymentStart = Date.now();
const payment = await processPayment(cart, user);
event.payment = {
method: payment.method,
provider: payment.provider,
latency_ms: Date.now() - paymentStart,
attempt: payment.attemptNumber,
};
// Si el pago falla, agregar detalles del error
if (payment.error) {
event.error = {
type: 'PaymentError',
code: payment.error.code,
stripe_decline_code: payment.error.declineCode,
};
}
return ctx.json({ orderId: payment.orderId });
});
```
## Tail Sampling (Muestreo Inteligente)
Para controlar costos sin perder eventos crticos, implementar tail sampling que toma la decisin de muestreo despus de que la request completa.
```typescript
function shouldSample(event: WideEvent): boolean {
// SIEMPRE mantener errores (100%)
if (event.status_code >= 500) return true;
if (event.error) return true;
// SIEMPRE mantener requests lentas (arriba del p99)
if (event.duration_ms > 2000) return true;
// SIEMPRE mantener usuarios VIP
if (event.user?.subscription === 'enterprise') return true;
// SIEMPRE mantener requests con feature flags especficos (para debugging de rollouts)
if (event.feature_flags?.new_checkout_flow) return true;
// Muestreo aleatorio del resto al 5%
return Math.random() < 0.05;
}
```
### Reglas de Tail Sampling
1. **Siempre mantener errores**: 100% de 500s, excepciones y fallos
2. **Siempre mantener requests lentas**: Cualquier cosa arriba del threshold de p99 latency
3. **Siempre mantener usuarios especficos**: Clientes VIP, cuentas de testing interno, sesiones marcadas
4. **Muestrear aleatoriamente el resto**: Requests exitosas y rpidas al 1-5%
## Queries Habilitados por Wide Events
Con wide events, el debugging se transforma de bsqueda de texto a queries de datos estructurados:
```sql
-- Tasa de error por tier de suscripcin
SELECT
user.subscription_tier,
COUNT(*) as total,
SUM(CASE WHEN status_code >= 500 THEN 1 ELSE 0 END) as errors,
ROUND(100.0 * SUM(CASE WHEN status_code >= 500 THEN 1 ELSE 0 END) / COUNT(*), 2) as error_rate
FROM events
WHERE timestamp > NOW() - INTERVAL '1 hour'
GROUP BY user.subscription_tier
-- Requests ms lentas (p99 latency)
SELECT
request_id,
path,
duration_ms,
user.id,
error.type
FROM events
WHERE timestamp > NOW() - INTERVAL '1 hour'
ORDER BY duration_ms DESC
LIMIT 10
-- Impacto de feature flags en errores
SELECT
feature_flags.new_checkout_flow,
COUNT(*) as total,
SUM(CASE WHEN error IS NOT NULL THEN 1 ELSE 0 END) as errors
FROM events
WHERE path = '/api/checkout'
GROUP BY feature_flags.new_checkout_flow
-- Fallos de pago por cdigo de decline
SELECT
error.stripe_decline_code,
COUNT(*) as count,
AVG(cart.total_cents) as avg_cart_value
FROM events
WHERE error.type = 'PaymentError'
GROUP BY error.stripe_decline_code
ORDER BY count DESC
```
## Misconceptions Comunes
### "Structured logging es lo mismo que wide events"
**Falso.** Structured logging significa que tus logs son JSON en lugar de strings. Eso es lo mnimo. Wide events son una filosofa: un evento comprehensivo por request, con todo el contexto adjunto. Puedes tener logs estructurados que siguen siendo intiles (5 campos, sin contexto de usuario, dispersos en 20 lneas de log).
### "Ya usamos OpenTelemetry, as que estamos bien"
**Falso.** Ests usando un mecanismo de entrega. OpenTelemetry no decide qu capturar. T lo decides. La mayora de implementaciones de OTel capturan lo mnimo: nombre del span, duracin, status. Eso no es suficiente. Necesitas instrumentar deliberadamente con contexto de negocio.
### "Esto es solo tracing con pasos extra"
**Falso.** Tracing te da el flujo de requests entre servicios (qu servicio llam a cul). Wide events te dan contexto dentro de un servicio. Son complementarios. Idealmente, tus wide events SON tus trace spans, enriquecidos con todo el contexto que necesitas.
### "Los datos de alta cardinalidad son caros y lentos"
**Parcialmente falso.** Es caro en sistemas de logging legacy construidos para bsqueda de texto de baja cardinalidad. Las bases de datos columnares modernas (ClickHouse, BigQuery, etc.) estn especficamente diseadas para datos de alta cardinalidad y alta dimensionalidad. Las herramientas han evolucionado. Tus prcticas tambin deberan.
### "Los logs son para debugging, las mtricas son para dashboards"
**Falso.** Esta distincin es artificial y daina. Los wide events pueden alimentar ambos. Consltalos para debugging. Agrgalos para dashboards. Los datos son los mismos, solo diferentes vistas.
## Beneficios Clave
1. **Debugging transformado de arqueologa a analytics**: En lugar de grep a travs de 50 servicios, ejecutas una query
2. **Queries en sub-segundos**: "Mustrame todos los fallos de checkout para usuarios premium en la ltima hora donde el nuevo checkout flow estaba habilitado, agrupados por cdigo de error"
3. **Causa raz identificada inmediatamente**: Un query, resultados instantneos
4. **Correlacin trivial**: Todo el contexto est en un solo evento, no disperso en mltiples lneas
5. **Costos controlados**: Con tail sampling inteligente, mantienes lo importante y muestreas el resto
## Checklist de Implementacin
- [ ] Implementar middleware que inicializa el wide event al inicio de cada request
- [ ] Agregar contexto de request (request_id, trace_id, method, path, etc.)
- [ ] Agregar contexto de usuario (user_id, subscription, feature_flags, etc.)
- [ ] Agregar contexto de negocio especfico de tu dominio
- [ ] Agregar contexto de infraestructura (service_name, version, region, etc.)
- [ ] Capturar errores con contexto completo (type, code, message, retriable, etc.)
- [ ] Capturar mtricas de performance (db_query_count, cache_hits, external_call_time, etc.)
- [ ] Emitir UN SOLO evento al final de la request
- [ ] Implementar tail sampling para controlar costos
- [ ] Configurar queries/dashboards para aprovechar los datos estructurados
## Fuente
Basado en el artculo "Logging Sucks - Your Logs Are Lying To You" por Boris Tane: https://loggingsucks.com/