Skip to main content

Online edition for BLOGE 0.9.8-RC1 · facts verified 2026-09-15 · 中文

Chapter 19 — Observability in Production

Promise: By the end of this chapter you will know how to see what a BLOGE graph is doing in production — through listeners, interceptors, metrics, tracing, structured logging, context propagation, and audit journaling — without changing the workflow logic itself.

Learning Goals​

  1. Explain the two main observability extension points: ExecutionListener for lifecycle events and OperatorInterceptor for around-invocation behavior.
  2. Capture graph and node lifecycle signals with a custom listener and know which of the fine-grained sub-interfaces to implement.
  3. Wire MetricsExecutionListener, TracingOperatorInterceptor, and LoggingExecutionListener into a GraphEngine correctly.
  4. Use CallerContextCarrier to propagate MDC or OpenTelemetry context into the engine's virtual threads.
  5. Recognize when aggregate metrics are enough and when you need the structured, per-event fidelity of AuditJournalListener.

Prerequisites​

Source Examples​

FileWhat it shows
GraphEngineListenerTest.javaLifecycle callbacks and listener exception isolation
ResilientOperatorWrapperObservabilityTest.javaRetry, timeout, and fallback events
MetricsExecutionListenerTest.javaMicrometer timers and counters
TracingOperatorInterceptorTest.javaGraph and node spans
AuditJournalListenerTest.javaStructured audit entries and event coverage
BlogeObservabilityAutoConfiguration.javaSpring Boot observability auto-configuration

Why This Matters​

A graph that runs correctly on your machine today can still fail silently in production:

  • A node starts throwing after a dependency upgrade. Without metrics you won't notice until a customer complains.
  • A retry loop burns 30 seconds per request. Without per-node timing data you can't identify the bottleneck.
  • A branch change skips a node that used to run. Without lifecycle signals, the system looks idle when it is actually making the wrong choice.

BLOGE separates concerns: the engine runs nodes, and extension hooks observe what happened. That separation is what makes production visibility possible without forcing metrics, tracing, or logging logic into every operator.

One Incident, One Execution ID, Four Projections​

At 10:03, the order dashboard reports a latency spike. The failing request is executionId=exec-order-42; its chargePayment node retries twice and then uses a fallback. Keep that identity fixed while changing the question:

Diagram: one incident timeline

Diagram: metrics, trace, log, and audit as four projections

ProjectionBest questionObservation for exec-order-42What it cannot establish alone
MetricIs this widespread?retry count and p95 latency roseWhich exact attempt failed
TraceWhere was time spent?chargePayment child span dominatesThe durable event sequence
Structured logWhat did the runtime report?timeout token plus execution/node IDsA complete, ordered history
Audit/event journalWhat happened in order?start → retry → retry → fallback → completeFleet-wide rate without aggregation

The correlation key is the spine, not a fifth observability product. A metric starts the investigation; the same execution ID narrows the trace and logs; the journal reconstructs order. This incident is a teaching reconstruction from source-tested event types, not a captured production outage.

Mental Model​

Think of the engine as a stage with fixed spotlight positions. Every node execution walks through the same spotlight sequence:

Diagram: 19-observability-in-production figure 1

If you know which spotlight position you need, you know where to plug in your observability feature.

First Working Example​

A minimal production-style wiring combines a listener and an interceptor around an otherwise ordinary engine:

var meterRegistry = new SimpleMeterRegistry();
var metrics = new MetricsExecutionListener(meterRegistry, "bloge");
var tracing = new TracingOperatorInterceptor(tracer);

var engine = GraphEngine.builder()
        .registry(registry)
        .listeners(List.of(metrics, tracing))
        .interceptors(List.of(tracing))
        .build();

That one builder call gives you three different views of the same execution:

  • graph/node duration metrics,
  • graph and node tracing spans, and
  • the raw lifecycle event stream that powers both.

The important detail is not the specific library. It is the contract: listeners observe events; interceptors wrap execution.

Break It Apart​

ExecutionListener — the event backbone​

ExecutionListener is a composite interface that extends seven fine-grained sub-interfaces:

