{"record":{"id":"5fba99241a5f589a","repo":"tinyhumansai/openhuman","slug":"skill-latency-tool-chain-on-thread-event-threa","errorCode":null,"errorMessage":"[skill-latency] tool chain on thread ${event.thread_id} took ${latency.elapsedMs}ms across ${latency.toolCount} tool(s) — exceeds the ${SKILL_TOOL_CHAIN_TARGET_MS}ms target","messagePattern":"\\[skill-latency\\] tool chain on thread (.+?) took (.+?)ms across (.+?) tool\\(s\\) — exceeds the (.+?)ms target","errorType":"console","errorClass":null,"httpStatus":null,"severity":"error","filePath":"app/src/providers/ChatRuntimeProvider.tsx","lineNumber":1106,"sourceCode":"          output_tokens: event.total_output_tokens,\n        });\n\n        // Close the tool-chain latency window and surface overruns of the 60s\n        // target (#4273, AC3). Observability only — never blocks the turn.\n        const latency = skillLatencyRef.current.finishChain(\n          segmentDeliveryKey(event.thread_id, event.request_id),\n          { ok: true }\n        );\n        if (latency) {\n          rtLog('skill_tool_chain_latency', {\n            thread: event.thread_id,\n            request: event.request_id,\n            elapsed_ms: latency.elapsedMs,\n            tools: latency.toolCount,\n            within_target: latency.withinTarget ? 'true' : 'false',\n          });\n          if (!latency.withinTarget) {\n            console.warn(\n              `[skill-latency] tool chain on thread ${event.thread_id} took ${latency.elapsedMs}ms ` +\n                `across ${latency.toolCount} tool(s) — exceeds the ${SKILL_TOOL_CHAIN_TARGET_MS}ms target`\n            );\n          }\n        }\n\n        // Parallel (forked) turn: resolve only its own lane. The primary turn's\n        // stream / status / lifecycle / active marker may still be running, so\n        // we must NOT clear them here. Segmented parallel turns already\n        // persisted via `onSegment` (keyed by thread+request); a single-bubble\n        // parallel turn persists its full response now.\n        if (\n          event.request_id !== undefined &&\n          store.getState().chatRuntime.parallelRequestThreads[event.request_id] !== undefined\n        ) {\n          const parallelRequestId = event.request_id;\n          dispatch(recordChatTurnUsage(chatTurnUsagePayload(event)));\n          if (!event.segment_total && event.full_response.length > 0) {","sourceCodeStart":1088,"sourceCodeEnd":1124,"githubUrl":"https://github.com/tinyhumansai/openhuman/blob/749120085864ce16e0f273c7b86fac7740b39c5b/app/src/providers/ChatRuntimeProvider.tsx#L1088-L1124","documentation":"Observability-only log from ChatRuntimeProvider (#4273 AC3): finishChain closed the per-turn tool-chain latency window and the elapsed time from first tool to last tool across toolCount calls exceeded SKILL_TOOL_CHAIN_TARGET_MS (60s). Nothing fails or blocks — the turn completes; the log exists to track skill/tool-chain latency regressions against the target.","triggerScenarios":"Thrown at app/src/providers/ChatRuntimeProvider.tsx:1106 when the library encounters an invalid state.","commonSituations":"See trigger scenarios.","solutions":["Inspect which tools dominated the chain (pair with per-tool timing events on the same thread/request)","Treat as a performance signal: long-running tools (shell, generation) or retry loops are usual culprits","File/tune the specific slow tool rather than acting on the aggregate alone"],"exampleFix":null,"handlingStrategy":"fallback","validationCode":null,"typeGuard":null,"tryCatchPattern":null,"preventionTips":[],"tags":[],"backgroundTag":null,"analyzedSha":"749120085864ce16e0f273c7b86fac7740b39c5b","analyzedAt":"2026-08-17T21:21:45.363Z","contentChangedAt":null,"schemaVersion":2},"datasetVersion":"2026-09-14T05:17:10.506Z"}