Logging Sucks. Autotel Makes Wide Events the Default

Boris is spot on in his Logging Sucks post

logs are optimised for writing, not querying

He explains why debugging in production feels like archaeology.

You grep for user-123, find it logged 47 different ways, then spend an hour correlating timestamps across services.

We've all been there.

His wide event example nails it:

{
  "user": {"id": "user_456", "subscription": "premium", "lifetime_value_cents": 284700},
  "cart": {"item_count": 3, "total_cents": 15999, "coupon_applied": "SAVE20"},
  "payment": {"method": "card", "provider": "stripe", "latency_ms": 1089},
  "error": {"type": "PaymentError", "code": "card_declined", "stripe_decline_code": "insufficient_funds"}
}

One event. High-cardinality keys (user.id, traceId). High dimensionality. Queryable.

But there’s still a gap…

I built Autotel to close that gap.

Autotel makes wide events the default output of traces, producing one canonical structured log per request, chosen via tail sampling.

By default, Autotel emits a canonical log line for the root/server span (and optionally for spans that match custom filters such as status=ERROR or duration_ms > 2000), with tail sampling applied automatically.

The middleware-based approach still requires wiring, manual context accumulation, and custom sampling logic.

It works, but it’s a lot of ceremony for something we all want to be the default.

The Problem You’re Solving

A single checkout produces scattered logs:

2024-12-20T10:23:45.100Z INFO  Checkout started userId=user-123
2024-12-20T10:23:45.150Z DEBUG Cart loaded cartId=cart-1 itemCount=2
2024-12-20T10:23:45.300Z INFO  Payment processing method=card provider=stripe
2024-12-20T10:23:45.450Z DEBUG Validating payment details
2024-12-20T10:23:45.612Z ERROR Payment failed error=card_declined userId=user-123

To debug, you grep for userId, then cartId, then correlate timestamps across services.

One Wide Event. Zero Per-Endpoint Wiring

With Autotel, the same checkout produces a single canonical log line (a wide event). No per-endpoint middleware wiring, no finally blocks, no string logs:

{
  "level": 50, // Pino numeric level (50=error, 30=info)
  "name": "checkout-api",
  "msg": "[HTTP POST /api/checkout] Request completed",
  "http.request.method": "POST",
  "http.route": "/api/checkout",
  "http.response.status_code": 500,
  "user.id": "user-123",
  "user.subscription": "premium",
  "user.account_age_days": 847,
  "user.lifetime_value_cents": 284700,
  "request.id": "req_123",
  "cart.id": "cart-1",
  "cart.item_count": 2,
  "cart.total_cents": 7998,
  "cart.coupon_applied": "SAVE20",
  "payment.method": "card",
  "payment.provider": "stripe",
  "payment.latency_ms": 150,
  "payment.attempt": 1,
  "error.type": "PaymentError",
  "error.code": "card_declined",
  "error.message": "Card declined by issuer",
  "error.stripe_decline_code": "insufficient_funds",
  "service.name": "checkout-api",
  "service.version": "1.0.0",
  "deployment.environment": "development",
  "traceId": "4bf92f3577b34da6a3ce929d0e0e4736",
  "spanId": "00f067aa0ba902b7",
  "correlationId": "4bf92f3577b34da6",
  "duration_ms": 512.3,
  "status_code": 2, // OpenTelemetry StatusCode (1=OK, 2=ERROR)
  "status_message": "Payment failed: card_declined",
  "timestamp": "2024-12-20T10:23:45.612Z"
}

Examples are JSONC for readability. The status_code field uses OpenTelemetry's StatusCode enum (OK=1, ERROR=2); for errors, status_message provides a human-readable description.

Use attributeRedactor in production to redact PII.

One event with 25+ fields, emitted automatically when the root span completes.

All attributes use dot-notation (e.g., user.id) rather than nested objects. Most log stores flatten nested objects into dotted keys anyway.

Autotel emits that shape directly.

Which spans become wide events?

By default, Autotel emits canonical logs for root/server spans (typically your HTTP request handlers).

You can configure additional spans via filters (e.g., by span.kind, minimum duration, or status).

This avoids a log volume explosion from every nested span.

Limits & safety rails

OpenTelemetry SDKs enforce attribute limits (defaults vary by SDK and are configurable). Autotel respects SDK limits and truncates when exceeded. For large payloads, store IDs and pointers rather than full objects. Use attributeRedactor to redact PII before emission.

Be intentional about which high-cardinality fields you index vs store: index a small set, store the rest.

Manual Wide-Event Assembly vs Autotel

Manual middleware-based approach builds the event manually:

// Manual approach: middleware + manual accumulation
export function wideEventMiddleware() {
  return async (ctx, next) => {
    const startTime = Date.now();
    const event = { 'request.id': ctx.get('requestId') };
    ctx.set('wideEvent', event);

    try {
      await next();
    } finally {
      event.duration_ms = Date.now() - startTime;
      logger.info(event);
    }
  };
}

// Then in every handler:
app.post('/checkout', async (ctx) => {
  const event = ctx.get('wideEvent');
  // Manual approach often ends up with nested blobs that get flattened inconsistently
  event.user = { id: user.id, subscription: user.subscription };
  event.cart = { id: cart.id, item_count: cart.items.length };
  // ...more manual accumulation
});

With Autotel, context accumulates naturally:

import { trace, setUser, httpServer } from 'autotel';