Sub-interfaceCallbacks
GraphLifecycleListeneronGraphStart, onGraphComplete
NodeLifecycleListeneronNodeStart, onNodeComplete, onNodeFailed, onNodeSkipped, onNodeSuspended, onNodeResumed
ResilienceListeneronNodeRetry, onNodeTimeout, onNodeFallback
StreamingListeneronNodeStreamStart, onNodeStreamChunk, onNodeStreamEnd, onNodeStreamError
IterationLifecycleListenerLoop/foreach iteration events
TimerEventListenerTimer-fired events
EventCorrelationListenerEvent-matching events

New integrations can implement just the narrowest sub-interface they need. Existing code can continue implementing the aggregate ExecutionListener.

Safety guarantee: A throwing listener does not break graph execution. The engine catches listener exceptions and continues with the remaining listeners. This is tested in GraphEngineListenerTest.listener_exceptionInListener_doesNotBreakExecution.

OperatorInterceptor — the AOP layer​

OperatorInterceptor wraps every operator call. The interceptor receives an OperatorInvocation and must call invocation.proceed() to continue the chain (or short-circuit by returning a value directly).

public interface OperatorInterceptor {
    Object intercept(OperatorInvocation invocation) throws Exception;
}

This is how TracingOperatorInterceptor creates child spans per node — it starts a span before proceed() and ends it in the finally block.

CallerContextCarrier — context across virtual threads​

The engine runs each node on a virtual thread. Thread-local state like OpenTelemetry context or SLF4J MDC does not propagate automatically. CallerContextCarrier bridges this gap with a three-phase contract:

  1. capture() — called on the caller thread, snapshots the context.
  2. Snapshot.attach() — called on the virtual thread, restores it.
  3. Scope.close() — called when the node finishes, cleans up. Scope.NOOP is available for carriers that need no cleanup.

Two implementations ship in bloge-metrics-otel:

Production observability components​

The bloge-metrics-otel module provides three ready-to-use components:

MetricsExecutionListener — emits Micrometer timers and counters:

  • bloge.graph.duration — Timer, tagged graph + outcome
  • bloge.node.duration — Timer, tagged graph + node + outcome
  • bloge.node.errors — Counter, tagged by exception class
  • bloge.node.retries, bloge.node.timeouts, bloge.node.fallbacks, bloge.node.skipped — Counters
  • bloge.stream.chunk.count, bloge.stream.duration, bloge.stream.errors — Streaming metrics

All names use a configurable prefix (default bloge).

Source: MetricsExecutionListener.java

TracingOperatorInterceptor — creates a parent span (bloge.graph.execute) on graph start and a child span (bloge.node.execute) around each operator invocation. It implements both OperatorInterceptor and ExecutionListener — register the same instance in both the interceptors and listeners lists.

Source: TracingOperatorInterceptor.java

LoggingExecutionListener — structured SLF4J logs with bloge.graph, bloge.node, and bloge.executionId MDC keys. Two optional flags — includeInput and includeOutput — control whether payloads appear in logs. Keep both disabled unless you have reviewed payloads for sensitive data.

Source: LoggingExecutionListener.java

Audit journal​

For compliance-grade event recording, bloge-runtime-spi includes AuditJournalListener. It captures NODE_START, NODE_COMPLETE, NODE_FAILED, NODE_RETRY, NODE_SUSPEND, and NODE_RESUME events as structured AuditEntry records and writes them to an AuditJournalStore. An asynchronous flush mode (virtual-thread worker + configurable batch size) keeps the hot path lightweight.

AuditJournalListener accepts an optional TimeSource parameter so that audit timestamps are derived from the same clock the engine uses. In tests you can inject ManualTimeSource to get deterministic audit entries; in production the default SystemTimeSource.INSTANCE is used.

// Production — wall clock
var listener = new AuditJournalListener(store, config, jsonCodec);

// Test — deterministic time
var listener = new AuditJournalListener(store, config, jsonCodec, manualTimeSource);

AuditConfig controls: captureInput, captureOutput, asyncFlush, flushInterval (default 100ms), batchSize (default 64).

ExecutionEventStore — tenant-scoped queries and purging​

The ExecutionEventStore interface exposes several methods that matter for production observability pipelines:

