From 3b9490e3fb126d0efb1c929acdc42b1b620a1840 Mon Sep 17 00:00:00 2001 From: KiriAky 107 Date: Sun, 6 Sep 2026 16:26:17 +0800 Subject: [PATCH] fix: stabilize background operations and large embedding results --- .gitignore | 1 + README.md | 1 + backend/app/agent/async_trace.py | 51 ++ backend/app/agent/runtime.py | 205 +++-- backend/app/agent/trace_repository.py | 41 +- backend/app/contracts.py | 5 + backend/app/errors.py | 4 + backend/app/local_models/protocol.py | 11 + backend/app/local_models/runtime.py | 17 +- backend/app/local_models/worker.py | 4 +- backend/app/log_routes.py | 11 + backend/app/main.py | 36 + backend/app/operation_logs.py | 186 +++++ backend/app/retrieval/activity.py | 30 + backend/app/retrieval/engine.py | 2 + backend/app/retrieval/routed_vectors.py | 3 + backend/app/routes.py | 21 +- backend/app/services/index_service.py | 29 +- backend/app/services/model_diagnostics.py | 7 + backend/app/services/task_service.py | 29 + backend/app/services/usage_service.py | 5 + backend/scripts/agent-task-stress.py | 250 +++++++ backend/scripts/task-http-stress.py | 96 +++ backend/tests/test_agent_core.py | 7 +- backend/tests/test_index_activity.py | 68 ++ backend/tests/test_local_models.py | 36 + backend/tests/test_operation_logs.py | 151 ++++ docs/README.md | 2 + docs/contracts/后端接口契约-开发版.md | 11 + docs/development/Agent与任务压测报告.md | 156 ++++ .../2026-09-06-agent-task-backend-fixed.json | 230 ++++++ .../2026-09-06-agent-task-backend.json | 230 ++++++ .../performance/2026-09-06-agent-task-ui.json | 706 ++++++++++++++++++ .../2026-09-06-agent-trace-ui-fixed.json | 156 ++++ .../2026-09-06-scroll-theme-comparison.json | 150 ++++ .../2026-09-06-scroll-token-cache.json | 66 ++ .../2026-09-06-task-http-fixed.json | 36 + .../performance/2026-09-06-task-http.json | 36 + .../performance/2026-09-06-task-ui-fixed.json | 70 ++ .../development/后台运行日志与压力问题修复.md | 101 +++ docs/development/长文渲染优化与压测报告.md | 31 + .../src/assets/themes/paper-moments.theme | 12 +- frontend/src/components/common/AppShell.vue | 5 +- .../src/components/common/PrimarySidebar.vue | 3 +- frontend/src/components/common/StatusBar.vue | 8 +- frontend/src/contracts/index.ts | 10 + frontend/src/features/agent/RunListPanel.vue | 9 +- .../src/features/agent/TraceTimeline.spec.ts | 11 + frontend/src/features/agent/TraceTimeline.vue | 36 +- .../editor/VisualMarkdownEditor.spec.ts | 16 + .../features/editor/VisualMarkdownEditor.vue | 5 +- .../features/editor/linkNavigation.spec.ts | 33 + .../src/features/editor/linkNavigation.ts | 20 + .../features/editor/shikiCodeMirror.spec.ts | 28 +- .../src/features/editor/shikiCodeMirror.ts | 22 +- frontend/src/features/logs/LogsView.spec.ts | 65 ++ frontend/src/features/logs/LogsView.vue | 117 +++ .../features/settings/SettingsView.spec.ts | 25 + .../src/features/settings/SettingsView.vue | 27 +- frontend/src/features/tasks/TasksView.vue | 10 +- .../src/features/themes/ThemesView.spec.ts | 4 +- frontend/src/features/vault/VaultEntry.vue | 3 +- frontend/src/router/index.ts | 2 + frontend/src/services/indexService.ts | 5 + frontend/src/stores/agent.ts | 17 +- frontend/src/stores/listPagination.spec.ts | 29 + frontend/src/stores/settings.ts | 12 +- frontend/src/stores/task.ts | 17 +- frontend/tests/performance/README.md | 12 + frontend/tests/performance/agent-task.html | 98 +++ frontend/tests/performance/logs.html | 31 + frontend/tests/performance/run-stress.py | 6 +- frontend/tests/performance/stress.html | 10 +- 73 files changed, 3847 insertions(+), 149 deletions(-) create mode 100644 backend/app/agent/async_trace.py create mode 100644 backend/app/local_models/protocol.py create mode 100644 backend/app/log_routes.py create mode 100644 backend/app/operation_logs.py create mode 100644 backend/app/retrieval/activity.py create mode 100644 backend/scripts/agent-task-stress.py create mode 100644 backend/scripts/task-http-stress.py create mode 100644 backend/tests/test_index_activity.py create mode 100644 backend/tests/test_operation_logs.py create mode 100644 docs/development/Agent与任务压测报告.md create mode 100644 docs/development/performance/2026-09-06-agent-task-backend-fixed.json create mode 100644 docs/development/performance/2026-09-06-agent-task-backend.json create mode 100644 docs/development/performance/2026-09-06-agent-task-ui.json create mode 100644 docs/development/performance/2026-09-06-agent-trace-ui-fixed.json create mode 100644 docs/development/performance/2026-09-06-scroll-theme-comparison.json create mode 100644 docs/development/performance/2026-09-06-scroll-token-cache.json create mode 100644 docs/development/performance/2026-09-06-task-http-fixed.json create mode 100644 docs/development/performance/2026-09-06-task-http.json create mode 100644 docs/development/performance/2026-09-06-task-ui-fixed.json create mode 100644 docs/development/后台运行日志与压力问题修复.md create mode 100644 frontend/src/features/editor/linkNavigation.spec.ts create mode 100644 frontend/src/features/editor/linkNavigation.ts create mode 100644 frontend/src/features/logs/LogsView.spec.ts create mode 100644 frontend/src/features/logs/LogsView.vue create mode 100644 frontend/src/stores/listPagination.spec.ts create mode 100644 frontend/tests/performance/agent-task.html create mode 100644 frontend/tests/performance/logs.html diff --git a/.gitignore b/.gitignore index 5639423..b89ebd6 100644 --- a/.gitignore +++ b/.gitignore @@ -18,6 +18,7 @@ backend/.env # 运行期生成的 SQLite 索引（vault 下的 Markdown 测试数据需提交） backend/data/*.db* backend/data/credentials/ +backend/data/logs/ # 阶段验收笔记（验收用，不提交） backend/data/vault/验收/ # 本机 MCP 配置、授权状态及服务器工作目录不得提交。 diff --git a/README.md b/README.md index e10d989..d3d3c9a 100644 --- a/README.md +++ b/README.md @@ -26,6 +26,7 @@ NotesAgent/ - 多模态：API 优先，未配置或响应无效时回退本地；`local_only` 禁止远程调用。任务、修订、事件、来源和回退原因写入 SQLite。 - 模型运行：默认 CPU，可选 CUDA 12.8 组件；固定模型 revision，按需启动独立子进程，交互检索优先排队，CUDA 初始化或显存失败时用同一冻结配置在 CPU 重试一次。 - 可观测性：输入、输出、缓存命中、推理 Token 与音频用量卡片；本地运行诊断保留最近 200 条，不保存正文、文件路径、密钥或异常全文。 +- 运行日志：统一查看向量/模型错误、Agent、任务与 HTTP 操作；独立后台存储最近 20,000 条，支持错误码/关联 ID 筛选和游标分页。入口无需打开 Vault，详见 [后台运行日志与压力问题修复](docs/development/后台运行日志与压力问题修复.md)。 - 界面偏好：设置页可即时切换全局中文/英文界面，并控制由系统词典提供的编辑器拼写检查；偏好目前保存于 Web 端设备配置，后续由 Tauri 配置存储接管。 ## 第二阶段最新合并（2026-09-06） diff --git a/backend/app/agent/async_trace.py b/backend/app/agent/async_trace.py new file mode 100644 index 0000000..3020ef4 --- /dev/null +++ b/backend/app/agent/async_trace.py @@ -0,0 +1,51 @@ +"""Serialize and batch durable Trace writes off the asyncio event loop.""" +import asyncio +from contextvars import copy_context + + +class AsyncTraceWriter: + def __init__(self, repository): + self.repository = repository + self.queue = asyncio.Queue(maxsize=1024) + self.worker = None + + async def submit(self, operation, *args): + future = asyncio.get_running_loop().create_future() + await self.queue.put((operation, args, future)) + if self.worker is None or self.worker.done(): + self.worker = asyncio.create_task(self._drain()) + # Cancellation must not let an older snapshot commit after cancellation. + cancelled = False + while not future.done(): + try: + await asyncio.shield(future) + except asyncio.CancelledError: + cancelled = True + future.result() + return cancelled + + async def _drain(self): + while not self.queue.empty(): + batch = [] + while len(batch) < 64 and not self.queue.empty(): + batch.append(self.queue.get_nowait()) + try: + work = asyncio.get_running_loop().run_in_executor( + None, copy_context().run, self.repository.write_batch, [(op, args) for op, args, _ in batch]) + # asyncio.run/shutdown may cancel every Task simultaneously. The + # executor Future survives; finish it and release all waiters. + while not work.done(): + try: + await asyncio.shield(work) + except asyncio.CancelledError: + pass + work.result() + except Exception as exc: + for _, _, future in batch: + future.set_exception(exc) + else: + for _, _, future in batch: + future.set_result(None) + finally: + for _ in batch: + self.queue.task_done() diff --git a/backend/app/agent/runtime.py b/backend/app/agent/runtime.py index eb7fd03..09f3934 100644 --- a/backend/app/agent/runtime.py +++ b/backend/app/agent/runtime.py @@ -4,6 +4,8 @@ from __future__ import annotations import asyncio import json +from app.agent.async_trace import AsyncTraceWriter +from app.operation_logs import log_event, agent_run_id from collections.abc import AsyncIterator from dataclasses import dataclass, field from datetime import datetime, timezone @@ -65,6 +67,9 @@ class RunRecord: subscribers: set[asyncio.Queue[AgentEvent]] = field(default_factory=set) task: asyncio.Task[None] | None = None next_sequence: int = 0 + publish_lock: asyncio.Lock = field(default_factory=asyncio.Lock) + cancel_lock: asyncio.Lock = field(default_factory=asyncio.Lock) + persisted_run: AgentRun | None = None class AgentRuntime: @@ -84,6 +89,7 @@ class AgentRuntime: self.skills = skills self.trace_repository = trace_repository or AgentTraceRepository() self._records: dict[str, RunRecord] = {} + self._writer = AsyncTraceWriter(self.trace_repository) async def create_run(self, request: AgentRunCreateRequest) -> AgentRun: self._prune_records() @@ -122,19 +128,25 @@ class AgentRuntime: skill_config=skill_config, allowed_tools=allowed_tools, ) - self.trace_repository.create_run( - run, - request, - self._config_snapshot(record), - ) + # Reserve capacity before yielding to concurrent creators. self._records[run.run_id] = record + try: + cancelled = await self._writer.submit('create', run.model_copy(deep=True), request.model_copy(deep=True), self._config_snapshot(record)) + except BaseException: + self._records.pop(run.run_id, None) + raise + record.persisted_run = run.model_copy(deep=True) + log_event('agent', 'run.created', run_id=run.run_id, provider_id=run.provider_id, model=run.model) + if cancelled: + await self._finish_cancelled(record) + raise asyncio.CancelledError record.task = asyncio.create_task(self._execute(record), name=run.run_id) return run.model_copy(deep=True) def get_run(self, run_id: str) -> AgentRun: record = self._records.get(run_id) if record is not None: - return record.run.model_copy(deep=True) + return (record.persisted_run or record.run).model_copy(deep=True) run = self.trace_repository.recover_interrupted(run_id) if run is None: raise AgentRunNotFoundError(run_id) @@ -145,7 +157,7 @@ class AgentRuntime: recovered = [ self.trace_repository.recover_interrupted(item.run_id) or item if item.run_id not in self._records - else self._records[item.run_id].run.model_copy(deep=True) + else (self._records[item.run_id].persisted_run or self._records[item.run_id].run).model_copy(deep=True) for item in items ] return recovered, total @@ -154,25 +166,24 @@ class AgentRuntime: record = self._records.get(run_id) if record is None: return self.get_run(run_id) - if record.run.status in TERMINAL_STATUSES: - return record.run.model_copy(deep=True) - record.run.cancelled = True - record.run.status = AgentRunStatus.cancelled - record.run.updated_at = datetime.now(timezone.utc) - self.permissions.cancel_run(run_id) - self._publish(record, AgentEventType.run_cancelled, {}) - if record.task and not record.task.done(): - record.task.cancel() - return record.run.model_copy(deep=True) + async with record.cancel_lock: + if record.task and not record.task.done(): + if record.run.status not in TERMINAL_STATUSES: + record.task.cancel() + self.permissions.cancel_run(run_id) + await asyncio.gather(record.task, return_exceptions=True) + if record.run.status not in TERMINAL_STATUSES: + await self._finish_cancelled(record) + return (record.persisted_run or record.run).model_copy(deep=True) - def resolve_permission(self, run_id: str, request_id: str, decision: str) -> bool: + async def resolve_permission(self, run_id: str, request_id: str, decision: str) -> bool: record = self._records.get(run_id) if record is None: return False ticket = self.permissions.get_ticket(run_id, request_id) resolved = self.permissions.resolve(run_id, request_id, decision) if resolved: - self._publish( + await self._publish( record, AgentEventType.permission_resolved, { @@ -189,23 +200,24 @@ class AgentRuntime: record = self._records.get(run_id) run = self.get_run(run_id) if record is None: - for event in self.trace_repository.list_events( + for event in await asyncio.to_thread(self.trace_repository.list_events, run_id, after_sequence=after_sequence ): yield event return - # 先注册订阅再读持久化历史；同一事件循环内没有 await，不会丢失交界事件。 + # 先注册再异步读取历史；历史与实时队列的交界用 sequence 去重。 queue: asyncio.Queue[AgentEvent] = asyncio.Queue() record.subscribers.add(queue) - history = self.trace_repository.list_events( - run_id, after_sequence=after_sequence - ) last_sequence = after_sequence try: + history = await asyncio.to_thread(self.trace_repository.list_events, + run_id, after_sequence=after_sequence) for event in history: last_sequence = event.sequence yield event + if event.event in {AgentEventType.run_completed, AgentEventType.run_failed, AgentEventType.run_cancelled}: + return if run.status in TERMINAL_STATUSES: return while True: @@ -232,7 +244,7 @@ class AgentRuntime: await asyncio.shield(record.task) except asyncio.CancelledError: pass - return record.run.model_copy(deep=True) + return (record.persisted_run or record.run).model_copy(deep=True) def get_trace( self, run_id: str, *, after_sequence: int, limit: int @@ -246,23 +258,35 @@ class AgentRuntime: return trace async def _execute(self, record: RunRecord) -> None: + token = agent_run_id.set(record.run.run_id) try: async with asyncio.timeout(record.request.run_timeout_seconds): await self._run_loop(record) except asyncio.CancelledError: if record.run.status != AgentRunStatus.cancelled: - self._finish_cancelled(record) + await self._finish_cancelled(record) except TimeoutError: - self._fail(record, "AGENT_TIMEOUT", "Agent run exceeded its timeout.") + await self._fail(record, "AGENT_TIMEOUT", "Agent run exceeded its timeout.") except ProviderError as exc: - self._fail(record, exc.code, exc.message) + await self._fail(record, exc.code, exc.message) except Exception as exc: - self._fail(record, "AGENT_FAILED", str(exc)) + log_event('agent', 'execution.failed', level='ERROR', error=exc, run_id=record.run.run_id) + await self._fail(record, "AGENT_FAILED", str(exc)) + finally: + self.permissions.cancel_run(record.run.run_id) + agent_run_id.reset(token) + + async def shutdown(self) -> None: + results = await asyncio.gather(*(self.cancel(run_id) for run_id in list(self._records)), return_exceptions=True) + for result in results: + if isinstance(result, BaseException): + log_event('agent', 'shutdown.failed', level='ERROR', error=result) + await self._writer.queue.join() async def _run_loop(self, record: RunRecord) -> None: record.run.status = AgentRunStatus.running record.run.updated_at = datetime.now(timezone.utc) - self._publish( + await self._publish( record, AgentEventType.run_started, {"provider_id": record.request.provider_id, "model": record.request.model}, @@ -277,7 +301,7 @@ class AgentRuntime: record.run.updated_at = datetime.now(timezone.utc) model_call_id = f"model_call_{uuid4().hex}" started_at = perf_counter() - self._publish( + await self._publish( record, AgentEventType.model_call_started, { @@ -299,7 +323,7 @@ class AgentRuntime: ) ) except Exception as exc: - self._publish( + await self._publish( record, AgentEventType.model_call_failed, { @@ -309,7 +333,7 @@ class AgentRuntime: }, ) raise - self._publish( + await self._publish( record, AgentEventType.model_call_completed, { @@ -322,7 +346,7 @@ class AgentRuntime: }, ) record.run.token_usage += turn.input_tokens + turn.output_tokens - self._publish( + await self._publish( record, AgentEventType.usage, {"token_usage": record.run.token_usage}, @@ -331,12 +355,12 @@ class AgentRuntime: record.request.token_budget is not None and record.run.token_usage > record.request.token_budget ): - self._fail(record, "TOKEN_BUDGET_EXCEEDED", "Agent token budget exceeded.") + await self._fail(record, "TOKEN_BUDGET_EXCEEDED", "Agent token budget exceeded.") return if turn.tool_calls: if len(turn.tool_calls) > MAX_TOOL_CALLS_PER_TURN: - self._fail( + await self._fail( record, "TOO_MANY_TOOL_CALLS", f"Provider requested more than {MAX_TOOL_CALLS_PER_TURN} tools in one turn.", @@ -360,10 +384,17 @@ class AgentRuntime: async with semaphore: return await self._execute_tool(record, call, model_call_id) - results = await asyncio.gather(*(execute(call) for call in calls)) + executions = [asyncio.create_task(execute(call)) for call in calls] + try: + results = await asyncio.gather(*executions) + finally: + for execution in executions: + if not execution.done(): + execution.cancel() + await asyncio.gather(*executions, return_exceptions=True) for call, result in zip(calls, results): record.run.tool_results.append(result) - self._collect_citations(record, result) + await self._collect_citations(record, result) messages.append( Message( role=MessageRole.tool, @@ -376,20 +407,20 @@ class AgentRuntime: if turn.text is not None: record.run.output = turn.text - self._publish(record, AgentEventType.text_delta, {"text": turn.text}) + await self._publish(record, AgentEventType.text_delta, {"text": turn.text}) record.run.status = AgentRunStatus.completed record.run.updated_at = datetime.now(timezone.utc) - self._publish( + await self._publish( record, AgentEventType.run_completed, {"output": turn.text, "token_usage": record.run.token_usage}, ) return - self._fail(record, "EMPTY_MODEL_RESPONSE", "Provider returned no text or tool call.") + await self._fail(record, "EMPTY_MODEL_RESPONSE", "Provider returned no text or tool call.") return - self._fail(record, "MAX_STEPS_EXCEEDED", "Agent reached its maximum step count.") + await self._fail(record, "MAX_STEPS_EXCEEDED", "Agent reached its maximum step count.") async def _execute_tool( self, record: RunRecord, call: ToolCall, parent_model_call_id: str @@ -397,7 +428,7 @@ class AgentRuntime: started_at = perf_counter() call_data = call.model_dump(mode="json") call_data["parent_model_call_id"] = parent_model_call_id - self._publish(record, AgentEventType.tool_call, call_data) + await self._publish(record, AgentEventType.tool_call, call_data) try: registered = self.tools.get(call.name) except ToolNotFoundError: @@ -411,7 +442,7 @@ class AgentRuntime: error_code="TOOL_NOT_ALLOWED", error_message="Tool is not included in allowed_tools.", ) - self._publish_tool_result( + await self._publish_tool_result( record, result, parent_model_call_id, started_at ) return result @@ -425,7 +456,7 @@ class AgentRuntime: error_code="NETWORK_NOT_ALLOWED", error_message="Agent run does not allow network tools.", ) - self._publish_tool_result( + await self._publish_tool_result( record, result, parent_model_call_id, started_at ) return result @@ -436,7 +467,7 @@ class AgentRuntime: # 运行状态必须在等待期间可见，前端才能展示并处理权限确认卡片。 ticket = self.permissions.create_ticket(record.run.run_id, permission) record.run.status = AgentRunStatus.waiting_permission - self._publish( + await self._publish( record, AgentEventType.permission_required, { @@ -458,13 +489,18 @@ class AgentRuntime: error_code="PERMISSION_TIMEOUT", error_message="Tool permission confirmation timed out.", ) - self._publish_tool_result( + await self._publish_tool_result( record, result, parent_model_call_id, started_at ) return result record.run.status = AgentRunStatus.running record.run.updated_at = datetime.now(timezone.utc) - self.trace_repository.save_run(record.run) + async with record.publish_lock: + snapshot = record.run.model_copy(deep=True) + cancelled = await self._writer.submit('save', snapshot) + record.persisted_run = snapshot + if cancelled: + raise asyncio.CancelledError result = ( await self._invoke_tool(record, call) if decision in {"allow_once", "allow_session"} @@ -473,10 +509,10 @@ class AgentRuntime: else: result = await self._invoke_tool(record, call) - self._publish_tool_result(record, result, parent_model_call_id, started_at) + await self._publish_tool_result(record, result, parent_model_call_id, started_at) return result - def _publish_tool_result( + async def _publish_tool_result( self, record: RunRecord, result: ToolResult, @@ -486,7 +522,7 @@ class AgentRuntime: data = result.model_dump(mode="json") data["parent_model_call_id"] = parent_model_call_id data["duration_ms"] = int((perf_counter() - started_at) * 1000) - self._publish(record, AgentEventType.tool_result, data) + await self._publish(record, AgentEventType.tool_result, data) async def _invoke_tool(self, record: RunRecord, call: ToolCall) -> ToolResult: try: @@ -519,45 +555,60 @@ class AgentRuntime: error_message="Tool permission was denied.", ) - def _finish_cancelled(self, record: RunRecord) -> None: + async def _finish_cancelled(self, record: RunRecord) -> None: record.run.cancelled = True record.run.status = AgentRunStatus.cancelled record.run.updated_at = datetime.now(timezone.utc) - self._publish(record, AgentEventType.run_cancelled, {}) + await self._publish(record, AgentEventType.run_cancelled, {}) - def _fail(self, record: RunRecord, code: str, message: str) -> None: - if record.run.status in TERMINAL_STATUSES: + async def _fail(self, record: RunRecord, code: str, message: str) -> None: + log_event('agent', 'run.error', level='ERROR', run_id=record.run.run_id, error_code=code) + if record.persisted_run and record.persisted_run.status in TERMINAL_STATUSES: return record.run.status = AgentRunStatus.failed record.run.error_code = code record.run.error_message = message record.run.updated_at = datetime.now(timezone.utc) - self._publish( + await self._publish( record, AgentEventType.run_failed, {"code": code, "message": message}, ) - def _publish( + async def _publish( self, record: RunRecord, event_type: AgentEventType, data: dict[str, object] ) -> None: - sanitized = sanitize_trace_value(data) - assert isinstance(sanitized, dict) - event = AgentEvent( - event=event_type, - run_id=record.run.run_id, - sequence=record.next_sequence, - data=sanitized, - timestamp=datetime.now(timezone.utc), - ) - record.next_sequence += 1 - record.events.append(event) - self.trace_repository.append_event(record.run, event) - # 内存只保留实时订阅窗口；完整审计轨迹由 SQLite 保存。 - if len(record.events) > MAX_EVENTS_PER_RUN: - del record.events[: len(record.events) - MAX_EVENTS_PER_RUN] - for queue in record.subscribers: - queue.put_nowait(event) + async with record.publish_lock: + sanitized = sanitize_trace_value(data) + assert isinstance(sanitized, dict) + event = AgentEvent( + event=event_type, + run_id=record.run.run_id, + sequence=record.next_sequence, + data=sanitized, + timestamp=datetime.now(timezone.utc), + ) + snapshot = record.run.model_copy(deep=True) + try: + cancelled = await self._writer.submit('event', snapshot, event) + except Exception as exc: + log_event('agent', 'trace.write_failed', level='ERROR', error=exc, run_id=record.run.run_id) + raise + record.next_sequence += 1 + record.persisted_run = snapshot + record.events.append(event) + log_event('agent', event_type.value, + level='ERROR' if event_type.value.endswith('Failed') or data.get('success') is False else 'INFO', + run_id=record.run.run_id, provider_id=record.run.provider_id, model=record.run.model, + sequence=event.sequence, step=record.run.current_step, status=snapshot.status.value, + tool=data.get('name'), error_code=data.get('code') or data.get('error_code')) + # 内存只保留实时订阅窗口；完整审计轨迹由 SQLite 保存。 + if len(record.events) > MAX_EVENTS_PER_RUN: + del record.events[: len(record.events) - MAX_EVENTS_PER_RUN] + for queue in record.subscribers: + queue.put_nowait(event) + if cancelled: + raise asyncio.CancelledError @staticmethod def _request_metadata(record: RunRecord) -> dict[str, object]: @@ -583,7 +634,7 @@ class AgentRuntime: "metadata": record.request.metadata, } - def _collect_citations(self, record: RunRecord, result: ToolResult) -> None: + async def _collect_citations(self, record: RunRecord, result: ToolResult) -> None: if not result.success or not isinstance(result.output, dict): return items = result.output.get("items") @@ -601,7 +652,7 @@ class AgentRuntime: continue known.add(citation.citation_id) record.run.citations.append(citation) - self._publish(record, AgentEventType.citation, citation.model_dump(mode="json")) + await self._publish(record, AgentEventType.citation, citation.model_dump(mode="json")) def _get_record(self, run_id: str) -> RunRecord: try: @@ -618,7 +669,7 @@ class AgentRuntime: ( record for record in self._records.values() - if record.run.status in TERMINAL_STATUSES + if record.run.status in TERMINAL_STATUSES and (record.task is None or record.task.done()) ), key=lambda record: record.run.updated_at, ) diff --git a/backend/app/agent/trace_repository.py b/backend/app/agent/trace_repository.py index e09759a..4ce3c20 100644 --- a/backend/app/agent/trace_repository.py +++ b/backend/app/agent/trace_repository.py @@ -6,6 +6,7 @@ SQLite 中的事件是 SSE、前端 Trace 和 Benchmark 的共同事实来源。 from __future__ import annotations +from contextlib import nullcontext import json import re from datetime import datetime, timezone @@ -94,15 +95,30 @@ def sanitize_trace_value( class AgentTraceRepository: + def write_batch(self, jobs): + conn = connect() + try: + with transaction(conn): + for operation, args in jobs: + if operation == 'create': + self.create_run(*args, _conn=conn) + elif operation == 'save': + self.save_run(*args, _conn=conn) + else: + self.append_event(*args, _conn=conn) + finally: + conn.close() + def create_run( self, run: AgentRun, request: AgentRunCreateRequest, config_snapshot: dict[str, Any], + *, _conn=None, ) -> None: - conn = connect() + conn = _conn or connect() try: - with transaction(conn): + with transaction(conn) if _conn is None else nullcontext(): conn.execute( """ INSERT INTO agent_runs( @@ -126,22 +142,24 @@ class AgentTraceRepository: ), ) finally: - conn.close() + if _conn is None: + conn.close() - def save_run(self, run: AgentRun) -> None: - conn = connect() + def save_run(self, run: AgentRun, *, _conn=None) -> None: + conn = _conn or connect() try: - with transaction(conn): + with transaction(conn) if _conn is None else nullcontext(): self._update_run(conn, run) finally: - conn.close() + if _conn is None: + conn.close() - def append_event(self, run: AgentRun, event: AgentEvent) -> None: + def append_event(self, run: AgentRun, event: AgentEvent, *, _conn=None) -> None: """在同一事务中保存最新 Run 和事件；复写同一序号时保持幂等。""" - conn = connect() + conn = _conn or connect() try: - with transaction(conn): + with transaction(conn) if _conn is None else nullcontext(): self._update_run(conn, run) conn.execute( """ @@ -158,7 +176,8 @@ class AgentTraceRepository: ), ) finally: - conn.close() + if _conn is None: + conn.close() def get_run(self, run_id: str) -> AgentRun | None: conn = connect() diff --git a/backend/app/contracts.py b/backend/app/contracts.py index fa8913c..2cc66b1 100644 --- a/backend/app/contracts.py +++ b/backend/app/contracts.py @@ -1132,6 +1132,11 @@ class TranscriptNoteRequest(Contract): class IndexStatus(Contract): + running_jobs: int = 0 + active_searches: int = 0 + completed_searches: int = 0 + failed_searches: int = 0 + cancelled_searches: int = 0 vector_refresh_required: bool = False total_notes: int = 0 total_blocks: int = 0 diff --git a/backend/app/errors.py b/backend/app/errors.py index d0c0f38..b49783b 100644 --- a/backend/app/errors.py +++ b/backend/app/errors.py @@ -25,6 +25,10 @@ class ApiError(Exception): async def api_error_handler(_: Request, exc: ApiError) -> JSONResponse: + from app.operation_logs import log_event + log_event('api', 'operation.failed', level='ERROR' if exc.status_code >= 500 else 'WARNING', + error=exc, status=exc.status_code, + **{key: value for key, value in exc.details.items() if key in {'run_id', 'task_id', 'note_id', 'job_id', 'provider_id'}}) body = ErrorResponse( error=ErrorDetail(code=exc.code, message=exc.message, details=exc.details) ) diff --git a/backend/app/local_models/protocol.py b/backend/app/local_models/protocol.py new file mode 100644 index 0000000..ed4bb35 --- /dev/null +++ b/backend/app/local_models/protocol.py @@ -0,0 +1,11 @@ +"""Bound embedding result frames so large notes do not exceed pipe line limits.""" +import json + + +def response_lines(response, operation): + if operation == 'embedding' and 'result' in response and 'error_code' not in response: + vectors = response['result'] + for offset in range(0, len(vectors), 128): + yield json.dumps({'embedding_offset': offset, 'embedding_chunk': vectors[offset:offset + 128]}, allow_nan=False) + '\n' + response = {**response, 'result': [], 'embedding_count': len(vectors)} + yield json.dumps(response, ensure_ascii=False, allow_nan=False) + '\n' diff --git a/backend/app/local_models/runtime.py b/backend/app/local_models/runtime.py index 62edf73..7bcb7e2 100644 --- a/backend/app/local_models/runtime.py +++ b/backend/app/local_models/runtime.py @@ -189,15 +189,30 @@ class Runtime: await process.stdin.drain() process.stdin.close() final = None + vectors = [] while line := await process.stdout.readline(): message = json.loads(line) - if "progress" in message: + if "embedding_chunk" in message: + chunk = message['embedding_chunk'] + if (operation != 'embedding' or not isinstance(chunk, list) + or message.get('embedding_offset') != len(vectors) + or len(vectors) + len(chunk) > len(payload.get('texts', []))): + raise ProviderError('LOCAL_MODEL_INVALID_RESPONSE', '本地向量传输顺序或数量无效。') + vectors.extend(chunk) + elif "progress" in message: callback = runtime_progress.get() if callback: callback(message) else: final = message await process.wait() + if isinstance(final, dict) and 'embedding_count' in final: + if (final['embedding_count'] != len(vectors) + or len(vectors) != len(payload.get('texts', []))): + raise ProviderError('LOCAL_MODEL_INVALID_RESPONSE', '本地向量传输不完整。') + final['result'] = vectors + elif vectors: + raise ProviderError('LOCAL_MODEL_INVALID_RESPONSE', '本地向量传输缺少结束标记。') return final try: result = await asyncio.wait_for(receive(), config.timeout_seconds) diff --git a/backend/app/local_models/worker.py b/backend/app/local_models/worker.py index a60151d..d9d7930 100644 --- a/backend/app/local_models/worker.py +++ b/backend/app/local_models/worker.py @@ -216,4 +216,6 @@ if __name__ == "__main__": response = {"error_code": "LOCAL_INFERENCE_FAILED", "message": "本地推理失败，请检查媒体格式、模型和设备配置。"} if "error_code" in response: response["diagnostics"] = {"requested_device": request["config"]["device"], "actual_device": request.get("_actual_device", "unknown")} - sys.stdout.buffer.write((json.dumps(response, ensure_ascii=False, allow_nan=False) + "\n").encode("utf-8")) + from protocol import response_lines + for line in response_lines(response, request['operation']): + sys.stdout.buffer.write(line.encode('utf-8')) diff --git a/backend/app/log_routes.py b/backend/app/log_routes.py new file mode 100644 index 0000000..3fd42a6 --- /dev/null +++ b/backend/app/log_routes.py @@ -0,0 +1,11 @@ +from fastapi import APIRouter, Query +from app.operation_logs import get_store + +router = APIRouter(prefix='/api/logs', tags=['Diagnostics']) + + +@router.get('') +def list_logs(limit: int = Query(50, ge=1, le=200), before: int | None = Query(None, ge=1), + level: str = Query('', pattern='^(|INFO|WARNING|ERROR|CRITICAL)$'), + source: str = Query('', max_length=100), q: str = Query('', max_length=200)): + return get_store().query(limit=limit, before=before, level=level, source=source, q=q) diff --git a/backend/app/main.py b/backend/app/main.py index 8320078..c47593e 100644 --- a/backend/app/main.py +++ b/backend/app/main.py @@ -1,4 +1,7 @@ from contextlib import asynccontextmanager +import asyncio +from time import perf_counter +from uuid import uuid4 from fastapi import FastAPI from fastapi.exceptions import RequestValidationError @@ -14,17 +17,22 @@ from app.local_model_routes import router as local_model_router from app.usage_routes import router as usage_router from app.provider_preview_routes import router as provider_preview_router from app.schemas import HealthResponse, ServiceStatusResponse +from app.log_routes import router as log_router +from app.operation_logs import install_logging, log_event, request_id, shutdown_logging settings = get_settings() @asynccontextmanager async def lifespan(_: FastAPI): + install_logging() + log_event('system', 'service.started') from app.services import transcription_service transcription_service.recover_interrupted() try: yield finally: + await container.agent.shutdown() from app.services import index_service await index_service.shutdown() await transcription_service.shutdown() @@ -35,6 +43,8 @@ async def lifespan(_: FastAPI): await manager.cancel_download(key) container.plugins.shutdown() container.mcp_servers.shutdown() + log_event('system', 'service.stopped') + await asyncio.to_thread(shutdown_logging) app = FastAPI( @@ -60,6 +70,32 @@ app.include_router(media_router) app.include_router(local_model_router) app.include_router(usage_router) app.include_router(provider_preview_router) +app.include_router(log_router) + + +@app.middleware('http') +async def operation_log(request, call_next): + token = request_id.set(uuid4().hex) + started = perf_counter() + status = 500 + failure = None + try: + response = await call_next(request) + status = response.status_code + response.headers['X-Request-ID'] = request_id.get() + return response + except Exception as exc: + failure = exc + raise + finally: + # Do not record query strings, request/response bodies or arbitrary URLs. + route = getattr(request.scope.get('route'), 'path', 'unmatched') + if not route.startswith('/api/logs') and (request.method not in {'GET', 'HEAD', 'OPTIONS'} or status >= 400 or perf_counter() - started > 1): + log_event('http', 'request.finished', level='ERROR' if status >= 500 else 'WARNING' if status >= 400 else 'INFO', + error=failure, method=request.method, route=route, status=status, + duration_ms=round((perf_counter() - started) * 1000, 2), + **{k: v for k, v in request.path_params.items() if k in {'run_id', 'task_id', 'note_id', 'job_id', 'provider_id'}}) + request_id.reset(token) @app.get("/health", response_model=HealthResponse, tags=["System"]) diff --git a/backend/app/operation_logs.py b/backend/app/operation_logs.py new file mode 100644 index 0000000..50af308 --- /dev/null +++ b/backend/app/operation_logs.py @@ -0,0 +1,186 @@ +"""Bounded, asynchronous operational diagnostics, separate from business/Trace data. + +Only explicitly allowed metadata is stored. Never store prompts, tool arguments, +provider response bodies or raw exception messages in this diagnostic channel. +""" +from __future__ import annotations + +import json +import logging +import math +import queue +import re +import sqlite3 +import threading +import traceback +from contextvars import ContextVar +from contextlib import closing +from datetime import datetime, timezone +from pathlib import Path + +from app.config import get_settings + +request_id: ContextVar[str] = ContextVar('log_request_id', default='') +agent_run_id: ContextVar[str] = ContextVar('log_agent_run_id', default='') +_allowed = {'run_id', 'task_id', 'note_id', 'job_id', 'provider_id', 'model', + 'device', 'error_code', 'error_type', 'status', 'duration_ms', 'count', + 'step', 'sequence', 'tool', 'method', 'route', 'request_id', 'fallback', + 'frames', 'source', 'changed_fields'} +_safe = re.compile(r'[^\w .:/@{}\[\],()=+\-]', re.UNICODE) + + +def metadata(values: dict) -> dict: + result = {} + for key, value in values.items(): + if key not in _allowed or value is None: + continue + if isinstance(value, (int, float, bool)): + if not isinstance(value, float) or math.isfinite(value): + result[key] = value + else: + text = str(value) + text = re.sub(r'(?i)(?:bearer\s+\S+|sk-[\w-]+)', '[REDACTED]', text) + result[key] = _safe.sub('', text)[:500] + return result + + +class LogStore: + def __init__(self, path: Path, *, retain: int = 20_000): + self.path = path + self.retain = retain + self.queue: queue.Queue = queue.Queue(maxsize=4096) + self.dropped = 0 + self.failed = 0 + self.closed = False + self.state_lock = threading.Lock() + self.thread = threading.Thread(target=self._write, name='operation-logs', daemon=True) + path.parent.mkdir(parents=True, exist_ok=True) + with closing(self._connect()) as conn, conn: + conn.execute('CREATE TABLE IF NOT EXISTS logs (id INTEGER PRIMARY KEY, timestamp TEXT NOT NULL, level TEXT NOT NULL, source TEXT NOT NULL, event TEXT NOT NULL, details TEXT NOT NULL)') + conn.execute('CREATE INDEX IF NOT EXISTS logs_level_id ON logs(level, id)') + conn.execute('CREATE INDEX IF NOT EXISTS logs_source_id ON logs(source, id)') + self.thread.start() + + def _connect(self): + conn = sqlite3.connect(self.path, timeout=5) + conn.row_factory = sqlite3.Row + return conn + + def emit(self, level: str, source: str, event: str, details: dict): + row = (datetime.now(timezone.utc).isoformat(), level, source[:100], event[:160], json.dumps(metadata(details), ensure_ascii=False)) + with self.state_lock: + if self.closed: + return + try: + self.queue.put_nowait(row) + except queue.Full: + self.dropped += 1 + + def _write(self): + while True: + first = self.queue.get() + batch = [first] + while len(batch) < 128: + try: + batch.append(self.queue.get_nowait()) + except queue.Empty: + break + stop = None in batch + rows = [row for row in batch if row is not None] + try: + if rows: + with closing(self._connect()) as conn, conn: + conn.executemany('INSERT INTO logs(timestamp,level,source,event,details) VALUES(?,?,?,?,?)', rows) + conn.execute('DELETE FROM logs WHERE id <= (SELECT id FROM logs ORDER BY id DESC LIMIT 1 OFFSET ?)', (self.retain,)) + except Exception: + self.failed += len(rows) + finally: + for _ in batch: + self.queue.task_done() + if stop: + return + + def query(self, *, limit=50, before=None, level='', source='', q=''): + clauses, args = [], [] + for column, value in [('level', level), ('source', source)]: + if value: + clauses.append(f'{column} = ?') + args.append(value) + if before is not None: + clauses.append('id < ?') + args.append(before) + if q: + clauses.append('(instr(event, ?) > 0 OR instr(details, ?) > 0)') + args += [q, q] + where = ' WHERE ' + ' AND '.join(clauses) if clauses else '' + with closing(self._connect()) as conn, conn: + rows = conn.execute('SELECT * FROM logs' + where + ' ORDER BY id DESC LIMIT ?', (*args, limit + 1)).fetchall() + sources = [row[0] for row in conn.execute('SELECT DISTINCT source FROM logs ORDER BY source')] + items = [{**dict(row), 'details': json.loads(row['details'])} for row in rows[:limit]] + return {'items': items, 'next_cursor': items[-1]['id'] if len(rows) > limit else None, + 'sources': sources, 'pending': self.queue.qsize(), 'dropped': self.dropped, + 'write_failures': self.failed, 'retention': self.retain} + + def close(self): + with self.state_lock: + if self.closed: + return + self.closed = True + self.queue.put(None) + self.thread.join(timeout=15) + + +_store: LogStore | None = None +_lock = threading.Lock() + + +def get_store() -> LogStore: + global _store + path = get_settings().data_dir / 'logs' / 'operations.sqlite3' + with _lock: + if _store is None or _store.path != path or _store.closed: + if _store is not None and not _store.closed: + _store.close() + _store = LogStore(path) + return _store + + +def log_event(module: str, event: str, *, level='INFO', error: BaseException | None = None, **details): + if request_id.get(): + details.setdefault('request_id', request_id.get()) + if agent_run_id.get(): + details.setdefault('run_id', agent_run_id.get()) + if error: + details['error_type'] = type(error).__name__ + details.setdefault('error_code', getattr(error, 'code', None)) + details['frames'] = '; '.join(f'{Path(f.filename).name}:{f.lineno}:{f.name}' for f in traceback.extract_tb(error.__traceback__)[-8:]) + try: + get_store().emit(level, module, event, details) + except Exception: + # Logging must not turn a successful save/run into a business failure. + logging.getLogger('operation_log_storage').error('Operational log storage unavailable') + + +class ApplicationLogHandler(logging.Handler): + def emit(self, record): + if record.name == 'operation_log_storage' or getattr(record, '_notes_operation_logged', False): + return + record._notes_operation_logged = True + # Legacy log messages can include note text/credentials, even in f-strings. + # Preserve source location and error class; structured call sites carry IDs. + log_event(record.name, 'application.warning' if record.levelno < 40 else 'application.error', + level=record.levelname, error=record.exc_info[1] if record.exc_info else None, + frames=f'{Path(record.pathname).name}:{record.lineno}:{record.funcName}') + + +def install_logging(): + # Uvicorn's default logger stops propagation before the root logger. + for name in ('', 'uvicorn'): + logger = logging.getLogger(name) + if not any(isinstance(h, ApplicationLogHandler) for h in logger.handlers): + logger.addHandler(ApplicationLogHandler(level=logging.WARNING)) + + +def shutdown_logging(): + if _store is not None and not _store.closed: + _store.close() diff --git a/backend/app/retrieval/activity.py b/backend/app/retrieval/activity.py new file mode 100644 index 0000000..dcd050a --- /dev/null +++ b/backend/app/retrieval/activity.py @@ -0,0 +1,30 @@ +"""Process-local retrieval activity, shared by search, RAG and Agent callers.""" +import asyncio +from functools import wraps + +active = 0 +completed = 0 +failed = 0 +cancelled = 0 + + +def track_search(operation): + @wraps(operation) + async def wrapped(self, request): + global active, completed, failed, cancelled + if request.mode == 'fts': + return await operation(self, request) + active += 1 + try: + result = await operation(self, request) + completed += 1 + return result + except asyncio.CancelledError: + cancelled += 1 + raise + except Exception: + failed += 1 + raise + finally: + active -= 1 + return wrapped diff --git a/backend/app/retrieval/engine.py b/backend/app/retrieval/engine.py index 50dce34..cc6f0e5 100644 --- a/backend/app/retrieval/engine.py +++ b/backend/app/retrieval/engine.py @@ -10,6 +10,7 @@ from __future__ import annotations from datetime import datetime, timezone from app import repository +from app.retrieval.activity import track_search from app.contracts import ( Citation, PageMeta, @@ -52,6 +53,7 @@ class RetrievalEngine: # remain authoritative, including monkeypatches on the singleton. self._routed_defaults = (embedding, vector_store) if route_embeddings else None + @track_search async def search(self, request: SearchRequest) -> SearchResponse: if request.mode == SearchMode.fts: return self._search_fts(request) diff --git a/backend/app/retrieval/routed_vectors.py b/backend/app/retrieval/routed_vectors.py index f259d3a..73901c9 100644 --- a/backend/app/retrieval/routed_vectors.py +++ b/backend/app/retrieval/routed_vectors.py @@ -20,6 +20,7 @@ from typing import Protocol from app.database.db import connect, transaction from app.errors import ApiError +from app.operation_logs import log_event from app.retrieval.vectorstore import VectorHit from app.retrieval.provenance import record_embedding from app.retrieval.hybrid import rrf_fuse @@ -101,6 +102,8 @@ async def embed_remote(texts: list[str], *, accept_local=False, strict=False, lo source=result.source, ) except Exception as exc: + log_event('vectors', 'embedding.failed', level='ERROR' if strict else 'WARNING', error=exc, + count=len(texts), fallback='none' if strict else 'local_index') # Avoid logging provider exceptions containing credentials or note text. record_embedding(fallback_reason="REMOTE_EMBEDDING_UNAVAILABLE") logger.warning("Remote embedding unavailable (%s); using local index", type(exc).__name__) diff --git a/backend/app/routes.py b/backend/app/routes.py index 2fee500..8ae1e73 100644 --- a/backend/app/routes.py +++ b/backend/app/routes.py @@ -11,6 +11,7 @@ from fastapi.responses import StreamingResponse from app.agent import AgentCapacityError, AgentRunNotFoundError from app.container import container from app.config import get_settings +from app.operation_logs import log_event from app.extensions.archive import MAX_ZIP_BYTES, install_zip from app.services.persona_settings import PersonaSettings, load_persona, save_persona from app.contracts import ( @@ -455,11 +456,15 @@ async def chat(request: ChatRequest) -> StreamingResponse: usage = {"input_tokens": input_tokens, "output_tokens": output_tokens, "total_tokens": input_tokens + output_tokens} elif event.event == ModelEventType.error: + log_event('chat', 'model.error', level='ERROR', provider_id=request.provider_id, + model=request.model, error_code=event.data.get('code')) if assistant_content: assistant_content += "\n\n" assistant_content += str(event.data.get("message", "Model generation failed.")) yield as_sse(event.event.value, event.model_dump_json()) except Exception as exc: + log_event('chat', 'chat.failed', level='ERROR', error=exc, + provider_id=request.provider_id, model=request.model) failure_message = exc.message if isinstance(exc, ApiError) else "知识库检索或模型生成失败，请检查服务状态。" if assistant_content: assistant_content += "\n\n" @@ -498,7 +503,7 @@ async def chat(request: ChatRequest) -> StreamingResponse: async def list_agent_runs( limit: int = Query(default=50, ge=1, le=100), offset: int = Query(default=0, ge=0) ) -> AgentRunListResponse: - items, total = container.agent.list_runs(limit=limit, offset=offset) + items, total = await asyncio.to_thread(container.agent.list_runs, limit=limit, offset=offset) return AgentRunListResponse( items=items, page=PageMeta(total=total, limit=limit, offset=offset), @@ -603,7 +608,7 @@ async def get_agent_trace( limit: int = Query(default=200, ge=1, le=500), ) -> AgentTraceResponse: try: - return container.agent.get_trace( + return await asyncio.to_thread(container.agent.get_trace, run_id, after_sequence=after_sequence, limit=limit ) except AgentRunNotFoundError as exc: @@ -624,7 +629,7 @@ async def decide_agent_permission( run_id: str, request_id: str, request: PermissionDecisionRequest ) -> OperationResponse: agent_run_or_404(run_id) - if not container.agent.resolve_permission(run_id, request_id, request.decision): + if not await container.agent.resolve_permission(run_id, request_id, request.decision): raise ApiError( 404, "PERMISSION_REQUEST_NOT_FOUND", @@ -1223,7 +1228,7 @@ async def test_provider(request: ProviderTestRequest) -> ProviderTestResponse: async def list_tasks( limit: int = Query(default=50, ge=1, le=100), offset: int = Query(default=0, ge=0) ) -> TaskListResponse: - items, total = task_service.list_tasks(limit=limit, offset=offset) + items, total = await asyncio.to_thread(task_service.list_tasks, limit=limit, offset=offset) return TaskListResponse( items=items, page=PageMeta(total=total, limit=limit, offset=offset) ) @@ -1231,12 +1236,12 @@ async def list_tasks( @router.post("/tasks", response_model=Task, tags=["Tasks"]) async def create_task(request: TaskCreateRequest) -> Task: - return task_service.create_task(**request.model_dump()) + return await task_service.write_in_background(task_service.create_task, **request.model_dump()) @router.get("/tasks/{task_id}", response_model=Task, tags=["Tasks"]) async def get_task(task_id: str) -> Task: - task = task_service.get_task(task_id) + task = await asyncio.to_thread(task_service.get_task, task_id) if task is None: raise ApiError( 404, "RESOURCE_NOT_FOUND", "task not found", {"task_id": task_id} @@ -1246,7 +1251,7 @@ async def get_task(task_id: str) -> Task: @router.patch("/tasks/{task_id}", response_model=Task, tags=["Tasks"]) async def update_task(task_id: str, request: TaskUpdateRequest) -> Task: - return task_service.update_task(task_id, request.model_dump(exclude_unset=True)) + return await task_service.write_in_background(task_service.update_task, task_id, request.model_dump(exclude_unset=True)) @router.delete( @@ -1255,7 +1260,7 @@ async def update_task(task_id: str, request: TaskUpdateRequest) -> Task: tags=["Tasks"], ) async def delete_task(task_id: str) -> OperationResponse: - if not task_service.delete_task(task_id): + if not await task_service.write_in_background(task_service.delete_task, task_id): raise ApiError( 404, "RESOURCE_NOT_FOUND", "task not found", {"task_id": task_id} ) diff --git a/backend/app/services/index_service.py b/backend/app/services/index_service.py index 947153d..55cd592 100644 --- a/backend/app/services/index_service.py +++ b/backend/app/services/index_service.py @@ -4,6 +4,7 @@ from __future__ import annotations import asyncio import logging +from app.operation_logs import log_event from datetime import datetime, timezone from pathlib import Path @@ -25,6 +26,7 @@ vector_store = SqliteVecStore() _jobs: dict[str, IndexJob] = {} _active_job_id: str | None = None +_active_scope: str | None = None _last_completed_at: datetime | None = None _last_error: str | None = None MAX_JOBS = 100 @@ -33,6 +35,7 @@ _logger = logging.getLogger(__name__) def _remember_job(job: IndexJob) -> None: + log_event('vectors', 'index.' + job.status, job_id=job.job_id, status=job.status) _jobs[job.job_id] = job while len(_jobs) > MAX_JOBS: oldest = next(iter(_jobs)) @@ -64,7 +67,7 @@ def _scan_vault() -> list[tuple[str, str, str, datetime, datetime]]: async def rebuild(request: IndexRebuildRequest) -> IndexJob: - global _active_job_id, _last_completed_at, _last_error + global _active_job_id, _active_scope, _last_completed_at, _last_error if _active_job_id is not None: raise ApiError(409, "INDEX_BUSY", "索引正在后台计算，请稍后重试。") job_id = "job_" + uuid4().hex[:12] @@ -82,6 +85,7 @@ async def rebuild(request: IndexRebuildRequest) -> IndexJob: saved_paths = {record.file_path: record for record in saved_records.values() if record is not None} _active_job_id = job_id + _active_scope = 'all' _last_error = None _remember_job(IndexJob( job_id=job_id, status="running", scope=request.scope, @@ -148,6 +152,7 @@ async def rebuild(request: IndexRebuildRequest) -> IndexJob: finally: conn.close() except BaseException as exc: + log_event('vectors', 'index.failed', level='WARNING' if isinstance(exc, asyncio.CancelledError) else 'ERROR', error=exc, job_id=job_id) _remember_job(IndexJob( job_id=job_id, status="failed", scope=request.scope, created_at=datetime.now(timezone.utc), @@ -156,6 +161,7 @@ async def rebuild(request: IndexRebuildRequest) -> IndexJob: raise finally: _active_job_id = None + _active_scope = None job = IndexJob(job_id=job_id, status="completed", scope=request.scope, created_at=datetime.now(timezone.utc)) _remember_job(job) @@ -166,16 +172,26 @@ async def rebuild(request: IndexRebuildRequest) -> IndexJob: def get_status() -> IndexStatus: + from app.retrieval import activity counts = repository.stats() - vector_refresh_required = repository.get_index_meta().get('workspace_vectors_pending') == '1' or bool(_pending_notes()) + workspace_pending = repository.get_index_meta().get('workspace_vectors_pending') == '1' + notes_pending = len(_pending_notes()) + vector_refresh_required = workspace_pending or bool(notes_pending) + running = int(_active_job_id is not None) + # An entire-vault rebuild is one job, not one job per block/note. + pending = 1 if running and _active_scope == 'all' else (1 + running if workspace_pending else max(notes_pending, running)) + activity_fields = dict(running_jobs=running, active_searches=activity.active, + completed_searches=activity.completed, failed_searches=activity.failed, + cancelled_searches=activity.cancelled) if _active_job_id is not None: - return IndexStatus(status="running", pending_jobs=0, active_job_id=_active_job_id, vector_refresh_required=vector_refresh_required, + return IndexStatus(**activity_fields, status="running", pending_jobs=pending, active_job_id=_active_job_id, vector_refresh_required=vector_refresh_required, total_notes=counts["notes"], total_blocks=counts["blocks"]) return IndexStatus( + **activity_fields, vector_refresh_required=vector_refresh_required, total_notes=counts["notes"], total_blocks=counts["blocks"], status="failed" if _last_error else "idle", - pending_jobs=0, + pending_jobs=pending, last_completed_at=_last_completed_at, error_message=_last_error, ) @@ -227,7 +243,7 @@ def _pending_notes() -> list[str]: async def _refresh_saved_note(note_id: str) -> None: - global _active_job_id, _last_error, _last_completed_at + global _active_job_id, _active_scope, _last_error, _last_completed_at record = repository.get_note_record(note_id) key = f'note_vectors_pending:{note_id}' if record is None: @@ -240,6 +256,7 @@ async def _refresh_saved_note(note_id: str) -> None: parsed.title = record.title job_id = 'job_' + uuid4().hex[:12] _active_job_id = job_id + _active_scope = 'note' _last_error = None _remember_job(IndexJob(job_id=job_id, status='running', scope='all', created_at=datetime.now(timezone.utc))) try: @@ -267,8 +284,10 @@ async def _refresh_saved_note(note_id: str) -> None: _last_completed_at = datetime.now(timezone.utc) _remember_job(IndexJob(job_id=job_id, status='completed', scope='all', created_at=_last_completed_at)) except BaseException as exc: + log_event('vectors', 'index.failed', level='WARNING' if isinstance(exc, asyncio.CancelledError) else 'ERROR', error=exc, job_id=job_id) _last_error = str(exc) or '后台向量计算已中断，笔记已保存。' _remember_job(IndexJob(job_id=job_id, status='failed', scope='all', created_at=datetime.now(timezone.utc))) raise finally: _active_job_id = None + _active_scope = None diff --git a/backend/app/services/model_diagnostics.py b/backend/app/services/model_diagnostics.py index 3accbaf..4662724 100644 --- a/backend/app/services/model_diagnostics.py +++ b/backend/app/services/model_diagnostics.py @@ -19,6 +19,13 @@ def connection(): def record(**values): + from app.operation_logs import log_event + log_event('models', 'model.' + str(values.get('operation', 'inference')), + level='ERROR' if values.get('status') == 'failed' else 'WARNING' if values.get('status') == 'fallback' else 'INFO', + model=values.get('model'), source=values.get('source'), status=values.get('status'), + device=values.get('actual_device') or values.get('attempted_device'), + error_code=values.get('error_code'), fallback=values.get('fallback_reason'), + duration_ms=round(values.get('elapsed_seconds', 0) * 1000, 2)) safe = {key: value[:240] for key, value in values.items() if key in TEXT and isinstance(value, str)} safe.update({key: value for key, value in values.items() if key in NUMBERS and type(value) in (float, int) and math.isfinite(value) and value >= 0}) diff --git a/backend/app/services/task_service.py b/backend/app/services/task_service.py index c38f5cf..830acb4 100644 --- a/backend/app/services/task_service.py +++ b/backend/app/services/task_service.py @@ -2,11 +2,37 @@ from __future__ import annotations from datetime import datetime, timezone from uuid import uuid4 +import asyncio +from contextvars import copy_context +from functools import partial +from weakref import WeakKeyDictionary from app import repository from app.contracts import Task, TaskStatus from app.database.db import connect, transaction from app.errors import ApiError +from app.operation_logs import log_event + +_write_locks = WeakKeyDictionary() + + +async def write_in_background(operation, *args, **kwargs): + # SQLite has one writer. Queue cooperatively instead of letting many worker + # threads fight over the file lock and starve unrelated model work. + loop = asyncio.get_running_loop() + lock = _write_locks.setdefault(loop, asyncio.Lock()) + async with lock: + work = loop.run_in_executor(None, copy_context().run, partial(operation, *args, **kwargs)) + cancelled = False + while not work.done(): + try: + await asyncio.shield(work) + except asyncio.CancelledError: + cancelled = True + result = work.result() + if cancelled: + raise asyncio.CancelledError + return result def _now() -> datetime: @@ -49,6 +75,7 @@ def create_task( ), ) row = conn.execute("SELECT * FROM tasks WHERE task_id = ?", (task_id,)).fetchone() + log_event('tasks', 'task.created', task_id=task_id, note_id=note_id, status='todo') return _task_from_row(row) finally: conn.close() @@ -111,6 +138,7 @@ def update_task(task_id: str, values: dict[str, object]) -> Task: params, ) row = conn.execute("SELECT * FROM tasks WHERE task_id = ?", (task_id,)).fetchone() + log_event('tasks', 'task.updated', task_id=task_id, status=row['status'], changed_fields=','.join(values)) return _task_from_row(row) finally: conn.close() @@ -121,6 +149,7 @@ def delete_task(task_id: str) -> bool: try: with transaction(conn): cursor = conn.execute("DELETE FROM tasks WHERE task_id = ?", (task_id,)) + log_event('tasks', 'task.deleted' if cursor.rowcount else 'task.not_found', task_id=task_id) return cursor.rowcount > 0 finally: conn.close() diff --git a/backend/app/services/usage_service.py b/backend/app/services/usage_service.py index 45a5e12..45cf9e0 100644 --- a/backend/app/services/usage_service.py +++ b/backend/app/services/usage_service.py @@ -98,6 +98,11 @@ class UsageAttempt: reasoning_tokens=first("output_tokens_details.reasoning_tokens", "completion_tokens_details.reasoning_tokens")) def persist(self): + from app.operation_logs import log_event + log_event('providers', 'model.request_finished', level='INFO' if self.completed else 'WARNING', + provider_id=self.provider_id, model=self.model, run_id=self.run_id, + request_id=self.request_id, source=self.source, + status='completed' if self.completed else 'incomplete') try: with closing(connection()) as conn: conn.execute("INSERT OR REPLACE INTO model_usage VALUES (?,?,?,?,?,?,?,?,?,?,?)", ( diff --git a/backend/scripts/agent-task-stress.py b/backend/scripts/agent-task-stress.py new file mode 100644 index 0000000..e5a9559 --- /dev/null +++ b/backend/scripts/agent-task-stress.py @@ -0,0 +1,250 @@ +"""Offline Agent/runtime and task API load test; all state lives in a temporary directory.""" +from __future__ import annotations + +import argparse +import asyncio +import json +import inspect +import math +import os +import pathlib +import platform +import sys +import tempfile +import time + +sys.path.insert(0, str(pathlib.Path(__file__).resolve().parents[1])) + + +def stats(values): + values = sorted(values) + return {"count": len(values), "median_ms": round(values[len(values)//2], 2), + "p95_ms": round(values[min(len(values)-1, math.ceil(len(values)*.95)-1)], 2), + "max_ms": round(values[-1], 2)} if values else {"count": 0} + + +async def main(output): + # Set before importing any app modules: container has import-time initialization. + with tempfile.TemporaryDirectory(prefix="notes-agent-task-stress-") as directory: + root = pathlib.Path(directory) + os.environ.update(APP_DATA_DIR=str(root / 'data'), APP_DB_PATH=str(root / 'app.db'), + APP_VAULT_PATH=str(root / 'vault')) + from app.container import container + from app.contracts import AgentRunCreateRequest, AgentRunStatus + from app.agent.runtime import AgentRuntime, AgentCapacityError + from app.agent.permissions import PermissionMode + from app.main import app + import httpx + + report = {"python": platform.python_version(), "platform": platform.platform(), + "provider": "mock with 50 ms injected delay per model turn; no network", "results": []} + + def save(name, value): + report['results'].append({"scenario": name, **value}) + output.write_text(json.dumps(report, ensure_ascii=False, indent=2), encoding='utf-8') + print(json.dumps(report['results'][-1], ensure_ascii=False), flush=True) + + async def measured(operation): + delays = [] + async def heartbeat(): + while True: + start = time.perf_counter() + await asyncio.sleep(.01) + delays.append(max(0, (time.perf_counter()-start)*1000-10)) + pulse = asyncio.create_task(heartbeat()) + await asyncio.sleep(0) + start = time.perf_counter() + try: + result = await operation() + await asyncio.sleep(.02) + return {**result, "elapsed_ms": round((time.perf_counter()-start)*1000, 2), + "event_loop_lag": stats(delays)} + finally: + pulse.cancel() + await asyncio.gather(pulse, return_exceptions=True) + + adapter = container.providers.get('mock').adapter + original = adapter.complete + async def delayed(request): + await asyncio.sleep(.05) + return await original(request) + adapter.complete = delayed + runtime = container.agent + + for concurrency in (1, 10, 50, 200): + async def batch(): + durations, sequences, statuses = [], [], [] + semaphore = asyncio.Semaphore(concurrency) + async def one(index): + async with semaphore: + start = time.perf_counter() + created = await runtime.create_run(AgentRunCreateRequest( + input=f'/tool system.echo {{"text":"pressure-{index}"}}', + provider_id='mock', model='mock-1', allowed_tools=['system.echo'])) + events = [event async for event in runtime.events(created.run_id)] + done = await runtime.wait(created.run_id) + durations.append((time.perf_counter()-start)*1000) + statuses.append(done.status.value) + sequence = [event.sequence for event in events] + sequences.append(sequence == list(range(len(sequence)))) + assert done.status == AgentRunStatus.completed + assert done.tool_results[0].output == {"text": f"pressure-{index}"} + replay = [event.sequence async for event in runtime.events(created.run_id, after_sequence=2)] + assert replay == sequence[3:] + return created.run_id + ids = await asyncio.gather(*(one(i) for i in range(max(20, concurrency)))) + assert all(sequences) + recovered = AgentRuntime(container.providers, container.tools, container.permissions, + trace_repository=runtime.trace_repository) + assert all(recovered.get_run(run_id).status == AgentRunStatus.completed for run_id in ids) + assert not any(record.subscribers for record in runtime._records.values()) + return {"concurrency": concurrency, "runs": len(ids), "latency": stats(durations), + "completed": statuses.count('completed'), "ordered_events_and_replay": True, + "terminal_recovery": True, "retained_records": len(runtime._records)} + save('agent_tool_runs', await measured(batch)) + + # Hold model calls so all 200 records remain active while testing admission. + gate = asyncio.Event() + async def blocked(request): + await gate.wait() + return await original(request) + adapter.complete = blocked + async def capacity(): + ids = [(await runtime.create_run(AgentRunCreateRequest(input='capacity', provider_id='mock', model='mock-1'))).run_id for _ in range(200)] + rejected = False + try: + await runtime.create_run(AgentRunCreateRequest(input='overflow', provider_id='mock', model='mock-1')) + except AgentCapacityError: + rejected = True + await asyncio.sleep(0) + latencies = [] + for run_id in ids: + start = time.perf_counter() + await runtime.cancel(run_id) + latencies.append((time.perf_counter()-start)*1000) + states = await asyncio.gather(*(runtime.wait(run_id) for run_id in ids)) + assert rejected and all(run.status == AgentRunStatus.cancelled for run in states) + assert all(not record.task or record.task.done() for record in runtime._records.values()) + return {"active_limit": 200, "overflow_rejected": rejected, "cancelled": len(states), "cancel_latency": stats(latencies)} + save('capacity_and_cancel', await measured(capacity)) + adapter.complete = delayed + + async def permissions(): + tool = container.tools.get('system.echo') + previous = tool.definition.permission + tool.definition.permission = 'stress.confirm' + container.permissions.policy.set_rule('stress.confirm', PermissionMode.confirm) + async def one(index): + created = await runtime.create_run(AgentRunCreateRequest(input='/tool system.echo {"text":"permission"}', + provider_id='mock', model='mock-1', allowed_tools=['system.echo'], tool_timeout_seconds=30)) + stream = runtime.events(created.run_id) + try: + async for event in stream: + if event.event.value == 'PermissionRequired': + if index % 2: await runtime.cancel(created.run_id) + else: assert await runtime.resolve_permission(created.run_id, str(event.data['request_id']), 'allow') + break + finally: + await stream.aclose() + return (await runtime.wait(created.run_id)).status.value + try: + states = await asyncio.wait_for(asyncio.gather(*(one(i) for i in range(20))), 60) + assert states.count('completed') == states.count('cancelled') == 10 + assert not any(record.subscribers for record in runtime._records.values()) + return {"runs": 20, "approved_completed": 10, "cancelled_waiting_permission": 10, "subscribers_released": True} + finally: + tool.definition.permission = previous + save('permission_wait', await measured(permissions)) + + async def failures(): + active = 0 + async def injected(request): + text = request.messages[-1].content + if text == 'inject-provider-error': raise RuntimeError('injected offline provider failure') + if text == 'inject-model-timeout': await asyncio.sleep(60) + return await delayed(request) + tool = container.tools.get('system.echo') + executor = tool.executor + async def slow_tool(arguments, context): + nonlocal active + active += 1 + try: + if arguments.text == 'slow': await asyncio.sleep(60) + value = executor(arguments, context) + return await value if inspect.isawaitable(value) else value + finally: active -= 1 + adapter.complete = injected + tool.executor = slow_tool + async def one(index): + mode = index % 4 + text = ['normal', 'inject-provider-error', 'inject-model-timeout', '/tool system.echo {"text":"slow"}'][mode] + created = await runtime.create_run(AgentRunCreateRequest(input=text, provider_id='mock', model='mock-1', + allowed_tools=['system.echo'], run_timeout_seconds=1 if mode == 2 else 30, tool_timeout_seconds=1)) + result = await runtime.wait(created.run_id) + if mode == 0: assert result.status == AgentRunStatus.completed + elif mode == 1: assert result.status == AgentRunStatus.failed and result.error_code == 'AGENT_FAILED' + elif mode == 2: assert result.status == AgentRunStatus.failed and result.error_code == 'AGENT_TIMEOUT' + else: assert result.tool_results[0].error_code == 'TOOL_TIMEOUT' + try: + await asyncio.wait_for(asyncio.gather(*(one(i) for i in range(20))), 45) + assert active == 0 + return {"runs": 20, "success": 5, "provider_errors": 5, "model_timeouts": 5, + "tool_timeouts": 5, "remaining_tool_executors": active} + finally: + adapter.complete = delayed + tool.executor = executor + save('failure_and_timeout_isolation', await measured(failures)) + + async with httpx.AsyncClient(transport=httpx.ASGITransport(app=app), base_url='http://stress.local') as client: + for count in (100, 1000): + async def tasks(): + timings = {name: [] for name in ('create', 'update', 'list', 'delete')} + async def call(method, path, **kwargs): + start = time.perf_counter() + response = await client.request(method, path, **kwargs) + response.raise_for_status() + return response.json(), (time.perf_counter()-start)*1000 + semaphore = asyncio.Semaphore(20) + async def create(index): + async with semaphore: + body, duration = await call('POST', '/api/tasks', json={'title': f'压测任务 {index}', 'description': '独立测试数据'}) + timings['create'].append(duration) + return body['task_id'] + ids = await asyncio.gather(*(create(i) for i in range(count))) + first, _ = await call('GET', '/api/tasks') + seen = [] + for offset in range(0, count, 100): + body, duration = await call('GET', f'/api/tasks?limit=100&offset={offset}') + timings['list'].append(duration) + seen.extend(item['task_id'] for item in body['items']) + assert len(set(seen)) == count and set(seen) == set(ids) + async def change(run_id): + async with semaphore: + body, duration = await call('PATCH', f'/api/tasks/{run_id}', json={'status': 'done'}) + assert body['status'] == 'done' + timings['update'].append(duration) + _, duration = await call('DELETE', f'/api/tasks/{run_id}') + timings['delete'].append(duration) + await asyncio.gather(*(change(run_id) for run_id in ids)) + final, _ = await call('GET', '/api/tasks') + assert final['page']['total'] == 0 + return {"tasks": count, "client_concurrency": 20, "latencies": {key: stats(value) for key, value in timings.items()}, + "default_page_count": len(first['items']), "default_total": first['page']['total'], + "pagination_complete": True, "final_total": 0} + save('task_api_crud', await measured(tasks)) + + report['database_bytes'] = (root / 'app.db').stat().st_size + report['complete'] = True + output.write_text(json.dumps(report, ensure_ascii=False, indent=2), encoding='utf-8') + container.plugins.shutdown() + container.mcp_servers.shutdown() + from app.operation_logs import shutdown_logging + await asyncio.to_thread(shutdown_logging) + + +if __name__ == '__main__': + parser = argparse.ArgumentParser() + parser.add_argument('--output', type=pathlib.Path, required=True) + args = parser.parse_args() + args.output.parent.mkdir(parents=True, exist_ok=True) + asyncio.run(main(args.output)) diff --git a/backend/scripts/task-http-stress.py b/backend/scripts/task-http-stress.py new file mode 100644 index 0000000..bd59fd9 --- /dev/null +++ b/backend/scripts/task-http-stress.py @@ -0,0 +1,96 @@ +"""Real loopback HTTP task load with a separate, temporary Uvicorn process.""" +import argparse +import asyncio +import json +import math +import os +from pathlib import Path +import socket +import subprocess +import sys +import tempfile +from time import perf_counter + +import httpx + + +def stats(values): + values = sorted(values) + return {'count': len(values), 'p95_ms': round(values[math.ceil(len(values)*.95)-1], 2), + 'max_ms': round(values[-1], 2)} if values else {'count': 0} + + +async def main(args): + with tempfile.TemporaryDirectory(prefix='notes-task-http-') as directory: + root = Path(directory) + env = {**os.environ, 'APP_DATA_DIR': str(root/'data'), 'APP_DB_PATH': str(root/'app.db'), 'APP_VAULT_PATH': str(root/'vault')} + with socket.socket() as sock: + sock.bind(('127.0.0.1', 0)); port = sock.getsockname()[1] + process = subprocess.Popen([sys.executable, '-m', 'uvicorn', 'app.main:app', '--host', '127.0.0.1', '--port', str(port), '--log-level', 'error'], + cwd=Path(__file__).resolve().parents[1], env=env, stdout=subprocess.DEVNULL, stderr=subprocess.DEVNULL, + creationflags=subprocess.CREATE_NO_WINDOW if os.name == 'nt' else 0) + try: + async with httpx.AsyncClient(base_url=f'http://127.0.0.1:{port}', timeout=30) as client: + for _ in range(150): + if process.poll() is not None: raise RuntimeError('Isolated Uvicorn exited') + try: + (await client.get('/health')).raise_for_status(); break + except httpx.HTTPError: await asyncio.sleep(.1) + else: raise TimeoutError('Isolated Uvicorn startup') + sem = asyncio.Semaphore(args.concurrency) + timings = {key: [] for key in ('create', 'update', 'list', 'delete', 'health')} + errors = [] + async def request(method, path, kind, **kwargs): + start = perf_counter() + response = await client.request(method, path, **kwargs) + timings[kind].append((perf_counter()-start)*1000) + response.raise_for_status() + return response.json() + async def health(): + while True: + try: await request('GET', '/health', 'health') + except httpx.HTTPError as error: errors.append(type(error).__name__) + await asyncio.sleep(.05) + heartbeat = asyncio.create_task(health()) + start = perf_counter() + try: + async def create(index): + async with sem: + return (await request('POST', '/api/tasks', 'create', json={'title': f'HTTP 压测 {index}'}))['task_id'] + ids = await asyncio.gather(*(create(i) for i in range(args.count))) + seen = [] + for offset in range(0, args.count, 100): + page = await request('GET', f'/api/tasks?limit=100&offset={offset}', 'list') + seen.extend(item['task_id'] for item in page['items']) + assert set(seen) == set(ids) and len(seen) == args.count + async def change(task_id): + async with sem: + updated = await request('PATCH', f'/api/tasks/{task_id}', 'update', json={'status': 'done'}) + assert updated['status'] == 'done' + await request('DELETE', f'/api/tasks/{task_id}', 'delete') + await asyncio.gather(*(change(task_id) for task_id in ids)) + remaining = await request('GET', '/api/tasks', 'list') + assert remaining['page']['total'] == 0 + finally: + heartbeat.cancel(); await asyncio.gather(heartbeat, return_exceptions=True) + report = {'transport': 'real loopback HTTP, separate Uvicorn process', 'tasks': args.count, + 'concurrency': args.concurrency, 'elapsed_ms': round((perf_counter()-start)*1000, 2), + 'latencies': {key: stats(value) for key,value in timings.items()}, 'health_errors': errors, + 'pagination_complete': True, 'final_total': 0} + args.output.parent.mkdir(parents=True, exist_ok=True) + args.output.write_text(json.dumps(report, ensure_ascii=False, indent=2), encoding='utf-8') + print(json.dumps(report, ensure_ascii=False)) + finally: + process.terminate() + try: process.wait(timeout=10) + except subprocess.TimeoutExpired: process.kill(); process.wait() + + +if __name__ == '__main__': + parser = argparse.ArgumentParser() + parser.add_argument('--output', type=Path, required=True) + parser.add_argument('--count', type=int, default=1000) + parser.add_argument('--concurrency', type=int, default=20) + args = parser.parse_args() + if args.count < 1 or args.concurrency < 1: parser.error('count and concurrency must be positive') + asyncio.run(main(args)) diff --git a/backend/tests/test_agent_core.py b/backend/tests/test_agent_core.py index 2cba7b7..63afa6e 100644 --- a/backend/tests/test_agent_core.py +++ b/backend/tests/test_agent_core.py @@ -112,7 +112,7 @@ def test_permission_confirmation_resumes_agent() -> None: break assert request_id is not None - assert container.agent.resolve_permission( + assert await container.agent.resolve_permission( created.run_id, request_id, "allow_once" ) completed = await container.agent.wait(created.run_id) @@ -370,8 +370,9 @@ def test_cancelling_permission_wait_cancels_run() -> None: ) async with asyncio.timeout(2): - while container.agent.get_run(created.run_id).status != AgentRunStatus.waiting_permission: - await asyncio.sleep(0) + async for event in container.agent.events(created.run_id): + if event.event == AgentEventType.permission_required: + break cancelled = await container.agent.cancel(created.run_id) await container.agent.wait(created.run_id) diff --git a/backend/tests/test_index_activity.py b/backend/tests/test_index_activity.py new file mode 100644 index 0000000..4ec9d34 --- /dev/null +++ b/backend/tests/test_index_activity.py @@ -0,0 +1,68 @@ +import asyncio +from types import SimpleNamespace + +import pytest + +from app.retrieval import activity +from app.services import index_service + + +@pytest.fixture(autouse=True) +def reset_activity(monkeypatch): + for field in ('active', 'completed', 'failed', 'cancelled'): + monkeypatch.setattr(activity, field, 0) + monkeypatch.setattr(index_service, '_active_job_id', None) + monkeypatch.setattr(index_service, '_active_scope', None) + monkeypatch.setattr(index_service, '_last_error', None) + monkeypatch.setattr(index_service.repository, 'stats', lambda: {'notes': 16, 'blocks': 3787}) + monkeypatch.setattr(index_service.repository, 'get_index_meta', lambda: {}) + + +def test_pending_rebuild_and_incremental_jobs(monkeypatch): + meta = {'workspace_vectors_pending': '1', 'note_vectors_pending:a': '1', 'note_vectors_pending:b': '1'} + monkeypatch.setattr(index_service.repository, 'get_index_meta', lambda: meta) + status = index_service.get_status() + assert status.vector_refresh_required and status.pending_jobs == 1 + assert status.running_jobs == 0 + monkeypatch.setattr(index_service, '_active_job_id', 'job_test') + monkeypatch.setattr(index_service, '_active_scope', 'all') + status = index_service.get_status() + assert (status.status, status.pending_jobs, status.running_jobs) == ('running', 1, 1) + monkeypatch.setattr(index_service, '_active_scope', 'note') + assert index_service.get_status().pending_jobs == 2 + meta.pop('workspace_vectors_pending') + assert index_service.get_status().pending_jobs == 2 + monkeypatch.setattr(index_service, '_active_job_id', None) + monkeypatch.setattr(index_service, '_last_error', 'failed') + status = index_service.get_status() + assert (status.status, status.pending_jobs, status.running_jobs) == ('failed', 2, 0) + meta.clear() + assert index_service.get_status().pending_jobs == 0 + + +def test_search_activity_covers_completion_failure_and_cancellation(): + async def scenario(): + gate = asyncio.Event() + + @activity.track_search + async def search(_self, request): + await gate.wait() + if request.query == 'fail': + raise ValueError('failure') + return 'ok' + + tasks = [asyncio.create_task(search(None, SimpleNamespace(mode=mode, query=query))) + for mode, query in [('vector', 'ok'), ('hybrid', 'fail'), ('vector', 'cancel'), ('fts', 'ok')]] + await asyncio.sleep(0) + assert index_service.get_status().active_searches == 3 + tasks[2].cancel() + with pytest.raises(asyncio.CancelledError): + await tasks[2] + gate.set() + results = await asyncio.gather(*tasks, return_exceptions=True) + assert results[0] == results[3] == 'ok' + status = index_service.get_status() + assert (status.active_searches, status.completed_searches, status.failed_searches, status.cancelled_searches) == (0, 1, 1, 1) + assert status.pending_jobs == 0 + + asyncio.run(scenario()) diff --git a/backend/tests/test_local_models.py b/backend/tests/test_local_models.py index bbd3a96..83a5435 100644 --- a/backend/tests/test_local_models.py +++ b/backend/tests/test_local_models.py @@ -12,6 +12,42 @@ from app.local_models.runtime import Runtime from app.providers.base import ProviderError +@pytest.mark.parametrize('threaded', [False, True]) +def test_large_embedding_result_crosses_pipe_limit_without_truncation(monkeypatch, tmp_path, threaded): + import app.local_models.runtime as module + import app.local_models.process as process_module + from app.local_models.protocol import response_lines + vector = [0.012345678901234567] * 384 + result = {'result': [vector] * 2111} + assert len(json.dumps(result).encode()) > 16 * 1024 * 1024 + assert max(map(len, response_lines(result, 'embedding'))) < 16 * 1024 * 1024 + worker = tmp_path / 'large_worker.py' + protocol_dir = Path(module.__file__).parent + worker.write_text( + 'import sys,json\n' + f'sys.path.insert(0, {str(protocol_dir)!r})\n' + 'from protocol import response_lines\n' + 'request=json.load(sys.stdin)\n' + 'vector=[0.012345678901234567]*384\n' + 'for line in response_lines({"result":[vector]*len(request["payload"]["texts"])}, "embedding"):\n' + ' sys.stdout.write(line)\n', encoding='utf-8') + monkeypatch.setattr(module, 'read_state', lambda key: {'status': 'installed'}) + monkeypatch.setattr(module, 'interpreter', lambda *_: Path(sys.executable)) + original_async = asyncio.create_subprocess_exec + original_threaded = process_module.ThreadedProcess + + async def spawn(*args, **kwargs): + if threaded: + raise NotImplementedError + return await original_async(sys.executable, str(worker), **kwargs) + + monkeypatch.setattr(module.asyncio, 'create_subprocess_exec', spawn) + monkeypatch.setattr(process_module, 'ThreadedProcess', + lambda args, **kwargs: original_threaded((sys.executable, str(worker)), **kwargs)) + actual = asyncio.run(Runtime().infer('bekko', 'embedding', {'texts': ['test'] * 2111})) + assert actual == result['result'] + + def test_download_resumes_partial_and_checks_digest(monkeypatch): payload = b'verified-model-weights' entry = {'path':'model.safetensors','size':len(payload),'hash':hashlib.sha256(payload).hexdigest(), diff --git a/backend/tests/test_operation_logs.py b/backend/tests/test_operation_logs.py new file mode 100644 index 0000000..8db70f2 --- /dev/null +++ b/backend/tests/test_operation_logs.py @@ -0,0 +1,151 @@ +import asyncio +import json +import logging +import threading +from pathlib import Path + +from app.operation_logs import LogStore, ApplicationLogHandler, get_store, log_event, shutdown_logging + + +def test_logs_persist_filter_cursor_and_retention(tmp_path): + store = LogStore(tmp_path / 'logs.db', retain=3) + try: + for i in range(6): + store.emit('ERROR' if i % 2 else 'INFO', 'vectors', 'embedding.failed', {'run_id': f'run_{i}'}) + store.queue.join() + first = store.query(limit=2) + assert len(first['items']) == 2 and first['next_cursor'] + assert len(store.query(before=first['next_cursor'])['items']) == 1 + assert len(store.query(level='ERROR')['items']) == 2 + assert len(store.query(q='run_5')['items']) == 1 + assert not store.query(source='tasks')['items'] + finally: + store.close() + reopened = LogStore(tmp_path / 'logs.db', retain=3) + try: + assert len(reopened.query()['items']) == 3 + finally: + reopened.close() + + +def test_logs_exclude_content_and_legacy_exception_messages(): + try: + log_event('vectors', 'embedding.failed', level='ERROR', + error=ValueError('private note and secret'), model='embedding-v1', + prompt='private note', arguments={'api_key': 'secret'}, api_key='secret') + handler = ApplicationLogHandler() + record = logging.LogRecord('app.sample', logging.ERROR, __file__, 1, + 'private note and secret %s', ('credentials',), None) + handler.emit(record) + handler.emit(record) # a logger propagated to another installed handler + store = get_store() + store.queue.join() + data = json.dumps(store.query()) + assert len(store.query()['items']) == 2 + assert 'private note' not in data and 'credentials' not in data and 'api_key' not in data + assert 'ValueError' in data and 'embedding-v1' in data + finally: + shutdown_logging() + + +def test_http_log_correlates_task_operations_without_body(): + import httpx + from app.main import app + async def scenario(): + async with httpx.AsyncClient(transport=httpx.ASGITransport(app=app), base_url='http://test') as client: + response = await client.post('/api/tasks', json={'title': 'private title'}) + assert response.status_code == 200 + rid = response.headers['x-request-id'] + store = get_store() + await asyncio.to_thread(store.queue.join) + result = (await client.get('/api/logs', params={'q': rid})).json() + assert len(result['items']) >= 2 + assert 'private title' not in json.dumps(result) + assert any(item['event'] == 'task.created' for item in result['items']) + assert (await client.get('/api/logs', params={'limit': 201})).status_code == 422 + try: + asyncio.run(scenario()) + finally: + shutdown_logging() + + +def test_trace_writer_batches_off_loop_and_survives_cancel(): + from app.agent.async_trace import AsyncTraceWriter + started, release = threading.Event(), threading.Event() + class Repository: + def write_batch(self, jobs): + assert threading.current_thread() is not threading.main_thread() + started.set() + assert release.wait(2) + self.jobs = jobs + async def scenario(): + repo = Repository() + writer = AsyncTraceWriter(repo) + pending = asyncio.create_task(writer.submit('save', 'snapshot')) + while not started.is_set(): + await asyncio.sleep(.001) + pending.cancel() + writer.worker.cancel() # simultaneous application shutdown + await asyncio.sleep(.005) + assert not pending.done() + release.set() + assert await asyncio.wait_for(pending, 2) is True + assert repo.jobs == [('save', ('snapshot',))] + assert writer.queue.empty() + asyncio.run(scenario()) + + +def test_trace_write_failure_is_reported_and_next_submission_recovers(): + from app.agent.async_trace import AsyncTraceWriter + class Repository: + fail = True + def write_batch(self, jobs): + if self.fail: + self.fail = False + raise OSError('disk unavailable') + async def scenario(): + import pytest + writer = AsyncTraceWriter(Repository()) + with pytest.raises(OSError): + await writer.submit('save', 'first') + assert not await writer.submit('save', 'second') + await writer.queue.join() + asyncio.run(scenario()) + + +def test_log_write_failure_does_not_stall_queue(tmp_path, monkeypatch): + store = LogStore(tmp_path / 'failed.db') + try: + def broken(): + raise OSError('disk unavailable') + monkeypatch.setattr(store, '_connect', broken) + store.emit('ERROR', 'vectors', 'embedding.failed', {'duration_ms': float('nan')}) + store.queue.join() + assert store.failed == 1 + finally: + store.close() + + +def test_cancelled_task_write_keeps_its_slot_until_commit(): + from app.services.task_service import write_in_background + started, release = threading.Event(), threading.Event() + order = [] + def first(): + started.set() + assert release.wait(2) + order.append('first') + async def scenario(): + import pytest + pending = asyncio.create_task(write_in_background(first)) + while not started.is_set(): + await asyncio.sleep(.001) + pending.cancel() + second = asyncio.create_task(write_in_background(lambda: order.append('second'))) + await asyncio.sleep(.01) + assert order == [] + release.set() + with pytest.raises(asyncio.CancelledError): + await pending + await second + assert order == ['first', 'second'] + asyncio.run(scenario()) diff --git a/docs/README.md b/docs/README.md index 360c5bd..d10d69a 100644 --- a/docs/README.md +++ b/docs/README.md @@ -97,3 +97,5 @@ - [Markdown 语法预设与外部文件刷新](development/Markdown语法预设与外部文件刷新.md) - [长文渲染优化与压测报告](development/长文渲染优化与压测报告.md) +- [Agent 与任务压测报告](development/Agent与任务压测报告.md) +- [后台运行日志与压力问题修复](development/后台运行日志与压力问题修复.md) diff --git a/docs/contracts/后端接口契约-开发版.md b/docs/contracts/后端接口契约-开发版.md index df0b20d..ff0a245 100644 --- a/docs/contracts/后端接口契约-开发版.md +++ b/docs/contracts/后端接口契约-开发版.md @@ -204,6 +204,17 @@ RunCancelled - `POST /api/workspace/open` 返回可使用的 WorkspaceSnapshot，不等待向量推理。 - `PATCH /api/notes/{note_id}` 成功代表正文、元数据和 FTS 已保存；后台向量失败不撤销这次保存。 - `GET /api/index/status` 新增 `vector_refresh_required: boolean`，表示工作区或笔记存在向量待处理标记。该字段不是进度百分比；任务失败时也可为 true。 +- `pending_jobs` 返回真实未完成索引任务数（包含运行中），不再固定为 0。全库待重建或运行中的全量重建计一个任务；逐笔记刷新按待处理标记计数。`running_jobs` 返回当前运行数。失败后保留的待重建标记仍计入未完成数。 +- `active_searches`、`completed_searches`、`failed_searches`、`cancelled_searches` 分别表示向量/混合检索的进行中、完成、失败、取消次数，覆盖搜索、对话和 Agent 经统一检索引擎发起的调用，排除纯 FTS；混合检索回退 FTS 后成功仍计完成。计数仅保存在当前服务进程内，重启归零，与索引队列互相独立。 +- 设置与搜索页每秒轮询状态，其他页面空闲时每 5 秒轮询；不是事件推送。短检索可能无法观察到进行中状态，但完成/失败计数会保留。设置页与底部状态栏复用状态标签，未知字段显示“未获取”。 - `POST /api/index/rebuild` 仍仅支持全量重建，并等待结果；不要将上述异步语义推广到所有索引 API。 状态、恢复限制与验证见 [工作区后台索引与保存开发说明](../development/工作区后台索引与保存开发说明.md)。 + +## 2026-09-06：统一运行日志 + +`GET /api/logs` 返回独立持久化的后台操作日志，无需打开 Vault。参数：`limit` 默认 50、最大 200；`before` 为上一页 next_cursor；`level` 为 INFO/WARNING/ERROR/CRITICAL 或空；`source` 按模块精确匹配；`q` 在事件名和脱敏元数据中做字面搜索。 + +返回 `items: [{id,timestamp,level,source,event,details}]`、`next_cursor`（无后续页时 null）、`sources`、`pending`、`dropped`、`write_failures`、`retention`。日志按 ID 倒序，保留最近 20,000 条。响应头 `X-Request-ID` 与后台日志关联。不得依赖日志记录笔记正文、工具参数、凭据或原始异常消息。 + +队列、错误处理、字段白名单和验证方法见 [后台运行日志与压力问题修复](../development/后台运行日志与压力问题修复.md)。 diff --git a/docs/development/Agent与任务压测报告.md b/docs/development/Agent与任务压测报告.md new file mode 100644 index 0000000..50b9115 --- /dev/null +++ b/docs/development/Agent与任务压测报告.md @@ -0,0 +1,156 @@ +# Agent 与任务压测报告 + +> 日期：2026-09-06。范围：当前第二阶段 Agent Runtime、任务 API、任务列表及 Trace 组件。测试在 Windows 11、Python 3.12.6、独立无头 Chrome 下执行，前端为 Vite 开发模式，纸间时光版本 1.8.1。 + +## 1. 结论 + +功能正确性检查通过：Agent 工具调用、事件序号与回放、终态持久化恢复、容量拒绝、取消、权限等待、故障隔离，以及任务增删改查和分页均得到预期结果。性能仍有三项明确问题： + +| 优先级 | 问题 | 本轮证据 | 建议方向 | +| --- | --- | --- | --- | +| P1 | 任务列表未加载后续页；Agent 历史列表也没有后续分页入口 | 100、1000 条任务的实际页面均只请求 `/api/tasks` 并显示 50 条；Agent store 同样仅调用默认分页一次，接口默认 50 | 增加服务端筛选与分页/加载更多，显示总量，防止统计仅基于已加载项 | +| P1 | 高并发 Agent 阻塞事件循环 | 200 并发的完成延迟 P95 约 10.55 秒；进程内心跳最大延迟约 3.56 秒 | 分析同步持久化，设计有界执行调度及顺序写入，保留事件落盘、终态与回放一致性 | +| P1 | 大 Trace 的树形筛选长时间阻塞 | 2000 事件树形搜索约 483–617 ms；10000 事件约 25.91 秒 | 为匹配的 sequence/tool/model ID 建 Set，避免逐节点重复遍历事件；再评估分段显示及增量更新 | + +本次新增的是可复现压测与报告，没有把上述生产问题标记为已修复。页面滚动与树形搜索是不同瓶颈：10000 事件的滚动 P95 约 40 ms，并不能说明搜索交互也流畅。 + +## 2. 隔离与方法 + +- 后端脚本在导入任何 app 模块前，将 `APP_DATA_DIR`、`APP_DB_PATH`、`APP_VAULT_PATH` 指向临时目录，结束后清理；不读写用户 Vault、现有任务及 Provider 凭据。 +- Agent 使用内置 Mock Provider，每轮模型调用注入 50 ms 异步等待，正常样本包含一次 `system.echo` 工具调用和两轮模型调用；不调用真实厂商，也不衡量回答质量或真实模型吞吐。 +- 进程内运行直接调用真实 Runtime、SQLite 和任务 ASGI 路由。任务 HTTP 复核另起独立 Uvicorn 进程，用真实回环连接执行，避免将 ASGI 驱动的连续无让出执行误解为网络服务延迟。 +- 前端挂载真实 TasksView、TraceTimeline 和 Pinia store。压测页拦截全部 fetch，不向真实后端发出请求。任务接口夹具保留默认 50 条分页，先测实际加载条数，再注入完整列表测试渲染上限，两者分开记录。 +- Trace 由确定性模型开始/完成、工具调用/结果事件组成，带调用与父节点 ID；测量首次渲染、时间线过滤、树形切换、匹配全部节点的树形搜索。 +- 滚动用 CDP 派发 120 次滚轮事件，记录真实滚动容器及 `maxScrollTop`，防止对未滚动页面统计帧间隔。Trace 测试容器显式解除应用根节点的裁剪，由独立滚动区承担真实 Agent 页滚动容器的职责。 + +本轮每个前端配置测一次；开发编译、后台负载、缓存和浏览器调度都会影响结果，数据用于发现瓶颈，不作为生产环境 SLA。首次渲染计时不包含模块下载，包含 Vue 更新及两个 animation frame。 + +## 3. Agent 后端 + +### 3.1 正常工具调用与回放 + +| 并发数 | 运行数 | 完成延迟中位数（ms） | 完成延迟 P95（ms） | 场景心跳最大延迟（ms） | +| ---: | ---: | ---: | ---: | ---: | +| 1 | 20 | 146.20 | 170.13 | 26.84 | +| 10 | 20 | 405.75 | 505.74 | 136.71 | +| 50 | 50 | 2234.45 | 2304.42 | 798.84 | +| 200 | 200 | 10262.47 | 10554.52 | 3559.97 | + +290 个正常运行全部完成，工具返回内容逐项一致；实时订阅事件序号连续，`after_sequence=2` 回放与原事件后缀一致。新的 Runtime 实例可以从 SQLite 恢复这些终态运行。订阅者集合最终清空，进程内保留记录不超过 200。 + +“并发”是同时提交的协程数，不代表独立 CPU 工作线程。当前 queued 是启动前状态，Runtime 并没有把超额活跃运行无限排入执行队列。场景心跳还包含提交、持久化回放与恢复校验，不能将其全部归为模型执行耗时；50、200 并发场景的心跳采样数仅 8 个，表中因此列最大值而非宣称稳定分位数。 + +代码定位：`AgentRuntime._publish()` 同步调用 `AgentTraceRepository.append_event()`，后者逐事件连接 SQLite 并提交事务；`connect()` 还加载扩展和检查迁移。这是需要进一步拆分测量的阻塞路径，本轮未完成各子步骤 CPU/磁盘成本归因。 + +### 3.2 容量、取消与故障注入 + +- 保持 200 个模型调用活跃，第 201 次创建得到 `AgentCapacityError`；随后取消全部 200 个运行，全部进入 cancelled，后台任务均结束。 +- 20 个运行等待权限：10 个允许后完成，10 个等待中取消，订阅者均释放。 +- 20 个混合运行：5 个正常完成、5 个 Provider 异常、5 个模型超时、5 个工具超时，均获得预期状态或错误码；工具执行器剩余数量为 0。 +- 正常回放和故障场景合计创建 530 个运行，临时数据库最终约 2.95 MB。工具超时被记录为 ToolResult 错误，后续 Mock 模型仍可能完成运行，不将它误算为整个 Run 必然失败。 + +这里的“恢复”是新 Runtime 读取终态持久化数据，未模拟 OS 强杀时的写入中断。SSE 通过 Runtime 的事件生成器验证序号及断点回放，没有进行真实网络慢读者/断网压力测试。 + +## 4. 任务 API + +进程内分别对 100、1000 条任务执行创建、逐页读取、更新为 done、删除，所有 ID 完整，最终总量为 0。默认接口每页 50 条，显式每页 100 条遍历可以取回全部数据。 + +ASGITransport 的 1000 条突发操作中，心跳出现约 14 秒延迟：测试客户端与同步路由处于同一事件循环，连续就绪协程缺少网络等待，不能将其视作真实 HTTP 健康检查延迟。因此增加独立 Uvicorn + 回环 HTTP 复核： + +| 操作 | 数量 | P95（ms） | 最大值（ms） | +| --- | ---: | ---: | ---: | +| 创建 | 1000 | 116.45 | 134.91 | +| 更新 | 1000 | 159.29 | 193.37 | +| 删除 | 1000 | 156.43 | 190.10 | +| 分页/收尾查询 | 11 | 20.96 | 20.96 | +| 并行健康检查 | 117 | 157.00 | 195.07 | + +HTTP 客户端并发 20，总耗时约 18.31 秒；健康检查零失败，分页无重复/遗漏，最终任务数为 0。此处是本机单次结果，未覆盖跨网络、长期持久负载或多进程同时写同一数据库。 + +## 5. 前端 + +### 5.1 任务列表 + +100、1000 条数据的实际加载阶段都只有一次 `/api/tasks` 请求，store 中均为 50 条。以下是额外注入完整 1000 条数据后的结果，不是生产页面当前可以加载 1000 条的证明。 + +| 主题 | 完整列表渲染（ms） | 完成状态筛选（ms） | +| --- | ---: | ---: | +| 默认浅色 | 117.4 | 44.1 | +| 默认深色 | 137.8 | 47.8 | +| 纸间时光 1.8.1 | 150.0 | 59.5 | + +1000 条列表约 11007 个 DOM 节点，实际滚动最远达到 81000 px；筛选 done 得到 334 条，与夹具期望一致。100 条样本筛选得到 34 条，也一致。默认浅色的 1000 条滚动 P95 约 30.2 ms，纸间时光约 50.1 ms；样本数少，暂不据此认定新的单一 CSS 根因。 + +### 5.2 Agent Trace + +| 事件数/主题 | 首次渲染（ms） | 时间线搜索（ms） | 树形切换（ms） | 树形全匹配搜索（ms） | +| --- | ---: | ---: | ---: | ---: | +| 2000 / 默认浅色 | 283.8 | 97.4 | 64.0 | 617.2 | +| 2000 / 默认深色 | 289.0 | 74.5 | 62.9 | 483.0 | +| 2000 / 纸间时光 | 337.3 | 86.3 | 62.1 | 540.1 | +| 10000 / 纸间时光 | 1803.9 | 582.8 | 317.5 | 25914.8 | + +200 事件的树形搜索约 20–29 ms。2000 事件时间线约 20542 个 DOM 节点，10000 事件约 102542 个。查询“压力测试 1”分别命中 444、4444 条事件，与直接检查输入数据的结果一致；树形搜索“压力测试”匹配所有事件，会自动展开匹配子树。 + +代码定位：`TraceTimeline.filteredTree` 为每个节点调用 `filteredEvents.some(...)`。节点数和匹配事件数一起增加时，会产生近似二次增长的匹配工作，随后还需构造并渲染展开子树。建议先用匹配 ID 集合消除嵌套扫描，再测 DOM 更新成本；不要仅用防抖隐藏单次 25 秒阻塞。 + +10000 是扩大数据规模的诊断测试，高于 Runtime 默认内存事件保留量 2000；它直接向组件传入事件，不代表当前单次 API 页或实时 store 默认会收到这一数量。也未覆盖逐事件 SSE 增量刷新的端到端成本。 + +## 6. 复现与原始数据 + +```powershell +# 后端：独立临时数据，离线 Mock +backend/.venv/Scripts/python.exe backend/scripts/agent-task-stress.py --output .local-plans/agent-task-backend.json +# 真实 HTTP：独立 Uvicorn、随机回环端口 +backend/.venv/Scripts/python.exe backend/scripts/task-http-stress.py --count 1000 --concurrency 20 --output .local-plans/task-http.json +# 前端：先启动独立 Vite，另一个终端执行后续命令 +npm --prefix frontend run dev -- --port 5175 --strictPort +backend/.venv/Scripts/python.exe frontend/tests/performance/run-stress.py --url 'http://127.0.0.1:5175/tests/performance/agent-task.html?kind=tasks&theme=paper-moments' --scroll --sizes 100 1000 --runs 1 --output .local-plans/task-ui.json +backend/.venv/Scripts/python.exe frontend/tests/performance/run-stress.py --url 'http://127.0.0.1:5175/tests/performance/agent-task.html?kind=trace&theme=paper-moments' --scroll --sizes 200 2000 10000 --runs 1 --output .local-plans/trace-ui.json +``` + +URL 的 theme 可换为 light、dark。测试应串行运行，避免不同负载相互争用；10k Trace 树形筛选可能长时间占用测试浏览器。浏览器使用临时用户目录，不接管用户当前浏览器。 + +- [Agent 与进程内任务 API 数据](performance/2026-09-06-agent-task-backend.json) +- [真实 HTTP 任务数据](performance/2026-09-06-task-http.json) +- [前端 13 组样本数据](performance/2026-09-06-agent-task-ui.json) +- [前端压测工具](../../frontend/tests/performance/README.md) + +附加回归：`test_agent_core.py`、`test_api.py` 共 26 项通过。脚本中的状态、序号、输出、分页与筛选断言均通过。未提交或推送本次材料。 + +## 7. 修复后复测（2026-09-06） + +以上保留首次压测基线。本节对应后台 Trace 批量写入、任务后台写入、完整列表加载、Trace 集合匹配/分页和统一日志接入后的实现。样本开启新操作日志，仍只调用隔离 Mock。 + +| 项目 | 修复前 | 修复后 | +| --- | ---: | ---: | +| 200 并发 Agent 完成 P95 | 10,554.52 ms | 1,233.12 ms | +| 200 并发测量区间事件循环最大延迟 | 3,559.97 ms | 509.00 ms | +| 纸间时光 10k Trace 首次渲染 | 1,803.9 ms | 94.4 ms | +| 纸间时光 10k Trace 树形全匹配筛选 | 25,914.8 ms | 189.2 ms | +| 纸间时光 10k Trace 首屏 DOM 节点 | 约 102,542 | 1,852 | +| 1,000 条任务首次实际加载 | 50 条 | 1,000 条（10 次 API 请求） | + +Agent 测量区间还包含同步读回、校验和重启恢复，最大心跳延迟不是纯执行阶段指标。290 次普通运行、200 个容量/取消场景、20 个权限场景、20 个失败/超时场景全部通过，订阅者和工具执行器释放。不能声称消除了所有主线程工作。 + +Trace 搜索检查完整数据，只有渲染分页。10k 样本滚动 frame gap P95 为 10.1 ms，无 longtask；时间线筛选 284.9 ms，树形切换 100.9 ms。这是单次本机样本，不代表所有硬件与实时 SSE 输入。 + +1,000 条任务界面每页 100 条；筛选后数据总数 334，当前页 100。筛选 18.7 ms，滚动 frame gap P95 为 30 ms，无 longtask。断言同时检查完整数据量和分页渲染数量。 + +真实 HTTP 测试 1,000 条任务、20 并发，CRUD 全部成功，分页完整，最终任务数 0： + +| 指标 | 修复前 | 修复后 | +| --- | ---: | ---: | +| health P95 | 157.00 ms | 38.64 ms | +| 创建 P95 | 116.45 ms | 157.68 ms | +| 更新 P95 | 159.29 ms | 208.68 ms | +| 删除 P95 | 156.43 ms | 205.45 ms | +| 总耗时 | 18.31 s | 24.51 s | + +后台排队和操作记录改善了无关请求的响应，但这组样本写入吞吐下降，不能描述为 CRUD 全面提速。后续可以评估任务事务批量化与连接初始化开销；本次没有降低 SQLite 持久化级别。 + +- [Agent / 进程内任务复测](performance/2026-09-06-agent-task-backend-fixed.json) +- [真实 HTTP 任务复测](performance/2026-09-06-task-http-fixed.json) +- [Trace 浏览器复测](performance/2026-09-06-agent-trace-ui-fixed.json) +- [任务浏览器复测](performance/2026-09-06-task-ui-fixed.json) +- [日志架构与验收说明](后台运行日志与压力问题修复.md) diff --git a/docs/development/performance/2026-09-06-agent-task-backend-fixed.json b/docs/development/performance/2026-09-06-agent-task-backend-fixed.json new file mode 100644 index 0000000..7903bc4 --- /dev/null +++ b/docs/development/performance/2026-09-06-agent-task-backend-fixed.json @@ -0,0 +1,230 @@ +{ + "python": "3.12.6", + "platform": "Windows-11-10.0.26100-SP0", + "provider": "mock with 50 ms injected delay per model turn; no network", + "results": [ + { + "scenario": "agent_tool_runs", + "concurrency": 1, + "runs": 20, + "latency": { + "count": 20, + "median_ms": 150.79, + "p95_ms": 169.57, + "max_ms": 178.52 + }, + "completed": 20, + "ordered_events_and_replay": true, + "terminal_recovery": true, + "retained_records": 20, + "elapsed_ms": 3047.59, + "event_loop_lag": { + "count": 995, + "median_ms": 0, + "p95_ms": 5.65, + "max_ms": 21.83 + } + }, + { + "scenario": "agent_tool_runs", + "concurrency": 10, + "runs": 20, + "latency": { + "count": 20, + "median_ms": 187.48, + "p95_ms": 214.02, + "max_ms": 214.58 + }, + "completed": 20, + "ordered_events_and_replay": true, + "terminal_recovery": true, + "retained_records": 40, + "elapsed_ms": 514.15, + "event_loop_lag": { + "count": 192, + "median_ms": 0, + "p95_ms": 4.82, + "max_ms": 20.02 + } + }, + { + "scenario": "agent_tool_runs", + "concurrency": 50, + "runs": 50, + "latency": { + "count": 50, + "median_ms": 364.9, + "p95_ms": 366.99, + "max_ms": 367.3 + }, + "completed": 50, + "ordered_events_and_replay": true, + "terminal_recovery": true, + "retained_records": 90, + "elapsed_ms": 526.56, + "event_loop_lag": { + "count": 172, + "median_ms": 0, + "p95_ms": 4.57, + "max_ms": 69.89 + } + }, + { + "scenario": "agent_tool_runs", + "concurrency": 200, + "runs": 200, + "latency": { + "count": 200, + "median_ms": 1118.63, + "p95_ms": 1233.12, + "max_ms": 1237.31 + }, + "completed": 200, + "ordered_events_and_replay": true, + "terminal_recovery": true, + "retained_records": 200, + "elapsed_ms": 1839.2, + "event_loop_lag": { + "count": 470, + "median_ms": 0, + "p95_ms": 2.6, + "max_ms": 509.0 + } + }, + { + "scenario": "capacity_and_cancel", + "active_limit": 200, + "overflow_rejected": true, + "cancelled": 200, + "cancel_latency": { + "count": 200, + "median_ms": 7.71, + "p95_ms": 10.8, + "max_ms": 17.37 + }, + "elapsed_ms": 3613.48, + "event_loop_lag": { + "count": 1613, + "median_ms": 0, + "p95_ms": 0, + "max_ms": 7.86 + } + }, + { + "scenario": "permission_wait", + "runs": 20, + "approved_completed": 10, + "cancelled_waiting_permission": 10, + "subscribers_released": true, + "elapsed_ms": 388.83, + "event_loop_lag": { + "count": 72, + "median_ms": 0, + "p95_ms": 9.9, + "max_ms": 15.27 + } + }, + { + "scenario": "failure_and_timeout_isolation", + "runs": 20, + "success": 5, + "provider_errors": 5, + "model_timeouts": 5, + "tool_timeouts": 5, + "remaining_tool_executors": 0, + "elapsed_ms": 1295.29, + "event_loop_lag": { + "count": 152, + "median_ms": 0, + "p95_ms": 7.2, + "max_ms": 17.24 + } + }, + { + "scenario": "task_api_crud", + "tasks": 100, + "client_concurrency": 20, + "latencies": { + "create": { + "count": 100, + "median_ms": 214.09, + "p95_ms": 264.51, + "max_ms": 309.99 + }, + "update": { + "count": 100, + "median_ms": 221.48, + "p95_ms": 403.74, + "max_ms": 495.1 + }, + "list": { + "count": 1, + "median_ms": 7.92, + "p95_ms": 7.92, + "max_ms": 7.92 + }, + "delete": { + "count": 100, + "median_ms": 232.9, + "p95_ms": 468.48, + "max_ms": 475.63 + } + }, + "default_page_count": 50, + "default_total": 100, + "pagination_complete": true, + "final_total": 0, + "elapsed_ms": 3673.22, + "event_loop_lag": { + "count": 2337, + "median_ms": 0, + "p95_ms": 0, + "max_ms": 118.92 + } + }, + { + "scenario": "task_api_crud", + "tasks": 1000, + "client_concurrency": 20, + "latencies": { + "create": { + "count": 1000, + "median_ms": 200.87, + "p95_ms": 237.75, + "max_ms": 376.8 + }, + "update": { + "count": 1000, + "median_ms": 220.04, + "p95_ms": 260.19, + "max_ms": 300.07 + }, + "list": { + "count": 10, + "median_ms": 7.89, + "p95_ms": 9.61, + "max_ms": 9.61 + }, + "delete": { + "count": 1000, + "median_ms": 218.1, + "p95_ms": 266.23, + "max_ms": 316.14 + } + }, + "default_page_count": 50, + "default_total": 1000, + "pagination_complete": true, + "final_total": 0, + "elapsed_ms": 32562.93, + "event_loop_lag": { + "count": 24893, + "median_ms": 0, + "p95_ms": 0, + "max_ms": 91.85 + } + } + ], + "database_bytes": 2981888, + "complete": true +} \ No newline at end of file diff --git a/docs/development/performance/2026-09-06-agent-task-backend.json b/docs/development/performance/2026-09-06-agent-task-backend.json new file mode 100644 index 0000000..18de7eb --- /dev/null +++ b/docs/development/performance/2026-09-06-agent-task-backend.json @@ -0,0 +1,230 @@ +{ + "python": "3.12.6", + "platform": "Windows-11-10.0.26100-SP0", + "provider": "mock with 50 ms injected delay per model turn; no network", + "results": [ + { + "scenario": "agent_tool_runs", + "concurrency": 1, + "runs": 20, + "latency": { + "count": 20, + "median_ms": 146.2, + "p95_ms": 170.13, + "max_ms": 171.23 + }, + "completed": 20, + "ordered_events_and_replay": true, + "terminal_recovery": true, + "retained_records": 20, + "elapsed_ms": 3041.03, + "event_loop_lag": { + "count": 190, + "median_ms": 5.64, + "p95_ms": 16.81, + "max_ms": 26.84 + } + }, + { + "scenario": "agent_tool_runs", + "concurrency": 10, + "runs": 20, + "latency": { + "count": 20, + "median_ms": 405.75, + "p95_ms": 505.74, + "max_ms": 539.28 + }, + "completed": 20, + "ordered_events_and_replay": true, + "terminal_recovery": true, + "retained_records": 40, + "elapsed_ms": 1045.19, + "event_loop_lag": { + "count": 15, + "median_ms": 57.63, + "p95_ms": 136.71, + "max_ms": 136.71 + } + }, + { + "scenario": "agent_tool_runs", + "concurrency": 50, + "runs": 50, + "latency": { + "count": 50, + "median_ms": 2234.45, + "p95_ms": 2304.42, + "max_ms": 2307.54 + }, + "completed": 50, + "ordered_events_and_replay": true, + "terminal_recovery": true, + "retained_records": 90, + "elapsed_ms": 2552.49, + "event_loop_lag": { + "count": 8, + "median_ms": 345.24, + "p95_ms": 798.84, + "max_ms": 798.84 + } + }, + { + "scenario": "agent_tool_runs", + "concurrency": 200, + "runs": 200, + "latency": { + "count": 200, + "median_ms": 10262.47, + "p95_ms": 10554.52, + "max_ms": 10584.03 + }, + "completed": 200, + "ordered_events_and_replay": true, + "terminal_recovery": true, + "retained_records": 200, + "elapsed_ms": 11442.28, + "event_loop_lag": { + "count": 8, + "median_ms": 1647.87, + "p95_ms": 3559.97, + "max_ms": 3559.97 + } + }, + { + "scenario": "capacity_and_cancel", + "active_limit": 200, + "overflow_rejected": true, + "cancelled": 200, + "cancel_latency": { + "count": 200, + "median_ms": 4.32, + "p95_ms": 5.36, + "max_ms": 8.27 + }, + "elapsed_ms": 3645.04, + "event_loop_lag": { + "count": 3, + "median_ms": 14.04, + "p95_ms": 3610.52, + "max_ms": 3610.52 + } + }, + { + "scenario": "permission_wait", + "runs": 20, + "approved_completed": 10, + "cancelled_waiting_permission": 10, + "subscribers_released": true, + "elapsed_ms": 971.64, + "event_loop_lag": { + "count": 11, + "median_ms": 49.09, + "p95_ms": 314.46, + "max_ms": 314.46 + } + }, + { + "scenario": "failure_and_timeout_isolation", + "runs": 20, + "success": 5, + "provider_errors": 5, + "model_timeouts": 5, + "tool_timeouts": 5, + "remaining_tool_executors": 0, + "elapsed_ms": 1531.14, + "event_loop_lag": { + "count": 83, + "median_ms": 5.17, + "p95_ms": 27.82, + "max_ms": 255.96 + } + }, + { + "scenario": "task_api_crud", + "tasks": 100, + "client_concurrency": 20, + "latencies": { + "create": { + "count": 100, + "median_ms": 5.37, + "p95_ms": 34.16, + "max_ms": 61.99 + }, + "update": { + "count": 100, + "median_ms": 7.22, + "p95_ms": 35.0, + "max_ms": 96.33 + }, + "list": { + "count": 1, + "median_ms": 3.73, + "p95_ms": 3.73, + "max_ms": 3.73 + }, + "delete": { + "count": 100, + "median_ms": 5.44, + "p95_ms": 14.57, + "max_ms": 36.43 + } + }, + "default_page_count": 50, + "default_total": 100, + "pagination_complete": true, + "final_total": 0, + "elapsed_ms": 2532.22, + "event_loop_lag": { + "count": 4, + "median_ms": 776.23, + "p95_ms": 1712.81, + "max_ms": 1712.81 + } + }, + { + "scenario": "task_api_crud", + "tasks": 1000, + "client_concurrency": 20, + "latencies": { + "create": { + "count": 1000, + "median_ms": 5.18, + "p95_ms": 32.23, + "max_ms": 43.29 + }, + "update": { + "count": 1000, + "median_ms": 6.51, + "p95_ms": 14.72, + "max_ms": 90.27 + }, + "list": { + "count": 10, + "median_ms": 5.48, + "p95_ms": 6.18, + "max_ms": 6.18 + }, + "delete": { + "count": 1000, + "median_ms": 4.76, + "p95_ms": 8.42, + "max_ms": 97.64 + } + }, + "default_page_count": 50, + "default_total": 1000, + "pagination_complete": true, + "final_total": 0, + "elapsed_ms": 21242.37, + "event_loop_lag": { + "count": 4, + "median_ms": 6932.7, + "p95_ms": 14260.46, + "max_ms": 14260.46 + } + } + ], + "database_bytes": 2949120, + "complete": true +} \ No newline at end of file diff --git a/docs/development/performance/2026-09-06-agent-task-ui.json b/docs/development/performance/2026-09-06-agent-task-ui.json new file mode 100644 index 0000000..5d9efd9 --- /dev/null +++ b/docs/development/performance/2026-09-06-agent-task-ui.json @@ -0,0 +1,706 @@ +[ + { + "kind": "tasks", + "theme": "light", + "size": 100, + "initialRenderMs": 33.099999994039536, + "requests": [ + "/api/tasks" + ], + "initialTaskCount": 50, + "fullListRenderMs": 79.09999999403954, + "fullListIsInjected": true, + "domNodes": 1107, + "frameGapsMs": { + "median": 10, + "p95": 10.100000000000364, + "max": 69.49999999403951 + }, + "frames": 407, + "longTasks": [], + "scrollTop": 0, + "scrollHeight": 11702, + "maxScrollTop": 10845, + "filteredCount": 34, + "expectedFilteredCount": 34, + "filterMs": 16.299999982118607, + "repeat": 1 + }, + { + "kind": "tasks", + "theme": "light", + "size": 1000, + "initialRenderMs": 4.4000000059604645, + "requests": [ + "/api/tasks" + ], + "initialTaskCount": 50, + "fullListRenderMs": 117.39999997615814, + "fullListIsInjected": true, + "domNodes": 11007, + "frameGapsMs": { + "median": 20.099999999999454, + "p95": 30.199999999999818, + "max": 50 + }, + "frames": 353, + "longTasks": [], + "scrollTop": 54000, + "scrollHeight": 115652, + "maxScrollTop": 81000, + "filteredCount": 334, + "expectedFilteredCount": 334, + "filterMs": 44.10000002384186, + "repeat": 1 + }, + { + "kind": "tasks", + "theme": "dark", + "size": 100, + "initialRenderMs": 30.900000005960464, + "requests": [ + "/api/tasks" + ], + "initialTaskCount": 50, + "fullListRenderMs": 78.2999999821186, + "fullListIsInjected": true, + "domNodes": 1107, + "frameGapsMs": { + "median": 10, + "p95": 10.100000000000364, + "max": 49.69999998807907 + }, + "frames": 411, + "longTasks": [], + "scrollTop": 0, + "scrollHeight": 11702, + "maxScrollTop": 10845, + "filteredCount": 34, + "expectedFilteredCount": 34, + "filterMs": 16.099999994039536, + "repeat": 1 + }, + { + "kind": "tasks", + "theme": "dark", + "size": 1000, + "initialRenderMs": 5, + "requests": [ + "/api/tasks" + ], + "initialTaskCount": 50, + "fullListRenderMs": 137.7999999821186, + "fullListIsInjected": true, + "domNodes": 11007, + "frameGapsMs": { + "median": 20, + "p95": 30.199999999999818, + "max": 40.19999999999982 + }, + "frames": 360, + "longTasks": [], + "scrollTop": 54000, + "scrollHeight": 115652, + "maxScrollTop": 81000, + "filteredCount": 334, + "expectedFilteredCount": 334, + "filterMs": 47.79999998211861, + "repeat": 1 + }, + { + "kind": "tasks", + "theme": "paper-moments", + "size": 100, + "initialRenderMs": 38.099999994039536, + "requests": [ + "/api/tasks" + ], + "initialTaskCount": 50, + "fullListRenderMs": 116.09999999403954, + "fullListIsInjected": true, + "domNodes": 1107, + "frameGapsMs": { + "median": 10, + "p95": 20, + "max": 59.900000000000034 + }, + "frames": 387, + "longTasks": [], + "scrollTop": 0, + "scrollHeight": 11764, + "maxScrollTop": 10907, + "filteredCount": 34, + "expectedFilteredCount": 34, + "filterMs": 11.600000023841858, + "repeat": 1 + }, + { + "kind": "tasks", + "theme": "paper-moments", + "size": 1000, + "initialRenderMs": 5.800000011920929, + "requests": [ + "/api/tasks" + ], + "initialTaskCount": 50, + "fullListRenderMs": 150, + "fullListIsInjected": true, + "domNodes": 11007, + "frameGapsMs": { + "median": 10.100000000000364, + "p95": 50.100000000000364, + "max": 80 + }, + "frames": 368, + "longTasks": [], + "scrollTop": 54000, + "scrollHeight": 115714, + "maxScrollTop": 81000, + "filteredCount": 334, + "expectedFilteredCount": 334, + "filterMs": 59.5, + "repeat": 1 + }, + { + "kind": "trace", + "theme": "light", + "size": 200, + "initialRenderMs": 75.10000002384186, + "requests": [], + "domNodes": 2092, + "scrollContainers": [ + { + "node": "HTML", + "height": 905, + "scrollHeight": 905, + "overflow": "hidden", + "position": "static" + }, + { + "node": "BODY", + "height": 905, + "scrollHeight": 905, + "overflow": "hidden", + "position": "static" + }, + { + "node": "viewport", + "height": 905, + "scrollHeight": 18853, + "overflow": "auto", + "position": "static" + }, + { + "node": "app", + "height": 18853, + "scrollHeight": 18853, + "overflow": "visible", + "position": "static" + }, + { + "node": "trace-visualization", + "height": 18805, + "scrollHeight": 18805, + "overflow": "visible", + "position": "static" + }, + { + "node": "timeline-view", + "height": 16692, + "scrollHeight": 16692, + "overflow": "visible", + "position": "static" + }, + { + "node": "timeline", + "height": 16692, + "scrollHeight": 16692, + "overflow": "visible", + "position": "relative" + } + ], + "frameGapsMs": { + "median": 10, + "p95": 10.100000000000364, + "max": 40.00000000000003 + }, + "frames": 411, + "longTasks": [], + "scrollTop": 0, + "scrollHeight": 18853, + "maxScrollTop": 17948, + "filteredDomNodes": 436, + "filteredCount": 44, + "expectedFilteredCount": 44, + "filterMs": 16, + "treeSwitchMs": 32.099999994039536, + "treeFilterMs": 27.900000005960464, + "treeFilteredDomNodes": 689, + "repeat": 1 + }, + { + "kind": "trace", + "theme": "light", + "size": 2000, + "initialRenderMs": 283.7999999821186, + "requests": [], + "domNodes": 20542, + "scrollContainers": [ + { + "node": "HTML", + "height": 905, + "scrollHeight": 905, + "overflow": "hidden", + "position": "static" + }, + { + "node": "BODY", + "height": 905, + "scrollHeight": 905, + "overflow": "hidden", + "position": "static" + }, + { + "node": "viewport", + "height": 905, + "scrollHeight": 184678, + "overflow": "auto", + "position": "static" + }, + { + "node": "app", + "height": 184678, + "scrollHeight": 184678, + "overflow": "visible", + "position": "static" + }, + { + "node": "trace-visualization", + "height": 184630, + "scrollHeight": 184630, + "overflow": "visible", + "position": "static" + }, + { + "node": "timeline-view", + "height": 166992, + "scrollHeight": 166992, + "overflow": "visible", + "position": "static" + }, + { + "node": "timeline", + "height": 166992, + "scrollHeight": 166992, + "overflow": "visible", + "position": "relative" + } + ], + "frameGapsMs": { + "median": 10, + "p95": 10.100000000000364, + "max": 20.100000000000023 + }, + "frames": 491, + "longTasks": [], + "scrollTop": 54000, + "scrollHeight": 184678, + "maxScrollTop": 81000, + "filteredDomNodes": 4036, + "filteredCount": 444, + "expectedFilteredCount": 444, + "filterMs": 97.40000000596046, + "treeSwitchMs": 64, + "treeFilterMs": 617.1999999880791, + "treeFilteredDomNodes": 6539, + "repeat": 1 + }, + { + "kind": "trace", + "theme": "dark", + "size": 200, + "initialRenderMs": 81.5, + "requests": [], + "domNodes": 2092, + "scrollContainers": [ + { + "node": "HTML", + "height": 905, + "scrollHeight": 905, + "overflow": "hidden", + "position": "static" + }, + { + "node": "BODY", + "height": 905, + "scrollHeight": 905, + "overflow": "hidden", + "position": "static" + }, + { + "node": "viewport", + "height": 905, + "scrollHeight": 18853, + "overflow": "auto", + "position": "static" + }, + { + "node": "app", + "height": 18853, + "scrollHeight": 18853, + "overflow": "visible", + "position": "static" + }, + { + "node": "trace-visualization", + "height": 18805, + "scrollHeight": 18805, + "overflow": "visible", + "position": "static" + }, + { + "node": "timeline-view", + "height": 16692, + "scrollHeight": 16692, + "overflow": "visible", + "position": "static" + }, + { + "node": "timeline", + "height": 16692, + "scrollHeight": 16692, + "overflow": "visible", + "position": "relative" + } + ], + "frameGapsMs": { + "median": 10, + "p95": 10.100000000000364, + "max": 30 + }, + "frames": 415, + "longTasks": [], + "scrollTop": 0, + "scrollHeight": 18853, + "maxScrollTop": 17948, + "filteredDomNodes": 436, + "filteredCount": 44, + "expectedFilteredCount": 44, + "filterMs": 16.69999998807907, + "treeSwitchMs": 31.099999994039536, + "treeFilterMs": 28.900000005960464, + "treeFilteredDomNodes": 689, + "repeat": 1 + }, + { + "kind": "trace", + "theme": "dark", + "size": 2000, + "initialRenderMs": 289, + "requests": [], + "domNodes": 20542, + "scrollContainers": [ + { + "node": "HTML", + "height": 905, + "scrollHeight": 905, + "overflow": "hidden", + "position": "static" + }, + { + "node": "BODY", + "height": 905, + "scrollHeight": 905, + "overflow": "hidden", + "position": "static" + }, + { + "node": "viewport", + "height": 905, + "scrollHeight": 184678, + "overflow": "auto", + "position": "static" + }, + { + "node": "app", + "height": 184678, + "scrollHeight": 184678, + "overflow": "visible", + "position": "static" + }, + { + "node": "trace-visualization", + "height": 184630, + "scrollHeight": 184630, + "overflow": "visible", + "position": "static" + }, + { + "node": "timeline-view", + "height": 166992, + "scrollHeight": 166992, + "overflow": "visible", + "position": "static" + }, + { + "node": "timeline", + "height": 166992, + "scrollHeight": 166992, + "overflow": "visible", + "position": "relative" + } + ], + "frameGapsMs": { + "median": 10, + "p95": 10.100000000000364, + "max": 20.200000000000045 + }, + "frames": 487, + "longTasks": [], + "scrollTop": 54000, + "scrollHeight": 184678, + "maxScrollTop": 81000, + "filteredDomNodes": 4036, + "filteredCount": 444, + "expectedFilteredCount": 444, + "filterMs": 74.5, + "treeSwitchMs": 62.900000005960464, + "treeFilterMs": 483, + "treeFilteredDomNodes": 6539, + "repeat": 1 + }, + { + "kind": "trace", + "theme": "paper-moments", + "size": 200, + "initialRenderMs": 119.59999999403954, + "requests": [], + "domNodes": 2092, + "scrollContainers": [ + { + "node": "HTML", + "height": 905, + "scrollHeight": 905, + "overflow": "hidden", + "position": "static" + }, + { + "node": "BODY", + "height": 905, + "scrollHeight": 905, + "overflow": "hidden", + "position": "static" + }, + { + "node": "viewport", + "height": 905, + "scrollHeight": 18853, + "overflow": "auto", + "position": "static" + }, + { + "node": "app", + "height": 18853, + "scrollHeight": 18853, + "overflow": "visible", + "position": "static" + }, + { + "node": "trace-visualization", + "height": 18805, + "scrollHeight": 18805, + "overflow": "visible", + "position": "static" + }, + { + "node": "timeline-view", + "height": 16692, + "scrollHeight": 16692, + "overflow": "visible", + "position": "static" + }, + { + "node": "timeline", + "height": 16692, + "scrollHeight": 16692, + "overflow": "visible", + "position": "relative" + } + ], + "frameGapsMs": { + "median": 10, + "p95": 20, + "max": 89.99999999999997 + }, + "frames": 394, + "longTasks": [], + "scrollTop": 0, + "scrollHeight": 18853, + "maxScrollTop": 17948, + "filteredDomNodes": 436, + "filteredCount": 44, + "expectedFilteredCount": 44, + "filterMs": 19.700000017881393, + "treeSwitchMs": 40.10000002384186, + "treeFilterMs": 19.899999976158142, + "treeFilteredDomNodes": 689, + "repeat": 1 + }, + { + "kind": "trace", + "theme": "paper-moments", + "size": 2000, + "initialRenderMs": 337.2999999821186, + "requests": [], + "domNodes": 20542, + "scrollContainers": [ + { + "node": "HTML", + "height": 905, + "scrollHeight": 905, + "overflow": "hidden", + "position": "static" + }, + { + "node": "BODY", + "height": 905, + "scrollHeight": 905, + "overflow": "hidden", + "position": "static" + }, + { + "node": "viewport", + "height": 905, + "scrollHeight": 184678, + "overflow": "auto", + "position": "static" + }, + { + "node": "app", + "height": 184678, + "scrollHeight": 184678, + "overflow": "visible", + "position": "static" + }, + { + "node": "trace-visualization", + "height": 184630, + "scrollHeight": 184630, + "overflow": "visible", + "position": "static" + }, + { + "node": "timeline-view", + "height": 166992, + "scrollHeight": 166992, + "overflow": "visible", + "position": "static" + }, + { + "node": "timeline", + "height": 166992, + "scrollHeight": 166992, + "overflow": "visible", + "position": "relative" + } + ], + "frameGapsMs": { + "median": 10, + "p95": 20.100000000000023, + "max": 30.100000000000023 + }, + "frames": 416, + "longTasks": [], + "scrollTop": 54000, + "scrollHeight": 184678, + "maxScrollTop": 81000, + "filteredDomNodes": 4036, + "filteredCount": 444, + "expectedFilteredCount": 444, + "filterMs": 86.2999999821186, + "treeSwitchMs": 62.099999994039536, + "treeFilterMs": 540.0999999940395, + "treeFilteredDomNodes": 6539, + "repeat": 1 + }, + { + "kind": "trace", + "theme": "paper-moments", + "size": 10000, + "initialRenderMs": 1803.9000000059605, + "requests": [], + "domNodes": 102542, + "scrollContainers": [ + { + "node": "HTML", + "height": 905, + "scrollHeight": 905, + "overflow": "hidden", + "position": "static" + }, + { + "node": "BODY", + "height": 905, + "scrollHeight": 905, + "overflow": "hidden", + "position": "static" + }, + { + "node": "viewport", + "height": 905, + "scrollHeight": 921678, + "overflow": "auto", + "position": "static" + }, + { + "node": "app", + "height": 921678, + "scrollHeight": 921678, + "overflow": "visible", + "position": "static" + }, + { + "node": "trace-visualization", + "height": 921630, + "scrollHeight": 921630, + "overflow": "visible", + "position": "static" + }, + { + "node": "timeline-view", + "height": 834992, + "scrollHeight": 834992, + "overflow": "visible", + "position": "static" + }, + { + "node": "timeline", + "height": 834992, + "scrollHeight": 834992, + "overflow": "visible", + "position": "relative" + } + ], + "frameGapsMs": { + "median": 20.100000000000364, + "p95": 40, + "max": 100 + }, + "frames": 357, + "longTasks": [ + 82, + 53 + ], + "scrollTop": 54000, + "scrollHeight": 921678, + "maxScrollTop": 81000, + "filteredDomNodes": 40036, + "filteredCount": 4444, + "expectedFilteredCount": 4444, + "filterMs": 582.7999999821186, + "treeSwitchMs": 317.5, + "treeFilterMs": 25914.80000001192, + "treeFilteredDomNodes": 32539, + "repeat": 1 + } +] diff --git a/docs/development/performance/2026-09-06-agent-trace-ui-fixed.json b/docs/development/performance/2026-09-06-agent-trace-ui-fixed.json new file mode 100644 index 0000000..19f868f --- /dev/null +++ b/docs/development/performance/2026-09-06-agent-trace-ui-fixed.json @@ -0,0 +1,156 @@ +[ + { + "kind": "trace", + "theme": "paper-moments", + "size": 2000, + "initialRenderMs": 117.19999998807907, + "requests": [], + "domNodes": 1852, + "scrollContainers": [ + { + "node": "HTML", + "height": 905, + "scrollHeight": 905, + "overflow": "hidden", + "position": "static" + }, + { + "node": "BODY", + "height": 905, + "scrollHeight": 905, + "overflow": "hidden", + "position": "static" + }, + { + "node": "viewport", + "height": 905, + "scrollHeight": 17214, + "overflow": "auto", + "position": "static" + }, + { + "node": "app", + "height": 17214, + "scrollHeight": 17214, + "overflow": "visible", + "position": "static" + }, + { + "node": "trace-visualization", + "height": 17166, + "scrollHeight": 17166, + "overflow": "visible", + "position": "static" + }, + { + "node": "timeline-view", + "height": 16692, + "scrollHeight": 16692, + "overflow": "visible", + "position": "static" + }, + { + "node": "timeline", + "height": 16692, + "scrollHeight": 16692, + "overflow": "visible", + "position": "relative" + } + ], + "frameGapsMs": { + "median": 10, + "p95": 10.100000000000364, + "max": 80.09999999999997 + }, + "frames": 408, + "longTasks": [], + "scrollTop": 0, + "scrollHeight": 17214, + "maxScrollTop": 16309, + "filteredDomNodes": 1844, + "filteredCount": 200, + "expectedFilteredCount": 200, + "filterMs": 71.90000000596046, + "treeSwitchMs": 51.400000005960464, + "treeFilterMs": 48.70000001788139, + "treeFilteredDomNodes": 1343, + "repeat": 1 + }, + { + "kind": "trace", + "theme": "paper-moments", + "size": 10000, + "initialRenderMs": 94.40000000596046, + "requests": [], + "domNodes": 1852, + "scrollContainers": [ + { + "node": "HTML", + "height": 905, + "scrollHeight": 905, + "overflow": "hidden", + "position": "static" + }, + { + "node": "BODY", + "height": 905, + "scrollHeight": 905, + "overflow": "hidden", + "position": "static" + }, + { + "node": "viewport", + "height": 905, + "scrollHeight": 17214, + "overflow": "auto", + "position": "static" + }, + { + "node": "app", + "height": 17214, + "scrollHeight": 17214, + "overflow": "visible", + "position": "static" + }, + { + "node": "trace-visualization", + "height": 17166, + "scrollHeight": 17166, + "overflow": "visible", + "position": "static" + }, + { + "node": "timeline-view", + "height": 16692, + "scrollHeight": 16692, + "overflow": "visible", + "position": "static" + }, + { + "node": "timeline", + "height": 16692, + "scrollHeight": 16692, + "overflow": "visible", + "position": "relative" + } + ], + "frameGapsMs": { + "median": 10, + "p95": 10.100000000000364, + "max": 50.09999999999991 + }, + "frames": 414, + "longTasks": [], + "scrollTop": 0, + "scrollHeight": 17214, + "maxScrollTop": 16309, + "filteredDomNodes": 1844, + "filteredCount": 200, + "expectedFilteredCount": 200, + "filterMs": 284.90000000596046, + "treeSwitchMs": 100.90000000596046, + "treeFilterMs": 189.19999998807907, + "treeFilteredDomNodes": 1343, + "repeat": 1 + } +] \ No newline at end of file diff --git a/docs/development/performance/2026-09-06-scroll-theme-comparison.json b/docs/development/performance/2026-09-06-scroll-theme-comparison.json new file mode 100644 index 0000000..687c76d --- /dev/null +++ b/docs/development/performance/2026-09-06-scroll-theme-comparison.json @@ -0,0 +1,150 @@ +{ + "light": { + "requestedHan": 120000, + "theme": "light", + "variant": "default", + "frameGapsMs": { + "median": 10, + "p95": 30, + "max": 90.09999999999991 + }, + "frames": 403, + "framesOver25ms": 29, + "longTasks": [ + 89 + ], + "scrollTop": 54000, + "scrollHeight": 168515, + "foldedScrollTop": 0, + "caretAfterFold": 1, + "repeat": 1 + }, + "dark": { + "requestedHan": 120000, + "theme": "dark", + "variant": "default", + "frameGapsMs": { + "median": 10, + "p95": 30, + "max": 90 + }, + "frames": 408, + "framesOver25ms": 27, + "longTasks": [ + 88 + ], + "scrollTop": 54000, + "scrollHeight": 168515, + "foldedScrollTop": 0, + "caretAfterFold": 1, + "repeat": 1 + }, + "fixed": [ + { + "requestedHan": 120000, + "theme": "paper-moments", + "variant": "default", + "frameGapsMs": { + "median": 10, + "p95": 30.100000000000136, + "max": 100 + }, + "frames": 422, + "framesOver25ms": 31, + "longTasks": [ + 99 + ], + "scrollTop": 54037, + "scrollHeight": 160247, + "foldedScrollTop": 0, + "caretAfterFold": 1, + "repeat": 1 + }, + { + "requestedHan": 120000, + "theme": "paper-moments", + "variant": "default", + "frameGapsMs": { + "median": 10, + "p95": 30, + "max": 90 + }, + "frames": 427, + "framesOver25ms": 31, + "longTasks": [ + 84, + 58 + ], + "scrollTop": 54000, + "scrollHeight": 160211, + "foldedScrollTop": 0, + "caretAfterFold": 1, + "repeat": 2 + }, + { + "requestedHan": 120000, + "theme": "paper-moments", + "variant": "default", + "frameGapsMs": { + "median": 10, + "p95": 30.09999999999991, + "max": 90.09999999999991 + }, + "frames": 422, + "framesOver25ms": 29, + "longTasks": [ + 85 + ], + "scrollTop": 54037, + "scrollHeight": 160247, + "foldedScrollTop": 0, + "caretAfterFold": 1, + "repeat": 3 + } + ], + "outlineDisabled": [ + { + "requestedHan": 120000, + "theme": "paper-moments", + "variant": "no-outline", + "frameGapsMs": { + "median": 10, + "p95": 30.099999999999454, + "max": 100 + }, + "frames": 418, + "framesOver25ms": 31, + "longTasks": [ + 101 + ], + "scrollTop": 54037, + "scrollHeight": 160247, + "foldedScrollTop": 0, + "caretAfterFold": 1, + "repeat": 1 + }, + { + "requestedHan": 120000, + "theme": "paper-moments", + "variant": "no-outline", + "frameGapsMs": { + "median": 10, + "p95": 30, + "max": 99.89999999999964 + }, + "frames": 413, + "framesOver25ms": 32, + "longTasks": [ + 87, + 50, + 52, + 52 + ], + "scrollTop": 53965, + "scrollHeight": 160174, + "foldedScrollTop": 0, + "caretAfterFold": 1, + "repeat": 2 + } + ] +} diff --git a/docs/development/performance/2026-09-06-scroll-token-cache.json b/docs/development/performance/2026-09-06-scroll-token-cache.json new file mode 100644 index 0000000..57c10ec --- /dev/null +++ b/docs/development/performance/2026-09-06-scroll-token-cache.json @@ -0,0 +1,66 @@ +[ + { + "requestedHan": 120000, + "theme": "paper-moments", + "frameGapsMs": { + "median": 70.29999999999927, + "p95": 100.20000000000073, + "max": 210.20000000000073 + }, + "frames": 308, + "framesOver25ms": 286, + "longTasks": [ + 86, + 54, + 56, + 62, + 50, + 58, + 53, + 52, + 58, + 100, + 107, + 96, + 60, + 99, + 89, + 136, + 101, + 98, + 101, + 90, + 66, + 120, + 74, + 99, + 58 + ], + "scrollTop": 53127, + "scrollHeight": 159554, + "foldedScrollTop": 0, + "caretAfterFold": 1, + "repeat": 1 + }, + { + "requestedHan": 120000, + "theme": "paper-moments", + "frameGapsMs": { + "median": 70, + "p95": 90, + "max": 150 + }, + "frames": 261, + "framesOver25ms": 235, + "longTasks": [ + 84, + 67, + 52 + ], + "scrollTop": 53233, + "scrollHeight": 159554, + "foldedScrollTop": 0, + "caretAfterFold": 1, + "repeat": 2 + } +] \ No newline at end of file diff --git a/docs/development/performance/2026-09-06-task-http-fixed.json b/docs/development/performance/2026-09-06-task-http-fixed.json new file mode 100644 index 0000000..d19013c --- /dev/null +++ b/docs/development/performance/2026-09-06-task-http-fixed.json @@ -0,0 +1,36 @@ +{ + "transport": "real loopback HTTP, separate Uvicorn process", + "tasks": 1000, + "concurrency": 20, + "elapsed_ms": 24509.81, + "latencies": { + "create": { + "count": 1000, + "p95_ms": 157.68, + "max_ms": 186.7 + }, + "update": { + "count": 1000, + "p95_ms": 208.68, + "max_ms": 259.91 + }, + "list": { + "count": 11, + "p95_ms": 23.39, + "max_ms": 23.39 + }, + "delete": { + "count": 1000, + "p95_ms": 205.45, + "max_ms": 279.12 + }, + "health": { + "count": 375, + "p95_ms": 38.64, + "max_ms": 164.76 + } + }, + "health_errors": [], + "pagination_complete": true, + "final_total": 0 +} \ No newline at end of file diff --git a/docs/development/performance/2026-09-06-task-http.json b/docs/development/performance/2026-09-06-task-http.json new file mode 100644 index 0000000..81ac402 --- /dev/null +++ b/docs/development/performance/2026-09-06-task-http.json @@ -0,0 +1,36 @@ +{ + "transport": "real loopback HTTP, separate Uvicorn process", + "tasks": 1000, + "concurrency": 20, + "elapsed_ms": 18312.92, + "latencies": { + "create": { + "count": 1000, + "p95_ms": 116.45, + "max_ms": 134.91 + }, + "update": { + "count": 1000, + "p95_ms": 159.29, + "max_ms": 193.37 + }, + "list": { + "count": 11, + "p95_ms": 20.96, + "max_ms": 20.96 + }, + "delete": { + "count": 1000, + "p95_ms": 156.43, + "max_ms": 190.1 + }, + "health": { + "count": 117, + "p95_ms": 157.0, + "max_ms": 195.07 + } + }, + "health_errors": [], + "pagination_complete": true, + "final_total": 0 +} \ No newline at end of file diff --git a/docs/development/performance/2026-09-06-task-ui-fixed.json b/docs/development/performance/2026-09-06-task-ui-fixed.json new file mode 100644 index 0000000..ef12cc1 --- /dev/null +++ b/docs/development/performance/2026-09-06-task-ui-fixed.json @@ -0,0 +1,70 @@ +[ + { + "kind": "tasks", + "theme": "paper-moments", + "size": 1000, + "initialRenderMs": 173, + "requests": [ + "/api/tasks?limit=100&offset=0", + "/api/tasks?limit=100&offset=100", + "/api/tasks?limit=100&offset=200", + "/api/tasks?limit=100&offset=300", + "/api/tasks?limit=100&offset=400", + "/api/tasks?limit=100&offset=500", + "/api/tasks?limit=100&offset=600", + "/api/tasks?limit=100&offset=700", + "/api/tasks?limit=100&offset=800", + "/api/tasks?limit=100&offset=900" + ], + "initialTaskCount": 1000, + "fullListRenderMs": 85.39999997615814, + "fullListIsInjected": true, + "renderedTasks": 100, + "domNodes": 1111, + "scrollContainers": [ + { + "node": "HTML", + "height": 905, + "scrollHeight": 905, + "overflow": "hidden", + "position": "static" + }, + { + "node": "BODY", + "height": 905, + "scrollHeight": 905, + "overflow": "hidden", + "position": "static" + }, + { + "node": "viewport", + "height": 905, + "scrollHeight": 905, + "overflow": "auto", + "position": "static" + }, + { + "node": "app", + "height": 905, + "scrollHeight": 905, + "overflow": "hidden", + "position": "static" + } + ], + "frameGapsMs": { + "median": 10, + "p95": 30, + "max": 50.10000000000002 + }, + "frames": 384, + "longTasks": [], + "scrollTop": 0, + "scrollHeight": 11798, + "maxScrollTop": 10941, + "filteredCount": 100, + "totalFilteredCount": 334, + "expectedFilteredCount": 100, + "filterMs": 18.69999998807907, + "repeat": 1 + } +] \ No newline at end of file diff --git a/docs/development/后台运行日志与压力问题修复.md b/docs/development/后台运行日志与压力问题修复.md new file mode 100644 index 0000000..48ac272 --- /dev/null +++ b/docs/development/后台运行日志与压力问题修复.md @@ -0,0 +1,101 @@ +# 后台运行日志与压力问题修复 + +## 1. 范围与入口 + +本次针对 Agent 与任务压测发现的历史记录截断、同步数据库写入阻塞事件循环、长 Trace 树形筛选过慢进行修复，并增加统一运行日志。 + +主导航的「日志」打开 `/logs`。知识库选择页也有入口；无需成功打开 Vault 即可查看。需要 AI Core 正常提供 HTTP 服务。后台未启动时，页面显示连接错误，不伪造历史结果。 + +页面提供级别、模块、事件名/错误码/关联 ID 筛选及详情展开。日志列表高度受限，按时间从旧到新显示，默认每 5 秒获取新日志并跟随到底部。向上滚动时暂停跟随，抵达顶部自动加载更早日志并保持阅读位置；可一键回到最新。隐藏页面和卸载后停止轮询。界面最多保留当前浏览窗口的 500 条，继续读取旧日志时移出另一端的记录，后台保留窗口不受影响。所有组件使用已有主题变量、卡片、按钮、下拉框及 `ui-disclosure` 展开样式。 + +## 2. 日志覆盖 + +| 模块 | 记录内容 | 定位信息 | +| --- | --- | --- | +| vectors | 后台索引状态、向量调用失败、是否使用本地索引回退 | job_id、错误码、异常类型、调用位置、批次数量 | +| models | 本地模型/远程模型运行诊断、CUDA/CPU、失败与回退 | 模型、设备、状态、错误码、耗时 | +| agent | 创建运行、模型轮次、工具调用与结果、权限决策、完成/失败/取消 | run_id、Provider、模型、步骤、事件序号、工具名 | +| tasks | 创建、修改、删除及不存在的删除目标 | task_id、关联 note_id、修改字段名、状态 | +| providers / chat | 模型请求完成或未完整结束、流式模型错误、对话失败 | Provider、模型、request_id、run_id、错误码 | +| http / api | HTTP 写操作、失败请求、超过一秒的请求及业务错误 | HTTP 方法、路由模板、状态码、耗时、request_id、资源 ID | +| system / Python logger | 服务启动与停止，以及应用、服务器和依赖库的 warning/error | 模块、代码位置、异常类型 | + +`X-Request-ID` 响应头可与日志中的 request_id 对照。请求上下文通过 ContextVar 传播到后台任务和线程；Agent 内部工具触发的日志还带 run_id。查询日志自身以及正常短轮询不生成 HTTP 操作日志，避免轮询放大日志量。 + +这里只记录操作诊断，不替代完整 Agent Trace、Token 用量台账和模型诊断表。旧代码 logger 的自由文本可能包含笔记或厂商返回，因此桥接时只记录级别、模块、代码位置和异常类型；需要业务错误码的地方使用结构化接口。 + +## 3. 存储、容量与隐私 + +- 位置：`APP_DATA_DIR/logs/operations.sqlite3`，与业务数据库独立，应用重启后可继续查看。 +- 保留最近 20,000 条；每批写入时淘汰更早的记录。不是按天永久归档。 +- 后台线程批量写入，队列最多 4,096 条，一批最多 128 条。队列满时丢弃新诊断记录并计数，绝不阻塞保存或模型推理。 +- 日志页面显示待写入数量、队列溢出和写入失败数量。计数属于当前进程；重启后重置。存储不可读时显示请求失败。 +- 正常退出先停止 Agent 和其他后台工作，再排空日志队列；强制终止进程可能丢失尚未写入的队列内容。 +- 不记录请求/响应正文、系统提示词、工具参数/输出、笔记标题或正文、凭据、原始异常消息、查询字符串。元数据按白名单筛选并限长，Bearer 和 `sk-` 凭据形式额外脱敏。 +- API 仅返回保留窗口内的诊断数据，不提供任意文件读取和日志删除接口。 + +## 4. 开发接口 + +```python +from app.operation_logs import log_event + +log_event('vectors', 'embedding.failed', level='ERROR', error=exc, + model=model_id, job_id=job_id, error_code='EMBEDDING_UNAVAILABLE', + fallback='local_index') +``` + +第一个参数是模块名。`source` 是可选的元数据字段，例如 `local` 或 `api`，不要与模块名混淆。事件名应使用开发时定义的短常量。不要把正文、URL、异常消息或用户输入拼入事件名。 + +`GET /api/logs` 参数： + +| 参数 | 规则 | +| --- | --- | +| limit | 默认 50，范围 1–200 | +| before | 上页 next_cursor；正整数，返回更早的 ID | +| level | 空或 INFO / WARNING / ERROR / CRITICAL | +| source | 模块名精确匹配，最多 100 字符 | +| q | 在事件名及脱敏元数据中做字面子串搜索，最多 200 字符 | + +返回 `items`、`next_cursor`、`sources`、`pending`、`dropped`、`write_failures`、`retention`。按递增 ID 的倒序分页，插入新日志不改变已经翻到的旧页边界。没有匹配记录时 items 为空、next_cursor 为 null。 + +## 5. 压力问题的修复方式 + +Agent Trace 写入由独立异步队列调度到线程，最多合并 64 个写入为一个 SQLite 事务。提交成功后才更新对外可见快照和广播 SSE。创建记录在第一次 await 前占用运行名额，避免并发创建突破 200 个活动运行上限。取消等待正在提交的快照结束，再写终态；服务关闭会等待 Agent 和 Trace 队列。数据库失败不会被当成成功提交。 + +任务 HTTP 写操作在协程中排队，然后在线程执行；读操作也在线程执行，减少文件锁争用和主事件循环阻塞。SQLite 仍是单写者，不意味着任务写入支持无限并发。 + +前端读取任务和 Agent 列表的后续 API 页，不再只显示第一页的 50 条。任务筛选和数量基于已获取的完整列表，界面每页显示 100 个任务；运行侧栏每页 50 条。列表刷新失败保留上次结果。列表读取使用现有 offset 协议，不是跨多页的事务快照；其他客户端同时修改数据时可以刷新重新获取。 + +Trace 搜索先生成事件序号、模型调用 ID、工具调用 ID 的集合，再一次遍历调用树。匹配子节点保留父节点。搜索作用于完整已加载的历史，每页只渲染 200 个事件或树节点。工具统计按工具名和状态汇总，避免在底部再次生成数千个调用卡片。 + +## 6. 验证方法 + +后端回归覆盖日志持久化、重启、保留窗口、筛选与游标、正文排除、HTTP 关联 ID，以及后台 Trace 写入同时取消时仍释放等待方。业务回归覆盖 Agent/任务、模型路由、本地模型、用量统计和对话。 + +```powershell +cd backend +.venv/Scripts/python.exe -m pytest tests/test_agent_core.py tests/test_api.py tests/test_operation_logs.py tests/test_model_routing.py tests/test_local_models.py tests/test_usage_overrides.py tests/test_chat_history.py tests/test_chat_context.py -q +``` + +运行测试前应将 APP_DATA_DIR、APP_DB_PATH 和 APP_VAULT_PATH 指向临时目录，避免模块导入时初始化真实扩展。pytest 的 fixture 会继续为每个测试隔离数据。 + +前端执行 `npm --prefix frontend test` 和 `npm --prefix frontend run build`。新增用例验证后续任务/Agent 页完整加载、Trace 全历史搜索与分页、日志筛选/游标、自动跟随与上滚暂停、顶部历史加载、存储异常提示及卸载后停止刷新。 + +2026-09-06 实测：后端全量 627 项通过；随后增加的 3 项写入失败/取消回归也通过，最后相关接口回归 21 项通过。前端全量 413 项通过，生产构建通过。构建仍提示已有部分 Markdown/Mermaid 依赖块大于 500 kB；后端测试保留已有 Starlette TestClient 弃用提示。纸间时光日志页已用隔离合成数据检查截图，运行中的本机 `/api/logs` 也已确认可返回结果。 + +离线并发压测与真实本机 HTTP 压测复现方式、前后数据见 [Agent 与任务压测报告](Agent与任务压测报告.md)。压测只使用隔离数据和 Mock Provider，不消耗用户厂商额度。 + +手工验收建议： + +1. 创建、修改和删除一个测试任务，按返回的 task_id 或 X-Request-ID 筛选日志。 +2. 运行含工具调用的 Agent，批准或取消权限请求；按 run_id 检查创建、权限、工具结果和终态。 +3. 在隔离配置中请求未安装的本地模型，查看 models/vectors 的错误码与回退信息，不应出现输入文本。 +4. 重启 AI Core，确认已提交日志仍可查看；退出 Vault 后从入口页打开日志。 +5. 切换默认浅色、深色、纸间时光主题，检查筛选栏、错误徽标和详情展开；窄窗口下应换行且详情不撑出页面。 +# 2026-09-06：大批量本地向量传输修复 + +全量重建包含 2111 个文本块时，本地模型可能成功完成推理，但整批向量被写成一行 JSON。接收端单行限制为 16 MiB：asyncio 管道拒绝超长行，Windows 线程管道则读到不完整 JSON，最终被包装成 `LOCAL_MODEL_INVALID_RESPONSE`。这类错误不表示 CUDA 显存不足，也不应通过切换 CPU 处理。 + +Embedding 响应改为每 128 条向量一个 JSON 帧，结束帧携带总数。接收端检查偏移连续性、请求数量和结束标记；缺块时明确失败，不把部分向量写入索引。模型仍只加载一次，推理批大小不变。语音等其他响应保持原协议。 + +验证方法：在隔离数据目录运行 `tests/test_local_models.py`，分别使用 asyncio 与 Windows 线程管道传输 2111 × 384 的结果，确认旧格式超过 16 MiB，而分帧可完整接收。该文件 7 项测试通过。另使用本机 Bekko 权重、CUDA 对 2111 条合成文本做真实推理：返回 2111 条 384 维向量，设备 `cuda:0`，耗时约 12.55 秒；旧格式 JSON 为 17,886,180 字节。该验收不修改用户笔记、索引或运行配置；用户原始长文档的全库重建仍需在服务加载修复后重试。 diff --git a/docs/development/长文渲染优化与压测报告.md b/docs/development/长文渲染优化与压测报告.md index 923c277..ac734b3 100644 --- a/docs/development/长文渲染优化与压测报告.md +++ b/docs/development/长文渲染优化与压测报告.md @@ -77,3 +77,34 @@ backend/.venv/Scripts/python.exe frontend/tests/performance/run-stress.py --url 下一步需要评估代码块按交互初始化或编辑器级虚拟化，并同时验证输入、选区、搜索定位和折叠；当前不将 12 万字滚动问题标记为完成。 本轮前端 405 项测试通过，涵盖折叠定位、语言标签增量同步、菜单祖先滚动定位和卸载清理。 + +## 7. CodeMirror 高亮复用实验 + +在上轮提交 `874e916` 的基础上继续尝试：同一语言及主题的 CodeMirror LanguageSupport 内缓存高亮装饰，代码块离屏销毁后重新创建时，相同正文不再重复分词及构建装饰。缓存最多 32 项、64000 个源字符，超过 16000 字符的单块不缓存，使用 LRU 淘汰；语言支持释放时缓存一并释放。编辑后的内容按新正文计算，不复用旧位置。 + +回归测试通过统计分词调用验证跨视图复用、正文编辑重新计算和超限淘汰。原有深浅主题切换与编辑测试继续验证显示内容。 + +12 万字继续测量两次，帧间隔 P95 分别约 100.2 ms、90 ms，二者中位数约 95.1 ms；上一轮约 100 ms。样本重复代码较多，结果仍在明显波动范围内，不能宣称解决滚动卡顿。此优化减少确定可重复的高亮工作，但下一步仍须处理创建 CodeMirror 和布局测量的成本。 + +- [本轮滚轮原始数据](performance/2026-09-06-scroll-token-cache.json) + +## 8. 主题对照与纸间时光 1.8.1 修复 + +用户补充：同一份 12 万字文档在默认浅色、深色下不卡顿。因此重新进行主题对照，之前将 CodeMirror 作为主要优化方向的判断不足；CPU 采样中的布局及选区测量耗时不能单独证明编辑器是主要原因。 + +保持相同文档和滚轮脚本，默认浅色、深色各测一次，P95 均约 30 ms。纸间时光 1.8.0 仅禁用整篇 `.ProseMirror` 的虚线 outline 后，两次 P95 约 30.1、30 ms；相比此前约 90–100 ms，构成明确的样式消融证据。主题与 CodeMirror 的交互仍可能影响布局，但不需要先用编辑器虚拟化解决这个差异。 + +修复将贯穿长文的虚线轮廓改为四条小尺寸渐变平铺背景，保留纸张、缝线、胶带、段落横线和叠纸阴影。独立伪元素虚线 border 的实验反而更慢，已撤回。正式主题版本升为 1.8.1。 + +| 主题或实验 | 次数 | 帧间隔 P95（ms） | +| --- | ---: | --- | +| 默认浅色 | 1 | 30 | +| 默认深色 | 1 | 30 | +| 1.8.0 仅禁用整篇 outline | 2 | 30.1、30 | +| 1.8.1 平铺缝线 | 3 | 30.1、30、30.1 | + +1.8.1 三次测试的帧间隔中位数均为 10 ms，全部折叠后的 scrollTop 均为 0，光标位置均为 1。已检查视口截图，手账装饰保留。这里的结果说明本轮样本与环境下，纸间时光恢复到接近默认主题的滚动表现，不代表所有设备、所有复杂文档均无长任务。 + +已安装主题保存在本地，不会自动被新版资源覆盖。刷新前端后，到“主题 → 社区主题 → 纸间时光”点击“更新”，确认版本 1.8.1 再进行手动复测。 + +- [主题对比原始数据](performance/2026-09-06-scroll-theme-comparison.json) diff --git a/frontend/src/assets/themes/paper-moments.theme b/frontend/src/assets/themes/paper-moments.theme index 667b04f..36869b0 100644 --- a/frontend/src/assets/themes/paper-moments.theme +++ b/frontend/src/assets/themes/paper-moments.theme @@ -1,6 +1,6 @@ theme_id: paper-moments name: 纸间时光 · Paper Moments -version: 1.8.0 +version: 1.8.1 author: NotesAgent description: 奶油纸张、手帐虚线与粉蓝胶带，把每天的灵感好好收藏。 min_app_version: 0.2.0 @@ -155,9 +155,13 @@ license: MIT padding: 44px 40px 60px 52px; border: 1px solid #685949; border-radius: 8px 16px 8px 8px; - outline: 1px dashed #c5b9a7; - outline-offset: -10px; - background: linear-gradient(90deg, transparent 32px, #e9cfc7 32px 34px, transparent 34px), #fffef8; + /* Small repeated tiles retain the stitching without a document-height dashed outline. */ + background: + linear-gradient(#c5b9a7 50%, transparent 50%) 10px 0 / 1px 8px repeat-y, + linear-gradient(#c5b9a7 50%, transparent 50%) calc(100% - 10px) 0 / 1px 8px repeat-y, + linear-gradient(90deg, #c5b9a7 50%, transparent 50%) 0 10px / 8px 1px repeat-x, + linear-gradient(90deg, #c5b9a7 50%, transparent 50%) 0 calc(100% - 10px) / 8px 1px repeat-x, + linear-gradient(90deg, transparent 32px, #e9cfc7 32px 34px, transparent 34px), #fffef8; box-shadow: 6px 6px 0 #d8e6e2, 12px 12px 0 #f0d8cf; } [data-theme="paper-moments"] .milkdown-host .ProseMirror::before { diff --git a/frontend/src/components/common/AppShell.vue b/frontend/src/components/common/AppShell.vue index 2d792ee..ef49197 100644 --- a/frontend/src/components/common/AppShell.vue +++ b/frontend/src/components/common/AppShell.vue @@ -29,8 +29,9 @@ const router = useRouter() let statusTimer: ReturnType | undefined let disposed = false async function pollIndex() { - try { settingsStore.indexStatus = await getIndexStatus() } catch { /* retain last status; retry */ } - if (!disposed) statusTimer = setTimeout(pollIndex, 5000) + try { const status = await getIndexStatus(); if (!disposed) settingsStore.indexStatus = status } catch { /* retain last status; retry */ } + const busy = settingsStore.indexStatus.status === 'indexing' || settingsStore.indexStatus.active_searches + if (!disposed) statusTimer = setTimeout(pollIndex, busy || route.name === 'settings' || route.name === 'search' ? 1000 : 5000) } onMounted(() => { void settingsStore.loadDiagnostics(); void pollIndex() }) onUnmounted(() => { disposed = true; clearTimeout(statusTimer) }) diff --git a/frontend/src/components/common/PrimarySidebar.vue b/frontend/src/components/common/PrimarySidebar.vue index b0b371b..b0966ad 100644 --- a/frontend/src/components/common/PrimarySidebar.vue +++ b/frontend/src/components/common/PrimarySidebar.vue @@ -1,7 +1,7 @@