Feature Request: Add LLM API Call Duration Logging #6568

Open
opened 2026-02-16 18:04:36 -05:00 by yindo · 1 comment
Owner

Originally created by @stare-star on GitHub (Jan 17, 2026).

Originally assigned to: @thdxr on GitHub.

Feature Request: Add LLM API Call Duration Logging

Summary

OpenCode currently tracks LLM call timing internally but does not log the total duration of LLM API calls. This makes it difficult to monitor and analyze API latency.

Problem

When debugging performance issues or monitoring API costs, users need visibility into:

  • How long each LLM API call takes
  • Which models/providers have high latency
  • Overall time spent waiting for LLM responses

Currently:

  • service=llm logs only show when streaming starts
  • No duration/end time is logged for LLM calls
  • Internal timing exists in MessageV2 Parts but is not exposed in logs

Proposed Solution

Add duration logging for LLM API calls, similar to how service=session.prompt logs duration=xxx.

Examples

Current logging:

INFO 2026-01-17T06:30:36 +0ms service=llm providerID=zhipuai-coding-plan modelID=glm-4.7 sessionID=ses_4355b9979ffeLoxgoHRHr6IAnb small=false agent=plan stream

Proposed logging:

INFO 2026-01-17T06:30:36 +0ms service=llm providerID=zhipuai-coding-plan modelID=glm-4.7 sessionID=ses_4355b9979ffeLoxgoHRHr6IAnb small=false agent=plan stream
INFO 2026-01-17T06:30:50 +14321ms service=llm providerID=zhipuai-coding-plan modelID=glm-4.7 sessionID=ses_4355b9979ffeLoxgoHRHr6IAnb status=completed duration=14321

Implementation Details

The timing information can be captured in packages/opencode/src/session/llm.ts:

// At the start of stream()
const startTime = Date.now()
l.info("stream", { modelID: input.model.id, providerID: input.model.providerID })

// Track stream completion and log duration
const streamResult = streamText({...})

// Use for-await-of to track when the stream completes
let streamCompleted = false
const wrappedStream = {
  ...streamResult,
  fullStream: (async function* () {
    for await (const chunk of streamResult.fullStream) {
      yield chunk
    }
    // Log completion when stream finishes
    if (!streamCompleted) {
      streamCompleted = true
      const duration = Date.now() - startTime
      l.info("stream completed", { 
        modelID: input.model.id, 
        providerID: input.model.providerID,
        duration 
      })
    }
  })()
}
return wrappedStream

Benefits

  • Better performance monitoring
  • Easier debugging of latency issues
  • Improved cost analysis (time × rate)
  • Consistent with existing logging patterns in OpenCode

Alternatives Considered

  • Using OpenTelemetry (already supported via experimental_telemetry config) - but logs are more accessible for most users
  • Manual calculation from MessageV2 timestamps - requires querying internal storage

Additional Context

OpenCode already tracks timing for:

  • Tool execution (tool.call to tool.result)
  • Text generation (time.start to time.end in TextPart)
  • Message completion (time.completed)

Adding LLM stream duration would complete the picture.

Originally created by @stare-star on GitHub (Jan 17, 2026). Originally assigned to: @thdxr on GitHub. # Feature Request: Add LLM API Call Duration Logging ## Summary OpenCode currently tracks LLM call timing internally but does not log the total duration of LLM API calls. This makes it difficult to monitor and analyze API latency. ## Problem When debugging performance issues or monitoring API costs, users need visibility into: - How long each LLM API call takes - Which models/providers have high latency - Overall time spent waiting for LLM responses Currently: - `service=llm` logs only show when streaming starts - No duration/end time is logged for LLM calls - Internal timing exists in MessageV2 Parts but is not exposed in logs ## Proposed Solution Add duration logging for LLM API calls, similar to how `service=session.prompt` logs `duration=xxx`. ### Examples **Current logging:** ``` INFO 2026-01-17T06:30:36 +0ms service=llm providerID=zhipuai-coding-plan modelID=glm-4.7 sessionID=ses_4355b9979ffeLoxgoHRHr6IAnb small=false agent=plan stream ``` **Proposed logging:** ``` INFO 2026-01-17T06:30:36 +0ms service=llm providerID=zhipuai-coding-plan modelID=glm-4.7 sessionID=ses_4355b9979ffeLoxgoHRHr6IAnb small=false agent=plan stream INFO 2026-01-17T06:30:50 +14321ms service=llm providerID=zhipuai-coding-plan modelID=glm-4.7 sessionID=ses_4355b9979ffeLoxgoHRHr6IAnb status=completed duration=14321 ``` ## Implementation Details The timing information can be captured in `packages/opencode/src/session/llm.ts`: ```typescript // At the start of stream() const startTime = Date.now() l.info("stream", { modelID: input.model.id, providerID: input.model.providerID }) // Track stream completion and log duration const streamResult = streamText({...}) // Use for-await-of to track when the stream completes let streamCompleted = false const wrappedStream = { ...streamResult, fullStream: (async function* () { for await (const chunk of streamResult.fullStream) { yield chunk } // Log completion when stream finishes if (!streamCompleted) { streamCompleted = true const duration = Date.now() - startTime l.info("stream completed", { modelID: input.model.id, providerID: input.model.providerID, duration }) } })() } return wrappedStream ``` ## Benefits - Better performance monitoring - Easier debugging of latency issues - Improved cost analysis (time × rate) - Consistent with existing logging patterns in OpenCode ## Alternatives Considered - Using OpenTelemetry (already supported via `experimental_telemetry` config) - but logs are more accessible for most users - Manual calculation from MessageV2 timestamps - requires querying internal storage ## Additional Context OpenCode already tracks timing for: - Tool execution (`tool.call` to `tool.result`) - Text generation (`time.start` to `time.end` in TextPart) - Message completion (`time.completed`) Adding LLM stream duration would complete the picture.
Author
Owner

@github-actions[bot] commented on GitHub (Jan 17, 2026):

This issue might be a duplicate of or closely related to existing issues. Please check:

  • #219: Feature Request: Add Langfuse Tracing - comprehensive observability that would include duration logging
  • #6142: Feature: Add sessionID to experimental.chat.system.transform hook for tracing integration - related observability infrastructure
  • #6096: [FEATURE]: Adding Experimental Calculation and Display of Tokens per second - both require timing data for API calls
  • #5374: [FEATURE]: show tokens / second - requires duration metrics for throughput calculation
  • #2666: [Question] detailed per-interaction telemetry - related telemetry expansion feature
  • #4577: [FEATURE]: Show the number of api requests made by opencode to the LLM in a session - complementary API usage tracking

Feel free to ignore if none of these address your specific case or if you see these as separate, complementary features.

@github-actions[bot] commented on GitHub (Jan 17, 2026): This issue might be a duplicate of or closely related to existing issues. Please check: - #219: Feature Request: Add Langfuse Tracing - comprehensive observability that would include duration logging - #6142: Feature: Add sessionID to experimental.chat.system.transform hook for tracing integration - related observability infrastructure - #6096: [FEATURE]: Adding Experimental Calculation and Display of Tokens per second - both require timing data for API calls - #5374: [FEATURE]: show tokens / second - requires duration metrics for throughput calculation - #2666: [Question] detailed per-interaction telemetry - related telemetry expansion feature - #4577: [FEATURE]: Show the number of api requests made by opencode to the LLM in a session - complementary API usage tracking Feel free to ignore if none of these address your specific case or if you see these as separate, complementary features.
Sign in to join this conversation.
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: anomalyco/opencode#6568