ADR-025: LangChain4j Observability and Trace Support

Status

Proposed

Date

2025-12-07

Deciders

• Development Team

Context and Problem Statement

The CLI uses Quarkus LangChain4j for AI-powered commands (ask, MCP tools). Currently, there is no visibility into:

• Which tools the LLM selects for a given request
• The order and duration of tool executions
• Token usage and costs
• Reasoning steps the LLM takes

Users and developers need observability to:

1. Debug why queries return unexpected results
2. Understand what the AI is doing internally
3. Optimize prompts and tool selection
4. Troubleshoot failures in multi-step operations

Decision Drivers

• Transparency: Users should understand AI behavior
• Debuggability: Developers need to trace tool calls
• Performance: Identify slow tools and optimize
• Cost Awareness: Track token usage per request
• Non-intrusive: Observability should be opt-in

Considered Options

Option 1: --trace Flag on ask Command

Add a simple flag to enable verbose output:

idempiere-cli ask --trace "list all C_ tables"

Output:

[TRACE] Request: "list all C_ tables"
[TRACE] LLM thinking...
[TRACE] → Tool: RegistryTools.listTables(pattern="C_%", limit=100)
[TRACE] ← Result (234ms): 465 tables found
[TRACE] LLM formatting response...
[TRACE] Total: 1.2s, tokens: 850 in / 120 out

Found 465 tables with C_ prefix...

Pros:

• Simple implementation
• No additional dependencies
• Familiar UX pattern

Cons:

• Limited to ask command
• No structured output for tooling

Option 2: Quarkus LangChain4j AuditService (Recommended)

Implement dev.langchain4j.model.chat.listener.ChatModelListener and use Quarkus configuration:

@ApplicationScoped
public class CliChatModelListener implements ChatModelListener {

    @Override
    public void onRequest(ChatModelRequestContext ctx) {
        if (TraceContext.isEnabled()) {
            log("→ LLM Request: " + ctx.request().messages().size() + " messages");
        }
    }

    @Override
    public void onResponse(ChatModelResponseContext ctx) {
        if (TraceContext.isEnabled()) {
            var usage = ctx.response().tokenUsage();
            log("← LLM Response: " + usage.inputTokenCount() + " in / " +
                usage.outputTokenCount() + " out");
        }
    }
}

Combined with tool execution tracking:

@ApplicationScoped
public class CliToolExecutionListener {

    public void onToolSelected(@Observes ToolExecutionRequest event) {
        if (TraceContext.isEnabled()) {
            log("→ Tool: " + event.name() + "(" + formatArgs(event.arguments()) + ")");
        }
    }

    public void onToolExecuted(@Observes ToolExecutionResult event) {
        if (TraceContext.isEnabled()) {
            log("← Result (" + event.durationMs() + "ms)");
        }
    }
}

Pros:

• Framework-native approach
• Works across all AI features (ask, MCP, RAG)
• Structured events for future integrations
• Token tracking built-in

Cons:

• More complex implementation
• Requires Quarkus CDI events

Option 3: OpenTelemetry Integration

Use Quarkus OpenTelemetry extension for distributed tracing:

quarkus.otel.enabled=true
quarkus.otel.traces.enabled=true
quarkus.langchain4j.otel.enabled=true

Pros:

• Industry standard
• Integrates with Jaeger, Zipkin, etc.
• Rich visualization tools

Cons:

• Overkill for CLI debugging
• Requires external infrastructure
• Not suitable for quick debugging

Decision Outcome

Chosen: Option 2 (AuditService) with Option 1 (--trace flag) as UX

Combine both approaches:

1. Implement ChatModelListener for framework-level observability
2. Add --trace flag to ask command for user-facing output
3. Use TraceContext thread-local to enable/disable tracing

Implementation Plan

Phase 1: TraceContext (Thread-local state)

public final class TraceContext {
    private static final ThreadLocal<Boolean> enabled = ThreadLocal.withInitial(() -> false);
    private static final ThreadLocal<List<TraceEvent>> events = ThreadLocal.withInitial(ArrayList::new);

    public static void enable() { enabled.set(true); }
    public static void disable() { enabled.set(false); events.get().clear(); }
    public static boolean isEnabled() { return enabled.get(); }

    public static void record(TraceEvent event) {
        if (isEnabled()) events.get().add(event);
    }

    public static List<TraceEvent> getEvents() { return List.copyOf(events.get()); }
}

public sealed interface TraceEvent permits
    LlmRequest, LlmResponse, ToolCall, ToolResult {
    Instant timestamp();
    String format();
}

Phase 2: ChatModelListener

@ApplicationScoped
public class CliChatModelListener implements ChatModelListener {

    @Override
    public void onRequest(ChatModelRequestContext ctx) {
        TraceContext.record(new LlmRequest(
            Instant.now(),
            ctx.request().messages().size(),
            ctx.request().toolSpecifications().size()
        ));
    }

    @Override
    public void onResponse(ChatModelResponseContext ctx) {
        var usage = ctx.response().tokenUsage();
        TraceContext.record(new LlmResponse(
            Instant.now(),
            usage != null ? usage.inputTokenCount() : 0,
            usage != null ? usage.outputTokenCount() : 0,
            ctx.response().aiMessage().hasToolExecutionRequests()
        ));
    }
}

