feat: add plot studio timing observability

Author: Wing900

frontend/src/studio/hooks/use-studio-session.test.tsx

@@ -1,5 +1,7 @@
+import type { ReactNode } from 'react'
 import { act, renderHook } from '@testing-library/react'
 import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest'
+import { I18nProvider } from '../../i18n'
 import { useStudioSession } from './use-studio-session'
 import { createStudioSession, getPendingStudioPermissions, getStudioSessionSnapshot } from '../api/studio-agent-api'
 import type { StudioPermissionRequest, StudioSession, StudioSessionSnapshot } from '../protocol/studio-agent-types'
@@ -28,6 +30,10 @@ const mockedCreateStudioSession = vi.mocked(createStudioSession)
 const mockedGetPendingStudioPermissions = vi.mocked(getPendingStudioPermissions)
 const mockedGetStudioSessionSnapshot = vi.mocked(getStudioSessionSnapshot)
 
+function wrapper({ children }: { children: ReactNode }) {
+  return <I18nProvider>{children}</I18nProvider>
+}
+
 function createSession(id = 'session-1'): StudioSession {
   const now = '2026-03-22T00:00:00.000Z'
   return {
@@ -90,7 +96,7 @@ describe('useStudioSession', () => {
     mockedGetPendingStudioPermissions.mockResolvedValue([createPermission(session.id)])
     mockedGetStudioSessionSnapshot.mockResolvedValue(createSnapshot(session, 'running'))
 
-    const { result } = renderHook(() => useStudioSession())
+    const { result } = renderHook(() => useStudioSession(), { wrapper })
 
     await act(async () => {
       await Promise.resolve()
@@ -114,7 +120,7 @@ describe('useStudioSession', () => {
     mockedCreateStudioSession.mockResolvedValue(session)
     mockedGetStudioSessionSnapshot.mockResolvedValue(createSnapshot(session))
 
-    const { result } = renderHook(() => useStudioSession())
+    const { result } = renderHook(() => useStudioSession(), { wrapper })
 
     await act(async () => {
       await Promise.resolve()

src/routes/studio-agent.route.ts

@@ -15,6 +15,7 @@ import {
 } from './helpers/studio-agent-run-request'
 import { ensureDefaultStudioWorkspaceExists } from '../studio-agent/workspace/default-studio-workspace'
 import { createLogger } from '../utils/logger'
+import { logPlotStudioTiming, readElapsedMs } from '../studio-agent/observability/plot-studio-timing'
 
 const router = express.Router()
 const logger = createLogger('StudioAgentRoute')
@@ -119,25 +120,13 @@ router.get('/studio-agent/works/:sessionId', authMiddleware, asyncHandler(async
 }))
 
 router.get('/studio-agent/events', authMiddleware, asyncHandler(async (req, res) => {
-  logger.info('Studio SSE client connected', {
-    ip: req.ip,
-    userAgent: req.get('user-agent') ?? '',
-  })
   res.setHeader('Content-Type', 'text/event-stream')
   res.setHeader('Cache-Control', 'no-cache, no-transform')
   res.setHeader('Connection', 'keep-alive')
   res.flushHeaders?.()
 
   const backlog = studioRuntime.listExternalEvents()
   for (const event of backlog) {
-    logger.info('Writing backlog SSE event', {
-      type: event.type,
-      sessionId: (event.properties as { sessionId?: string; sessionID?: string; run?: { sessionId?: string } })?.sessionId
-        ?? (event.properties as { sessionID?: string })?.sessionID
-        ?? (event.properties as { run?: { sessionId?: string } })?.run?.sessionId
-        ?? null,
-      runId: (event.properties as { runId?: string })?.runId ?? null,
-    })
     res.write(`event: ${event.type}\n`)
     res.write(`data: ${JSON.stringify(event)}\n\n`)
   }
@@ -148,14 +137,6 @@ router.get('/studio-agent/events', authMiddleware, asyncHandler(async (req, res)
   }, 15000)
 
   const unsubscribe = studioRuntime.subscribeExternalEvents((event) => {
-    logger.info('Writing live SSE event', {
-      type: event.type,
-      sessionId: (event.properties as { sessionId?: string; sessionID?: string; run?: { sessionId?: string } })?.sessionId
-        ?? (event.properties as { sessionID?: string })?.sessionID
-        ?? (event.properties as { run?: { sessionId?: string } })?.run?.sessionId
-        ?? null,
-      runId: (event.properties as { runId?: string })?.runId ?? null,
-    })
     res.write(`event: ${event.type}\n`)
     res.write(`data: ${JSON.stringify(event)}\n\n`)
   })
@@ -164,17 +145,14 @@ router.get('/studio-agent/events', authMiddleware, asyncHandler(async (req, res)
   res.write(`data: ${JSON.stringify({ type: 'studio.connected', properties: { timestamp: Date.now() } })}\n\n`)
 
   req.on('close', () => {
-    logger.info('Studio SSE client disconnected', {
-      ip: req.ip,
-      userAgent: req.get('user-agent') ?? '',
-    })
     clearInterval(heartbeat)
     unsubscribe()
     res.end()
   })
 }))
 
 router.post('/studio-agent/runs', authMiddleware, asyncHandler(async (req, res) => {
+  const requestStartedAt = Date.now()
   const parsed = parseStudioCreateRunRequest(req.body)
   const sessionId = parsed.sessionId
   const inputText = parsed.inputText
@@ -189,19 +167,15 @@ router.post('/studio-agent/runs', authMiddleware, asyncHandler(async (req, res)
     return sendStudioError(res, 404, 'NOT_FOUND', 'Session not found', { sessionId })
   }
 
-  logger.info('Studio run requested', {
+  logPlotStudioTiming(session.studioKind, 'http.run.requested', {
     sessionId,
     projectId,
-    agent: session.agentType,
-    studioKind: session.studioKind,
-    inputPreview: summarizeInput(inputText),
     inputLength: inputText.length,
     hasCustomApiConfig: Boolean(
       parsed.customApiConfig?.apiUrl?.trim()
       && parsed.customApiConfig?.apiKey?.trim()
       && parsed.customApiConfig?.model?.trim()
     ),
-    toolChoice: parsed.toolChoice ?? null,
   })
 
   const started = await studioRuntime.startRun({
@@ -221,10 +195,11 @@ router.post('/studio-agent/runs', authMiddleware, asyncHandler(async (req, res)
     })
   }
 
-  logger.info('Studio run started', {
+  logPlotStudioTiming(session.studioKind, 'http.run.accepted', {
     sessionId,
     runId: started.run.id,
     assistantMessageId: started.assistantMessage.id,
+    durationMs: readElapsedMs(requestStartedAt),
   })
 
   await studioRuntime.syncSession(session.id)
@@ -352,8 +327,3 @@ router.post('/studio-agent/permissions/reply', authMiddleware, replyPermissionHa
 router.post('/studio-agent/permissions/:requestID/reply', authMiddleware, replyPermissionHandler)
 
 export default router
-
-function summarizeInput(inputText: string): string {
-  const normalized = inputText.replace(/\s+/g, ' ').trim()
-  return normalized.length > 120 ? `${normalized.slice(0, 117)}...` : normalized
-}

src/studio-agent/observability/plot-studio-timing.ts

@@ -0,0 +1,37 @@
+import { createLogger } from '../../utils/logger'
+
+const logger = createLogger('PlotStudioTiming')
+
+export function isPlotStudioKind(studioKind?: string | null): boolean {
+  return studioKind === 'plot'
+}
+
+export function logPlotStudioTiming(
+  studioKind: string | null | undefined,
+  event: string,
+  data: Record<string, unknown>,
+  level: 'info' | 'warn' = 'info'
+): void {
+  if (!isPlotStudioKind(studioKind)) {
+    return
+  }
+
+  logger[level](event, data)
+}
+
+export function readElapsedMs(startedAt: number): number {
+  return Math.max(0, Date.now() - startedAt)
+}
+
+export function readRunElapsedMs(run: { createdAt?: string }): number | null {
+  if (!run.createdAt) {
+    return null
+  }
+
+  const createdAt = new Date(run.createdAt).getTime()
+  if (!Number.isFinite(createdAt)) {
+    return null
+  }
+
+  return Math.max(0, Date.now() - createdAt)
+}

src/studio-agent/orchestration/studio-execution-policy.ts

@@ -26,7 +26,7 @@ const MANIM_POLICY: StudioExecutionPolicy = {
     'Before rendering, make sure the target Manim code exists in the workspace or is fully prepared in the render request.',
     'If the requested scene flow, assets, render mode, or target file is ambiguous, ask before rendering.'
   ],
-  builderContinueText: 'I will continue the current Manim Studio subagent work first.',
+  builderContinueText: '延续当前正在进行的子代理工作。',
   builderTaskIntentText: (subagentType, skillName) => {
     const skillSegment = skillName ? ` using skill "${skillName}"` : ''
     return `I will hand this off to the ${subagentType} subagent${skillSegment}.`
@@ -38,8 +38,8 @@ const MANIM_POLICY: StudioExecutionPolicy = {
       : 'This input did not trigger an automatic planning path in Manim Studio.'
   ),
   builderReminderTexts: {
-    runningWork: (title) => `There is still in-progress work in this session: ${title}`,
-    failedRender: 'The most recent render failed. Check the failure details before attempting another render.',
+    runningWork: (title) => `当前会话存在进行中的 Work：${title}`,
+    failedRender: '最近一次 render 结果失败，请先确认失败原因再尝试。',
     unsupportedTools: (toolNames) => `Automatic planning does not cover these requested tools yet: ${toolNames.join(', ')}.`,
     pendingEvents: (summaries) => `Pending backend updates: ${summaries.join(' | ')}`
   },
@@ -58,7 +58,7 @@ const PLOT_POLICY: StudioExecutionPolicy = {
     'Before rendering, make sure the target matplotlib code exists in the workspace or is fully prepared in the render request.',
     'If the chart type, data source, subplot layout, axes, labels, or output target is ambiguous, ask before rendering.'
   ],
-  builderContinueText: 'I will continue the current Plot Studio subagent work first.',
+  builderContinueText: '延续当前正在进行的子代理工作。',
   builderTaskIntentText: (subagentType, skillName) => {
     const skillSegment = skillName ? ` using skill "${skillName}"` : ''
     return `I will hand this off to the ${subagentType} subagent${skillSegment}.`
@@ -70,8 +70,8 @@ const PLOT_POLICY: StudioExecutionPolicy = {
       : 'This input did not trigger an automatic planning path in Plot Studio.'
   ),
   builderReminderTexts: {
-    runningWork: (title) => `There is still in-progress work in this session: ${title}`,
-    failedRender: 'The most recent plot render failed. Check the failure details before attempting another render.',
+    runningWork: (title) => `当前会话存在进行中的 Work：${title}`,
+    failedRender: '最近一次 render 结果失败，请先确认失败原因再尝试。',
     unsupportedTools: (toolNames) => `Automatic planning does not cover these requested tools yet: ${toolNames.join(', ')}.`,
     pendingEvents: (summaries) => `Pending backend updates: ${summaries.join(' | ')}`
   },
@@ -84,3 +84,6 @@ const PLOT_POLICY: StudioExecutionPolicy = {
 export function getStudioExecutionPolicy(studioKind: StudioKind = 'manim'): StudioExecutionPolicy {
   return studioKind === 'plot' ? PLOT_POLICY : MANIM_POLICY
 }
+
+
+

src/studio-agent/orchestration/studio-message-history.ts

@@ -1,12 +1,9 @@
 import type OpenAI from 'openai'
 import type { StudioAssistantMessage, StudioMessage, StudioToolPart } from '../domain/types'
-import { createLogger } from '../../utils/logger'
 import {
-  summarizeConversationMessageForDebug,
   type StudioStoredAssistantPayload,
   type StudioStoredAssistantToolCall,
 } from './studio-provider-message'
-const logger = createLogger('StudioMessageHistory')
 
 export function buildStudioConversationMessages(input: {
   messages: StudioMessage[]
@@ -37,12 +34,6 @@ function toConversationMessages(message: StudioMessage): OpenAI.Chat.Completions
       ...toolMessages
     ]
 
-    logger.info('Rehydrating stored assistant provider payload', {
-      messageId: message.id,
-      sessionId: message.sessionId,
-      conversationMessages: conversationMessages.map((item) => summarizeConversationMessageForDebug(item)),
-    })
-
     return conversationMessages
   }