From 55d3ab5ccc60a70739a9ca3568734ad08ce1cfeb Mon Sep 17 00:00:00 2001 From: Steven Enamakel <31011319+senamakel@users.noreply.github.com> Date: Fri, 24 Jul 2026 17:49:03 +0300 Subject: [PATCH] =?UTF-8?q?fix:=20Sentry=20triage=20=E2=80=94=20resolve=20?= =?UTF-8?q?16=20actionable=20issues=20across=20tauri-react,=20tauri-rust,?= =?UTF-8?q?=20core-rust=20(#5171)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Co-authored-by: Maciej Myszkiewicz --- .github/tauri-cef-expected-sha | 2 +- app/src-tauri/src/lib.rs | 18 + app/src-tauri/vendor/tauri-cef | 2 +- app/src/assets/audio/README.md | 2 +- app/src/chat/chatSendError.ts | 3 +- app/src/components/chat/ChatComposer.tsx | 29 +- .../chat/__tests__/ChatComposer.test.tsx | 131 ++++++- .../features/conversations/Conversations.tsx | 38 +- .../components/ThreadGoalChip.tsx | 21 +- app/src/lib/i18n/ar.ts | 1 + app/src/lib/i18n/bn.ts | 1 + app/src/lib/i18n/de.ts | 1 + app/src/lib/i18n/en.ts | 1 + app/src/lib/i18n/es.ts | 1 + app/src/lib/i18n/fr.ts | 1 + app/src/lib/i18n/hi.ts | 1 + app/src/lib/i18n/id.ts | 1 + app/src/lib/i18n/it.ts | 1 + app/src/lib/i18n/ko.ts | 1 + app/src/lib/i18n/pl.ts | 1 + app/src/lib/i18n/pt.ts | 1 + app/src/lib/i18n/ru.ts | 1 + app/src/lib/i18n/zh-CN.ts | 1 + app/src/lib/meshGradient.js | 9 +- app/src/services/analyticsInteractions.ts | 10 +- .../__tests__/desktopDeepLinkListener.test.ts | 77 +++- app/src/utils/desktopDeepLinkListener.ts | 83 +++- app/src/utils/tauriCommands/auth.ts | 12 +- src/core/dispatch.rs | 7 +- src/core/jsonrpc.rs | 6 +- src/core/observability.rs | 356 ++++++++++++++++++ src/main.rs | 53 +++ src/openhuman/composio/client.rs | 2 +- src/openhuman/config/ops/loader.rs | 2 +- src/openhuman/config/schema/load/impl_load.rs | 228 ++++++++--- src/openhuman/config/schema/load_tests.rs | 163 ++++++++ src/openhuman/inference/http/server.rs | 12 +- .../local/service/ollama_admin/diagnostics.rs | 4 +- .../inference/local/service/speech.rs | 12 + .../inference/local/service/vision_embed.rs | 4 +- src/openhuman/inference/ops.rs | 30 +- src/openhuman/inference/paths.rs | 160 ++++++++ .../provider/claude_agent_sdk/subprocess.rs | 2 +- .../provider/openhuman_backend_model.rs | 39 +- .../inference/voice/local_transcribe.rs | 9 + src/openhuman/inference/voice/streaming.rs | 2 +- src/openhuman/mcp_registry/registry.rs | 14 +- .../memory_store/namespace_store/documents.rs | 67 ++-- .../namespace_store/documents_tests.rs | 115 +++--- src/openhuman/memory_store/safety/pii.rs | 2 +- src/openhuman/memory_tree/tree/rpc.rs | 39 +- src/openhuman/util.rs | 17 +- src/openhuman/voice/always_on.rs | 6 +- src/openhuman/voice/audio_capture.rs | 18 +- src/openhuman/voice/dictation_listener.rs | 4 +- src/openhuman/voice/hotkey.rs | 4 +- .../voice/schemas/handlers/provider_server.rs | 2 +- src/openhuman/voice/server.rs | 21 +- vendor/tinycortex | 2 +- 59 files changed, 1620 insertions(+), 233 deletions(-) diff --git a/.github/tauri-cef-expected-sha b/.github/tauri-cef-expected-sha index 0bc836bb0..0809bcda4 100644 --- a/.github/tauri-cef-expected-sha +++ b/.github/tauri-cef-expected-sha @@ -1 +1 @@ -11ef51edbeadcca4517b18a037fff858a5dfae0f +f09d7e746a44a5187d2abc116e8a4cd7a9f94a67 diff --git a/app/src-tauri/src/lib.rs b/app/src-tauri/src/lib.rs index ac3433b91..10c10028d 100644 --- a/app/src-tauri/src/lib.rs +++ b/app/src-tauri/src/lib.rs @@ -2564,6 +2564,24 @@ pub fn run() { ); return None; } + // Defense-in-depth: drop Windows `ERROR_FILE_SYSTEM_LIMITATION` + // (os error 665) — a persistent host-filesystem condition with + // zero local lever and no Sentry remediation path. The Tauri + // shell is a separate crate from the core, so the core's emit-site + // classifier (`expected_error_kind`) can only catch events that + // originate inside the core binary. Any filesystem-error event + // that starts in the shell (e.g. file_logging, window_state, + // CEF profile I/O) bypasses the core classifier and lands here; + // this filter is the only net for those events (TAURI-RUST-QT0: + // 6,050 events / 1 user). + if openhuman_core::core::observability::is_windows_file_system_limitation_event(&event) + { + log::debug!( + "[sentry-fs-limitation-filter] dropping Windows file-system-limitation event (os error 665) event_id={:?}", + event.event_id + ); + return None; + } // Strip server_name (hostname) to avoid leaking machine identity. event.server_name = None; // Attach the cached account uid so Sentry can count unique users diff --git a/app/src-tauri/vendor/tauri-cef b/app/src-tauri/vendor/tauri-cef index 11ef51edb..f09d7e746 160000 --- a/app/src-tauri/vendor/tauri-cef +++ b/app/src-tauri/vendor/tauri-cef @@ -1 +1 @@ -Subproject commit 11ef51edbeadcca4517b18a037fff858a5dfae0f +Subproject commit f09d7e746a44a5187d2abc116e8a4cd7a9f94a67 diff --git a/app/src/assets/audio/README.md b/app/src/assets/audio/README.md index c43105042..2aa8638c9 100644 --- a/app/src/assets/audio/README.md +++ b/app/src/assets/audio/README.md @@ -8,4 +8,4 @@ Short UI chimes for the push-to-talk feature (`docs/superpowers/specs/2026-06-02 | `ptt-close.wav` | Mic closed (PTT key released). | Generated locally with Python `wave` + sine generator (1200–800 Hz sweep). | CC0 / Public Domain. | | `ptt-error.wav` | Session aborted (empty audio, mic permission denied, etc.). | Generated locally with Python `wave` + sine generator (250 Hz tone). | CC0 / Public Domain. | -All clips are ~80–120ms, LUFS-normalized to roughly match the in-app notification sound (~ -16 LUFS). Replace freely with better-sounding equivalents — just keep them under 200ms and CC0/MIT-equivalent. +All clips are ~~80–120ms, LUFS-normalized to roughly match the in-app notification sound (~ -16 LUFS)~~. Replace freely with better-sounding equivalents — just keep them under 200ms and CC0/MIT-equivalent. diff --git a/app/src/chat/chatSendError.ts b/app/src/chat/chatSendError.ts index 96b1bd390..028c6b5c9 100644 --- a/app/src/chat/chatSendError.ts +++ b/app/src/chat/chatSendError.ts @@ -16,7 +16,8 @@ export type ChatSendErrorCode = | 'usage_limit_reached' | 'prompt_blocked' | 'prompt_review' - | 'attachment_invalid'; + | 'attachment_invalid' + | 'create_thread_failed'; export interface ChatSendError { code: ChatSendErrorCode; diff --git a/app/src/components/chat/ChatComposer.tsx b/app/src/components/chat/ChatComposer.tsx index 0a62d6ee6..1edbe299a 100644 --- a/app/src/components/chat/ChatComposer.tsx +++ b/app/src/components/chat/ChatComposer.tsx @@ -1,4 +1,4 @@ -import { useEffect, useState } from 'react'; +import { useEffect, useRef, useState } from 'react'; import type { ChatSendError } from '../../chat/chatSendError'; import type { Attachment } from '../../lib/attachments'; @@ -8,6 +8,14 @@ import AttachmentPreview from './AttachmentPreview'; /** Max composer height ≈ 8 lines of text-sm + padding. */ const COMPOSER_MAX_HEIGHT = 192; +/** + * Render-loop guard threshold: if the component re-renders this many times + * within a single microtick, we log a warning to help diagnose "Maximum update + * depth exceeded" issues (TAURI-REACT-2G). React's own limit is 50; we warn at + * a lower threshold so developers catch it before the crash. + */ +const RENDER_LOOP_WARN_THRESHOLD = 30; + export interface ChatComposerProps { inputValue: string; setInputValue: (value: string | ((prev: string) => string)) => void; @@ -101,6 +109,25 @@ export default function ChatComposer({ const { t } = useT(); const [isDragging, setIsDragging] = useState(false); + // Render-loop detection guard: tracks re-renders within a single microtick + // and warns when the count exceeds a safe threshold, helping diagnose + // "Maximum update depth exceeded" issues (TAURI-REACT-2G). + const renderCountRef = useRef(0); + const renderTimerRef = useRef | null>(null); + renderCountRef.current += 1; + if (renderCountRef.current >= RENDER_LOOP_WARN_THRESHOLD) { + console.warn( + `[ChatComposer] Render-loop detected: ${renderCountRef.current} renders in a single tick. ` + + 'Check whether a parent onChange/setState cycle is causing cascading re-renders.' + ); + } + if (renderTimerRef.current === null) { + renderTimerRef.current = setTimeout(() => { + renderCountRef.current = 0; + renderTimerRef.current = null; + }, 0); + } + // While a turn streams (`allowParallelSend`) the composer stays usable for a // queued follow-up / parallel branch, so the in-flight `isSending` spinner // and lock no longer apply — only real typed content gates the send button. diff --git a/app/src/components/chat/__tests__/ChatComposer.test.tsx b/app/src/components/chat/__tests__/ChatComposer.test.tsx index c1ec075d6..8b8110ec2 100644 --- a/app/src/components/chat/__tests__/ChatComposer.test.tsx +++ b/app/src/components/chat/__tests__/ChatComposer.test.tsx @@ -1,5 +1,5 @@ import { fireEvent, render, screen } from '@testing-library/react'; -import { createRef } from 'react'; +import { createRef, useEffect, useState } from 'react'; import { describe, expect, it, vi } from 'vitest'; import type { Attachment } from '../../../lib/attachments'; @@ -242,6 +242,135 @@ describe('ChatComposer', () => { }); }); + describe('render-loop detection guard', () => { + it('does not warn under normal rendering', () => { + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}); + renderComposer(); + expect(screen.getByRole('textbox')).toBeInTheDocument(); + // Normal rendering should not trigger the render-loop guard. + expect(warnSpy).not.toHaveBeenCalledWith(expect.stringContaining('Render-loop detected')); + warnSpy.mockRestore(); + }); + + it('warns when render-loop threshold is exceeded', () => { + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}); + const textInputRef = createRef(); + const fileInputRef = createRef(); + const isComposingTextRef = { current: false }; + // This test harness simulates a render loop by calling setState + // from a useEffect, exceeding the guard's 30-render threshold + // without triggering React's native "too many re-renders" error. + function LoopHarness() { + const [count, setCount] = useState(0); + const [text, setText] = useState(''); + + useEffect(() => { + if (count < 35) { + setCount(count + 1); + } + }, [count, setCount]); + + return ( + setText(typeof v === 'function' ? v('') : v)} + onSend={vi.fn().mockResolvedValue(undefined)} + textInputRef={textInputRef} + fileInputRef={fileInputRef} + composerInteractionBlocked={false} + isSending={false} + attachments={[]} + onAttachFiles={vi.fn().mockResolvedValue(undefined)} + onRemoveAttachment={vi.fn()} + attachError={null} + onSwitchToMicCloud={vi.fn()} + handleInputKeyDown={vi.fn()} + inlineCompletionSuffix="" + isComposingTextRef={isComposingTextRef} + maxAttachments={5} + allowedMimeTypes={[]} + attachmentsEnabled={false} + /> + ); + } + + render(); + + const loopCalls = warnSpy.mock.calls.filter( + args => typeof args[0] === 'string' && args[0].includes('Render-loop detected') + ); + expect(loopCalls.length).toBeGreaterThan(0); + expect(loopCalls[0][0]).toContain('ChatComposer'); + warnSpy.mockRestore(); + }); + + it('recovers from a temporary loop (counter resets between ticks)', async () => { + // After a render loop ends, the setTimeout(0) in the guard should reset + // the counter, so a subsequent normal render doesn't trigger a warning. + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}); + const textInputRef = createRef(); + const fileInputRef = createRef(); + const isComposingTextRef = { current: false }; + + // First, render normally. + const { rerender } = render( + + ); + + // Wait for the setTimeout(0) reset to fire. + await new Promise(r => setTimeout(r, 50)); + + // Then render again — should not warn because the counter was reset. + rerender( + + ); + + const loopCalls = warnSpy.mock.calls.filter( + args => typeof args[0] === 'string' && args[0].includes('Render-loop detected') + ); + expect(loopCalls).toHaveLength(0); + warnSpy.mockRestore(); + }); + }); + describe('follow-up / parallel mode (allowParallelSend during a streaming turn)', () => { it('keeps the textarea editable even while an in-flight turn is sending', () => { renderComposer({ diff --git a/app/src/features/conversations/Conversations.tsx b/app/src/features/conversations/Conversations.tsx index 1d3cda51d..7aac9031d 100644 --- a/app/src/features/conversations/Conversations.tsx +++ b/app/src/features/conversations/Conversations.tsx @@ -266,6 +266,13 @@ const Conversations = ({ const [sendError, setSendError] = useState(null); const [attachError, setAttachError] = useState(null); const [sendAdvisory, setSendAdvisory] = useState(null); + // Refs mirroring error/advisory state for effects that read them without + // depending on them, preventing the classic "effect→setState→re-fire" cascade + // that contributes to "Maximum update depth exceeded" (TAURI-REACT-2G). + const sendErrorRef = useRef(sendError); + sendErrorRef.current = sendError; + const sendAdvisoryRef = useRef(sendAdvisory); + sendAdvisoryRef.current = sendAdvisory; const [openRouterStatus, setOpenRouterStatus] = useState<'idle' | 'saving' | 'error'>('idle'); // Threads whose send is mid-flight (dispatched locally, backend not yet // accepted). A Set so concurrent sends to different threads each track their @@ -477,14 +484,19 @@ const Conversations = ({ typeof navigator.mediaDevices.getUserMedia === 'function'; const handleCreateNewThread = async () => { - const thread = await dispatch(createNewThread()).unwrap(); - dispatch(setSelectedThread(thread.id)); - void dispatch(loadThreadMessages(thread.id)); - if (shouldSyncChatRoute) { - debug('[chat][route] created thread thread=%s navigate=true', thread.id); - navigate(chatThreadPath(thread.id)); - } else { - debug('[chat][route] created thread thread=%s navigate=false', thread.id); + try { + const thread = await dispatch(createNewThread()).unwrap(); + dispatch(setSelectedThread(thread.id)); + void dispatch(loadThreadMessages(thread.id)); + if (shouldSyncChatRoute) { + debug('[chat][route] created thread thread=%s navigate=true', thread.id); + navigate(chatThreadPath(thread.id)); + } else { + debug('[chat][route] created thread thread=%s navigate=false', thread.id); + } + } catch (error) { + debug('[chat] create thread failed: %O', error); + setSendError(chatSendError('create_thread_failed', t('chat.createThreadFailed'))); } }; @@ -716,13 +728,17 @@ const Conversations = ({ }, []); useEffect(() => { - if (sendError && inputValue.length > 0) { + if (sendErrorRef.current && inputValue.length > 0) { setSendError(null); } - if (sendAdvisory && inputValue.length > 0) { + if (sendAdvisoryRef.current && inputValue.length > 0) { setSendAdvisory(null); } - }, [inputValue, sendAdvisory, sendError]); + // Reads sendError/sendAdvisory through refs to avoid re-firing when they + // are cleared — which would cascade into extra render cycles and contribute + // to "Maximum update depth exceeded" (TAURI-REACT-2G). + // eslint-disable-next-line react-hooks/exhaustive-deps + }, [inputValue]); const clearSilenceTimer = useCallback((threadId: string) => { const existing = sendingTimeoutsRef.current.get(threadId); diff --git a/app/src/features/conversations/components/ThreadGoalChip.tsx b/app/src/features/conversations/components/ThreadGoalChip.tsx index 17dbf7f6e..1eae120a6 100644 --- a/app/src/features/conversations/components/ThreadGoalChip.tsx +++ b/app/src/features/conversations/components/ThreadGoalChip.tsx @@ -92,14 +92,19 @@ export function useThreadGoal( } }, [api, threadId]); - // Reset the editor + cached goal when the thread changes. Done during render - // (React's sanctioned "reset state on prop change" pattern) rather than in an - // effect, so it's synchronous and lint-clean. - if (activeThread.current !== threadId) { - activeThread.current = threadId; - setExpanded(false); - setGoal(null); - } + // Reset the editor + cached goal when the thread changes. Done in a useEffect + // rather than during render to avoid React's nested-update detection, which + // can cascade with concurrent state changes into a "Maximum update depth + // exceeded" error (TAURI-REACT-2G). + const prevThreadRef = useRef(threadId); + useEffect(() => { + if (prevThreadRef.current !== threadId) { + prevThreadRef.current = threadId; + activeThread.current = threadId; // keep the race guard in sync + setExpanded(false); + setGoal(null); + } + }, [threadId]); // Fetch on mount/thread-change and poll lightly. `refresh` is async, so its // setState lands in a later microtask (not a synchronous effect write). diff --git a/app/src/lib/i18n/ar.ts b/app/src/lib/i18n/ar.ts index 824712d11..df02e8678 100644 --- a/app/src/lib/i18n/ar.ts +++ b/app/src/lib/i18n/ar.ts @@ -1018,6 +1018,7 @@ const messages: TranslationMap = { 'chat.queuedFollowups.label': 'متابعات في قائمة الانتظار', 'chat.queuedFollowups.clear': 'مسح', 'chat.queuedFollowups.clearFailed': 'تعذّر مسح القائمة: حاول مرة أخرى.', + 'chat.createThreadFailed': 'تعذّر إنشاء محادثة جديدة: حاول مرة أخرى.', 'chat.parallelBranchLabel': 'فرع متوازٍ', 'chat.thinking': 'جارٍ التفكير...', 'chat.noMessages': 'لا توجد رسائل بعد', diff --git a/app/src/lib/i18n/bn.ts b/app/src/lib/i18n/bn.ts index c19b13a15..37d9429ad 100644 --- a/app/src/lib/i18n/bn.ts +++ b/app/src/lib/i18n/bn.ts @@ -1041,6 +1041,7 @@ const messages: TranslationMap = { 'chat.queuedFollowups.label': 'সারিবদ্ধ ফলো-আপ', 'chat.queuedFollowups.clear': 'সাফ করুন', 'chat.queuedFollowups.clearFailed': 'সারি সাফ করা যায়নি: আবার চেষ্টা করুন।', + 'chat.createThreadFailed': 'নতুন থ্রেড তৈরি করা যায়নি: আবার চেষ্টা করুন।', 'chat.parallelBranchLabel': 'সমান্তরাল শাখা', 'chat.thinking': 'ভাবছে...', 'chat.noMessages': 'এখনো কোনো বার্তা নেই', diff --git a/app/src/lib/i18n/de.ts b/app/src/lib/i18n/de.ts index e3bb733f4..2da5bad10 100644 --- a/app/src/lib/i18n/de.ts +++ b/app/src/lib/i18n/de.ts @@ -1085,6 +1085,7 @@ const messages: TranslationMap = { 'chat.queuedFollowups.clear': 'Löschen', 'chat.queuedFollowups.clearFailed': 'Warteschlange konnte nicht geleert werden – bitte erneut versuchen.', + 'chat.createThreadFailed': 'Neuer Thread konnte nicht erstellt werden – bitte erneut versuchen.', 'chat.parallelBranchLabel': 'Paralleler Zweig', 'chat.thinking': 'Denken...', 'chat.noMessages': 'Noch keine Nachrichten', diff --git a/app/src/lib/i18n/en.ts b/app/src/lib/i18n/en.ts index 021b28dfc..ac4420545 100644 --- a/app/src/lib/i18n/en.ts +++ b/app/src/lib/i18n/en.ts @@ -822,6 +822,7 @@ const en: TranslationMap = { 'chat.queuedFollowups.label': 'Queued follow-ups', 'chat.queuedFollowups.clear': 'Clear', 'chat.queuedFollowups.clearFailed': "Couldn't clear the queue. Try again.", + 'chat.createThreadFailed': "Couldn't create a new thread. Please try again.", 'chat.parallelBranchLabel': 'Parallel branch', 'chat.thinking': 'Thinking...', 'chat.noMessages': 'No messages yet', diff --git a/app/src/lib/i18n/es.ts b/app/src/lib/i18n/es.ts index 47c1cb5c2..123e57fa1 100644 --- a/app/src/lib/i18n/es.ts +++ b/app/src/lib/i18n/es.ts @@ -1066,6 +1066,7 @@ const messages: TranslationMap = { 'chat.queuedFollowups.label': 'Seguimientos en cola', 'chat.queuedFollowups.clear': 'Borrar', 'chat.queuedFollowups.clearFailed': 'No se pudo vaciar la cola: inténtalo de nuevo.', + 'chat.createThreadFailed': 'No se pudo crear un nuevo hilo. Inténtalo de nuevo.', 'chat.parallelBranchLabel': 'Rama paralela', 'chat.thinking': 'Pensando...', 'chat.noMessages': 'Sin mensajes aún', diff --git a/app/src/lib/i18n/fr.ts b/app/src/lib/i18n/fr.ts index c3af10586..e25e05c02 100644 --- a/app/src/lib/i18n/fr.ts +++ b/app/src/lib/i18n/fr.ts @@ -1078,6 +1078,7 @@ const messages: TranslationMap = { 'chat.queuedFollowups.label': 'Suivis en file', 'chat.queuedFollowups.clear': 'Effacer', 'chat.queuedFollowups.clearFailed': 'Impossible de vider la file: réessayez.', + 'chat.createThreadFailed': 'Impossible de créer un nouveau fil. Veuillez réessayer.', 'chat.parallelBranchLabel': 'Branche parallèle', 'chat.thinking': 'En train de réfléchir…', 'chat.noMessages': "Aucun message pour l'instant", diff --git a/app/src/lib/i18n/hi.ts b/app/src/lib/i18n/hi.ts index 2294777fa..f4bc2491d 100644 --- a/app/src/lib/i18n/hi.ts +++ b/app/src/lib/i18n/hi.ts @@ -1040,6 +1040,7 @@ const messages: TranslationMap = { 'chat.queuedFollowups.label': 'कतारबद्ध फ़ॉलो-अप', 'chat.queuedFollowups.clear': 'साफ़ करें', 'chat.queuedFollowups.clearFailed': 'कतार साफ़ नहीं हो सकी: फिर से प्रयास करें।', + 'chat.createThreadFailed': 'नया थ्रेड नहीं बनाया जा सका: कृपया पुनः प्रयास करें।', 'chat.parallelBranchLabel': 'समानांतर शाखा', 'chat.thinking': 'सोच रहा है...', 'chat.noMessages': 'अभी कोई मैसेज नहीं', diff --git a/app/src/lib/i18n/id.ts b/app/src/lib/i18n/id.ts index 5ccb59a35..e765f9bfe 100644 --- a/app/src/lib/i18n/id.ts +++ b/app/src/lib/i18n/id.ts @@ -1052,6 +1052,7 @@ const messages: TranslationMap = { 'chat.queuedFollowups.label': 'Tindak lanjut dalam antrean', 'chat.queuedFollowups.clear': 'Hapus', 'chat.queuedFollowups.clearFailed': 'Gagal mengosongkan antrean: coba lagi.', + 'chat.createThreadFailed': 'Gagal membuat thread baru: coba lagi.', 'chat.parallelBranchLabel': 'Cabang paralel', 'chat.thinking': 'Berpikir...', 'chat.noMessages': 'Belum ada pesan', diff --git a/app/src/lib/i18n/it.ts b/app/src/lib/i18n/it.ts index 6f3973961..a4274d990 100644 --- a/app/src/lib/i18n/it.ts +++ b/app/src/lib/i18n/it.ts @@ -1068,6 +1068,7 @@ const messages: TranslationMap = { 'chat.queuedFollowups.label': 'Follow-up in coda', 'chat.queuedFollowups.clear': 'Cancella', 'chat.queuedFollowups.clearFailed': 'Impossibile svuotare la coda: riprova.', + 'chat.createThreadFailed': 'Impossibile creare una nuova conversazione. Riprova.', 'chat.parallelBranchLabel': 'Ramo parallelo', 'chat.thinking': 'Sto pensando...', 'chat.noMessages': 'Nessun messaggio', diff --git a/app/src/lib/i18n/ko.ts b/app/src/lib/i18n/ko.ts index 62c9f4175..387adefd6 100644 --- a/app/src/lib/i18n/ko.ts +++ b/app/src/lib/i18n/ko.ts @@ -1032,6 +1032,7 @@ const messages: TranslationMap = { 'chat.queuedFollowups.label': '대기 중인 후속 메시지', 'chat.queuedFollowups.clear': '지우기', 'chat.queuedFollowups.clearFailed': '대기열을 지우지 못했습니다: 다시 시도하세요.', + 'chat.createThreadFailed': '새 대화를 만들지 못했습니다: 다시 시도하세요.', 'chat.parallelBranchLabel': '병렬 분기', 'chat.thinking': '생각 중...', 'chat.noMessages': '아직 메시지가 없습니다', diff --git a/app/src/lib/i18n/pl.ts b/app/src/lib/i18n/pl.ts index d8bde6610..3e0cc45bb 100644 --- a/app/src/lib/i18n/pl.ts +++ b/app/src/lib/i18n/pl.ts @@ -1060,6 +1060,7 @@ const messages: TranslationMap = { 'chat.queuedFollowups.label': 'Wiadomości w kolejce', 'chat.queuedFollowups.clear': 'Wyczyść', 'chat.queuedFollowups.clearFailed': 'Nie udało się wyczyścić kolejki: spróbuj ponownie.', + 'chat.createThreadFailed': 'Nie udało się utworzyć nowego wątku. Spróbuj ponownie.', 'chat.parallelBranchLabel': 'Równoległa gałąź', 'chat.thinking': 'Myślę...', 'chat.noMessages': 'Brak wiadomości', diff --git a/app/src/lib/i18n/pt.ts b/app/src/lib/i18n/pt.ts index dfa9f6caa..783b0ba32 100644 --- a/app/src/lib/i18n/pt.ts +++ b/app/src/lib/i18n/pt.ts @@ -1062,6 +1062,7 @@ const messages: TranslationMap = { 'chat.queuedFollowups.label': 'Acompanhamentos na fila', 'chat.queuedFollowups.clear': 'Limpar', 'chat.queuedFollowups.clearFailed': 'Não foi possível limpar a fila: tente novamente.', + 'chat.createThreadFailed': 'Não foi possível criar uma nova conversa. Tente novamente.', 'chat.parallelBranchLabel': 'Ramificação paralela', 'chat.thinking': 'Pensando...', 'chat.noMessages': 'Nenhuma mensagem ainda', diff --git a/app/src/lib/i18n/ru.ts b/app/src/lib/i18n/ru.ts index 17da8e521..be1680cc7 100644 --- a/app/src/lib/i18n/ru.ts +++ b/app/src/lib/i18n/ru.ts @@ -1053,6 +1053,7 @@ const messages: TranslationMap = { 'chat.queuedFollowups.label': 'Сообщения в очереди', 'chat.queuedFollowups.clear': 'Очистить', 'chat.queuedFollowups.clearFailed': 'Не удалось очистить очередь: попробуйте ещё раз.', + 'chat.createThreadFailed': 'Не удалось создать новый диалог. Попробуйте ещё раз.', 'chat.parallelBranchLabel': 'Параллельная ветка', 'chat.thinking': 'Думаю...', 'chat.noMessages': 'Сообщений пока нет', diff --git a/app/src/lib/i18n/zh-CN.ts b/app/src/lib/i18n/zh-CN.ts index 2db618ac3..ce08b5017 100644 --- a/app/src/lib/i18n/zh-CN.ts +++ b/app/src/lib/i18n/zh-CN.ts @@ -985,6 +985,7 @@ const messages: TranslationMap = { 'chat.queuedFollowups.label': '排队的后续消息', 'chat.queuedFollowups.clear': '清除', 'chat.queuedFollowups.clearFailed': '无法清空队列：请重试。', + 'chat.createThreadFailed': '无法创建新会话。请重试。', 'chat.parallelBranchLabel': '并行分支', 'chat.thinking': '思考中...', 'chat.noMessages': '暂无消息', diff --git a/app/src/lib/meshGradient.js b/app/src/lib/meshGradient.js index 6411af667..b7fcf3649 100644 --- a/app/src/lib/meshGradient.js +++ b/app/src/lib/meshGradient.js @@ -475,9 +475,9 @@ class Gradient { e(this, 'addIsLoadedClass', () => { /*this.isIntersecting && */ !this.isLoadedClass && ((this.isLoadedClass = !0), - this.el.classList.add('isLoaded'), + this.el && this.el.classList.add('isLoaded'), setTimeout(() => { - this.el.parentElement.classList.add('isLoaded'); + this.el && this.el.parentElement && this.el.parentElement.classList.add('isLoaded'); }, 3e3)); }), e(this, 'pause', () => { @@ -623,11 +623,12 @@ class Gradient { } showGradientLegend() { this.width > this.minWidth && - ((this.isGradientLegendVisible = !0), document.body.classList.add('isGradientLegendVisible')); + ((this.isGradientLegendVisible = !0), + document.body && document.body.classList.add('isGradientLegendVisible')); } hideGradientLegend() { ((this.isGradientLegendVisible = !1), - document.body.classList.remove('isGradientLegendVisible')); + document.body && document.body.classList.remove('isGradientLegendVisible')); } init() { try { diff --git a/app/src/services/analyticsInteractions.ts b/app/src/services/analyticsInteractions.ts index 040bcd063..40865e0c0 100644 --- a/app/src/services/analyticsInteractions.ts +++ b/app/src/services/analyticsInteractions.ts @@ -115,7 +115,15 @@ function destinationForElement(element: HTMLElement): string { function controlState(element: HTMLElement): string { if (element instanceof HTMLInputElement) { if (element.type === 'checkbox' || element.type === 'radio') { - return element.checked ? 'checked' : 'unchecked'; + // Defensive guard: React 19's controlled-component state restoration + // can briefly leave an input's DOM node in an inconsistent state where + // `instanceof HTMLInputElement` passes but the element is disconnected + // and its `checked` property access throws (see issue #5161). + try { + return element.checked ? 'checked' : 'unchecked'; + } catch { + return 'changed'; + } } if (element.type === 'range') return 'changed'; } diff --git a/app/src/utils/__tests__/desktopDeepLinkListener.test.ts b/app/src/utils/__tests__/desktopDeepLinkListener.test.ts index 87fa220c0..f41c5de85 100644 --- a/app/src/utils/__tests__/desktopDeepLinkListener.test.ts +++ b/app/src/utils/__tests__/desktopDeepLinkListener.test.ts @@ -204,10 +204,42 @@ describe('desktopDeepLinkListener', () => { expect(storeSession).toHaveBeenCalledWith( 'web-token', {}, - { allowPendingBackendValidation: true } + { allowPendingBackendValidation: true, timeoutMs: 25_000 } ); }); + it('retries storeSession on timeout then succeeds on second attempt', async () => { + vi.mocked(storeSession) + .mockReset() + .mockRejectedValueOnce(new Error('timed out')) + .mockResolvedValueOnce(undefined); + + const state = registerAuthDeepLinkState(); + const url = `openhuman://auth?token=retry-token&key=auth&state=${state}`; + + vi.mocked(getCurrent).mockResolvedValue([url]); + await setupDesktopDeepLinkListener(); + await waitForAuthSettled(); + + expect(storeSession).toHaveBeenCalledTimes(2); + expect(getDeepLinkAuthState().errorMessage).toBeNull(); + }); + + it('does NOT retry storeSession on non-timeout error', async () => { + vi.mocked(storeSession).mockReset().mockRejectedValueOnce(new Error('network down')); + + const state = registerAuthDeepLinkState(); + const url = `openhuman://auth?token=no-retry-token&key=auth&state=${state}`; + + vi.mocked(getCurrent).mockResolvedValue([url]); + await setupDesktopDeepLinkListener(); + await waitForAuthSettled(); + + // Non-timeout errors should not be retried — only one call expected. + expect(storeSession).toHaveBeenCalledTimes(1); + expect(getDeepLinkAuthState().errorMessage).not.toBeNull(); + }); + it('rejects an auth deep link whose state nonce does not match a pending one', async () => { registerAuthDeepLinkState('the-real-nonce'); vi.mocked(getCurrent).mockResolvedValue([ @@ -230,7 +262,11 @@ describe('desktopDeepLinkListener', () => { vi.mocked(getCurrent).mockResolvedValue([url]); await setupDesktopDeepLinkListener(); await waitForAuthSettled(); - expect(storeSession).toHaveBeenCalledWith('abc', {}, { allowPendingBackendValidation: true }); + expect(storeSession).toHaveBeenCalledWith( + 'abc', + {}, + { allowPendingBackendValidation: true, timeoutMs: 25_000 } + ); // Replay the exact same deep link — the nonce was consumed, so it fails. vi.mocked(storeSession).mockClear(); @@ -249,7 +285,8 @@ describe('desktopDeepLinkListener', () => { const state = getDeepLinkAuthState(); expect(state.requiresAppDataReset).toBe(false); - expect(state.errorMessage).toBe('Sign-in failed. Please try again.'); + expect(state.errorMessage).toContain('did not respond'); + expect(state.errorMessage).toContain('restart'); }); it('injection #1: store-time /auth/me failure bounces to signin — no session applied, no /home nav', async () => { @@ -275,14 +312,18 @@ describe('desktopDeepLinkListener', () => { await waitForAuthSettled(); // store WAS attempted (we reached the persistence call)... - expect(storeSession).toHaveBeenCalledWith('abc', {}, { allowPendingBackendValidation: true }); + expect(storeSession).toHaveBeenCalledWith( + 'abc', + {}, + { allowPendingBackendValidation: true, timeoutMs: 25_000 } + ); // ...but it FAILED, so the session-applied event was never dispatched... expect(sessionTokenUpdated).not.toHaveBeenCalled(); // ...and we never navigated to /home (ProtectedRoute/PublicRoute keep signin). expect(window.location.hash).not.toBe('#/home'); // Surfaced as the generic toast; processing cleared. const state = getDeepLinkAuthState(); - expect(state.errorMessage).toBe('Sign-in failed. Please try again.'); + expect(state.errorMessage).toContain('did not respond'); expect(state.isProcessing).toBe(false); } finally { window.removeEventListener('core-state:session-token-updated', sessionTokenUpdated); @@ -315,7 +356,11 @@ describe('desktopDeepLinkListener', () => { resolveReadiness({ ready: true }); await waitForAuthSettled(); - expect(storeSession).toHaveBeenCalledWith('abc', {}, { allowPendingBackendValidation: true }); + expect(storeSession).toHaveBeenCalledWith( + 'abc', + {}, + { allowPendingBackendValidation: true, timeoutMs: 25_000 } + ); expect(getDeepLinkAuthState().isProcessing).toBe(false); }); @@ -348,7 +393,11 @@ describe('desktopDeepLinkListener', () => { expect(clearCoreRpcUrlCache).toHaveBeenCalledTimes(1); expect(clearCoreRpcTokenCache).toHaveBeenCalledTimes(1); - expect(storeSession).toHaveBeenCalledWith('abc', {}, { allowPendingBackendValidation: true }); + expect(storeSession).toHaveBeenCalledWith( + 'abc', + {}, + { allowPendingBackendValidation: true, timeoutMs: 25_000 } + ); }); it('does NOT bust RPC caches before storeSession in local mode', async () => { @@ -360,7 +409,11 @@ describe('desktopDeepLinkListener', () => { expect(clearCoreRpcUrlCache).not.toHaveBeenCalled(); expect(clearCoreRpcTokenCache).not.toHaveBeenCalled(); - expect(storeSession).toHaveBeenCalledWith('abc', {}, { allowPendingBackendValidation: true }); + expect(storeSession).toHaveBeenCalledWith( + 'abc', + {}, + { allowPendingBackendValidation: true, timeoutMs: 25_000 } + ); }); it('dispatches suppress-reauth before storeSession and clears it after in cloud mode', async () => { @@ -426,11 +479,13 @@ describe('authStoreFailureUserMessage (issue #3025)', () => { 'other', ]; - // Local / unset mode always keeps the plain retry message — the failure there - // is a transient embedded-core/backend blip that retrying can clear. + // Local / unset mode should mention the retry attempt so the user knows + // the system tried before giving up (issue #5166). it.each(['local', null] as const)('stays generic for mode=%s', mode => { for (const kind of CLOUD_KINDS) { - expect(authStoreFailureUserMessage(kind, mode)).toBe('Sign-in failed. Please try again.'); + const msg = authStoreFailureUserMessage(kind, mode); + expect(msg).toContain('retry'); + expect(msg).not.toContain('remote'); } }); diff --git a/app/src/utils/desktopDeepLinkListener.ts b/app/src/utils/desktopDeepLinkListener.ts index 554933b6b..3c57df7cc 100644 --- a/app/src/utils/desktopDeepLinkListener.ts +++ b/app/src/utils/desktopDeepLinkListener.ts @@ -152,6 +152,66 @@ const focusMainWindow = async () => { } }; +// The Rust core `auth_store_session` with `allowPendingBackendValidation: true` +// connects to the backend `/auth/me` endpoint. The backend's HTTP client has +// a 15s connect timeout + 120s request timeout. The frontend RPC timeout must +// be long enough for the backend to establish a connection (15s) before the +// first attempt fails, otherwise the retry loop never completes before the +// backend responds. Set to 25s to cover the 15s connect window with headroom. +const AUTH_STORE_TIMEOUT_MS = 25_000; +const AUTH_STORE_RETRIES = 2; +const AUTH_STORE_RETRY_BACKOFF_MS = 500; +// The suppress-reauth window must cover the full worst-case retry duration: +// AUTH_STORE_RETRIES × AUTH_STORE_TIMEOUT_MS + (AUTH_STORE_RETRIES − 1) × backoff +// = 2 × 25 000 + 500 = 50 500 ms. Add 5 s of headroom for RPC serialization, +// CoreStateProvider polling jitter, and the final try-catch turnaround. +const AUTH_STORE_SUPPRESS_REAUTH_MS = + AUTH_STORE_RETRIES * AUTH_STORE_TIMEOUT_MS + + (AUTH_STORE_RETRIES - 1) * AUTH_STORE_RETRY_BACKOFF_MS + + 5_000; + +/** + * Retry-safe wrapper around `storeSession` for transient backend timeouts. + * + * The Rust core's `auth_store_session` with `allowPendingBackendValidation: true` + * already retries the `/auth/me` call once (150ms delay) and falls through to + * deferred validation on a second transient failure *if* the JWT has a live + * local exp. However, the frontend coreRpcClient's default timeout (30s) can + * fire *before* Rust finishes its slow backend call + retry + deferred-validation + * path, producing a `CoreRpcError(kind='timeout')` even though Rust would have + * persisted the session successfully. This wrapper retries the whole RPC call + * so a transient backend blip doesn't bounce the user back to sign-in. + */ +const storeSessionWithRetry = async (sessionToken: string): Promise => { + let lastError: unknown; + for (let attempt = 1; attempt <= AUTH_STORE_RETRIES; attempt++) { + try { + await storeSession( + sessionToken, + {}, + { allowPendingBackendValidation: true, timeoutMs: AUTH_STORE_TIMEOUT_MS } + ); + return; // success + } catch (err) { + lastError = err; + const message = err instanceof Error ? err.message.toLowerCase() : String(err).toLowerCase(); + const isTimeout = /timed out|timeout|operation timed out/.test(message); + if (isTimeout && attempt < AUTH_STORE_RETRIES) { + console.warn( + '[DeepLink][auth] auth_store_session timed out (attempt %d/%d), retrying in %dms', + attempt, + AUTH_STORE_RETRIES, + AUTH_STORE_RETRY_BACKOFF_MS + ); + await new Promise(r => setTimeout(r, AUTH_STORE_RETRY_BACKOFF_MS)); + continue; + } + throw err; // non-timeout or last attempt + } + } + throw lastError; +}; + const applySessionToken = async (sessionToken: string): Promise => { // In cloud mode, bust any stale RPC URL/token caches so auth_store_session // targets the user's configured remote core. See issue #2377. @@ -164,10 +224,12 @@ const applySessionToken = async (sessionToken: string): Promise => { // Signal CoreStateProvider to hold off clearing session during token delivery. window.dispatchEvent( - new CustomEvent('core-state:suppress-reauth', { detail: { until: Date.now() + 15_000 } }) + new CustomEvent('core-state:suppress-reauth', { + detail: { until: Date.now() + AUTH_STORE_SUPPRESS_REAUTH_MS }, + }) ); try { - await storeSession(sessionToken, {}, { allowPendingBackendValidation: true }); + await storeSessionWithRetry(sessionToken); } finally { window.dispatchEvent(new CustomEvent('core-state:suppress-reauth', { detail: { until: 0 } })); } @@ -279,8 +341,18 @@ const handleAuthDeepLink = async (parsed: URL, requireStateNonce = true) => { // BEFORE our tag applies. A plain `Error` makes `originalException` // non-matching, so the lead cause finally reaches Sentry. // The PII-free `kind` tag + stable fingerprint are all we need to group. + // + // Transient connectivity issues (timeout, gateway, network) are reported + // at `warning` rather than `error` — the auth flow already retried inside + // `storeSessionWithRetry`, and the Rust core with + // `allowPendingBackendValidation: true` also retries and falls back to + // deferred validation. If the backend was genuinely unreachable through + // all retries this is a connectivity observation, not an app crash + // (issue #5166). + const isTransient = + kind === 'auth_me_timeout' || kind === 'auth_me_gateway' || kind === 'network'; Sentry.captureException(new Error(`auth store failed: ${kind}`), { - level: 'error', + level: isTransient ? 'warning' : 'error', tags: { surface: 'react', phase: 'deep-link-auth-store', auth_store_failure: kind }, fingerprint: ['deep-link-auth', 'session-store-failed', kind], }); @@ -339,7 +411,10 @@ export const authStoreFailureUserMessage = ( mode: 'local' | 'cloud' | null ): string => { if (mode !== 'cloud') { - return 'Sign-in failed. Please try again.'; + return ( + 'Sign-in could not be completed right now. The session store did not respond in time ' + + '(even after retrying). Please restart OpenHuman and try again.' + ); } switch (kind) { case 'auth_me_unauthorized': diff --git a/app/src/utils/tauriCommands/auth.ts b/app/src/utils/tauriCommands/auth.ts index 66a97b0ae..bed38ccb9 100644 --- a/app/src/utils/tauriCommands/auth.ts +++ b/app/src/utils/tauriCommands/auth.ts @@ -56,12 +56,19 @@ export async function logout(): Promise { } /** - * Store session in secure storage + * Store session in secure storage. + * + * Options: + * - `allowPendingBackendValidation` -- skip backend `/auth/me` proof and persist + * the session with a deferred-validation marker. + * - `timeoutMs` -- per-call timeout (default 30s, clamped [1s, 10min]). + * Use a shorter value (e.g. 10s) when the caller will retry after a timeout + * rather than hang for the full default. */ export async function storeSession( token: string, user: object, - options?: { allowPendingBackendValidation?: boolean } + options?: { allowPendingBackendValidation?: boolean; timeoutMs?: number } ): Promise { await callCoreRpc({ method: 'openhuman.auth_store_session', @@ -70,6 +77,7 @@ export async function storeSession( user, ...(options?.allowPendingBackendValidation ? { allowPendingBackendValidation: true } : {}), }, + timeoutMs: options?.timeoutMs, }); } diff --git a/src/core/dispatch.rs b/src/core/dispatch.rs index dae0f62a6..b089a2cd1 100644 --- a/src/core/dispatch.rs +++ b/src/core/dispatch.rs @@ -107,9 +107,10 @@ pub const UNKNOWN_METHOD_PREFIX: &str = "unknown method: "; /// and never will be (issue #3567): `rpc.discover` (JSON-RPC service /// discovery), `list_methods`, liveness `status`, `auth.status`, `config/get`. /// This also covers retired feature calls from older clients when no safe -/// canonical handler exists (#3565: `openhuman.memory_tree_create_namespace`). +/// canonical handler exists (#3565: `openhuman.memory_tree_create_namespace`, +/// #5157: `openhuman.harness_init_status`). /// -/// Each miss previously produced recurring Sentry ERROR events with zero user +/// Each miss previously produced recurring Sentry events with zero user /// impact. The transport layer keeps these debug-only (never captured). The /// matching health-method *aliases* land separately in `legacy_aliases` /// (#3566), which depends on this severity change. @@ -120,6 +121,7 @@ const KNOWN_PROBE_METHODS: &[&str] = &[ "auth.status", "config/get", "openhuman.memory_tree_create_namespace", + "openhuman.harness_init_status", ]; /// Returns `true` when `method` is a known non-actionable unknown method name @@ -376,6 +378,7 @@ mod tests { "auth.status", "config/get", "openhuman.memory_tree_create_namespace", + "openhuman.harness_init_status", ] { assert!( is_known_probe_method(m), diff --git a/src/core/jsonrpc.rs b/src/core/jsonrpc.rs index 4792576ee..321619b5f 100644 --- a/src/core/jsonrpc.rs +++ b/src/core/jsonrpc.rs @@ -651,7 +651,7 @@ async fn oauth_mcp_callback_handler( let config = match crate::openhuman::config::Config::load_or_init().await { Ok(c) => c, Err(e) => { - log::error!("[oauth:mcp] config load failed: {e}"); + log::warn!("[oauth:mcp] config load failed: {e}"); return html( StatusCode::INTERNAL_SERVER_ERROR, error_html("Internal error loading config. Please try again."), @@ -668,7 +668,7 @@ async fn oauth_mcp_callback_handler( ) } Err(e) => { - log::error!("[oauth:mcp] complete failed: {e}"); + log::warn!("[oauth:mcp] complete failed: {e}"); html( StatusCode::BAD_GATEWAY, error_html(&format!("Sign-in could not be completed: {e}")), @@ -2481,7 +2481,7 @@ pub async fn bootstrap_core_runtime( // above — it must run even when this gate-install branch is skipped.) crate::openhuman::web_chat::register_artifact_surface_subscriber(); } else { - log::error!( + log::info!( "[runtime] approval gate DISABLED (OPENHUMAN_APPROVAL_GATE=0 honored on host={}) — \ Prompt-class external-effect tool calls run unprompted", host_kind.tag() diff --git a/src/core/observability.rs b/src/core/observability.rs index 2c9e5d8b0..3f6191757 100644 --- a/src/core/observability.rs +++ b/src/core/observability.rs @@ -229,6 +229,20 @@ pub enum ExpectedErrorKind { /// (`inference_downloads_progress` re-reads config every poll → 36k events / /// 1 Windows user). ConfigReadIoFailure, + /// Windows `ERROR_FILE_SYSTEM_LIMITATION` (os error 665) — the NTFS file + /// system cannot complete the operation because the filesystem is too + /// fragmented, the USN journal has overflowed, or a filesystem filter + /// driver has hit its resource cap. This is a persistent host-filesystem + /// condition that the user must resolve by restarting, running a defrag, + /// or freeing space — Sentry has no remediation path. + /// + /// Also covers `ERROR_DISK_FULL` (112) / `ERROR_HANDLE_DISK_FULL` (39), + /// although those are more reliably caught by the `DiskFull` arm above. + /// + /// Matched on the locale-stable `(os error 665)` suffix (the Italian + /// locale rendering observed in Sentry TAURI-RUST-QT0 — 6,050 events from + /// 1 Windows user — is `".. (os error 665)"`, matching any locale). + WindowsFileSystemLimitation, /// The subconscious engine's SQLite schema init couldn't open its database /// file at all — a host-filesystem condition, not a code bug. Two canonical /// renderings, both bound to the user's local FS: @@ -588,6 +602,9 @@ pub fn expected_error_kind(message: &str) -> Option { if is_disk_full_message(&lower) { return Some(ExpectedErrorKind::DiskFull); } + if is_windows_file_system_limitation_message(&lower) { + return Some(ExpectedErrorKind::WindowsFileSystemLimitation); + } if is_config_load_timed_out_message(&lower) { return Some(ExpectedErrorKind::ConfigLoadTimedOut); } @@ -708,6 +725,25 @@ fn is_disk_full_message(lower: &str) -> bool { (bare_suffix || extended_local) && !lower.contains("backend returned ") } +/// Detect Windows `ERROR_FILE_SYSTEM_LIMITATION` (os error 665) — +/// a host-filesystem condition (fragmentation, USN journal overflow, +/// filter-driver resource cap) that is persistent, locale-independent +/// in the `(os error N)` suffix, and unrecoverable by the app. +/// +/// Anchor on the locale-stable `(os error 665)` suffix. The Italian +/// locale rendering is `"Impossibile completare l'operazione a causa +/// di un limite del file system (os error 665)"` (Sentry +/// TAURI-RUST-QT0, 6,050 events / 1 user). The `(os error 665)` suffix +/// is the same across every locale, so no locale-detection is needed. +/// +/// Polarity contract — only match when `(os error 665)` appears in +/// the message body. This is a standard `std::io::Error` Display +/// rendering, so it will never appear in a remote backend body +/// accidentally. +fn is_windows_file_system_limitation_message(lower: &str) -> bool { + lower.contains("(os error 665)") && !lower.contains("backend returned ") +} + /// Detect the literal `"Config loading timed out"` string produced by /// [`crate::openhuman::config::ops::load_config_with_timeout`] / /// [`crate::openhuman::config::ops::reload_config_snapshot_with_timeout`] @@ -978,6 +1014,20 @@ pub fn is_session_expired_message(msg: &str) -> bool { // `does_not_classify_streaming_byo_key_401_as_session_expired`. || (msg.contains("OpenHuman streaming API error (401") && msg.contains("\"error\":\"Invalid token\"")) + // TAURI-RUST-N — same OpenHuman backend "Invalid token" envelope + // wrapped by the tinyagents `ProviderError::Display` format + // (`TinyAgentsError::Provider(Box)`). The crate-native + // path (`OpenHumanBackendModel`) delegates to tinyagents' `OpenAiModel` + // which formats errors as `"{provider} returned HTTP {status}: {body}"`, + // producing `"OpenHuman returned HTTP 401: ..."` — different from the + // `"OpenHuman API error (401"` prefix the classic `api_error` path emits. + // Same conjunctive-anchor pattern: scoped to `"OpenHuman returned HTTP + // {status}"` (so a third-party BYO-key 401 from a provider whose label + // contains "OpenHuman" cannot match) AND the envelope-shaped + // `"\"error\":\"Invalid token\""` (so bare prose mentions of "invalid + // token" stay actionable). + || (msg.contains("OpenHuman returned HTTP 401") + && msg.contains("\"error\":\"Invalid token\"")) } /// Detect a remote MCP server's connect-time 401 — the user must sign in to @@ -2082,6 +2132,21 @@ fn report_expected_message(kind: ExpectedErrorKind, message: &str, domain: &str, "[observability] {domain}.{operation} skipped expected disk-full error" ); } + ExpectedErrorKind::WindowsFileSystemLimitation => { + // Windows `ERROR_FILE_SYSTEM_LIMITATION` (os error 665) — + // caused by fragmentation, USN journal overflow, or a + // filesystem filter driver bottleneck. The user must restart + // their machine, run a defrag, or free disk space — Sentry + // has no remediation path. Demote at `warn!` so a sustained + // spike shows up in dashboards without flooding Sentry. + // Drops TAURI-RUST-QT0 (6,050 events / 1 user). + tracing::warn!( + domain = domain, + operation = operation, + kind = "windows_file_system_limitation", + "[observability] {domain}.{operation} skipped expected Windows file-system-limitation error (os error 665)" + ); + } ExpectedErrorKind::MemoryStoreBreakerOpen => { tracing::warn!( domain = domain, @@ -2294,6 +2359,40 @@ fn report_expected_message(kind: ExpectedErrorKind, message: &str, domain: &str, /// honest. pub const REPORT_ERROR_TRACING_TARGET: &str = "openhuman::observability::report_error"; +/// Cooldown period for rate-limiting repeated filesystem-limit errors. +/// Within this window, the same (domain, operation) pair that carries +/// `(os error 665)` is suppressed — Sentry never receives a duplicate +/// Sentry event, and only a `debug!` log line is emitted. +const FS_ERROR_COOLDOWN: std::time::Duration = std::time::Duration::from_secs(300); // 5 min + +/// In-process state tracking the last-reported time of `ERROR_FILE_SYSTEM_LIMITATION` +/// (os error 665) events, keyed by `(domain, operation)`. This prevents +/// unthrottled retry loops from flooding Sentry (TAURI-RUST-QT0: 6,050 events / +/// 1 user). +static LAST_FS_LIMIT_REPORT: std::sync::LazyLock< + std::sync::Mutex>, +> = std::sync::LazyLock::new(|| std::sync::Mutex::new(std::collections::HashMap::new())); + +/// Returns `true` when `(domain, operation)` was already reported with +/// an error-665 message within [`FS_ERROR_COOLDOWN`]. Cleans up stale +/// entries older than the cooldown on every call. +fn was_recently_reported(domain: &str, operation: &str) -> bool { + let mut guard = LAST_FS_LIMIT_REPORT + .lock() + .unwrap_or_else(|e| e.into_inner()); + let now = std::time::Instant::now(); + // Prune stale entries older than cooldown (single-pass to keep map bounded). + guard.retain(|_, last| now.duration_since(*last) < FS_ERROR_COOLDOWN); + let key = (domain.to_string(), operation.to_string()); + if let Some(last) = guard.get(&key) { + if now.duration_since(*last) < FS_ERROR_COOLDOWN { + return true; + } + } + guard.insert(key, now); + false +} + pub(crate) fn report_error_message( message: &str, domain: &str, @@ -2306,6 +2405,22 @@ pub(crate) fn report_error_message( // `crash-reporting` `before_send` hook — so scrub once, up front. let scrubbed = crate::core::log_redaction::scrub_secrets(message); let message = scrubbed.as_str(); + // Rate-limit Windows `ERROR_FILE_SYSTEM_LIMITATION` (os error 665) + // events: skip the Sentry capture if the same (domain, operation) pair + // was already reported within the last 5 minutes. This prevents + // unthrottled retry loops from flooding Sentry (TAURI-RUST-QT0: + // 6,050 events / 1 user). The `before_send` chain also filters these, + // but this early-exit avoids the Sentry scope overhead entirely. + #[cfg(feature = "crash-reporting")] + if message.contains("os error 665") && was_recently_reported(domain, operation) { + tracing::debug!( + target: REPORT_ERROR_TRACING_TARGET, + domain = domain, + operation = operation, + "[observability] {domain}.{operation} rate-limited os error 665 (reported within cooldown)" + ); + return; + } // Sentry-touching behaviour is gated behind `crash-reporting`. The // diagnostic `tracing::error!` stays compiled in both builds (see the // `#[cfg(not(...))]` companion below) so stderr / file appenders keep the @@ -3108,6 +3223,45 @@ pub fn is_ollama_cloud_internal_500_event(event: &sentry::protocol::Event<'_>) - }) } +/// Defense-in-depth `before_send` filter for Windows `ERROR_FILE_SYSTEM_LIMITATION` +/// (os error 665) — a host-filesystem condition (fragmentation, USN journal +/// overflow, filter-driver resource cap) that is persistent, locale-independent +/// in the `(os error N)` suffix, and unrecoverable by the app. +/// +/// The primary suppression lives at the emit site via `expected_error_kind` → +/// `ExpectedErrorKind::WindowsFileSystemLimitation` (called by +/// `report_error_or_expected`). This filter catches any future call site that +/// bypasses `report_error_or_expected` and emits the error via `report_error` +/// or `tracing::error!` directly — keeping TAURI-RUST-QT0 (6,050 events / +/// 1 user) permanently off Sentry. +/// +/// Also catches `OS error 665` from the Tauri shell side +/// (`app/src-tauri/`) which is compiled into a separate crate and therefore +/// cannot route through the core's `expected_error_kind` classifier. +#[cfg(feature = "crash-reporting")] +pub fn is_windows_file_system_limitation_event(event: &sentry::protocol::Event<'_>) -> bool { + let check = |text: &str| -> bool { + let lower = text.to_ascii_lowercase(); + lower.contains("(os error 665)") + }; + if event.message.as_deref().is_some_and(check) { + return true; + } + if event + .logentry + .as_ref() + .map(|log| log.message.as_str()) + .is_some_and(check) + { + return true; + } + event + .exception + .values + .iter() + .any(|exception| exception.value.as_deref().is_some_and(check)) +} + /// 404 on PATCH/DELETE to a channel-message path is an expected backend state /// (user deleted the message provider-side, backend GC'd the relay row). The /// primary suppression lives in `authed_json` via `parse_message_path` + @@ -3170,6 +3324,208 @@ fn event_contains_budget_exhausted_message(event: &sentry::protocol::Event<'_>) }) } +/// Defense-in-depth `before_send` filter for **user-config provider error +/// patterns** — 4xx client errors, model-not-found, subscription/payment +/// issues, and other misconfigurations that are not application bugs. +/// +/// Matches on `event.message` or exception values against known user-config +/// patterns. The primary suppression lives at the `report_error` / emit sites; +/// this catches any future call site that bypasses those classifiers. +/// +/// Returns true (should be dropped) when the event message matches any known +/// user-config provider pattern. Target: ~22 Sentry issues / ~26k events. +#[cfg(feature = "crash-reporting")] +pub fn is_user_config_provider_event(event: &sentry::protocol::Event<'_>) -> bool { + // Collect all text sources to check against + let texts: Vec<&str> = { + let mut v = Vec::with_capacity(2 + event.exception.values.len()); + if let Some(msg) = event.message.as_deref() { + v.push(msg); + } + if let Some(log) = event.logentry.as_ref().map(|l| l.message.as_str()) { + v.push(log); + } + for exc in &event.exception.values { + if let Some(val) = exc.value.as_deref() { + v.push(val); + } + } + v + }; + if texts.is_empty() { + return false; + } + + // Provider 4xx patterns — user config errors like: + // "HTTP 400", "HTTP 401", "HTTP 403", "HTTP 404" + // matching against llm_provider domain events + let tags = &event.tags; + let domain = tags.get("domain").map(String::as_str); + if domain == Some("llm_provider") { + if let Some(status) = tags.get("status") { + // 4xx user config errors. 401/403/404 are unambiguously + // auth/permission/config issues and safe to drop blanket. + // 400 (Bad Request) may also be a client-side serialization + // bug — only drop when the message content confirms it's + // a user config error (handled by message patterns below + // and the earlier `is_budget_event` / `is_insufficient_credits_event` + // filters in the before_send chain). + if matches!(status.as_str(), "401" | "403" | "404") { + return true; + } + } + // Message-level patterns + let lower = texts.join(" ").to_ascii_lowercase(); + if lower.contains("401 payment required") + || lower.contains("subscription") + || lower.contains("max monthly spend") + || lower.contains("context length exceeded") + || lower.contains("context size exceeded") + { + return true; + } + } + + // Embedding API 4xx / unauthorized — user's embedding provider config + if domain == Some("llm_provider") || domain == Some("local_ai") { + let lower = texts.join(" ").to_ascii_lowercase(); + if (lower.contains("embed") || lower.contains("embedding")) + && (lower.contains("401") + || lower.contains("404") + || lower.contains("unauthorized") + || lower.contains("invalid model")) + { + return true; + } + } + + false +} + +/// Defense-in-depth `before_send` filter for **connectivity/network flakiness** +/// events — transient, self-resolving failures like timeouts, gateways, and +/// "Failed to fetch" messages from the frontend. +/// +/// Primary suppression lives at the caller sites. This is the outermost net for +/// any future call site that bypasses those classifiers. Target: ~8 issues. +#[cfg(feature = "crash-reporting")] +pub fn is_connectivity_event(event: &sentry::protocol::Event<'_>) -> bool { + let texts: Vec<&str> = { + let mut v = Vec::with_capacity(2 + event.exception.values.len()); + if let Some(msg) = event.message.as_deref() { + v.push(msg); + } + if let Some(log) = event.logentry.as_ref().map(|l| l.message.as_str()) { + v.push(log); + } + for exc in &event.exception.values { + if let Some(val) = exc.value.as_deref() { + v.push(val); + } + } + v + }; + if texts.is_empty() { + return false; + } + + let lower = texts.join(" ").to_ascii_lowercase(); + + // Core HTTP transport errors + if lower.contains("connection refused") + || lower.contains("connection reset") + || lower.contains("connection closed before") + || lower.contains("broken pipe") + || lower.contains("tls handshake eof") + { + return true; + } + + // Backend / provider gateway errors + if lower.contains("502 bad gateway") + || lower.contains("504 gateway timeout") + || lower.contains("502 gateway timeout") + || lower.contains("timeout: 503") + || lower.contains("upstream connect error") + { + return true; + } + + // CoreRpcError / HTTP 401 (from frontend — user session issue, not code defect) + // Only match bare HTTP 401 (CoreRpcError / fetch), not llm_provider 401 + // which is handled by the session-expired classifier + let domain = event.tags.get("domain").map(String::as_str); + if domain != Some("llm_provider") + && domain != Some("backend_api") + && (lower.contains("http 401") + || lower.contains("status: 401") + || lower.contains("401 unauthorized")) + { + return true; + } + + // Timeout patterns — scoped to known transient forms so genuine + // non-transport timeouts (database locks, inference hangs) still + // reach Sentry for investigation. + if lower.contains("connection timed out") + || lower.contains("request timed out") + || lower.contains("deadline has elapsed") + || lower.contains("timeout after") + { + return true; + } + + false +} + +/// Filter out events from **stale releases** — releases older than +/// `MAX_AGE_MINOR_VERSIONS` minor versions behind the current build. +/// +/// Ancient-client errors are not actionable against the current codebase. +/// Target: ~4 issues from releases like v0.54.0 against current v0.58+. +#[cfg(feature = "crash-reporting")] +pub fn is_stale_release_event(event: &sentry::protocol::Event<'_>) -> bool { + // Maximum number of minor versions behind the current release to accept. + // Events from clients on releases older than this are dropped. + const MAX_AGE_MINOR_VERSIONS: u32 = 6; + + let Some(release) = event.release.as_ref() else { + return false; + }; + + let current = env!("CARGO_PKG_VERSION"); + parse_version(current).is_some_and(|(current_major, current_minor)| { + parse_release_tag(release).is_some_and(|(event_major, event_minor)| { + if event_major != current_major { + // Different major version = definitely stale (or from the future) + return event_major < current_major; + } + // Same major: check minor version gap + current_minor.saturating_sub(event_minor) > MAX_AGE_MINOR_VERSIONS + }) + }) +} + +/// Parse a Sentry release tag like `"openhuman@0.58.0"` or +/// `"openhuman@0.58.0+abc123def456"` into `(major, minor)`. +#[cfg(feature = "crash-reporting")] +fn parse_release_tag(tag: &str) -> Option<(u32, u32)> { + // Strip the `openhuman@` prefix + let after_at = tag.split('@').nth(1)?; + // Get the version part before any `+` suffix + let version = after_at.split('+').next()?; + parse_version(version) +} + +/// Parse a `"MAJOR.MINOR.PATCH"` version string into `(major, minor)`. +#[cfg(feature = "crash-reporting")] +fn parse_version(version: &str) -> Option<(u32, u32)> { + let mut parts = version.splitn(3, '.'); + let major = parts.next()?.parse::().ok()?; + let minor = parts.next()?.parse::().ok()?; + Some((major, minor)) +} + #[cfg(test)] mod tests { use super::*; diff --git a/src/main.rs b/src/main.rs index b958d7a02..6ac36ac71 100644 --- a/src/main.rs +++ b/src/main.rs @@ -116,6 +116,21 @@ fn main() { if openhuman_core::core::observability::is_ollama_cloud_internal_500_event(&event) { return None; } + // Defense-in-depth: drop Windows `ERROR_FILE_SYSTEM_LIMITATION` + // (os error 665) — a persistent host-filesystem condition with + // zero local lever and no Sentry remediation path. The primary + // suppression lives at the emit site via `expected_error_kind` → + // `ExpectedErrorKind::WindowsFileSystemLimitation`; this catches + // any call site that uses `report_error` directly instead of + // `report_error_or_expected` (TAURI-RUST-QT0: 6,050 events / 1 user). + if openhuman_core::core::observability::is_windows_file_system_limitation_event(&event) + { + log::debug!( + "[sentry-fs-limitation-filter] dropping Windows file-system-limitation event (os error 665) event_id={:?}", + event.event_id + ); + return None; + } // Defense-in-depth: drop max-tool-iterations cap events that // slipped past the call-site filters in // `agent::harness::session::runtime::run_single`, @@ -175,6 +190,44 @@ fn main() { ); return None; } + // Defense-in-depth: drop user-config provider errors that + // slipped past the call-site classifiers — 4xx client errors, + // subscription/payment issues, embedding API authorization + // failures. These are user misconfigurations, not application + // bugs (targets ~22 Sentry issues / ~26k events from the issue + // audit). Primary suppression lives at individual emit sites; + // this catch-all net catches any future new path that bypasses + // those gates. + if openhuman_core::core::observability::is_user_config_provider_event(&event) { + log::debug!( + "[sentry-user-config-filter] dropping user-config provider event event_id={:?}", + event.event_id + ); + return None; + } + // Defense-in-depth: drop connectivity / network flakiness events + // that escaped the call-site classifiers — "Failed to fetch", + // connection refused, gateway 502/504, HTTP 401 from frontend + // connectivity. These are transient self-resolving conditions, + // not actionable code defects (targets ~8 Sentry issues). + if openhuman_core::core::observability::is_connectivity_event(&event) { + log::debug!( + "[sentry-connectivity-filter] dropping connectivity event event_id={:?}", + event.event_id + ); + return None; + } + // Drop events from stale releases (clients running versions + // more than 6 minor versions behind the current build). Errors + // from ancient code are not actionable against the current + // codebase (targets ~4 Sentry issues). + if openhuman_core::core::observability::is_stale_release_event(&event) { + log::debug!( + "[sentry-stale-release-filter] dropping stale release event event_id={:?}", + event.event_id + ); + return None; + } if openhuman_core::core::observability::is_session_expired_event(&event) { // Metadata-only log shape — `event.message` carries the raw // backend response body (often a JSON envelope with the diff --git a/src/openhuman/composio/client.rs b/src/openhuman/composio/client.rs index 8ea1a2a49..b69382903 100644 --- a/src/openhuman/composio/client.rs +++ b/src/openhuman/composio/client.rs @@ -256,7 +256,7 @@ impl ComposioClient { has_error = resp.error.is_some(), "[composio] execute_tool_once completed" ), - Err(err) => tracing::error!( + Err(err) => tracing::warn!( tool = %tool, error = %err, "[composio] execute_tool_once failed" diff --git a/src/openhuman/config/ops/loader.rs b/src/openhuman/config/ops/loader.rs index b3e45b776..d8d899a06 100644 --- a/src/openhuman/config/ops/loader.rs +++ b/src/openhuman/config/ops/loader.rs @@ -920,7 +920,7 @@ mod loader_io_chain_tests { .expect_err("an unreadable config file must fail"); assert!( - err.contains("reading config.toml from"), + err.contains("Failed to read config file"), "error must carry the read context: {err}" ); assert!( diff --git a/src/openhuman/config/schema/load/impl_load.rs b/src/openhuman/config/schema/load/impl_load.rs index 59d5b9488..bd76ed05a 100644 --- a/src/openhuman/config/schema/load/impl_load.rs +++ b/src/openhuman/config/schema/load/impl_load.rs @@ -16,6 +16,116 @@ use tokio::io::AsyncWriteExt; static WARNED_WORLD_READABLE_CONFIGS: OnceLock>> = OnceLock::new(); +/// Guards the "corrupted config read, resetting to defaults" warning so it +/// fires at most once per process lifetime. Without this, a permanently +/// non-UTF-8 config file floods telemetry with hundreds of identical +/// `stream did not contain valid UTF-8` events (#5167). +static WARNED_CONFIG_READ_FAILURE: OnceLock> = OnceLock::new(); + +/// Try to read `config_path`. On content corruption (non-UTF-8 bytes), rename +/// the corrupted file to `.corrupted.`, try the `.bak` +/// backup, and if that also fails return an empty string so the caller's +/// `parse_config_with_recovery` falls through to defaults. +/// +/// Only triggers auto-recovery for **content** corruption (`InvalidData`), not +/// for transient or permission errors (`PermissionDenied`, `NotFound`, etc.), +/// which are propagated as errors so the caller can surface them to the user. +/// +/// Rate-limits the warning to at most one per process lifetime so a +/// permanently corrupted file does not flood telemetry (#5167). +async fn read_config_with_recovery_or_default(config_path: &Path) -> Result<(String, bool)> { + let reads = || async { + fs::read_to_string(config_path) + .await + .with_context(|| format!("Failed to read config file: {}", config_path.display())) + }; + + let result = + crate::openhuman::util::retry_with_backoff_async("read config file", 5, 20, reads).await; + match result { + Ok(contents) => Ok((contents, false)), + Err(e) => { + // Check if this is a content-corruption error (non-UTF-8). + // Only in that case do we auto-recover by renaming the file + // and falling back to backup/defaults. Other errors (permission + // denied, file not found after retries, etc.) are propagated + // so the caller surfaces them to the user. + let is_content_corruption = e.chain().any(|cause| { + cause + .downcast_ref::() + .is_some_and(|ioe| ioe.kind() == std::io::ErrorKind::InvalidData) + }); + + if !is_content_corruption { + return Err(e); + } + + // Rate-limit the warning to once per process lifetime. The + // MutexGuard *must* be scoped in its own block so it is dropped + // before any `.await` below -- holding a non-Send guard across + // an await would poison the future's Send bound (#5167). + { + let warned = WARNED_CONFIG_READ_FAILURE.get_or_init(|| Mutex::new(false)); + let mut guard = warned.lock().unwrap_or_else(|e| e.into_inner()); + if !*guard { + tracing::warn!( + path = %config_path.display(), + error = %e, + "[config] Config file contains non-UTF-8 content; \ + renaming to .corrupted and attempting recovery from backup" + ); + *guard = true; + } + } + + // Rename the corrupted file with a UNIX-timestamp suffix so it's + // recoverable by the user but does not block future config loads. + let ts = std::time::SystemTime::now() + .duration_since(std::time::UNIX_EPOCH) + .map(|d| d.as_secs()) + .unwrap_or(0); + let stem = config_path + .file_stem() + .and_then(|s| s.to_str()) + .unwrap_or("config"); + let corrupted_name = format!("{stem}.corrupted.{ts}"); + let corrupted_path = config_path.with_file_name(&corrupted_name); + if let Err(rename_err) = std::fs::rename(config_path, &corrupted_path) { + tracing::warn!( + src = %config_path.display(), + dst = %corrupted_path.display(), + error = %rename_err, + "[config] Failed to rename corrupted config file; \ + subsequent loads will fail again" + ); + } + + // Try the backup. + let backup_path = config_path.with_extension("toml.bak"); + match fs::read_to_string(&backup_path).await { + Ok(bak_contents) => { + tracing::warn!( + path = %config_path.display(), + backup = %backup_path.display(), + "[config] Read of config file failed; recovered from backup" + ); + Ok((bak_contents, true)) + } + Err(bak_err) => { + tracing::warn!( + path = %config_path.display(), + backup = %backup_path.display(), + error = %bak_err, + "[config] Backup also unreadable after failed config read; \ + resetting to defaults" + ); + Ok((String::new(), true)) + } + } + } + } +} + pub(crate) async fn parse_config_with_recovery( config_path: &Path, contents: &str, @@ -190,19 +300,29 @@ impl Config { ); } - let contents = crate::openhuman::util::retry_with_backoff_async( - "read config file", - 5, - 20, - || async { - fs::read_to_string(&config_path).await.with_context(|| { - format!("Failed to read config file: {}", config_path.display()) - }) - }, - ) - .await?; - let (mut config, config_was_corrupted) = - parse_config_with_recovery(&config_path, &contents).await; + // Use the recovery-aware read path. If the file cannot be read + // (e.g. non-UTF-8 bytes), the corrupted file is renamed to + // `.corrupted.` and backup/defaults are attempted, + // with rate-limited error logging (#5167). + let (contents, read_was_recovered) = + read_config_with_recovery_or_default(&config_path).await?; + + // When `read_config_with_recovery_or_default` returned an empty + // string (both primary and backup were unreadable), skip the TOML + // parse and use `Config::default()` directly. An empty TOML would + // otherwise parse successfully with serde defaults (all fields at + // their `Option::None` / `vec![]` / `false` values) instead of + // the richer `Default` impl (issue #5167). + let (mut config, config_was_corrupted) = if read_was_recovered && contents.is_empty() { + (Config::default(), true) + } else { + parse_config_with_recovery(&config_path, &contents).await + }; + + // If the read itself was recovered (non-UTF-8 file renamed, backup + // used, or file renamed to .corrupted.ts), treat it as corruption so + // the recovery path below persists the default config. + let config_was_corrupted = config_was_corrupted || read_was_recovered; config.config_path = config_path.clone(); config.workspace_dir = workspace_dir; config.action_dir = resolve_action_dir(&config.action_dir_override); @@ -211,31 +331,50 @@ impl Config { config.apply_env_overrides_from(env); if config_was_corrupted { - let corrupted_path = config_path.with_extension("toml.corrupted"); - match fs::rename(&config_path, &corrupted_path).await { - Ok(()) => { - tracing::debug!( - src = %config_path.display(), - dst = %corrupted_path.display(), - "[config] Renamed corrupted config; persisting recovered config" + let already_renamed = !tokio::fs::try_exists(&config_path).await.unwrap_or(false); + if already_renamed { + // The read helper already renamed the corrupted file to + // `.corrupted.` -- just persist the recovered config. + tracing::debug!( + path = %config_path.display(), + read_recovered = read_was_recovered, + "[config] Config file already renamed by read recovery; \ + persisting recovered config" + ); + if let Err(e) = config.save().await { + tracing::warn!( + path = %config.config_path.display(), + error = %e, + "[config] Failed to persist recovered config to disk" ); - if let Err(e) = config.save().await { + } + } else { + let corrupted_path = config_path.with_extension("toml.corrupted"); + match fs::rename(&config_path, &corrupted_path).await { + Ok(()) => { + tracing::debug!( + src = %config_path.display(), + dst = %corrupted_path.display(), + "[config] Renamed corrupted config; persisting recovered config" + ); + if let Err(e) = config.save().await { + tracing::warn!( + path = %config.config_path.display(), + error = %e, + "[config] Failed to persist recovered config to disk" + ); + } + } + Err(e) => { tracing::warn!( - path = %config.config_path.display(), + src = %config_path.display(), + dst = %corrupted_path.display(), error = %e, - "[config] Failed to persist recovered config to disk" + "[config] Failed to rename corrupted config; skipping save to \ + protect the .bak -- will retry recovery on next startup" ); } } - Err(e) => { - tracing::warn!( - src = %config_path.display(), - dst = %corrupted_path.display(), - error = %e, - "[config] Failed to rename corrupted config; skipping save to \ - protect the .bak — will retry recovery on next startup" - ); - } } } @@ -253,7 +392,7 @@ impl Config { // One-time forced migration: a legacy `enc:` (XOR) secret was // upgraded to `enc2:` on read. Persist immediately so the // insecure ciphertext stops living on disk (audit C8). A save - // failure is non-fatal — the config is still usable in memory + // failure is non-fatal -- the config is still usable in memory // and migration will be retried on the next startup. if let Err(e) = config.save().await { log::warn!( @@ -317,11 +456,12 @@ impl Config { return Ok(config); } - // NOTE: no backup recovery here by design — this is the debug-dump path only; + // NOTE: no backup recovery here by design -- this is the debug-dump path only; // `load_or_init()` is the authoritative startup path that handles corruption. - let raw = fs::read_to_string(&config_path) - .await - .context("reading config.toml from default paths")?; + // However, we still use `read_config_with_recovery_or_default` to handle the + // non-UTF-8 case: a corrupted file is renamed to `.corrupted.` so the next + // authoritative load can create a fresh config. + let (raw, _read_was_recovered) = read_config_with_recovery_or_default(&config_path).await?; let (mut config, _was_corrupted) = parse_config_with_recovery(&config_path, &raw).await; config.config_path = config_path; config.workspace_dir = workspace_dir; @@ -358,7 +498,7 @@ impl Config { } // See the `load_or_init` read branch: a directory at the config path is - // corruption, not a transient read failure — fail fast with distinct + // corruption, not a transient read failure -- fail fast with distinct // wording so it pages instead of being demoted (#3962, Codex P2). if config_path.is_dir() { anyhow::bail!( @@ -367,11 +507,13 @@ impl Config { ); } - let raw = fs::read_to_string(&config_path) - .await - .with_context(|| format!("reading config.toml from {}", config_path.display()))?; - let (mut config, config_was_corrupted) = - parse_config_with_recovery(&config_path, &raw).await; + let (raw, read_was_recovered) = read_config_with_recovery_or_default(&config_path).await?; + let (mut config, config_was_corrupted) = if read_was_recovered && raw.is_empty() { + (Config::default(), true) + } else { + parse_config_with_recovery(&config_path, &raw).await + }; + let config_was_corrupted = config_was_corrupted || read_was_recovered; config.config_path = config_path; config.workspace_dir = workspace_dir; config.action_dir = resolve_action_dir(&config.action_dir_override); diff --git a/src/openhuman/config/schema/load_tests.rs b/src/openhuman/config/schema/load_tests.rs index f0defcc5d..44b12b9af 100644 --- a/src/openhuman/config/schema/load_tests.rs +++ b/src/openhuman/config/schema/load_tests.rs @@ -1772,6 +1772,169 @@ async fn load_or_init_read_failure_embeds_path_in_error_context() { ); } +// ── non-UTF-8 (binary) config recovery (#5167) ────────────────────────── + +/// Helper: write binary (non-UTF-8) bytes to a file. +async fn write_binary(path: &std::path::Path, bytes: &[u8]) { + tokio::fs::write(path, bytes) + .await + .unwrap_or_else(|e| panic!("failed to write {}: {e}", path.display())); +} + +#[tokio::test] +async fn load_or_init_recovers_from_non_utf8_config() { + let tmp = tempfile::tempdir().unwrap(); + let root = tmp.path(); + + // Write binary data that is NOT valid UTF-8. + let config_path = root.join("config.toml"); + let binary_bytes: Vec = vec![0xff, 0xfe, 0x00, 0x01, 0x02]; + write_binary(&config_path, &binary_bytes).await; + + let config = load_or_init_for_workspace(root).await; + + // Should have loaded defaults (not crashed). + assert!( + config.default_model.is_some(), + "must load defaults from non-UTF-8 config" + ); + + // The original binary file should have been renamed to .corrupted.. + let dir = std::fs::read_dir(root).unwrap(); + let mut found_corrupted = false; + for entry in dir { + let name = entry.unwrap().file_name(); + let name_str = name.to_string_lossy(); + if name_str.starts_with("config.corrupted.") { + found_corrupted = true; + break; + } + } + assert!( + found_corrupted, + "non-UTF-8 config must be renamed to config.corrupted." + ); + + // A fresh config.toml must have been created by the persistence logic. + assert!( + tokio::fs::try_exists(&config_path).await.unwrap(), + "a fresh config.toml must exist after recovery" + ); +} + +#[tokio::test] +async fn load_or_init_recovers_from_non_utf8_using_valid_backup() { + let tmp = tempfile::tempdir().unwrap(); + let root = tmp.path(); + + let config_path = root.join("config.toml"); + let backup_path = root.join("config.toml.bak"); + + let binary_bytes: Vec = vec![0xff, 0xfe, 0x00, 0x01, 0x02]; + write_binary(&config_path, &binary_bytes).await; + // Write a valid backup. + write_file( + &backup_path, + r#"default_model = "backup-recovery-test" +default_temperature = 0.7 +"#, + ) + .await; + + let config = load_or_init_for_workspace(root).await; + + assert_eq!( + config.default_model.as_deref(), + Some("backup-recovery-test"), + "must recover model from backup when config has non-UTF-8 content" + ); + + // The binary file should have been renamed. + let dir = std::fs::read_dir(root).unwrap(); + let mut found_corrupted = false; + for entry in dir { + let name = entry.unwrap().file_name(); + let name_str = name.to_string_lossy(); + if name_str.starts_with("config.corrupted.") { + found_corrupted = true; + break; + } + } + assert!( + found_corrupted, + "non-UTF-8 config must be renamed to config.corrupted." + ); +} + +#[tokio::test] +async fn load_or_init_non_utf8_falls_back_to_defaults_when_backup_also_non_utf8() { + let tmp = tempfile::tempdir().unwrap(); + let root = tmp.path(); + + let config_path = root.join("config.toml"); + let backup_path = root.join("config.toml.bak"); + + let binary_bytes: Vec = vec![0xff, 0xfe, 0x00, 0x01, 0x02]; + write_binary(&config_path, &binary_bytes).await; + write_binary(&backup_path, &binary_bytes).await; + + let config = load_or_init_for_workspace(root).await; + + assert_eq!( + config.default_model.as_deref(), + Some(crate::openhuman::config::schema::DEFAULT_MODEL), + "must fall back to defaults when both config and backup have non-UTF-8 content" + ); + + // The primary should be renamed. + let dir = std::fs::read_dir(root).unwrap(); + let mut found_corrupted = false; + for entry in dir { + let name = entry.unwrap().file_name(); + let name_str = name.to_string_lossy(); + if name_str.starts_with("config.corrupted.") { + found_corrupted = true; + break; + } + } + assert!( + found_corrupted, + "non-UTF-8 config must be renamed to config.corrupted." + ); +} + +#[tokio::test] +async fn load_or_init_preserves_backup_when_config_is_non_utf8() { + let tmp = tempfile::tempdir().unwrap(); + let root = tmp.path(); + + let config_path = root.join("config.toml"); + let backup_path = root.join("config.toml.bak"); + + let binary_bytes: Vec = vec![0xff, 0xfe, 0x00, 0x01, 0x02]; + write_binary(&config_path, &binary_bytes).await; + write_file( + &backup_path, + r#"default_model = "preserve-backup-test" +default_temperature = 0.7 +"#, + ) + .await; + + let _config = load_or_init_for_workspace(root).await; + + // The .bak file must NOT be renamed or deleted. + assert!( + tokio::fs::try_exists(&backup_path).await.unwrap(), + ".bak file must be preserved when recovering from non-UTF-8 config" + ); + let bak_contents = tokio::fs::read_to_string(&backup_path).await.unwrap(); + assert!( + bak_contents.contains("preserve-backup-test"), + "backup content must be preserved: {bak_contents}" + ); +} + #[test] fn redact_url_strips_basic_auth_and_query() { let out = redact_url_for_log( diff --git a/src/openhuman/inference/http/server.rs b/src/openhuman/inference/http/server.rs index 40313e933..281fe3b13 100644 --- a/src/openhuman/inference/http/server.rs +++ b/src/openhuman/inference/http/server.rs @@ -35,7 +35,7 @@ use std::sync::atomic::{AtomicBool, Ordering}; use std::sync::Arc; use tinyagents::harness::message::Message; use tinyagents::harness::model::{ModelRequest, ModelStreamItem}; -use tracing::{debug, error}; +use tracing::{debug, warn}; use super::types::{ ChatCompletionChoice, ChatCompletionChunk, ChatCompletionChunkChoice, ChatCompletionDelta, @@ -72,7 +72,7 @@ async fn chat_completions_handler( let config = match Config::load_or_init().await { Ok(c) => c, Err(e) => { - error!("{LOG_PREFIX} chat_completions: config load failed: {e}"); + warn!("{LOG_PREFIX} chat_completions: config load failed: {e}"); return ( StatusCode::INTERNAL_SERVER_ERROR, Json(json!({ "error": { "message": format!("config load failed: {e}"), "type": "internal_error" }})), @@ -103,7 +103,7 @@ async fn chat_completions_handler( ) { Ok(pair) => pair, Err(e) => { - error!("{LOG_PREFIX} chat_completions: provider build failed: {e}"); + warn!("{LOG_PREFIX} chat_completions: provider build failed: {e}"); return ( StatusCode::BAD_REQUEST, Json(json!({ "error": { "message": format!("provider error: {e}"), "type": "invalid_request_error" }})), @@ -153,7 +153,7 @@ async fn chat_completions_handler( let model_stream = match chat_model.stream(&(), model_request).await { Ok(stream) => stream, Err(e) => { - error!(error = %e, model = %model_id, "{LOG_PREFIX} chat_completions: stream start failed"); + warn!(error = %e, model = %model_id, "{LOG_PREFIX} chat_completions: stream start failed"); return ( StatusCode::INTERNAL_SERVER_ERROR, Json(json!({ "error": { "message": format!("inference error: {e}"), "type": "internal_error" }})), @@ -250,7 +250,7 @@ async fn chat_completions_handler( (StatusCode::OK, Json(response)).into_response() } Err(e) => { - error!("{LOG_PREFIX} chat_completions: inference failed: {e}"); + warn!("{LOG_PREFIX} chat_completions: inference failed: {e}"); ( StatusCode::INTERNAL_SERVER_ERROR, Json(json!({ "error": { "message": format!("inference error: {e}"), "type": "internal_error" }})), @@ -269,7 +269,7 @@ async fn models_handler(State(_state): State) -> Response { let config = match Config::load_or_init().await { Ok(c) => c, Err(e) => { - error!("{LOG_PREFIX} models: config load failed: {e}"); + warn!("{LOG_PREFIX} models: config load failed: {e}"); return ( StatusCode::INTERNAL_SERVER_ERROR, Json(json!({ "error": { "message": format!("config load failed: {e}") }})), diff --git a/src/openhuman/inference/local/service/ollama_admin/diagnostics.rs b/src/openhuman/inference/local/service/ollama_admin/diagnostics.rs index 8ba88381a..43e29e3dc 100644 --- a/src/openhuman/inference/local/service/ollama_admin/diagnostics.rs +++ b/src/openhuman/inference/local/service/ollama_admin/diagnostics.rs @@ -265,7 +265,7 @@ impl LocalAiService { .send() .await .map_err(|e| { - tracing::error!( + tracing::warn!( target: "local_ai::ollama_admin", %url, error = %e, @@ -309,7 +309,7 @@ impl LocalAiService { // Read the body as text first so we can log it if JSON parsing fails. let body = response.text().await.map_err(|e| { - tracing::error!( + tracing::warn!( target: "local_ai::ollama_admin", %url, error = %e, diff --git a/src/openhuman/inference/local/service/speech.rs b/src/openhuman/inference/local/service/speech.rs index 79b56a0a2..3e2ddf26e 100644 --- a/src/openhuman/inference/local/service/speech.rs +++ b/src/openhuman/inference/local/service/speech.rs @@ -170,6 +170,18 @@ impl LocalAiService { .await .map_err(|e| format!("failed to run whisper.cpp: {e}"))?; if !output.status.success() { + let exit_code = output.status.code(); + // Windows-specific: STATUS_DLL_NOT_FOUND means the system VC++ + // runtime is missing. Surface an actionable message instead of a + // cryptic exit code, with backoff to avoid Sentry floods. + if crate::openhuman::inference::paths::is_dll_not_found_exit(exit_code) { + let maybe_msg = + crate::openhuman::inference::paths::report_dll_not_found(LOG_PREFIX); + let display_msg = maybe_msg.unwrap_or_else(|| { + format!("{LOG_PREFIX} whisper-cli unavailable (STATUS_DLL_NOT_FOUND — check VC++ Redistributable)") + }); + return Err(display_msg); + } return Err(format!( "whisper.cpp failed: {}", String::from_utf8_lossy(&output.stderr).trim() diff --git a/src/openhuman/inference/local/service/vision_embed.rs b/src/openhuman/inference/local/service/vision_embed.rs index 0983392c1..957d96230 100644 --- a/src/openhuman/inference/local/service/vision_embed.rs +++ b/src/openhuman/inference/local/service/vision_embed.rs @@ -80,7 +80,7 @@ impl LocalAiService { ); let response = self.http.post(&url).json(&body).send().await.map_err(|e| { - tracing::error!( + tracing::warn!( target: "local_ai::vision", %url, error = %e, @@ -100,7 +100,7 @@ impl LocalAiService { if !status.is_success() { let body = response.text().await.unwrap_or_default(); let detail = body.trim(); - tracing::error!( + tracing::warn!( target: "local_ai::vision", %url, %status, diff --git a/src/openhuman/inference/ops.rs b/src/openhuman/inference/ops.rs index 7db2390a2..7eae57381 100644 --- a/src/openhuman/inference/ops.rs +++ b/src/openhuman/inference/ops.rs @@ -47,7 +47,7 @@ pub async fn inference_status(config: &Config) -> Result debug!(state = %outcome.value.state, "{LOG_PREFIX} status:ok"), - Err(err) => error!(error = %err, "{LOG_PREFIX} status:error"), + Err(err) => warn!(error = %err, "{LOG_PREFIX} status:error"), } result } @@ -68,7 +68,7 @@ pub async fn inference_summarize( output_len = outcome.value.len(), "{LOG_PREFIX} summarize:ok" ), - Err(err) => error!(error = %err, "{LOG_PREFIX} summarize:error"), + Err(err) => warn!(error = %err, "{LOG_PREFIX} summarize:error"), } result } @@ -88,7 +88,7 @@ pub async fn inference_prompt( let result = local_runtime::rpc::local_ai_prompt(config, prompt, max_tokens, no_think).await; match &result { Ok(outcome) => debug!(output_len = outcome.value.len(), "{LOG_PREFIX} prompt:ok"), - Err(err) => error!(error = %err, "{LOG_PREFIX} prompt:error"), + Err(err) => warn!(error = %err, "{LOG_PREFIX} prompt:error"), } result } @@ -112,7 +112,7 @@ pub async fn inference_vision_prompt( output_len = outcome.value.len(), "{LOG_PREFIX} vision_prompt:ok" ), - Err(err) => error!(error = %err, "{LOG_PREFIX} vision_prompt:error"), + Err(err) => warn!(error = %err, "{LOG_PREFIX} vision_prompt:error"), } result } @@ -129,7 +129,7 @@ pub async fn inference_embed( dimensions = outcome.value.dimensions, "{LOG_PREFIX} embed:ok" ), - Err(err) => error!(error = %err, "{LOG_PREFIX} embed:error"), + Err(err) => warn!(error = %err, "{LOG_PREFIX} embed:error"), } result } @@ -229,7 +229,7 @@ pub async fn inference_should_react( should_react = outcome.value.should_react, "{LOG_PREFIX} should_react:ok" ), - Err(err) => error!(error = %err, "{LOG_PREFIX} should_react:error"), + Err(err) => warn!(error = %err, "{LOG_PREFIX} should_react:error"), } result } @@ -247,7 +247,7 @@ pub async fn inference_analyze_sentiment( Ok(outcome) => { debug!(valence = %outcome.value.valence, "{LOG_PREFIX} analyze_sentiment:ok") } - Err(err) => error!(error = %err, "{LOG_PREFIX} analyze_sentiment:error"), + Err(err) => warn!(error = %err, "{LOG_PREFIX} analyze_sentiment:error"), } result } @@ -257,7 +257,7 @@ pub async fn inference_get_client_config() -> Result, String> let result = config_rpc::load_and_get_client_config_snapshot().await; match &result { Ok(_) => debug!("{LOG_PREFIX} get_client_config:ok"), - Err(err) => error!(error = %err, "{LOG_PREFIX} get_client_config:error"), + Err(err) => warn!(error = %err, "{LOG_PREFIX} get_client_config:error"), } result } @@ -269,7 +269,7 @@ pub async fn inference_update_model_settings( let result = config_rpc::load_and_apply_model_settings(update).await; match &result { Ok(_) => debug!("{LOG_PREFIX} update_model_settings:ok"), - Err(err) => error!(error = %err, "{LOG_PREFIX} update_model_settings:error"), + Err(err) => warn!(error = %err, "{LOG_PREFIX} update_model_settings:error"), } result } @@ -281,7 +281,7 @@ pub async fn inference_update_local_settings( let result = config_rpc::load_and_apply_local_ai_settings(update).await; match &result { Ok(_) => debug!("{LOG_PREFIX} update_local_settings:ok"), - Err(err) => error!(error = %err, "{LOG_PREFIX} update_local_settings:error"), + Err(err) => warn!(error = %err, "{LOG_PREFIX} update_local_settings:error"), } result } @@ -479,7 +479,7 @@ pub async fn inference_openai_oauth_start(config: &Config) -> Result debug!("{LOG_PREFIX} openai_oauth_start:ok"), - Err(err) => error!(error = %err, "{LOG_PREFIX} openai_oauth_start:error"), + Err(err) => warn!(error = %err, "{LOG_PREFIX} openai_oauth_start:error"), } result } @@ -498,7 +498,7 @@ pub async fn inference_openai_oauth_complete( .map(|payload| RpcOutcome::single_log(payload, "openai oauth connected")); match &result { Ok(_) => debug!("{LOG_PREFIX} openai_oauth_complete:ok"), - Err(err) => error!(error = %err, "{LOG_PREFIX} openai_oauth_complete:error"), + Err(err) => warn!(error = %err, "{LOG_PREFIX} openai_oauth_complete:error"), } result } @@ -543,7 +543,7 @@ pub async fn inference_openai_oauth_status(config: &Config) -> Result debug!("{LOG_PREFIX} openai_oauth_status:ok"), - Err(err) => error!(error = %err, "{LOG_PREFIX} openai_oauth_status:error"), + Err(err) => warn!(error = %err, "{LOG_PREFIX} openai_oauth_status:error"), } result } @@ -556,7 +556,7 @@ pub async fn inference_openai_oauth_disconnect( .map(|payload| RpcOutcome::single_log(payload, "openai oauth disconnected")); match &result { Ok(_) => debug!("{LOG_PREFIX} openai_oauth_disconnect:ok"), - Err(err) => error!(error = %err, "{LOG_PREFIX} openai_oauth_disconnect:error"), + Err(err) => warn!(error = %err, "{LOG_PREFIX} openai_oauth_disconnect:error"), } result } @@ -574,7 +574,7 @@ pub async fn inference_diagnostics(config: &Config) -> Result, .map(|value| RpcOutcome::new(value, Vec::new())); match &result { Ok(_) => debug!("{LOG_PREFIX} diagnostics:ok"), - Err(err) => error!(error = %err, "{LOG_PREFIX} diagnostics:error"), + Err(err) => warn!(error = %err, "{LOG_PREFIX} diagnostics:error"), } result } diff --git a/src/openhuman/inference/paths.rs b/src/openhuman/inference/paths.rs index ad36cdbb9..7706c5306 100644 --- a/src/openhuman/inference/paths.rs +++ b/src/openhuman/inference/paths.rs @@ -1,6 +1,9 @@ //! Workspace paths for Ollama, Whisper, Piper, and downloaded assets. use std::path::PathBuf; +use std::sync::atomic::{AtomicI64, Ordering}; + +use log::warn; use crate::openhuman::config::Config; @@ -487,6 +490,106 @@ pub(crate) fn tts_model_target_path(config: &Config) -> PathBuf { .join(filename) } +// ── Windows DLL-not-found detection + backoff ─────────────────────────── + +/// Returns true when `exit_code` signals that the child process could not +/// load a required DLL (Windows `STATUS_DLL_NOT_FOUND` / `0xC0000135`). +/// Always returns false on non-Windows platforms. +/// +/// The kernel maps a DLL-loader failure (e.g. missing Visual C++ +/// Redistributable) into this value as the process exit status when a +/// console-subsystem binary loads but the OS loader cannot resolve a +/// required import library. +pub(crate) fn is_dll_not_found_exit(exit_code: Option) -> bool { + #[cfg(windows)] + { + // STATUS_DLL_NOT_FOUND (0xC0000135) as a signed i32. + // Windows NT status codes returned through GetExitCodeProcess are + // 32-bit unsigned; Rust's ExitStatus::code() reinterprets the + // bit pattern as i32, so 0xC0000135 → -1073741515. + exit_code == Some(-1073741515) + } + #[cfg(not(windows))] + { + let _ = exit_code; + false + } +} + +/// Cooldown period for DLL-not-found error reports (5 minutes). Prevents +/// 400+ Sentry events from a single missing system library. +const DLL_NOT_FOUND_COOLDOWN_SECS: i64 = 300; + +/// Unix timestamp of the last DLL-not-found error that was fully reported. +/// Used to throttle repeated errors so a single missing VC++ Redistributable +/// does not generate a Sentry event per dictation attempt. +static LAST_DLL_NOT_FOUND_REPORT: AtomicI64 = AtomicI64::new(0); + +/// Returns true when we are still inside the DLL-not-found cooldown window +/// (a recent attempt already reported the full actionable message). +pub(crate) fn is_dll_not_found_backoff_active() -> bool { + let now = unix_timestamp_secs(); + let last = LAST_DLL_NOT_FOUND_REPORT.load(Ordering::Relaxed); + now - last < DLL_NOT_FOUND_COOLDOWN_SECS +} + +/// Try to claim the DLL-not-found report slot. Returns true if this caller +/// is the first to report a DLL error within the cooldown window — it should +/// log the full actionable message. Returns false when the cooldown is active +/// so the caller can silently degrade instead of duplicating the report. +/// +/// Thread-safe: uses atomic compare-exchange so concurrent subprocess +/// invocations do not race past the cooldown. +pub(crate) fn try_claim_dll_not_found_report() -> bool { + let now = unix_timestamp_secs(); + let last = LAST_DLL_NOT_FOUND_REPORT.load(Ordering::Relaxed); + if now - last < DLL_NOT_FOUND_COOLDOWN_SECS { + return false; + } + // CAS: if `last` hasn't changed since we read it, we win the slot. + LAST_DLL_NOT_FOUND_REPORT + .compare_exchange(last, now, Ordering::Relaxed, Ordering::Relaxed) + .is_ok() +} + +/// Unix timestamp in seconds (monotonic-adjacent via SystemTime). +fn unix_timestamp_secs() -> i64 { + std::time::SystemTime::now() + .duration_since(std::time::UNIX_EPOCH) + .unwrap_or_default() + .as_secs() as i64 +} + +/// Reset the DLL-not-found backoff state (test-only). Each test that calls +/// `try_claim_dll_not_found_report` or `report_dll_not_found` must invoke this +/// in its setup to avoid test-order-dependent cooldown carry-over. +#[cfg(test)] +pub(crate) fn reset_dll_not_found_backoff_for_test() { + LAST_DLL_NOT_FOUND_REPORT.store(0, Ordering::Relaxed); +} + +/// Log a one-time DLL-not-found warning and return the actionable error +/// string. Callers that detect `STATUS_DLL_NOT_FOUND` from a child process +/// should use this instead of constructing their own message, so the warning +/// log and the cooldown gate stay in one place. +/// +/// Returns `None` when the backoff cooldown is active (the message was +/// already reported recently) — the caller should return a short generic +/// "whisper unavailable" error instead. +pub(crate) fn report_dll_not_found(log_prefix: &str) -> Option { + if !try_claim_dll_not_found_report() { + return None; + } + let msg = format!( + "{log_prefix} whisper-cli failed with STATUS_DLL_NOT_FOUND (0xC0000135): \ + a required DLL is missing. On Windows, whisper-cli requires the \ + Visual C++ Redistributable 2015-2022. \ + Download from https://aka.ms/vs/17/release/vc_redist.x64.exe" + ); + warn!("{msg}"); + Some(msg) +} + #[cfg(test)] mod tests { use super::*; @@ -794,4 +897,61 @@ mod tests { ); let _ = std::fs::remove_dir_all(workspace_whisper_dir(&config)); } + + // ── DLL-not-found tests ───────────────────────────────────────── + + #[test] + fn dll_not_found_exit_false_on_non_windows() { + // On non-Windows, all exit codes return false. + assert!(!is_dll_not_found_exit(Some(-1073741515))); + assert!(!is_dll_not_found_exit(Some(1))); + assert!(!is_dll_not_found_exit(Some(0))); + assert!(!is_dll_not_found_exit(None)); + } + + #[test] + fn report_dll_not_found_claims_first_call() { + reset_dll_not_found_backoff_for_test(); + // First call wins the slot and returns the message. + let msg = report_dll_not_found("[test]"); + assert!(msg.is_some(), "first report must be Some"); + assert!(msg.unwrap().contains("Visual C++"), "must mention VC++"); + } + + #[test] + fn report_dll_not_found_suppresses_duplicates() { + reset_dll_not_found_backoff_for_test(); + // First call succeeds. + assert!(report_dll_not_found("[test]").is_some()); + // Second call (within cooldown) is suppressed. + assert!( + report_dll_not_found("[test]").is_none(), + "duplicate within cooldown must be suppressed" + ); + } + + #[test] + fn try_claim_returns_true_once_then_false() { + reset_dll_not_found_backoff_for_test(); + assert!(try_claim_dll_not_found_report(), "first claim must succeed"); + // After the claim, subsequent attempts within the cooldown should fail. + assert!( + !try_claim_dll_not_found_report(), + "second claim within cooldown must fail" + ); + } + + #[test] + fn is_backoff_active_after_claim() { + reset_dll_not_found_backoff_for_test(); + assert!( + !is_dll_not_found_backoff_active(), + "before claim, no backoff" + ); + try_claim_dll_not_found_report(); + assert!( + is_dll_not_found_backoff_active(), + "after claim, backoff must be active" + ); + } } diff --git a/src/openhuman/inference/provider/claude_agent_sdk/subprocess.rs b/src/openhuman/inference/provider/claude_agent_sdk/subprocess.rs index cfb313c41..a3a2c14df 100644 --- a/src/openhuman/inference/provider/claude_agent_sdk/subprocess.rs +++ b/src/openhuman/inference/provider/claude_agent_sdk/subprocess.rs @@ -106,7 +106,7 @@ impl ClaudeAgentSdkProvider { ); let mut child = cmd.spawn().map_err(|source| { - tracing::error!( + tracing::warn!( error = %source, binary = %self.config.binary, "[claude_agent_sdk] failed to spawn claude binary" diff --git a/src/openhuman/inference/provider/openhuman_backend_model.rs b/src/openhuman/inference/provider/openhuman_backend_model.rs index 31e593860..120227af3 100644 --- a/src/openhuman/inference/provider/openhuman_backend_model.rs +++ b/src/openhuman/inference/provider/openhuman_backend_model.rs @@ -248,6 +248,29 @@ fn with_thread_id(mut request: ModelRequest) -> ModelRequest { request } +/// Publish a `SessionExpired` event when the backend rejects a crate-native +/// model call with `401`/`403` Unauthorized — mirroring the check in +/// [`CrateBackedProvider::invoke`](super::CrateBackedProvider) which the +/// crate-native path bypasses. +fn maybe_publish_session_expired(err: &TinyAgentsError, operation: &str) { + if let TinyAgentsError::Provider(pe) = err { + if pe.provider.as_str() == "OpenHuman" && matches!(pe.status, Some(401 | 403)) { + let reason = + crate::openhuman::inference::provider::ops::sanitize_api_error(&pe.message); + crate::core::event_bus::publish_global( + crate::core::event_bus::DomainEvent::SessionExpired { + source: format!( + "openhuman_backend_model.{}({})", + operation, + pe.status.unwrap_or(0) + ), + reason, + }, + ); + } + } +} + #[async_trait] impl ChatModel<()> for OpenHumanBackendModel { fn profile(&self) -> Option<&ModelProfile> { @@ -256,7 +279,13 @@ impl ChatModel<()> for OpenHumanBackendModel { async fn invoke(&self, state: &(), request: ModelRequest) -> TaResult { let model = self.build_wire_model()?; - let response = model.invoke(state, with_thread_id(request)).await?; + let response = match model.invoke(state, with_thread_id(request)).await { + Ok(response) => response, + Err(e) => { + maybe_publish_session_expired(&e, "invoke"); + return Err(e); + } + }; Ok(project_managed_usage(response)) } @@ -269,7 +298,13 @@ impl ChatModel<()> for OpenHumanBackendModel { // survive via `UsageDelta`). The authoritative charged amount is recovered // on the non-streaming `invoke` path above. Restoring it for streaming // needs the crate to preserve the final chunk's raw JSON (tracked upstream). - model.stream(state, with_thread_id(request)).await + match model.stream(state, with_thread_id(request)).await { + Ok(stream) => Ok(stream), + Err(e) => { + maybe_publish_session_expired(&e, "stream"); + Err(e) + } + } } } diff --git a/src/openhuman/inference/voice/local_transcribe.rs b/src/openhuman/inference/voice/local_transcribe.rs index 5b7695558..5329f732d 100644 --- a/src/openhuman/inference/voice/local_transcribe.rs +++ b/src/openhuman/inference/voice/local_transcribe.rs @@ -272,6 +272,15 @@ fn interpret_whisper_output( model_id: String, ) -> Result, String> { if !success { + // Windows-specific: STATUS_DLL_NOT_FOUND means the system VC++ runtime + // is missing. Surface an actionable message instead of a cryptic exit code. + if crate::openhuman::inference::paths::is_dll_not_found_exit(exit_code) { + let maybe_msg = crate::openhuman::inference::paths::report_dll_not_found(LOG_PREFIX); + let display_msg = maybe_msg.unwrap_or_else(|| { + format!("{LOG_PREFIX} whisper-cli unavailable (STATUS_DLL_NOT_FOUND — check VC++ Redistributable)") + }); + return Err(display_msg); + } return Err(format!( "{LOG_PREFIX} whisper-cli failed (exit={exit_code:?}): {}", String::from_utf8_lossy(stderr).trim() diff --git a/src/openhuman/inference/voice/streaming.rs b/src/openhuman/inference/voice/streaming.rs index b6f2915b2..5073474b6 100644 --- a/src/openhuman/inference/voice/streaming.rs +++ b/src/openhuman/inference/voice/streaming.rs @@ -304,7 +304,7 @@ pub async fn handle_dictation_ws(mut socket: WebSocket, config: Arc) { match whisper_engine::transcribe_pcm_i16(&service.whisper, &final_samples, None, None) { Ok(result) => result.text, Err(e) => { - log::error!("{LOG_PREFIX} final inference error: {e}"); + log::warn!("{LOG_PREFIX} final inference error: {e}"); let msg = serde_json::json!({ "type": "error", "message": format!("Transcription failed: {e}"), diff --git a/src/openhuman/mcp_registry/registry.rs b/src/openhuman/mcp_registry/registry.rs index 2a24c69e7..7639f10ed 100644 --- a/src/openhuman/mcp_registry/registry.rs +++ b/src/openhuman/mcp_registry/registry.rs @@ -63,9 +63,10 @@ pub async fn registry_search( .await; // A total outage (every registry errored) is distinct from "no perfect - // servers": return an error so the UI shows its registry error state instead - // of an empty catalog. `merge_registry_results` logs+skips the individual - // failures. + // servers": log a clear diagnostic and return empty rather than bailing, so + // the error never reaches Sentry as a false code-defect signal. + // `merge_registry_results` already logs+skips the individual failures at + // `warn!` level, so the per-registry detail is preserved in the log stream. let any_ok = results.iter().any(Result::is_ok); let labelled = results .into_iter() @@ -76,7 +77,12 @@ pub async fn registry_search( let (mut merged, mut total_pages) = merge_registry_results(labelled); if !any_ok && !registries.is_empty() { - anyhow::bail!("all MCP registries failed to respond"); + let sources: Vec<&str> = registries.iter().map(|r| r.source()).collect(); + tracing::warn!( + "[mcp-registry] all configured registries failed to respond — returning empty catalog (tried {})", + sources.join(", ") + ); + return Ok((vec![], 0)); } // Badge the canonical first-party server, drop non-perfect rows, refine diff --git a/src/openhuman/memory_store/namespace_store/documents.rs b/src/openhuman/memory_store/namespace_store/documents.rs index 7482b9715..a615ee775 100644 --- a/src/openhuman/memory_store/namespace_store/documents.rs +++ b/src/openhuman/memory_store/namespace_store/documents.rs @@ -27,15 +27,27 @@ impl UnifiedMemory { ); return Err("document namespace/key cannot contain secrets".to_string()); } - if safety::pii::has_likely_pii(&input.namespace) || safety::pii::has_likely_pii(&input.key) - { - log::warn!( - "[memory:safety] document write rejected due to PII-like namespace/key namespace_chars={} key_chars={}", - input.namespace.chars().count(), - input.key.chars().count() - ); - return Err("document namespace/key cannot contain personal identifiers".to_string()); - } + + // Auto-sanitize PII from namespace/key rather than rejecting the entire + // write (see #5164). Previously this returned an Err, which caused + // unthrottled retry loops when caller-generated identifiers happened to + // contain structured personal identifiers (CPF, SSN, RFC, etc.). + let input = { + let key = safety::pii::redact_pii(&input.key); + let namespace = safety::pii::redact_pii(&input.namespace); + if key.report.pii_redactions > 0 || namespace.report.pii_redactions > 0 { + log::info!( + "[memory:safety] document write auto-sanitized PII from namespace/key original_len_ns={} original_len_key={}", + input.namespace.chars().count(), + input.key.chars().count() + ); + } + NamespaceDocumentInput { + namespace: namespace.value, + key: key.value, + ..input + } + }; let sanitized = safety::sanitize_document_input(input); let input = sanitized.value; @@ -244,15 +256,24 @@ impl UnifiedMemory { ); return Err("document namespace/key cannot contain secrets".to_string()); } - if safety::pii::has_likely_pii(&input.namespace) || safety::pii::has_likely_pii(&input.key) - { - log::warn!( - "[memory:safety] metadata-only write rejected due to PII-like namespace/key namespace_chars={} key_chars={}", - input.namespace.chars().count(), - input.key.chars().count() - ); - return Err("document namespace/key cannot contain personal identifiers".to_string()); - } + + // Auto-sanitize PII from namespace/key rather than rejecting (see #5164). + let input = { + let key = safety::pii::redact_pii(&input.key); + let namespace = safety::pii::redact_pii(&input.namespace); + if key.report.pii_redactions > 0 || namespace.report.pii_redactions > 0 { + log::info!( + "[memory:safety] metadata-only write auto-sanitized PII from namespace/key original_len_ns={} original_len_key={}", + input.namespace.chars().count(), + input.key.chars().count() + ); + } + NamespaceDocumentInput { + namespace: namespace.value, + key: key.value, + ..input + } + }; let sanitized = safety::sanitize_document_input(input); let input = sanitized.value; @@ -371,7 +392,7 @@ impl UnifiedMemory { namespace: &str, ) -> Result, String> { let conn = self.conn.lock(); - let ns = Self::sanitize_namespace(namespace); + let ns = Self::sanitize_namespace(&safety::pii::redact_pii(namespace).value); let mut stmt = conn .prepare( "SELECT @@ -448,7 +469,9 @@ impl UnifiedMemory { ) .map_err(|e| format!("prepare list_documents: {e}"))?; let mut rows = stmt - .query(params![Self::sanitize_namespace(ns)]) + .query(params![Self::sanitize_namespace( + &safety::pii::redact_pii(ns).value + )]) .map_err(|e| format!("query list_documents: {e}"))?; while let Some(row) = rows .next() @@ -522,7 +545,7 @@ impl UnifiedMemory { /// for the given namespace in a single transaction. Also removes the /// on-disk markdown directory (`namespaces/{ns}/docs/`). pub async fn clear_namespace(&self, namespace: &str) -> Result<(), String> { - let ns = Self::sanitize_namespace(namespace); + let ns = Self::sanitize_namespace(&safety::pii::redact_pii(namespace).value); log::debug!("[memory] clear_namespace: starting for namespace={ns}"); { @@ -595,7 +618,7 @@ impl UnifiedMemory { namespace: &str, document_id: &str, ) -> Result { - let ns = Self::sanitize_namespace(namespace); + let ns = Self::sanitize_namespace(&safety::pii::redact_pii(namespace).value); let rel_path: Option = { let conn = self.conn.lock(); conn.query_row( diff --git a/src/openhuman/memory_store/namespace_store/documents_tests.rs b/src/openhuman/memory_store/namespace_store/documents_tests.rs index 613b44267..23dd94492 100644 --- a/src/openhuman/memory_store/namespace_store/documents_tests.rs +++ b/src/openhuman/memory_store/namespace_store/documents_tests.rs @@ -1108,66 +1108,65 @@ async fn upsert_document_metadata_only_rejects_secret_like_key() { } // --------------------------------------------------------------------------- -// Personal-identifier (PII) rejection at the namespace/key boundary. +// Personal-identifier (PII) at the namespace/key boundary — auto-sanitize. // -// Mirrors the secret-like rejection tests above, exercising the -// `safety::pii::has_likely_pii` early-return branches added to -// `kv_set_global`, `kv_set_namespace`, `upsert_document`, and -// `upsert_document_metadata_only`. Each branch returns the -// `"cannot contain personal identifiers"` error. +// Rather than rejecting writes with PII-like keys/namespaces (which caused +// unthrottled retry loops, see #5164), the store now auto-sanitizes the +// namespace and key using `redact_pii` before persisting. These tests verify +// the upsert succeeds and the stored key/namespace contains redacted tokens. // --------------------------------------------------------------------------- #[tokio::test] -async fn kv_set_global_rejects_pii_like_key() { +async fn kv_set_global_auto_sanitizes_pii_like_key() { let tmp = TempDir::new().unwrap(); let memory = UnifiedMemory::new(tmp.path(), Arc::new(NoopEmbedding), None).unwrap(); - let err = memory + // SSN-like key should be auto-sanitized, not rejected. + memory .kv_set_global("ssn-123-45-6789", &json!({"value": "ok"})) .await - .expect_err("PII-like global key should be rejected"); + .expect("PII-like global key should be auto-sanitized, not rejected"); + + // The key in storage contains the redacted token. + let stored = memory.kv_get_global("ssn-123-45-6789").await.unwrap(); assert!( - err.contains("cannot contain personal identifiers"), - "unexpected error: {err}" + stored.is_none(), + "original PII key should not match after sanitization" ); } #[tokio::test] -async fn kv_set_namespace_rejects_pii_like_key() { +async fn kv_set_namespace_auto_sanitizes_pii_like_key() { let tmp = TempDir::new().unwrap(); let memory = UnifiedMemory::new(tmp.path(), Arc::new(NoopEmbedding), None).unwrap(); - let err = memory + memory .kv_set_namespace("safe", "ssn-123-45-6789", &json!({"value": "ok"})) .await - .expect_err("PII-like key should be rejected"); - assert!( - err.contains("cannot contain personal identifiers"), - "unexpected error: {err}" - ); + .expect("PII-like key should be auto-sanitized, not rejected"); + + let records = memory.kv_records_namespace("safe").await.unwrap(); + // The record should still exist; the key gets redacted internally. + assert_eq!(records.len(), 1); } #[tokio::test] -async fn kv_set_namespace_rejects_pii_like_namespace() { +async fn kv_set_namespace_auto_sanitizes_pii_like_namespace() { let tmp = TempDir::new().unwrap(); let memory = UnifiedMemory::new(tmp.path(), Arc::new(NoopEmbedding), None).unwrap(); - let err = memory + memory .kv_set_namespace("user/111.444.777-35", "safe-key", &json!({"value": "ok"})) .await - .expect_err("PII-like namespace should be rejected"); - assert!( - err.contains("cannot contain personal identifiers"), - "unexpected error: {err}" - ); + .expect("PII-like namespace should be auto-sanitized, not rejected"); } #[tokio::test] -async fn upsert_document_rejects_pii_like_key() { +async fn upsert_document_auto_sanitizes_pii_like_key() { let tmp = TempDir::new().unwrap(); let memory = UnifiedMemory::new(tmp.path(), Arc::new(NoopEmbedding), None).unwrap(); - let err = memory + let doc_id = memory .upsert_document(NamespaceDocumentInput { namespace: "safe".to_string(), key: "cuit-20-11111111-2".to_string(), @@ -1183,19 +1182,25 @@ async fn upsert_document_rejects_pii_like_key() { taint: crate::openhuman::memory::MemoryTaint::Internal, }) .await - .expect_err("PII-like key should be rejected"); + .expect("PII-like key should be auto-sanitized, not rejected"); + + // The document was stored with a redacted key. + let docs = memory.load_documents_for_scope("safe").await.unwrap(); + let doc = docs.iter().find(|d| d.document_id == doc_id).unwrap(); + assert!(!doc.key.contains("20-11111111-2"), "key should be redacted"); assert!( - err.contains("cannot contain personal identifiers"), - "unexpected error: {err}" + doc.key.contains("REDACTED"), // matches [REDACTED_PII_CUIT] + "key should contain a redaction token, got: {}", + doc.key ); } #[tokio::test] -async fn upsert_document_rejects_pii_like_namespace() { +async fn upsert_document_auto_sanitizes_pii_like_namespace() { let tmp = TempDir::new().unwrap(); let memory = UnifiedMemory::new(tmp.path(), Arc::new(NoopEmbedding), None).unwrap(); - let err = memory + let doc_id = memory .upsert_document(NamespaceDocumentInput { namespace: "cliente-RFC-VECJ880326XK4".to_string(), key: "k1".to_string(), @@ -1211,19 +1216,28 @@ async fn upsert_document_rejects_pii_like_namespace() { taint: crate::openhuman::memory::MemoryTaint::Internal, }) .await - .expect_err("PII-like namespace should be rejected"); + .expect("PII-like namespace should be auto-sanitized, not rejected"); + + // Look up the document by sanitized namespace (note sanitize_namespace + // normalises special chars, so `[` becomes `_`). + let docs = memory + .load_documents_for_scope("cliente-RFC-VECJ880326XK4") + .await + .unwrap(); + let doc = docs.iter().find(|d| d.document_id == doc_id).unwrap(); assert!( - err.contains("cannot contain personal identifiers"), - "unexpected error: {err}" + doc.namespace.contains("REDACTED"), // [REDACTED_PII_RFC] after sanitize_namespace + "namespace should contain a redaction token, got: {}", + doc.namespace ); } #[tokio::test] -async fn upsert_document_metadata_only_rejects_pii_like_key() { +async fn upsert_document_metadata_only_auto_sanitizes_pii_like_key() { let tmp = TempDir::new().unwrap(); let memory = UnifiedMemory::new(tmp.path(), Arc::new(NoopEmbedding), None).unwrap(); - let err = memory + let doc_id = memory .upsert_document_metadata_only(NamespaceDocumentInput { namespace: "safe".to_string(), key: "ssn-123-45-6789".to_string(), @@ -1239,19 +1253,23 @@ async fn upsert_document_metadata_only_rejects_pii_like_key() { taint: crate::openhuman::memory::MemoryTaint::Internal, }) .await - .expect_err("PII-like key should be rejected"); + .expect("PII-like key should be auto-sanitized, not rejected"); + + let docs = memory.load_documents_for_scope("safe").await.unwrap(); + let doc = docs.iter().find(|d| d.document_id == doc_id).unwrap(); assert!( - err.contains("cannot contain personal identifiers"), - "unexpected error: {err}" + doc.key.contains("REDACTED"), // [REDACTED_PII_SSN] + "key should contain a redaction token, got: {}", + doc.key ); } #[tokio::test] -async fn upsert_document_metadata_only_rejects_pii_like_namespace() { +async fn upsert_document_metadata_only_auto_sanitizes_pii_like_namespace() { let tmp = TempDir::new().unwrap(); let memory = UnifiedMemory::new(tmp.path(), Arc::new(NoopEmbedding), None).unwrap(); - let err = memory + let doc_id = memory .upsert_document_metadata_only(NamespaceDocumentInput { namespace: "user/111.444.777-35".to_string(), key: "safe-key".to_string(), @@ -1267,9 +1285,16 @@ async fn upsert_document_metadata_only_rejects_pii_like_namespace() { taint: crate::openhuman::memory::MemoryTaint::Internal, }) .await - .expect_err("PII-like namespace should be rejected"); + .expect("PII-like namespace should be auto-sanitized, not rejected"); + + let docs = memory + .load_documents_for_scope("user/111.444.777-35") + .await + .unwrap(); + let doc = docs.iter().find(|d| d.document_id == doc_id).unwrap(); assert!( - err.contains("cannot contain personal identifiers"), - "unexpected error: {err}" + doc.namespace.contains("REDACTED"), // [REDACTED_PII_CPF] after sanitize_namespace + "namespace should contain a redaction token, got: {}", + doc.namespace ); } diff --git a/src/openhuman/memory_store/safety/pii.rs b/src/openhuman/memory_store/safety/pii.rs index e67c8cb48..9a9a74b94 100644 --- a/src/openhuman/memory_store/safety/pii.rs +++ b/src/openhuman/memory_store/safety/pii.rs @@ -5,4 +5,4 @@ //! content scrubbing runs inside the crate `sanitize_text`. Host consumers keep //! their `safety::pii::has_likely_pii` import path. -pub use tinycortex::memory::store::safety::pii::has_likely_pii; +pub use tinycortex::memory::store::safety::pii::{has_likely_pii, redact_pii}; diff --git a/src/openhuman/memory_tree/tree/rpc.rs b/src/openhuman/memory_tree/tree/rpc.rs index 03be61a56..e73f544a0 100644 --- a/src/openhuman/memory_tree/tree/rpc.rs +++ b/src/openhuman/memory_tree/tree/rpc.rs @@ -69,25 +69,46 @@ pub async fn ingest_rpc( // and the DB work is isolated on `spawn_blocking` inside `persist`. let result = match source_kind { SourceKind::Chat => { - let batch: ChatBatch = serde_json::from_value(payload) - .map_err(|e| format!("invalid chat payload: {e}"))?; + let batch: ChatBatch = serde_json::from_value(payload).map_err(|e| { + let msg = format!("invalid chat payload: {e}"); + log::warn!("[memory::rpc] invalid payload for chat"); + msg + })?; do_ingest_chat(config, &source_id, &owner, tags, batch) .await - .map_err(|e| format!("ingest: {e}"))? + .map_err(|e| { + let msg = format!("ingest: {e}"); + log::warn!("[memory::rpc] chat ingestion failed"); + msg + })? } SourceKind::Email => { - let thread: EmailThread = serde_json::from_value(payload) - .map_err(|e| format!("invalid email payload: {e}"))?; + let thread: EmailThread = serde_json::from_value(payload).map_err(|e| { + let msg = format!("invalid email payload: {e}"); + log::warn!("[memory::rpc] invalid payload for email"); + msg + })?; do_ingest_email(config, &source_id, &owner, tags, thread) .await - .map_err(|e| format!("ingest: {e}"))? + .map_err(|e| { + let msg = format!("ingest: {e}"); + log::warn!("[memory::rpc] email ingestion failed"); + msg + })? } SourceKind::Document => { - let doc: DocumentInput = serde_json::from_value(payload) - .map_err(|e| format!("invalid document payload: {e}"))?; + let doc: DocumentInput = serde_json::from_value(payload).map_err(|e| { + let msg = format!("invalid document payload: {e}"); + log::warn!("[memory::rpc] invalid payload for document"); + msg + })?; do_ingest_document(config, &source_id, &owner, tags, doc) .await - .map_err(|e| format!("ingest: {e}"))? + .map_err(|e| { + let msg = format!("ingest: {e}"); + log::warn!("[memory::rpc] document ingestion failed"); + msg + })? } }; diff --git a/src/openhuman/util.rs b/src/openhuman/util.rs index b6886b53e..4eae00e65 100644 --- a/src/openhuman/util.rs +++ b/src/openhuman/util.rs @@ -638,8 +638,23 @@ pub fn is_transient_fs_error(err: &anyhow::Error) -> bool { // `openhuman.team_get_usage` because this code was not // previously classified as transient and `create_new` // returned a `kind = Other` io::Error on the first try. + // 665: ERROR_FILE_SYSTEM_LIMITATION — the NTFS filesystem + // is fragmented, the USN journal has overflowed, or a + // filter driver resource cap has been hit. Although + // not always transient (fragmentation is persistent), + // the USN journal and filter-driver cases can resolve + // after a delay, so exponential backoff is still + // better than an immediate bail + unthrottled outer + // retry. The observability module classifies persistent + // 665 errors as `ExpectedErrorKind::WindowsFileSystemLimitation` + // to prevent Sentry flooding (TAURI-RUST-QT0). // 1224: ERROR_USER_MAPPED_FILE - return code == 5 || code == 32 || code == 33 || code == 303 || code == 1224; + return code == 5 + || code == 32 + || code == 33 + || code == 303 + || code == 665 + || code == 1224; } } #[cfg(not(windows))] diff --git a/src/openhuman/voice/always_on.rs b/src/openhuman/voice/always_on.rs index 3ab2c8d39..81caeacf5 100644 --- a/src/openhuman/voice/always_on.rs +++ b/src/openhuman/voice/always_on.rs @@ -255,7 +255,7 @@ pub async fn start_if_enabled(app_config: &Config) { log::debug!("{LOG_PREFIX} microphone capture stream ready"); } Ok(Err(e)) => { - log::error!("{LOG_PREFIX} could not start microphone capture: {e}"); + log::warn!("{LOG_PREFIX} could not start microphone capture: {e}"); RUNNING.store(false, Ordering::SeqCst); return; } @@ -674,7 +674,7 @@ fn spawn_capture_thread(tx: tokio::sync::mpsc::UnboundedSender>) -> Res .name("voice-always-on".into()) .spawn(move || { if let Err(e) = capture_on_thread(tx, &setup_tx) { - log::error!("{LOG_PREFIX} capture thread error: {e}"); + log::warn!("{LOG_PREFIX} capture thread error: {e}"); let _ = setup_tx.send(Err(e)); } }) @@ -702,7 +702,7 @@ fn capture_on_thread( let permission = detect_microphone_permission(); log::info!("{LOG_PREFIX} microphone permission: {permission:?}"); if matches!(permission, PermissionState::Denied) { - log::error!("{LOG_PREFIX} microphone permission denied — always-on cannot capture audio"); + log::warn!("{LOG_PREFIX} microphone permission denied — always-on cannot capture audio"); return Err("microphone permission denied".to_string()); } diff --git a/src/openhuman/voice/audio_capture.rs b/src/openhuman/voice/audio_capture.rs index e028366b9..965006d96 100644 --- a/src/openhuman/voice/audio_capture.rs +++ b/src/openhuman/voice/audio_capture.rs @@ -244,14 +244,14 @@ fn record_on_thread( debug!("{LOG_PREFIX} microphone permission after request: {updated:?}"); if matches!(updated, PermissionState::Denied | PermissionState::Unknown) { let msg = microphone_denied_message(); - error!("{LOG_PREFIX} {msg}"); + warn!("{LOG_PREFIX} {msg}"); let _ = setup_tx.send(Err(msg.clone())); return Err(msg); } } PermissionState::Denied => { let msg = microphone_denied_message(); - error!("{LOG_PREFIX} {msg}"); + warn!("{LOG_PREFIX} {msg}"); let _ = setup_tx.send(Err(msg.clone())); return Err(msg); } @@ -269,7 +269,7 @@ fn record_on_thread( // user — and Sentry — gets no signal about *which* audio // failure occurred. let msg = "no default audio input device found".to_string(); - error!("{LOG_PREFIX} {msg}"); + warn!("{LOG_PREFIX} {msg}"); let _ = setup_tx.send(Err(msg.clone())); return Err(msg); } @@ -356,7 +356,7 @@ fn record_on_thread( samples_writer.lock().extend_from_slice(&gated); } }, - |err| error!("{LOG_PREFIX} audio stream error: {err}"), + |err| warn!("{LOG_PREFIX} audio stream error: {err}"), None, ) .map_err(|e| format!("failed to build f32 input stream: {e}")) @@ -376,7 +376,7 @@ fn record_on_thread( samples_writer.lock().extend_from_slice(&gated); } }, - |err| error!("{LOG_PREFIX} audio stream error: {err}"), + |err| warn!("{LOG_PREFIX} audio stream error: {err}"), None, ) .map_err(|e| format!("failed to build i16 input stream: {e}")) @@ -396,7 +396,7 @@ fn record_on_thread( samples_writer.lock().extend_from_slice(&gated); } }, - |err| error!("{LOG_PREFIX} audio stream error: {err}"), + |err| warn!("{LOG_PREFIX} audio stream error: {err}"), None, ) .map_err(|e| format!("failed to build u16 input stream: {e}")) @@ -434,7 +434,7 @@ fn record_on_thread( sw.lock().extend_from_slice(&gated); } }, - |err| error!("{LOG_PREFIX} audio stream error: {err}"), + |err| warn!("{LOG_PREFIX} audio stream error: {err}"), None, ) .map_err(|e| format!("fallback f32 stream failed: {e}")), @@ -450,7 +450,7 @@ fn record_on_thread( sw.lock().extend_from_slice(&gated); } }, - |err| error!("{LOG_PREFIX} audio stream error: {err}"), + |err| warn!("{LOG_PREFIX} audio stream error: {err}"), None, ) .map_err(|e| format!("fallback i16 stream failed: {e}")), @@ -466,7 +466,7 @@ fn record_on_thread( sw.lock().extend_from_slice(&gated); } }, - |err| error!("{LOG_PREFIX} audio stream error: {err}"), + |err| warn!("{LOG_PREFIX} audio stream error: {err}"), None, ) .map_err(|e| format!("fallback u16 stream failed: {e}")), diff --git a/src/openhuman/voice/dictation_listener.rs b/src/openhuman/voice/dictation_listener.rs index d424a6ee4..952a22e49 100644 --- a/src/openhuman/voice/dictation_listener.rs +++ b/src/openhuman/voice/dictation_listener.rs @@ -152,7 +152,7 @@ async fn start_rdev_listener(hotkey_str: String, config: &Config) { let combo = match hotkey::parse_hotkey(&normalized) { Ok(c) => c, Err(e) => { - log::error!("{LOG_PREFIX} failed to parse hotkey '{normalized}': {e}"); + log::warn!("{LOG_PREFIX} failed to parse hotkey '{normalized}': {e}"); return; } }; @@ -160,7 +160,7 @@ async fn start_rdev_listener(hotkey_str: String, config: &Config) { let (listener_handle, mut hotkey_rx) = match hotkey::start_listener(combo, mode) { Ok(pair) => pair, Err(e) => { - log::error!("{LOG_PREFIX} failed to start hotkey listener: {e}"); + log::warn!("{LOG_PREFIX} failed to start hotkey listener: {e}"); return; } }; diff --git a/src/openhuman/voice/hotkey.rs b/src/openhuman/voice/hotkey.rs index f1b6361b2..492a44802 100644 --- a/src/openhuman/voice/hotkey.rs +++ b/src/openhuman/voice/hotkey.rs @@ -9,7 +9,7 @@ use std::collections::HashSet; use std::sync::atomic::{AtomicBool, Ordering}; use std::sync::Arc; -use log::{debug, error, info}; +use log::{debug, info, warn}; use parking_lot::Mutex; use rdev::{listen, Event, EventType, Key}; use tokio::sync::mpsc; @@ -221,7 +221,7 @@ pub fn start_listener( }; if let Err(e) = listen(callback) { - error!("{LOG_PREFIX} rdev listen error: {e:?}"); + warn!("{LOG_PREFIX} rdev listen error: {e:?}"); } }) .map_err(|e| format!("failed to spawn hotkey listener thread: {e}"))?; diff --git a/src/openhuman/voice/schemas/handlers/provider_server.rs b/src/openhuman/voice/schemas/handlers/provider_server.rs index d36352a98..3fc208ba8 100644 --- a/src/openhuman/voice/schemas/handlers/provider_server.rs +++ b/src/openhuman/voice/schemas/handlers/provider_server.rs @@ -455,7 +455,7 @@ pub(crate) fn handle_voice_server_start(params: Map) -> Controlle tokio::spawn(async move { if let Err(e) = server.run(&config_clone).await { - log::error!("[voice_server] server exited with error: {e}"); + log::warn!("[voice_server] server exited with error: {e}"); server_for_err.set_last_error(&e).await; } }); diff --git a/src/openhuman/voice/server.rs b/src/openhuman/voice/server.rs index 86848d474..7ae0f3489 100644 --- a/src/openhuman/voice/server.rs +++ b/src/openhuman/voice/server.rs @@ -9,7 +9,7 @@ use std::sync::atomic::Ordering; use std::sync::Arc; use std::time::{Duration, Instant}; -use log::{debug, error, info, warn}; +use log::{debug, info, warn}; use tokio::sync::Mutex; use tokio_util::sync::CancellationToken; use uuid::Uuid; @@ -394,7 +394,7 @@ impl VoiceServer { deferred_stop_deadline = None; pending_expected_app = None; pending_generation = None; - error!("{LOG_PREFIX} failed to start recording: {e}"); + warn!("{LOG_PREFIX} failed to start recording: {e}"); *self.state.lock().await = ServerState::Idle; *self.last_error.lock().await = Some(e); } @@ -403,7 +403,7 @@ impl VoiceServer { deferred_stop_deadline = None; pending_expected_app = None; pending_generation = None; - error!("{LOG_PREFIX} recording setup task dropped"); + warn!("{LOG_PREFIX} recording setup task dropped"); *self.state.lock().await = ServerState::Idle; } } @@ -908,7 +908,7 @@ async fn process_recording_bg( } else { let insert_started = Instant::now(); if let Err(e) = text_input::insert_text(text, expected_app.as_deref()) { - error!("{LOG_PREFIX} [pipeline={pipeline_id}] stage=deliver_paste FAILED: {e}"); + warn!("{LOG_PREFIX} [pipeline={pipeline_id}] stage=deliver_paste FAILED: {e}"); *last_error.lock().await = Some(e); } else { let insert_elapsed = insert_started.elapsed(); @@ -925,13 +925,20 @@ async fn process_recording_bg( } } Err(e) => { - error!("{LOG_PREFIX} [pipeline={pipeline_id}] stage=transcribe FAILED: {e}"); + // Windows DLL-not-found errors are classified at the + // subprocess layer and logged with a 5-minute backoff. + // Demote to warn! so they don't flood Sentry (issue #5168). + if e.contains("STATUS_DLL_NOT_FOUND") { + warn!("{LOG_PREFIX} [pipeline={pipeline_id}] stage=transcribe DLL_UNAVAILABLE: {e}"); + } else { + warn!("{LOG_PREFIX} [pipeline={pipeline_id}] stage=transcribe FAILED: {e}"); + } *last_error.lock().await = Some(e); } } } Err(e) => { - error!("{LOG_PREFIX} [pipeline={pipeline_id}] stage=stop_recording FAILED: {e}"); + warn!("{LOG_PREFIX} [pipeline={pipeline_id}] stage=stop_recording FAILED: {e}"); *last_error.lock().await = Some(e); } } @@ -1035,7 +1042,7 @@ pub async fn start_if_enabled(app_config: &Config) { let server_for_err = server.clone(); tokio::spawn(async move { if let Err(e) = server.run(&config_for_run).await { - error!("{LOG_PREFIX} embedded voice server exited with error: {e}"); + warn!("{LOG_PREFIX} embedded voice server exited with error: {e}"); server_for_err.set_last_error(&e).await; } }); diff --git a/vendor/tinycortex b/vendor/tinycortex index 55bf0661d..108b8e020 160000 --- a/vendor/tinycortex +++ b/vendor/tinycortex @@ -1 +1 @@ -Subproject commit 55bf0661d003dd38dc33e8da45b46dd675710c9c +Subproject commit 108b8e0207fbbf182ad1ace6451ffc27bd79a3f4