Phase 3: Tool Execution Tracking

@ApplicationScoped
public class TracingToolExecutor {

    @Inject
    Event<ToolExecutionEvent> toolEvent;

    public Object executeWithTracing(String toolName, Object[] args, Supplier<Object> execution) {
        long start = System.currentTimeMillis();
        TraceContext.record(new ToolCall(Instant.now(), toolName, Arrays.toString(args)));

        try {
            Object result = execution.get();
            long duration = System.currentTimeMillis() - start;
            TraceContext.record(new ToolResult(Instant.now(), toolName, duration, true, null));
            return result;
        } catch (Exception e) {
            long duration = System.currentTimeMillis() - start;
            TraceContext.record(new ToolResult(Instant.now(), toolName, duration, false, e.getMessage()));
            throw e;
        }
    }
}

Phase 4: Update AskCommand

@Command(name = "ask", ...)
public class AskCommand implements Callable<Integer> {

    @Option(names = {"--trace", "-t"}, description = "Show LangChain execution trace")
    boolean trace;

    @Option(names = {"--trace-format"}, description = "Trace output format: text, json")
    String traceFormat = "text";

    @Override
    public Integer call() {
        if (trace) {
            TraceContext.enable();
        }

        try {
            String result = agent.route(request);
            ConsoleOutput.println(result);

            if (trace) {
                printTrace();
            }
            return 0;
        } finally {
            TraceContext.disable();
        }
    }

    private void printTrace() {
        ConsoleOutput.println();
        ConsoleOutput.info("=== Execution Trace ===");

        for (TraceEvent event : TraceContext.getEvents()) {
            ConsoleOutput.println(event.format());
        }

        // Summary
        var events = TraceContext.getEvents();
        long totalTokensIn = events.stream()
            .filter(e -> e instanceof LlmResponse)
            .mapToLong(e -> ((LlmResponse) e).tokensIn())
            .sum();
        long totalTokensOut = events.stream()
            .filter(e -> e instanceof LlmResponse)
            .mapToLong(e -> ((LlmResponse) e).tokensOut())
            .sum();
        long toolCount = events.stream()
            .filter(e -> e instanceof ToolCall)
            .count();

        ConsoleOutput.println();
        ConsoleOutput.info("Summary: " + toolCount + " tool calls, " +
            totalTokensIn + " tokens in, " + totalTokensOut + " tokens out");
    }
}

Example Output

$ idempiere-cli ask --trace "how many orders by document type"

[12:34:56.001] → LLM Request (2 messages, 7 tools available)
[12:34:56.523] ← LLM Response (245 tokens in, 42 tokens out, tool call requested)
[12:34:56.524] → Tool: QueryTools.executeQuery(sql="SELECT dt.name, COUNT(*)...")
[12:34:56.891] ← Tool Result (367ms): success
[12:34:57.102] ← LLM Response (180 tokens in, 95 tokens out, final)

Found 92 document types across 1,103,972 orders...

=== Execution Trace Summary ===
Tool calls: 1
Total time: 1.1s
Tokens: 425 in / 137 out

JSON Trace Format

For programmatic use:

$ idempiere-cli ask --trace --trace-format=json "list tables" 2>/dev/null | jq .trace

{
  "events": [
    {"type": "llm_request", "timestamp": "2025-12-07T12:34:56.001Z", "messages": 2, "tools": 7},
    {"type": "llm_response", "timestamp": "2025-12-07T12:34:56.523Z", "tokensIn": 245, "tokensOut": 42},
    {"type": "tool_call", "timestamp": "2025-12-07T12:34:56.524Z", "tool": "listTables", "args": {"pattern": "%"}},
    {"type": "tool_result", "timestamp": "2025-12-07T12:34:56.891Z", "tool": "listTables", "durationMs": 367, "success": true}
  ],
  "summary": {
    "toolCalls": 1,
    "totalDurationMs": 1100,
    "tokensIn": 425,
    "tokensOut": 137
  }
}

Configuration

# application.properties

# Enable request/response logging (development)
quarkus.langchain4j.log-requests=false
quarkus.langchain4j.log-responses=false

# Default trace format
idempiere.cli.trace.format=text
idempiere.cli.trace.include-args=true
idempiere.cli.trace.include-results=false

File Structure

src/main/java/org/idempiere/cli/ai/
├── observability/
│   ├── TraceContext.java           # Thread-local trace state
│   ├── TraceEvent.java             # Sealed interface for events
│   ├── CliChatModelListener.java   # LLM request/response tracking
│   └── TraceFormatter.java         # Text/JSON formatting
└── langchain/
    └── tools/                       # Existing tools (unchanged)

Security Considerations

• Sensitive Data: Tool arguments may contain sensitive data; --trace should sanitize credentials
• Token Logging: Full prompts should not be logged by default
• Production: Trace should be disabled in production builds by default

Future Enhancements

1. Cost Estimation: Calculate approximate API costs based on token usage
2. Trace Export: Export traces to file for later analysis
3. Performance Baseline: Compare against historical performance
4. MCP Integration: Add trace support to MCP server tools

References

• Quarkus LangChain4j Observability
• LangChain4j ChatModelListener
• ADR-023: Quarkus LangChain4j Migration