export const processCheckout = trace((ctx) => async (req: CheckoutRequest) => {
  const user = await getUser(req.userId);
  
  // Standard user attributes via setUser
  setUser(ctx, {
    id: user.id,
    // email: user.email, // Redact PII in production
  });

  // Custom user attributes via setAttributes
  ctx.setAttributes({
    'user.subscription': user.subscription,
    'user.account_age_days': user.accountAgeDays,
    'user.lifetime_value_cents': user.lifetimeValueCents,
  });

  httpServer(ctx, { method: 'POST', route: '/api/checkout' });

  const total = req.items.reduce((sum, item) => sum + item.price, 0);
  ctx.setAttributes({
    'cart.id': req.cartId,
    'cart.item_count': req.items.length,
    'cart.total_cents': Math.round(total * 100),
    'cart.coupon_applied': req.coupon,
  });

  const payment = await processPayment(req);

  ctx.setAttributes({
    'payment.method': payment.method,
    'payment.provider': payment.provider,
    'payment.latency_ms': payment.latencyMs,
  });

  if (payment.error) {
    ctx.setAttributes({
      'error.type': 'PaymentError',
      'error.code': payment.error.code,
      'error.can_retry': payment.error.canRetry,
    });
    throw new PaymentError(payment.error.message);
  }

  return { orderId: payment.orderId };
});
// On span end, Autotel emits one structured log line via the configured exporter

No per-endpoint middleware. No ctx.get('wideEvent'). No finally block. (You still need init() setup and exporter configuration, but that's one-time, not per-endpoint.)

By default, this can go to stdout (JSON) or to an OTLP/HTTP exporter, depending on your setup.

On "OTel Won't Save You"

He's right.

Most OTel setups capture span name, duration, and maybe recordException(error). That's baseline instrumentation: useful, but it won't give you queryable context.

Autotel’s trace() wrapper makes rich instrumentation the path of least resistance.

You’re already inside the traced function, so adding ctx.setAttributes() is natural. Context accumulates as you process, not in a separate middleware layer.

Tail Sampling Without the Logic

His sampling function:

function shouldSample(event) {
  if (event.status_code >= 500) return true;
  if (event.duration_ms > 2000) return true;
  if (event.user?.subscription === 'enterprise') return true;
  return Math.random() < 0.05;
}

With Autotel:

import { init, AdaptiveSampler } from 'autotel';

init({
  service: 'checkout-api',
  sampler: new AdaptiveSampler({
    baselineSampleRate: 0.05,
    alwaysSampleErrors: true,
    alwaysSampleSlow: true,
    slowThresholdMs: 2000,
  }),
});

Same logic, zero custom code. The sampler evaluates after the span completes (tail sampling), so it sees duration, status, and all attributes before deciding.

Autotel’s sampler decides whether to emit the canonical log line for each root span; it’s not trying to guarantee whole-trace retention.

Try It Yourself

If you want to see the shape firsthand, here’s a 60-second demo.

Quickstart: clone the repo and run the demo:

git clone https://github.com/jagreehal/autotel
cd autotel/apps/example-canonical-logs
pnpm install && pnpm start:server
# In another terminal: ./demo.sh

The demo accepts request_id in the request body, then records it on the span as request.id so the emitted logs stay dot-notated.

Request IDs:

• Inputs: request_id (ergonomic)
• Output: request.id (normalised)
• If header exists: also store http.request.header.x-request-id

The Queries You Want

SELECT * FROM logs
WHERE user.subscription = 'premium'
  AND error.type IS NOT NULL
  AND feature_flags.new_checkout_flow = true;

Failed payments by decline code:

SELECT error.code, COUNT(*) as count
FROM logs
WHERE error.type = 'PaymentError'
GROUP BY error.code;

Slow checkouts for high-value customers:

SELECT * FROM logs
WHERE duration_ms > 500
  AND user.lifetime_value_cents > 100000;

Each curl call adds context to the span. Watch the server console on the final step, one canonical log line with everything:

{
  "level": 30,
  "name": "checkout-api",
  "http.request.method": "POST",
  "http.route": "/api/checkout",
  "http.response.status_code": 200,
  "user.id": "user_456",
  "user.subscription": "premium",
  "user.account_age_days": 847,
  "user.lifetime_value_cents": 284700,
  "request.id": "req_test123",
  "cart.id": "cart_xyz",
  "cart.item_count": 3,
  "cart.total_cents": 15999,
  "cart.coupon_applied": "SAVE20",
  "payment.method": "card",
  "payment.provider": "stripe",
  "payment.latency_ms": 241,
  "payment.attempt": 1,
  "service.name": "checkout-api",
  "service.version": "1.0.0",
  "deployment.environment": "development",
  "traceId": "24e8e520137c5cdcdd59ffd5f653d870",
  "spanId": "ed53a2d659907201",
  "correlationId": "24e8e520137c5cdc",
  "duration_ms": 1.04,
  "status_code": 1,
  "timestamp": "2026-01-08T00:26:08.836Z",
  "msg": "[HTTP POST /api/checkout] Request completed"
}

The demo supports manual curl commands too:

Step 1: Initialize request

curl -X POST http://localhost:3000/checkout/start \
  -H "Content-Type: application/json" \
  -d '{"request_id": "req_123"}'

Step 2: Add user context

curl -X POST http://localhost:3000/checkout/auth \
  -H "Content-Type: application/json" \
  -d '{"request_id": "req_123", "user_id": "user_456"}'

Step 3: Add cart context

curl -X POST http://localhost:3000/checkout/cart \
  -H "Content-Type: application/json" \
  -d '{"request_id": "req_123", "cart_id": "cart_xyz"}'

Step 4: Process payment

curl -X POST http://localhost:3000/checkout/payment \
  -H "Content-Type: application/json" \
  -d '{"request_id": "req_123"}'

Step 5-6: Complete + emit canonical log

curl -X POST http://localhost:3000/checkout/complete \
  -H "Content-Type: application/json" \
  -d '{"request_id": "req_123"}'

Repo: github.com/jagreehal/autotel