How-to: Logging and Tracing Messages with Middleware

1) Decide your observability goal

Pick one of these goals (do not mix them blindly):

1. Audit logging

• Log “attempted” and “completed” operations.

• Useful for security and compliance.

2. Debug logging

• Log only selected message types during investigation.

• Must be easy to turn off and scope narrowly.

3. Tracing

• Create a span per operation and link it to an existing trace context.

• Useful for end-to-end latency and cross-service correlation.

4. Metrics-like logs

• Log duration and outcomes in a structured format that can be aggregated.

2) Choose what to log (minimal and safe)

Log only fields that are:

• stable (good for searching),

• cheap to compute,

• safe (no secrets / no PII unless you have a clear policy).

Recommended baseline fields:

• stage

• message type/category (or a stable name)

• message id

• middleware name (if relevant)

• outcome: attempted / succeeded / cancelled

• duration (if you measure it)

Avoid logging:

• full message payloads by default

• credentials, tokens, personal data

• large objects (performance + noise)

3) Decide whether you want to log cancelled attempts

Because interrupt/cancel happens in before:

• If you only log in after you will not see cancelled operations.

• If you want to log attempted operations (including cancelled), log in before.

A common pattern:

• before: log “attempt” (or start span)

• after: log “success” (or close span)

If you also want to log cancellations, ensure your guard middleware emits a clear cancellation reason, and your logging middleware logs attempts before any guard can interrupt (ordering matters).

4) Implement stage-first scoping in canHandle

To reduce noise and cost:

• decide which stages you want to observe

• and which message subset you care about

Examples:

• only Execute operations for “business actions”

• only Callback operations for “requests”

• all Publish operations but only for selected event types

5) Add timing (optional) using before/after state

If you measure durations:

• capture start time in before

• compute duration in after

Important constraints:

• after may not run for cancellations.

• Use bounded state (do not leak memory if after is skipped).

6) Attach the middleware early enough (and in the right order)

Ordering guidance:

• If you want to log attempts + cancellations, put logging/tracing middleware before guard middleware.

• If you only want to log successful completions, put it after guard middleware.

Basic logging check

Trigger one operation per stage:

• publish a message (Publish)

• fire a callback message (Callback)

• execute an executor (Execute)

Expected:

• logs include correct stage and message identity

• “attempt” appears in before

• “success” appears in after for successful operations

Cancellation visibility check (if you have guards)

Trigger a blocked operation.

Expected:

• you see an “attempt” log entry

• you do NOT see a “success” entry (because after does not run on cancel)

• you can correlate the cancellation via message id and middleware name/reason

“I only see successful logs, but not cancellations”

Cause:

• you log only in after. Fix:

• log attempts in before.

• ensure ordering places logging middleware before the middleware that interrupts.

“Logs are too noisy”

Likely causes:

• canHandle is too broad (applies to all stages and all message types). Fix:

• filter by stage first.

• filter by message category/type.

• add a feature flag or sampling policy for debug logs.

“Logging is slow”

Likely causes:

• heavy stringification of messages

• synchronous I/O logging on hot paths Fix:

• log structured, minimal fields

• avoid serializing payloads

• use an async logger backend if available

• measure overhead with Execute-stage timings

“Trace spans don’t match the user request”

Cause:

• you are not propagating correlation context across async boundaries (especially for Callback). Fix:

• store trace context in a request-local mechanism in your app runtime.

• for Callback, decide whether you trace “request accepted” or “request completed” and instrument accordingly.