/ services / api / logging.ts
logging.ts
  1  import { feature } from 'bun:bundle'
  2  import { APIError } from '@anthropic-ai/sdk'
  3  import type {
  4    BetaStopReason,
  5    BetaUsage as Usage,
  6  } from '@anthropic-ai/sdk/resources/beta/messages/messages.mjs'
  7  import {
  8    addToTotalDurationState,
  9    consumePostCompaction,
 10    getIsNonInteractiveSession,
 11    getLastApiCompletionTimestamp,
 12    getTeleportedSessionInfo,
 13    markFirstTeleportMessageLogged,
 14    setLastApiCompletionTimestamp,
 15  } from 'src/bootstrap/state.js'
 16  import type { QueryChainTracking } from 'src/Tool.js'
 17  import { isConnectorTextBlock } from 'src/types/connectorText.js'
 18  import type { AssistantMessage } from 'src/types/message.js'
 19  import { logForDebugging } from 'src/utils/debug.js'
 20  import type { EffortLevel } from 'src/utils/effort.js'
 21  import { logError } from 'src/utils/log.js'
 22  import { getAPIProviderForStatsig } from 'src/utils/model/providers.js'
 23  import type { PermissionMode } from 'src/utils/permissions/PermissionMode.js'
 24  import { jsonStringify } from 'src/utils/slowOperations.js'
 25  import { logOTelEvent } from 'src/utils/telemetry/events.js'
 26  import {
 27    endLLMRequestSpan,
 28    isBetaTracingEnabled,
 29    type Span,
 30  } from 'src/utils/telemetry/sessionTracing.js'
 31  import type { NonNullableUsage } from '../../entrypoints/sdk/sdkUtilityTypes.js'
 32  import { consumeInvokingRequestId } from '../../utils/agentContext.js'
 33  import {
 34    type AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
 35    logEvent,
 36  } from '../analytics/index.js'
 37  import { sanitizeToolNameForAnalytics } from '../analytics/metadata.js'
 38  import { EMPTY_USAGE } from './emptyUsage.js'
 39  import { classifyAPIError } from './errors.js'
 40  import { extractConnectionErrorDetails } from './errorUtils.js'
 41  
 42  export type { NonNullableUsage }
 43  export { EMPTY_USAGE }
 44  
 45  // Strategy used for global prompt caching
 46  export type GlobalCacheStrategy = 'tool_based' | 'system_prompt' | 'none'
 47  
 48  function getErrorMessage(error: unknown): string {
 49    if (error instanceof APIError) {
 50      const body = error.error as { error?: { message?: string } } | undefined
 51      if (body?.error?.message) return body.error.message
 52    }
 53    return error instanceof Error ? error.message : String(error)
 54  }
 55  
 56  type KnownGateway =
 57    | 'litellm'
 58    | 'helicone'
 59    | 'portkey'
 60    | 'cloudflare-ai-gateway'
 61    | 'kong'
 62    | 'braintrust'
 63    | 'databricks'
 64  
 65  // Gateway fingerprints for detecting AI gateways from response headers
 66  const GATEWAY_FINGERPRINTS: Partial<
 67    Record<KnownGateway, { prefixes: string[] }>
 68  > = {
 69    // https://docs.litellm.ai/docs/proxy/response_headers
 70    litellm: {
 71      prefixes: ['x-litellm-'],
 72    },
 73    // https://docs.helicone.ai/helicone-headers/header-directory
 74    helicone: {
 75      prefixes: ['helicone-'],
 76    },
 77    // https://portkey.ai/docs/api-reference/response-schema
 78    portkey: {
 79      prefixes: ['x-portkey-'],
 80    },
 81    // https://developers.cloudflare.com/ai-gateway/evaluations/add-human-feedback-api/
 82    'cloudflare-ai-gateway': {
 83      prefixes: ['cf-aig-'],
 84    },
 85    // https://developer.konghq.com/ai-gateway/ — X-Kong-Upstream-Latency, X-Kong-Proxy-Latency
 86    kong: {
 87      prefixes: ['x-kong-'],
 88    },
 89    // https://www.braintrust.dev/docs/guides/proxy — x-bt-used-endpoint, x-bt-cached
 90    braintrust: {
 91      prefixes: ['x-bt-'],
 92    },
 93  }
 94  
 95  // Gateways that use provider-owned domains (not self-hosted), so the
 96  // ANTHROPIC_BASE_URL hostname is a reliable signal even without a
 97  // distinctive response header.
 98  const GATEWAY_HOST_SUFFIXES: Partial<Record<KnownGateway, string[]>> = {
 99    // https://docs.databricks.com/aws/en/ai-gateway/
100    databricks: [
101      '.cloud.databricks.com',
102      '.azuredatabricks.net',
103      '.gcp.databricks.com',
104    ],
105  }
106  
107  function detectGateway({
108    headers,
109    baseUrl,
110  }: {
111    headers?: globalThis.Headers
112    baseUrl?: string
113  }): KnownGateway | undefined {
114    if (headers) {
115      // Header names are already lowercase from the Headers API
116      const headerNames: string[] = []
117      headers.forEach((_, key) => headerNames.push(key))
118      for (const [gw, { prefixes }] of Object.entries(GATEWAY_FINGERPRINTS)) {
119        if (prefixes.some(p => headerNames.some(h => h.startsWith(p)))) {
120          return gw as KnownGateway
121        }
122      }
123    }
124  
125    if (baseUrl) {
126      try {
127        const host = new URL(baseUrl).hostname.toLowerCase()
128        for (const [gw, suffixes] of Object.entries(GATEWAY_HOST_SUFFIXES)) {
129          if (suffixes.some(s => host.endsWith(s))) {
130            return gw as KnownGateway
131          }
132        }
133      } catch {
134        // malformed URL — ignore
135      }
136    }
137  
138    return undefined
139  }
140  
141  function getAnthropicEnvMetadata() {
142    return {
143      ...(process.env.ANTHROPIC_BASE_URL
144        ? {
145            baseUrl: process.env
146              .ANTHROPIC_BASE_URL as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
147          }
148        : {}),
149      ...(process.env.ANTHROPIC_MODEL
150        ? {
151            envModel: process.env
152              .ANTHROPIC_MODEL as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
153          }
154        : {}),
155      ...(process.env.ANTHROPIC_SMALL_FAST_MODEL
156        ? {
157            envSmallFastModel: process.env
158              .ANTHROPIC_SMALL_FAST_MODEL as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
159          }
160        : {}),
161    }
162  }
163  
164  function getBuildAgeMinutes(): number | undefined {
165    if (!MACRO.BUILD_TIME) return undefined
166    const buildTime = new Date(MACRO.BUILD_TIME).getTime()
167    if (isNaN(buildTime)) return undefined
168    return Math.floor((Date.now() - buildTime) / 60000)
169  }
170  
171  export function logAPIQuery({
172    model,
173    messagesLength,
174    temperature,
175    betas,
176    permissionMode,
177    querySource,
178    queryTracking,
179    thinkingType,
180    effortValue,
181    fastMode,
182    previousRequestId,
183  }: {
184    model: string
185    messagesLength: number
186    temperature: number
187    betas?: string[]
188    permissionMode?: PermissionMode
189    querySource: string
190    queryTracking?: QueryChainTracking
191    thinkingType?: 'adaptive' | 'enabled' | 'disabled'
192    effortValue?: EffortLevel | null
193    fastMode?: boolean
194    previousRequestId?: string | null
195  }): void {
196    logEvent('tengu_api_query', {
197      model: model as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
198      messagesLength,
199      temperature: temperature,
200      provider: getAPIProviderForStatsig(),
201      buildAgeMins: getBuildAgeMinutes(),
202      ...(betas?.length
203        ? {
204            betas: betas.join(
205              ',',
206            ) as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
207          }
208        : {}),
209      permissionMode:
210        permissionMode as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
211      querySource:
212        querySource as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
213      ...(queryTracking
214        ? {
215            queryChainId:
216              queryTracking.chainId as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
217            queryDepth: queryTracking.depth,
218          }
219        : {}),
220      thinkingType:
221        thinkingType as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
222      effortValue:
223        effortValue as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
224      fastMode,
225      ...(previousRequestId
226        ? {
227            previousRequestId:
228              previousRequestId as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
229          }
230        : {}),
231      ...getAnthropicEnvMetadata(),
232    })
233  }
234  
235  export function logAPIError({
236    error,
237    model,
238    messageCount,
239    messageTokens,
240    durationMs,
241    durationMsIncludingRetries,
242    attempt,
243    requestId,
244    clientRequestId,
245    didFallBackToNonStreaming,
246    promptCategory,
247    headers,
248    queryTracking,
249    querySource,
250    llmSpan,
251    fastMode,
252    previousRequestId,
253  }: {
254    error: unknown
255    model: string
256    messageCount: number
257    messageTokens?: number
258    durationMs: number
259    durationMsIncludingRetries: number
260    attempt: number
261    requestId?: string | null
262    /** Client-generated ID sent as x-client-request-id header (survives timeouts) */
263    clientRequestId?: string
264    didFallBackToNonStreaming?: boolean
265    promptCategory?: string
266    headers?: globalThis.Headers
267    queryTracking?: QueryChainTracking
268    querySource?: string
269    /** The span from startLLMRequestSpan - pass this to correctly match responses to requests */
270    llmSpan?: Span
271    fastMode?: boolean
272    previousRequestId?: string | null
273  }): void {
274    const gateway = detectGateway({
275      headers:
276        error instanceof APIError && error.headers ? error.headers : headers,
277      baseUrl: process.env.ANTHROPIC_BASE_URL,
278    })
279  
280    const errStr = getErrorMessage(error)
281    const status = error instanceof APIError ? String(error.status) : undefined
282    const errorType = classifyAPIError(error)
283  
284    // Log detailed connection error info to debug logs (visible via --debug)
285    const connectionDetails = extractConnectionErrorDetails(error)
286    if (connectionDetails) {
287      const sslLabel = connectionDetails.isSSLError ? ' (SSL error)' : ''
288      logForDebugging(
289        `Connection error details: code=${connectionDetails.code}${sslLabel}, message=${connectionDetails.message}`,
290        { level: 'error' },
291      )
292    }
293  
294    const invocation = consumeInvokingRequestId()
295  
296    if (clientRequestId) {
297      logForDebugging(
298        `API error x-client-request-id=${clientRequestId} (give this to the API team for server-log lookup)`,
299        { level: 'error' },
300      )
301    }
302  
303    logError(error as Error)
304    logEvent('tengu_api_error', {
305      model: model as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
306      error: errStr as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
307      status:
308        status as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
309      errorType:
310        errorType as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
311      messageCount,
312      messageTokens,
313      durationMs,
314      durationMsIncludingRetries,
315      attempt,
316      provider: getAPIProviderForStatsig(),
317      requestId:
318        (requestId as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS) ||
319        undefined,
320      ...(invocation
321        ? {
322            invokingRequestId:
323              invocation.invokingRequestId as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
324            invocationKind:
325              invocation.invocationKind as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
326          }
327        : {}),
328      clientRequestId:
329        (clientRequestId as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS) ||
330        undefined,
331      didFallBackToNonStreaming,
332      ...(promptCategory
333        ? {
334            promptCategory:
335              promptCategory as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
336          }
337        : {}),
338      ...(gateway
339        ? {
340            gateway:
341              gateway as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
342          }
343        : {}),
344      ...(queryTracking
345        ? {
346            queryChainId:
347              queryTracking.chainId as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
348            queryDepth: queryTracking.depth,
349          }
350        : {}),
351      ...(querySource
352        ? {
353            querySource:
354              querySource as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
355          }
356        : {}),
357      fastMode,
358      ...(previousRequestId
359        ? {
360            previousRequestId:
361              previousRequestId as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
362          }
363        : {}),
364      ...getAnthropicEnvMetadata(),
365    })
366  
367    // Log API error event for OTLP
368    void logOTelEvent('api_error', {
369      model: model,
370      error: errStr,
371      status_code: String(status),
372      duration_ms: String(durationMs),
373      attempt: String(attempt),
374      speed: fastMode ? 'fast' : 'normal',
375    })
376  
377    // Pass the span to correctly match responses to requests when beta tracing is enabled
378    endLLMRequestSpan(llmSpan, {
379      success: false,
380      statusCode: status ? parseInt(status) : undefined,
381      error: errStr,
382      attempt,
383    })
384  
385    // Log first error for teleported sessions (reliability tracking)
386    const teleportInfo = getTeleportedSessionInfo()
387    if (teleportInfo?.isTeleported && !teleportInfo.hasLoggedFirstMessage) {
388      logEvent('tengu_teleport_first_message_error', {
389        session_id:
390          teleportInfo.sessionId as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
391        error_type:
392          errorType as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
393      })
394      markFirstTeleportMessageLogged()
395    }
396  }
397  
398  function logAPISuccess({
399    model,
400    preNormalizedModel,
401    messageCount,
402    messageTokens,
403    usage,
404    durationMs,
405    durationMsIncludingRetries,
406    attempt,
407    ttftMs,
408    requestId,
409    stopReason,
410    costUSD,
411    didFallBackToNonStreaming,
412    querySource,
413    gateway,
414    queryTracking,
415    permissionMode,
416    globalCacheStrategy,
417    textContentLength,
418    thinkingContentLength,
419    toolUseContentLengths,
420    connectorTextBlockCount,
421    fastMode,
422    previousRequestId,
423    betas,
424  }: {
425    model: string
426    preNormalizedModel: string
427    messageCount: number
428    messageTokens: number
429    usage: Usage
430    durationMs: number
431    durationMsIncludingRetries: number
432    attempt: number
433    ttftMs: number | null
434    requestId: string | null
435    stopReason: BetaStopReason | null
436    costUSD: number
437    didFallBackToNonStreaming: boolean
438    querySource: string
439    gateway?: KnownGateway
440    queryTracking?: QueryChainTracking
441    permissionMode?: PermissionMode
442    globalCacheStrategy?: GlobalCacheStrategy
443    textContentLength?: number
444    thinkingContentLength?: number
445    toolUseContentLengths?: Record<string, number>
446    connectorTextBlockCount?: number
447    fastMode?: boolean
448    previousRequestId?: string | null
449    betas?: string[]
450  }): void {
451    const isNonInteractiveSession = getIsNonInteractiveSession()
452    const isPostCompaction = consumePostCompaction()
453    const hasPrintFlag =
454      process.argv.includes('-p') || process.argv.includes('--print')
455  
456    const now = Date.now()
457    const lastCompletion = getLastApiCompletionTimestamp()
458    const timeSinceLastApiCallMs =
459      lastCompletion !== null ? now - lastCompletion : undefined
460  
461    const invocation = consumeInvokingRequestId()
462  
463    logEvent('tengu_api_success', {
464      model: model as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
465      ...(preNormalizedModel !== model
466        ? {
467            preNormalizedModel:
468              preNormalizedModel as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
469          }
470        : {}),
471      ...(betas?.length
472        ? {
473            betas: betas.join(
474              ',',
475            ) as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
476          }
477        : {}),
478      messageCount,
479      messageTokens,
480      inputTokens: usage.input_tokens,
481      outputTokens: usage.output_tokens,
482      cachedInputTokens: usage.cache_read_input_tokens ?? 0,
483      uncachedInputTokens: usage.cache_creation_input_tokens ?? 0,
484      durationMs: durationMs,
485      durationMsIncludingRetries: durationMsIncludingRetries,
486      attempt: attempt,
487      ttftMs: ttftMs ?? undefined,
488      buildAgeMins: getBuildAgeMinutes(),
489      provider: getAPIProviderForStatsig(),
490      requestId:
491        (requestId as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS) ??
492        undefined,
493      ...(invocation
494        ? {
495            invokingRequestId:
496              invocation.invokingRequestId as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
497            invocationKind:
498              invocation.invocationKind as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
499          }
500        : {}),
501      stop_reason:
502        (stopReason as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS) ??
503        undefined,
504      costUSD,
505      didFallBackToNonStreaming,
506      isNonInteractiveSession,
507      print: hasPrintFlag,
508      isTTY: process.stdout.isTTY ?? false,
509      querySource:
510        querySource as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
511      ...(gateway
512        ? {
513            gateway:
514              gateway as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
515          }
516        : {}),
517      ...(queryTracking
518        ? {
519            queryChainId:
520              queryTracking.chainId as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
521            queryDepth: queryTracking.depth,
522          }
523        : {}),
524      permissionMode:
525        permissionMode as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
526      ...(globalCacheStrategy
527        ? {
528            globalCacheStrategy:
529              globalCacheStrategy as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
530          }
531        : {}),
532      ...(textContentLength !== undefined
533        ? ({
534            textContentLength,
535          } as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS)
536        : {}),
537      ...(thinkingContentLength !== undefined
538        ? ({
539            thinkingContentLength,
540          } as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS)
541        : {}),
542      ...(toolUseContentLengths !== undefined
543        ? ({
544            toolUseContentLengths: jsonStringify(
545              toolUseContentLengths,
546            ) as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
547          } as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS)
548        : {}),
549      ...(connectorTextBlockCount !== undefined
550        ? ({
551            connectorTextBlockCount,
552          } as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS)
553        : {}),
554      fastMode,
555      // Log cache_deleted_input_tokens for cache editing analysis. Casts needed
556      // because the field is intentionally not on NonNullableUsage (excluded from
557      // external builds). Set by updateUsage() when cache editing is active.
558      ...(feature('CACHED_MICROCOMPACT') &&
559      ((usage as unknown as { cache_deleted_input_tokens?: number })
560        .cache_deleted_input_tokens ?? 0) > 0
561        ? {
562            cacheDeletedInputTokens: (
563              usage as unknown as { cache_deleted_input_tokens: number }
564            ).cache_deleted_input_tokens,
565          }
566        : {}),
567      ...(previousRequestId
568        ? {
569            previousRequestId:
570              previousRequestId as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
571          }
572        : {}),
573      ...(isPostCompaction ? { isPostCompaction } : {}),
574      ...getAnthropicEnvMetadata(),
575      timeSinceLastApiCallMs,
576    })
577  
578    setLastApiCompletionTimestamp(now)
579  }
580  
581  export function logAPISuccessAndDuration({
582    model,
583    preNormalizedModel,
584    start,
585    startIncludingRetries,
586    ttftMs,
587    usage,
588    attempt,
589    messageCount,
590    messageTokens,
591    requestId,
592    stopReason,
593    didFallBackToNonStreaming,
594    querySource,
595    headers,
596    costUSD,
597    queryTracking,
598    permissionMode,
599    newMessages,
600    llmSpan,
601    globalCacheStrategy,
602    requestSetupMs,
603    attemptStartTimes,
604    fastMode,
605    previousRequestId,
606    betas,
607  }: {
608    model: string
609    preNormalizedModel: string
610    start: number
611    startIncludingRetries: number
612    ttftMs: number | null
613    usage: NonNullableUsage
614    attempt: number
615    messageCount: number
616    messageTokens: number
617    requestId: string | null
618    stopReason: BetaStopReason | null
619    didFallBackToNonStreaming: boolean
620    querySource: string
621    headers?: globalThis.Headers
622    costUSD: number
623    queryTracking?: QueryChainTracking
624    permissionMode?: PermissionMode
625    /** Assistant messages from the response - used to extract model_output and thinking_output
626     *  when beta tracing is enabled */
627    newMessages?: AssistantMessage[]
628    /** The span from startLLMRequestSpan - pass this to correctly match responses to requests */
629    llmSpan?: Span
630    /** Strategy used for global prompt caching: 'tool_based', 'system_prompt', or 'none' */
631    globalCacheStrategy?: GlobalCacheStrategy
632    /** Time spent in pre-request setup before the successful attempt */
633    requestSetupMs?: number
634    /** Timestamps (Date.now()) of each attempt start — used for retry sub-spans in Perfetto */
635    attemptStartTimes?: number[]
636    fastMode?: boolean
637    /** Request ID from the previous API call in this session */
638    previousRequestId?: string | null
639    betas?: string[]
640  }): void {
641    const gateway = detectGateway({
642      headers,
643      baseUrl: process.env.ANTHROPIC_BASE_URL,
644    })
645  
646    let textContentLength: number | undefined
647    let thinkingContentLength: number | undefined
648    let toolUseContentLengths: Record<string, number> | undefined
649    let connectorTextBlockCount: number | undefined
650  
651    if (newMessages) {
652      let textLen = 0
653      let thinkingLen = 0
654      let hasToolUse = false
655      const toolLengths: Record<string, number> = {}
656      let connectorCount = 0
657  
658      for (const msg of newMessages) {
659        for (const block of msg.message.content) {
660          if (block.type === 'text') {
661            textLen += block.text.length
662          } else if (feature('CONNECTOR_TEXT') && isConnectorTextBlock(block)) {
663            connectorCount++
664          } else if (block.type === 'thinking') {
665            thinkingLen += block.thinking.length
666          } else if (
667            block.type === 'tool_use' ||
668            block.type === 'server_tool_use' ||
669            block.type === 'mcp_tool_use'
670          ) {
671            const inputLen = jsonStringify(block.input).length
672            const sanitizedName = sanitizeToolNameForAnalytics(block.name)
673            toolLengths[sanitizedName] =
674              (toolLengths[sanitizedName] ?? 0) + inputLen
675            hasToolUse = true
676          }
677        }
678      }
679  
680      textContentLength = textLen
681      thinkingContentLength = thinkingLen > 0 ? thinkingLen : undefined
682      toolUseContentLengths = hasToolUse ? toolLengths : undefined
683      connectorTextBlockCount = connectorCount > 0 ? connectorCount : undefined
684    }
685  
686    const durationMs = Date.now() - start
687    const durationMsIncludingRetries = Date.now() - startIncludingRetries
688    addToTotalDurationState(durationMsIncludingRetries, durationMs)
689  
690    logAPISuccess({
691      model,
692      preNormalizedModel,
693      messageCount,
694      messageTokens,
695      usage,
696      durationMs,
697      durationMsIncludingRetries,
698      attempt,
699      ttftMs,
700      requestId,
701      stopReason,
702      costUSD,
703      didFallBackToNonStreaming,
704      querySource,
705      gateway,
706      queryTracking,
707      permissionMode,
708      globalCacheStrategy,
709      textContentLength,
710      thinkingContentLength,
711      toolUseContentLengths,
712      connectorTextBlockCount,
713      fastMode,
714      previousRequestId,
715      betas,
716    })
717    // Log API request event for OTLP
718    void logOTelEvent('api_request', {
719      model,
720      input_tokens: String(usage.input_tokens),
721      output_tokens: String(usage.output_tokens),
722      cache_read_tokens: String(usage.cache_read_input_tokens),
723      cache_creation_tokens: String(usage.cache_creation_input_tokens),
724      cost_usd: String(costUSD),
725      duration_ms: String(durationMs),
726      speed: fastMode ? 'fast' : 'normal',
727    })
728  
729    // Extract model output, thinking output, and tool call flag when beta tracing is enabled
730    let modelOutput: string | undefined
731    let thinkingOutput: string | undefined
732    let hasToolCall: boolean | undefined
733  
734    if (isBetaTracingEnabled() && newMessages) {
735      // Model output - visible to all users
736      modelOutput =
737        newMessages
738          .flatMap(m =>
739            m.message.content
740              .filter(c => c.type === 'text')
741              .map(c => (c as { type: 'text'; text: string }).text),
742          )
743          .join('\n') || undefined
744  
745      // Thinking output - Ant-only (build-time gated)
746      if (process.env.USER_TYPE === 'ant') {
747        thinkingOutput =
748          newMessages
749            .flatMap(m =>
750              m.message.content
751                .filter(c => c.type === 'thinking')
752                .map(c => (c as { type: 'thinking'; thinking: string }).thinking),
753            )
754            .join('\n') || undefined
755      }
756  
757      // Check if any tool_use blocks were in the output
758      hasToolCall = newMessages.some(m =>
759        m.message.content.some(c => c.type === 'tool_use'),
760      )
761    }
762  
763    // Pass the span to correctly match responses to requests when beta tracing is enabled
764    endLLMRequestSpan(llmSpan, {
765      success: true,
766      inputTokens: usage.input_tokens,
767      outputTokens: usage.output_tokens,
768      cacheReadTokens: usage.cache_read_input_tokens,
769      cacheCreationTokens: usage.cache_creation_input_tokens,
770      attempt,
771      modelOutput,
772      thinkingOutput,
773      hasToolCall,
774      ttftMs: ttftMs ?? undefined,
775      requestSetupMs,
776      attemptStartTimes,
777    })
778  
779    // Log first successful message for teleported sessions (reliability tracking)
780    const teleportInfo = getTeleportedSessionInfo()
781    if (teleportInfo?.isTeleported && !teleportInfo.hasLoggedFirstMessage) {
782      logEvent('tengu_teleport_first_message_success', {
783        session_id:
784          teleportInfo.sessionId as AnalyticsMetadata_I_VERIFIED_THIS_IS_NOT_CODE_OR_FILEPATHS,
785      })
786      markFirstTeleportMessageLogged()
787    }
788  }