MethodPurpose
loadEventsByTenant(tenantId, namespace, from, to, page, size)Page through events scoped to one tenant/namespace within a time range
countEventsByTenant(tenantId, namespace)Count total events for a tenant — useful for dashboard metrics
purgeEventsBefore(cutoff)Delete events older than a cutoff instant
purgeEventsBefore(cutoff, limit)Batch-aware purge to avoid long-running delete transactions
purgeExecutionEvents(executionId)Delete all events for a single execution (e.g. after archival)

All new methods have default implementations that throw UnsupportedOperationException, so existing store implementations continue to compile. Upgrade them incrementally as your observability pipeline needs these capabilities.

Read Stable Log Tokens by Severity​

Metrics and traces tell you that something is slow. Stable log tokens identify a specific runtime or DSL fallback without making the surrounding prose part of the contract. Alert policy belongs on the emitted severity and operational impact; FINE/FINER tokens are diagnostic breadcrumbs, not alarms by themselves.

TokenSeverityWhat it meansFirst step
[TIMER_RESTORE_FAILED]SEVERETimerManager could not reload active durable timers; persisted timers will not fire until the next restart.Inspect the attached exception, durable timer context, store connectivity, and the records being loaded.
[STREAMING_ITEM_ERROR_SEND_FAILED]WARNINGA streaming foreach item failed and the runtime could not emit its error chunk because the output channel also rejected the send.Inspect the original item failure, channel-close race, and selected item-failure policy.
[SCHEMA_NUMBER_PARSE_FALLBACK]FINERNumber coercion is trying a wider numeric type after an integer or long parse miss.Use for coercion diagnosis; alert only on a separately observed business or error-rate impact.
[ACCESSOR_METHOD_LOOKUP_MISS]FINERA direct method accessor was absent, so DSL path access is trying a JavaBean getter fallback.Confirm the property/getter contract when path resolution later fails.
[SCHEMA_ENRICH_SKIPPED]FINEOperator metadata lookup failed during DSL schema enrichment; compilation continues with reduced enrichment.Inspect the attached cause and registry metadata if diagnostics lose schema detail.
[FINGERPRINT_SKIPPED]FINEThe DSL compiler could not compute an Operator fingerprint and continues without it.Inspect Operator registration and fingerprint support before relying on mismatch detection during recovery.

These tokens are stable; the surrounding text is not. Match the bracketed token, not the prose.

Execution Event Journal​

EventJournalListener is a built-in ExecutionListener that records every engine-level event into an append-only journal. Unlike the audit journal (which captures state changes for durability) or the operator interceptor chain (which wraps single node calls), the event journal is your replayable record of an execution.

ExecutionEventJournal journal = new InMemoryExecutionEventJournal();

GraphEngine engine = GraphEngine.builder()
    .registry(registry)
    .listeners(List.of(new EventJournalListener(journal)))
    .build();

Each entry is an ExecutionEvent carrying an execution id, monotonic sequence number, timestamp, and one of these types:

TypeEmitted when
GRAPH_STARTED / GRAPH_COMPLETED / GRAPH_FAILEDEngine enters/leaves a graph.
NODE_STARTED / NODE_COMPLETED / NODE_FAILED / NODE_SKIPPEDPer node lifecycle.
FOREACH_BATCH_STARTED / FOREACH_BATCH_COMPLETEDEach batch of a foreach.
STREAM_ITEM_EMITTED / STREAM_COMPLETEDStreaming sources.
WAIT_FOR_TIMER_ARMED / WAIT_FOR_TIMER_FIREDDurable timer lifecycle.
LEASE_ACQUIRED / LEASE_REFRESHED / LEASE_LOSTDurable lease lifecycle.

Agent events — AgentEventJournalBridge​

When you use the bloge-agent-ext module, an AgentEventJournalBridge turns agent-internal lifecycle events into entries on the same journal. This gives you a unified replay timeline of "graph turn + agent turn + tool call":

GraphEngine engine = GraphEngine.builder()
    .registry(registry)
    .listeners(List.of(
        new EventJournalListener(journal),
        new AgentEventJournalBridge(journal)))   // route agent events too
    .build();

