Telemetry Plugin

The Telemetry Plugin tracks response timing, LLM call durations, and tool usage metrics. It's a great example of a well-structured plugin that demonstrates multiple hook patterns.

Overview

The plugin measures:

Wall time: Total response duration from input to completion
LLM time: Accumulated time spent in LLM API calls
Tool time: Per-tool breakdown of execution times
Agent processing: Time between LLM and tool calls (overhead)
Tool call counts: Including subagent tool usage

Configuration

plugins:
  - module: "codumentor.plugins.telemetry"
    class: "TelemetryPlugin"

The telemetry plugin has no configuration options—it tracks everything automatically.

Output

Log Output

After each response, the plugin logs timing metrics:

INFO - Response complete: wall_time=2456.3ms llm_time=1823.1ms (74.2%)
       tool_time=412.5ms (16.8%) agent_processing=89.2ms (3.6%)
       [before_tools=45.1ms after_tools=44.1ms] overhead=131.5ms (5.4%)
       tool_calls=8 tools[kb_search=2x/156.3ms, read_file=4x/201.2ms]

Evaluation Reports

The plugin exports data to evaluation reports via onReportCollect:

{
  "id": "telemetry",
  "title": "Telemetry Metrics",
  "blocks": [
    {
      "type": "metrics",
      "items": [
        {"label": "Wall Time", "value": "2456.3", "unit": "ms"},
        {"label": "LLM Time", "value": "1823.1", "unit": "ms"},
        {"label": "Tool Time", "value": "412.5", "unit": "ms"},
        {"label": "Agent Processing", "value": "89.2", "unit": "ms"},
        {"label": "Total Tool Calls", "value": 8}
      ]
    },
    {
      "type": "table",
      "columns": ["Tool", "Count", "Total ms"],
      "rows": [
        ["kb_search", 2, "156.3"],
        ["read_file", 4, "201.2"]
      ]
    }
  ]
}

Implementation Details

The telemetry plugin demonstrates several best practices:

Hook Registration

async def register(self, bus):
    # Use consistent high priority to capture accurate timing
    bus.on("onInputReceived", self._on_input_received, priority=100)
    bus.on("onLLMCallStart", self._on_llm_call_start, priority=100)
    bus.on("onLLMCallEnd", self._on_llm_call_end, priority=100)
    bus.on("onToolInvokeStart", self._on_tool_start, priority=100)
    bus.on("onToolExecuting", self._on_tool_executing, priority=100)
    bus.on("onToolInvokeEnd", self._on_tool_end, priority=100)
    bus.on("onResponsePersist", self._on_response_persist, priority=100)
    bus.on("onReportCollect", self._on_report_collect, priority=100)
    bus.on("onSessionReport", self._on_session_report, priority=100)

Context Storage Pattern

Uses ctx.kv for run-scoped data:

async def _on_input_received(self, agent, ctx, payload):
    kv = ctx.setdefault("kv", {})
    kv["response_start"] = time.time()
    kv["llm_total_ms"] = 0.0
    kv["tool_stats"] = {"total_ms": 0.0, "by_tool": {}}
    return None

Artifact Storage for Reports

Stores final metrics in the artifacts namespace:

async def _on_response_persist(self, agent, ctx, payload):
    kv = ctx.get("kv", {})
    # Store in artifacts for report collection
    artifacts = kv.setdefault("artifacts", {})
    artifacts["telemetry"] = {
        "wall_time_ms": total_wall_time_ms,
        "llm_total_ms": total_llm_time_ms,
        # ...
    }

Report Generation

Implements structured report sections:

async def _on_report_collect(self, agent, ctx_snapshot, payload):
    if payload.get("report_type") != "evaluation":
        return {"type": "continue"}

    telemetry_data = ctx_snapshot.get("kv", {}).get("artifacts", {}).get("telemetry")
    if not telemetry_data:
        return {"type": "continue"}

    return {
        "type": "report_collect",
        "sections": [{
            "id": "telemetry",
            "title": "Telemetry Metrics",
            "blocks": [
                {"type": "metrics", "items": [...]},
                {"type": "table", "columns": [...], "rows": [...]}
            ]
        }]
    }

Metrics Explained

Metric	Description
Wall Time	Total elapsed time from input received to response persisted
LLM Time	Cumulative time spent in LLM API calls (may span multiple calls)
Tool Time	Cumulative time spent executing tools (excludes permission wait time)
Tool Wait Time	Time spent waiting for user permission on tools (e.g., shell commands)
Agent Processing	Time spent between LLM calls and tool executions (parsing, routing)
Overhead	Wall time minus (LLM + Tool + Agent Processing) time
Tool Calls	Total count of tool invocations, including subagent tools

Wait Time vs Execution Time

For tools requiring user permission (like shell commands), the telemetry plugin separates:

Wait Time: Duration between onToolInvokeStart and onToolExecuting (user deciding)
Execution Time: Duration between onToolExecuting and onToolInvokeEnd (actual work)

This separation ensures accurate performance metrics—a 30-second user decision doesn't inflate the tool's execution time statistics.

onToolInvokeStart ──► [wait for permission] ──► onToolExecuting ──► [actual work] ──► onToolInvokeEnd
                      └─── wait_ms ──────────┘                      └─── exec_ms ───┘

Subagent Tool Tracking

The plugin aggregates tool calls from subagents spawned by the main agent:

tool_calls=15 (main=8, subagents=7)

This uses a global counter keyed by session ID, with subagent tracking via AgenticTool._SUBAGENT_PARENT.

Session Report Contribution

On session exit (when the session report is enabled), the plugin contributes a "Timing Metrics" section to the end-of-session report via onSessionReport. This section includes:

Turn count, wall time, LLM/tool time with percentages
Per-tool breakdown sorted by total time

This data is rendered by the Console Report Plugin.

Use Cases

Performance Optimization: Identify slow tools or excessive LLM calls
Cost Estimation: Correlate LLM time with token usage for cost analysis
Debugging: Understand where time is spent in complex agent workflows
Evaluation: Include timing data in automated test reports

Source Code

See src/codumentor/plugins/telemetry/telemetry_plugin.py for the complete implementation.