Agent event types added by the bridge:

TypeMeaning
AGENT_TURN_STARTED / AGENT_TURN_COMPLETEDAgent's reasoning loop iteration.
AGENT_LLM_CALLEDLLM request sent (carries token usage and model id).
AGENT_TOOL_INVOKED / AGENT_TOOL_COMPLETED / AGENT_TOOL_FAILEDTool/function call lifecycle.
AGENT_MEMORY_TRIMMEDA memory strategy dropped/summarised earlier turns.
AGENT_STREAM_CHUNK_EMITTEDA streaming agent produced a chunk.

A common pattern is to keep an in-memory journal for short-lived debugging and ship a JdbcExecutionEventJournal to your warehouse for long-term replay.

Common Trap​

❌ Registering TracingOperatorInterceptor only as a listener​

var tracing = new TracingOperatorInterceptor(tracer);

var engine = GraphEngine.builder()
    .registry(registry)
    .listeners(List.of(tracing))       // graph span ✅
    // missing .interceptors(List.of(tracing))  — no node spans! ❌
    .build();

TracingOperatorInterceptor wears two hats. The ExecutionListener side creates the graph-level span in onGraphStart / onGraphComplete. The OperatorInterceptor side creates node-level child spans in intercept(). If you only register it as a listener, you will see a single flat span per execution with no per-node breakdown.

Fix: register the same instance in both lists.

Guided Rewrite​

Open MetricsExecutionListenerTest.java and adapt it in three ways:

  1. Change the metric prefix to myapp.bloge and verify that the timer names follow the new prefix.
  2. Add a fallback path and assert that the fallback counter increments exactly once.
  3. Register an inline listener that records event strings and compare its event order with the metrics emitted for the same execution.

The exercise is useful because it keeps the graph constant while you vary the observability lens.

Brain Check​

  1. What is the difference between an ExecutionListener and an OperatorInterceptor?

    (A listener reacts to lifecycle events after they are emitted; an interceptor wraps the operator invocation itself and can add behavior around it.)

  2. Why must TracingOperatorInterceptor be registered in two places?

    (Its listener side manages the graph-level span; its interceptor side creates node-level spans.)

  3. What problem does CallerContextCarrier solve?

    (It propagates caller-thread context such as MDC or OpenTelemetry state into the engine's virtual threads.)

  4. When should you choose AuditJournalListener over plain metrics?

    (When you need structured, per-event auditability instead of aggregate counters or timers.)

  5. What guarantee does the engine provide if a listener throws?

    (Listener failures are isolated; execution continues and other listeners still run.)

Lab​

Goal: make one graph observable in three complementary ways.

  1. Build a small graph with one successful node and one flaky node.
  2. Register MetricsExecutionListener and verify a retry counter appears.
  3. Register TracingOperatorInterceptor in both places and verify graph and node spans are created.
  4. Register AuditJournalListener with an in-memory store and assert that the expected NODE_START, NODE_RETRY, and NODE_COMPLETE events were stored.
  5. Add MDC propagation with MdcContextCarrier and verify a node log line sees the caller's correlation ID.

Stretch: run the same graph once with observability enabled and once without it, then compare what each lens helps you answer fastest.

Experiment acceptance card​

  • Expected and observed: One executionId connects metric, trace, log, and audit.
  • Failure and recovery: Remove correlation; restore the shared identity and rebuild the timeline.
  • Proof boundary: Proves projections can correlate, not that metrics explain business cause.
  • Exercise contract: One retry-to-fallback incident; change correlation only; deliver four projections; stop when all resolve to one execution.

Recap​

  • Listeners observe lifecycle events; interceptors wrap operator calls.
  • Metrics, tracing, logging, and audit journaling all hang off the same engine extension surfaces.
  • CallerContextCarrier is the missing link between caller-thread context and virtual-thread execution.
  • The safest observability integrations are reusable because they add visibility without changing graph logic.

Next Step​

In Chapter 20 — Spring and Production Wiring, you will turn runtime visibility into an application integration: conditional beans, configuration boundaries, and operator-facing endpoints.

Coding Agent: Open the versioned task guide.