diff --git a/.env.example b/.env.example index 0fd106e..4605aef 100644 --- a/.env.example +++ b/.env.example @@ -7,4 +7,5 @@ UPLOAD_MAX_SIZE_MB=10 UPLOAD_MAX_FILES=5 UPLOAD_MAX_PIXELS=30000000 VISION_MODEL=gemma3:4b +VISION_DEBUG=false VISION_DEBUG_SHA256_ENABLED=false diff --git a/src/app.js b/src/app.js index 1fffe4b..972112b 100644 --- a/src/app.js +++ b/src/app.js @@ -18,6 +18,8 @@ import {createSettingsRouter} from "./routes/settings.js"; import {createSystemRouter} from "./routes/system.js"; import {createAttachmentService} from "./services/attachmentService.js"; import {createUploadsRouter} from "./routes/uploads.js"; +import {createVisionDebugService} from "./services/visionDebugService.js"; +import {createVisionDebugRouter} from "./routes/visionDebug.js"; export function createCloseHandler(resources) { let closed = false; @@ -247,8 +249,9 @@ export function createApp(options = {}) { const db = createDatabase(config); const repositories = createRepositories(db, config); const modelService = options.modelService || createModelService(config, options.modelOverrides); - const attachmentService = createAttachmentService(db, config, modelService); - const chatService = createChatService(repositories, modelService, config, undefined, attachmentService); + const visionDebugService = createVisionDebugService(config); + const attachmentService = createAttachmentService(db, config, modelService, visionDebugService); + const chatService = createChatService(repositories, modelService, config, undefined, attachmentService, visionDebugService); const FileStore = FileStoreFactory(session); const authRateLimiters = createAuthRateLimiters(config); const chatRateLimiters = createChatRateLimiters(config); @@ -285,6 +288,7 @@ export function createApp(options = {}) { app.locals.repositories = repositories; app.locals.modelService = modelService; app.locals.attachmentService = attachmentService; + app.locals.visionDebugService = visionDebugService; app.locals.observability = observability; app.locals.close = createCloseHandler(closeHandlers); @@ -300,6 +304,7 @@ export function createApp(options = {}) { })); app.use(createAuthRouter({repositories, authRateLimiters, config})); app.use(createUploadsRouter(attachmentService, config)); + if (config.visionDebug) app.use(createVisionDebugRouter({visionDebugService, repositories})); app.use(createSettingsRouter({repositories})); app.use(createChatsRouter({repositories, chatService, modelService, config, chatRateLimiters})); app.use(createPersonasRouter({repositories, chatService, modelService, config})); diff --git a/src/config.js b/src/config.js index c970a8f..2fb9829 100644 --- a/src/config.js +++ b/src/config.js @@ -52,6 +52,7 @@ export function createConfig(overrides = {}) { slowRequestLoggingEnabled: bool(process.env.SLOW_REQUEST_LOGGING_ENABLED, !testMode), slowRequestWarnMs: int(process.env.SLOW_REQUEST_WARN_MS, 50), structuredRequestLoggingEnabled: bool(process.env.STRUCTURED_REQUEST_LOGGING_ENABLED, !testMode), + visionDebug: bool(process.env.VISION_DEBUG, false), visionDebugSha256Enabled: bool(process.env.VISION_DEBUG_SHA256_ENABLED, false), chatLimit: int(process.env.CHAT_LIMIT, 10), chatHistoryLimit: int(process.env.CHAT_HISTORY_LIMIT, 20), diff --git a/src/services/attachmentService.js b/src/services/attachmentService.js index a4163bb..97a7f3b 100644 --- a/src/services/attachmentService.js +++ b/src/services/attachmentService.js @@ -23,7 +23,7 @@ export function parseVisionAnalysis(text) { } } -export function createAttachmentService(db, config, modelService) { +export function createAttachmentService(db, config, modelService, visionDebugService = null) { const storage = new LocalFileStorage(config.uploadDir); const log = (event, fields) => { if (config.structuredRequestLoggingEnabled) console.log(JSON.stringify({event, ...fields})); }; const get = id => db.prepare("SELECT * FROM attachments WHERE id = ?").get(id); @@ -66,24 +66,45 @@ export function createAttachmentService(db, config, modelService) { const analyzeRows = async (images, question, signal, diagnostics = {}) => { for (const row of images) { signal?.throwIfAborted(); + const normalizedQuestion = normalizeVisionQuestion(question); const fields = {requestId: diagnostics.requestId ?? null, chatId: diagnostics.chatId ?? null, triggeringMessageId: diagnostics.triggeringMessageId ?? row.messageId, attachmentId: row.id, sourceMessageId: row.messageId, attachmentPosition: row.position, scope: row.scope || "current", storageKey: row.storage_key, originalFilename: row.original_name, visionModel: config.visionModel, - visionPromptVersion: VISION_PROMPT_VERSION, question: normalizeVisionQuestion(question).slice(0, 500)}; + visionPromptVersion: VISION_PROMPT_VERSION, question: normalizedQuestion.slice(0, 500)}; + const cacheIdentity = {attachmentId: row.id, visionModel: config.visionModel, + visionPromptVersion: VISION_PROMPT_VERSION, normalizedQuestion}; + visionDebugService?.recordImage(diagnostics.requestId, { + attachmentId: row.id, sourceMessageId: row.messageId, position: row.position, + scope: row.scope || "current", label: row.label, originalFilename: row.original_name, + mimeType: row.mime_type, width: row.width, height: row.height, sizeBytes: row.size_bytes, + visionModel: config.visionModel, visionPromptVersion: VISION_PROMPT_VERSION, normalizedQuestion + }); const hit = cached(row, question); - if (hit) { log("visionAnalysisCacheHit", {...fields, cacheHit: true, resultSummary: hit.scene.slice(0, 160)}); continue; } + if (hit) { + visionDebugService?.recordCache(diagnostics.requestId, row.id, + {cacheHit: true, cacheIdentity, normalizedVisionAnalysis: hit}); + log("visionAnalysisCacheHit", {...fields, cacheHit: true, resultSummary: hit.scene.slice(0, 160)}); + continue; + } + visionDebugService?.recordCache(diagnostics.requestId, row.id, {cacheHit: false, cacheIdentity}); try { log("visionAnalysisStart", {...fields, cacheHit: false}); const buffer = await storage.read(row.storage_key); + const imageSha256 = visionDebugService?.enabled + ? createHash("sha256").update(buffer).digest("hex") : null; if (config.visionDebugSha256Enabled && config.structuredRequestLoggingEnabled) { log("visionImageRead", {...fields, sha256: createHash("sha256").update(buffer).digest("hex")}); } + let rawVisionResponse = null; const result = await modelService.generateReply(config.visionModel, [ {role: "system", content: VISION_ANALYSIS_PROMPT}, {role: "user", content: `User question (attention guidance only): ${JSON.stringify(String(question ?? ""))}\nReport the visible evidence relevant to this question without answering it.`, images: [buffer.toString("base64")]} - ], {signal, reasoning: false, format: VISION_RESPONSE_SCHEMA, generation: {temperature: 0.1, responseLength: 2400}}); + ], {signal, reasoning: false, format: VISION_RESPONSE_SCHEMA, generation: {temperature: 0.1, responseLength: 2400}, + ...(visionDebugService?.enabled ? {onRawReply: value => { rawVisionResponse = value; }} : {})}); const parsed = parseVisionAnalysis(result); + visionDebugService?.recordVisionRun(diagnostics.requestId, row.id, + {imageSha256, rawVisionResponse: rawVisionResponse ?? result, normalizedVisionAnalysis: parsed}); const analysis = JSON.stringify(parsed); signal?.throwIfAborted(); db.transaction(() => { diff --git a/src/services/chatService.js b/src/services/chatService.js index 372cddc..93f5ecb 100644 --- a/src/services/chatService.js +++ b/src/services/chatService.js @@ -17,11 +17,13 @@ import { parseSources, retryStylePrompts } from "./chatMessageHelpers.js"; +import {createHash} from "node:crypto"; -import { SearXNGSearchProvider, WebSearchError, buildWebSearchContext, retrieveWebSearch } from "./webSearchService.js"; +import { SearXNGSearchProvider, WebSearchError, buildWebSearchContext, decideWebSearch, retrieveWebSearch } from "./webSearchService.js"; import { supportsReasoning } from "../../public/js/modelCapabilities.js"; +import {VISION_EVIDENCE_GUIDANCE} from "./visionAnalysis.js"; -export function createChatService(repositories, modelService, config, webSearchProvider = new SearXNGSearchProvider(config), attachmentService = null) { +export function createChatService(repositories, modelService, config, webSearchProvider = new SearXNGSearchProvider(config), attachmentService = null, visionDebugService = null) { const formatChatMessage = row => { const message = formatBaseChatMessage(row); if (message?.role === "bot") { @@ -42,6 +44,36 @@ export function createChatService(repositories, modelService, config, webSearchP const regeneratingMessages = new Map(); const maxRetries = Number(config.chatMaxRetries ?? 5); const now = typeof config.now === "function" ? config.now : () => new Date(); + const visionGuidanceSha256 = createHash("sha256").update(VISION_EVIDENCE_GUIDANCE).digest("hex"); + + const beginVisionDiagnostics = ({requestId, user, chatId, triggeringMessageId, userQuestion, selectedModel, reasoningRequested, webSearchRequested, visionSelection}) => { + if (!visionDebugService?.enabled || !visionSelection || !attachmentService.hasImages(visionSelection)) return; + visionDebugService.begin({requestId, user, chatId, triggeringMessageId, userQuestion, selectedModel, reasoningRequested, webSearchRequested}); + const decision = decideWebSearch(userQuestion, webSearchRequested); + visionDebugService.recordSearch(requestId, { + requested: webSearchRequested, + needed: decision.needsSearch, + explicitSearchIntent: decision.explicitSearchIntent, + state: webSearchRequested ? (decision.shouldSearch ? "pending" : "skipped") : "disabled" + }); + }; + const recordQwenDiagnostics = ({requestId, messagesPayload, visionSelection, model, generation, reasoning}) => { + if (!visionDebugService?.enabled || !requestId) return; + const evidenceMessage = messagesPayload.find(message => message.role === "user" && message.content.startsWith("")); + const metadata = typeof modelService.getRequestMetadata === "function" + ? modelService.getRequestMetadata(model, generation, reasoning) + : {model, think: reasoning === true && supportsReasoning(model), stream: true, + temperature: generation.temperature ?? null, numCtx: generation.contextLength ?? null, + numPredict: generation.responseLength ?? null, keepAlive: config.ollamaKeepAlive ?? "30m"}; + visionDebugService.recordQwen(requestId, { + imageEvidence: evidenceMessage?.content || null, + visionGuidanceSha256, + visionEvidenceIncluded: Boolean(evidenceMessage), + imageCount: (visionSelection?.currentMessageImages.length || 0) + (visionSelection?.historicalImages.length || 0), + currentImageLabels: visionSelection?.currentMessageImages.map(image => image.label) || [], + ...metadata + }); + }; const insertChatMessage = (chatId, role, content, retryState = null, modelName = null, deliveryStatus = "complete", errorMessage = null) => { const normalizedContent = String(content || ""); @@ -342,19 +374,35 @@ export function createChatService(repositories, modelService, config, webSearchP const imageHistory = repositories.getRecentChatMessagesUpToId(chatId, promptMessage.id).reverse(); const visionSelection = attachmentService?.selectImages(imageHistory, promptMessage.content); + beginVisionDiagnostics({requestId, user, chatId, triggeringMessageId: promptMessage.id, + userQuestion: promptMessage.content, selectedModel, reasoningRequested: reasoning, + webSearchRequested: webSearch, visionSelection}); if (visionSelection && attachmentService.hasImages(visionSelection)) onStatus?.({ status: "analyzing" }); if (visionSelection) await attachmentService.analyzeContext(visionSelection, promptMessage.content, signal, {requestId, chatId, triggeringMessageId: promptMessage.id}); let sources = null; let searchState = "skipped"; if (webSearch) { - const search = await retrieveWebSearch(promptMessage.content, webSearchProvider, { - signal, - referenceText: visionSelection ? attachmentService.searchContext(visionSelection, promptMessage.content) : "", - onSearching: () => onStatus?.({ status: "searching" }) - }); - sources = search.sources; - searchState = search.state; + const visualReference = visionSelection ? attachmentService.searchContext(visionSelection, promptMessage.content) : ""; + try { + const search = await retrieveWebSearch(promptMessage.content, webSearchProvider, { + signal, referenceText: visualReference, + onSearching: () => { + visionDebugService?.recordSearch(requestId, {requested: true, state: "searching", visualReference}); + onStatus?.({ status: "searching" }); + } + }); + sources = search.sources; + searchState = search.state; + visionDebugService?.recordSearch(requestId, {requested: true, needed: search.decision.needsSearch, + explicitSearchIntent: search.decision.explicitSearchIntent, state: search.state, visualReference, + queries: search.queries, candidateCount: search.candidates.length, + selectedCount: search.sources?.length || 0, selectedSources: search.sources || []}); + } catch (error) { + visionDebugService?.recordSearch(requestId, {requested: true, state: "failed", visualReference}); + visionDebugService?.fail(requestId, error); + throw error; + } } onStatus?.({ status: "generating", searchState, sources }); const { messagesPayload } = buildConversationContext({ @@ -369,6 +417,8 @@ export function createChatService(repositories, modelService, config, webSearchP }); const styledPayload = appendRetryStyleInstruction(messagesPayload, retryStyle); + recordQwenDiagnostics({requestId, messagesPayload: styledPayload, visionSelection, + model: selectedModel, generation, reasoning}); const fullReply = activePersona ? await generateValidatedRoleplayReply({ selectedModel, messagesPayload: styledPayload, userPersona: activeUserPersona, signal, generation, onThinking: captureThinking, onChunk, reasoning }) : onChunk @@ -376,6 +426,7 @@ export function createChatService(repositories, modelService, config, webSearchP : await modelService.generateReply(selectedModel, styledPayload, { signal, generation, onThinking: captureThinking, reasoning }); if (!fullReply) return { error: "Failed to regenerate message" }; + visionDebugService?.complete(requestId, {finalAnswer: fullReply, visibleReasoning: reasoning ? thinking : null}); return { fullReply, thinking, sources, searchState, promptMessageId: promptMessage.id }; }; @@ -416,22 +467,41 @@ export function createChatService(repositories, modelService, config, webSearchP onStatus?.({ status: "accepted" }); const imageHistory = repositories.getRecentChatMessagesUpToId(chatId, userMessageId).reverse(); const visionSelection = attachmentService?.selectImages(imageHistory, message); + beginVisionDiagnostics({requestId, user, chatId, triggeringMessageId: userMessageId, + userQuestion: message, selectedModel: effectiveModel, reasoningRequested: useReasoning, + webSearchRequested: webSearch, visionSelection}); if (visionSelection && attachmentService.hasImages(visionSelection)) { onStatus?.({ status: "analyzing" }); await attachmentService.analyzeContext(visionSelection, message, activeSignal, {requestId, chatId, triggeringMessageId: userMessageId}); } if (webSearch) { - const search = await retrieveWebSearch(message, webSearchProvider, { - referenceText: visionSelection ? attachmentService.searchContext(visionSelection, message) : "", - signal: activeSignal, - onSearching: () => onStatus?.({ status: "searching" }) - }); + const visualReference = visionSelection ? attachmentService.searchContext(visionSelection, message) : ""; + let search; + try { + search = await retrieveWebSearch(message, webSearchProvider, { + referenceText: visualReference, + signal: activeSignal, + onSearching: () => { + visionDebugService?.recordSearch(requestId, {requested: true, state: "searching", visualReference}); + onStatus?.({ status: "searching" }); + } + }); + } catch (error) { + visionDebugService?.recordSearch(requestId, {requested: true, state: "failed", visualReference}); + visionDebugService?.fail(requestId, error); + throw error; + } sources = search.sources; searchState = search.state; + visionDebugService?.recordSearch(requestId, {requested: true, needed: search.decision.needsSearch, + explicitSearchIntent: search.decision.explicitSearchIntent, state: search.state, visualReference, + queries: search.queries, candidateCount: search.candidates.length, + selectedCount: search.sources?.length || 0, selectedSources: search.sources || []}); if (config.structuredRequestLoggingEnabled) { console.log(JSON.stringify({ event: "web_search", + requestId, webSearchRequested: true, explicitSearchRequested: search.decision.explicitSearchIntent, automaticSearchDecision: search.decision.automaticSearchDecision, @@ -448,6 +518,8 @@ export function createChatService(repositories, modelService, config, webSearchP onStatus?.({ status: "generating", searchState, ...(sources !== null ? { sourceCount: sources.length } : {}) }); payload = buildConversationContext({ user, chatId, session, message: null, upToMessageId: userMessageId, historyOverride: imageHistory, visionSelection, contextSummaryOverride: session.context_summary, sources }); + recordQwenDiagnostics({requestId, messagesPayload: payload.messagesPayload, visionSelection, + model: effectiveModel, generation, reasoning: useReasoning}); return payload.activePersona ? generateValidatedRoleplayReply({ selectedModel: effectiveModel, @@ -469,6 +541,8 @@ export function createChatService(repositories, modelService, config, webSearchP return { error: "Failed to generate a valid character reply", status: 500 }; } + visionDebugService?.complete(requestId, {finalAnswer: fullReply, visibleReasoning: useReasoning ? thinking : null}); + const retryState = { retryVariants: [fullReply], retryActiveIndex: 0, @@ -480,6 +554,7 @@ export function createChatService(repositories, modelService, config, webSearchP scheduleContextSummaryUpdate({ user, chatId, selectedModel: effectiveModel }); return { reply: fullReply, userMessageId, searchState, ...(sources ? { sources } : {}) }; } catch (error) { + visionDebugService?.fail(requestId, error); repositories.failChatTurn(chatId, userMessageId, String(error?.message || "Model request failed").slice(0, 500), webSearch ? userMessageId : effectiveParentId); repositories.touchChat(chatId, user); if (error instanceof WebSearchError) return { error: error.message, status: error.status, searchState: "failed" }; diff --git a/src/services/modelService.js b/src/services/modelService.js index 91e6b07..a401aba 100644 --- a/src/services/modelService.js +++ b/src/services/modelService.js @@ -104,7 +104,7 @@ export function createModelService(config, overrides = {}) { } }; - const readStreamingReply = async (response, onChunk = null, onThinking = null, touch = () => { }, signal = null) => { + const readStreamingReply = async (response, onChunk = null, onThinking = null, touch = () => { }, signal = null, onRawReply = null) => { if (!response.body) { throw new ModelServiceError("MODEL_BAD_RESPONSE", "Model backend returned no body.", 502); } @@ -161,6 +161,7 @@ export function createModelService(config, overrides = {}) { consume(buffer.trim()); } if (!completed) throw new ModelServiceError("MODEL_INTERRUPTED", "Model response was interrupted.", 502); + onRawReply?.(fullReply); return fullReply.trim(); } finally { signal?.removeEventListener("abort", cancel); @@ -187,6 +188,18 @@ export function createModelService(config, overrides = {}) { }; return { + getRequestMetadata(model, generation = {}, reasoning = false) { + const body = buildRequestBody(model, [], generation, reasoning); + return { + model: body.model, + think: body.think, + stream: body.stream, + temperature: body.options?.temperature ?? null, + numCtx: body.options?.num_ctx ?? null, + numPredict: body.options?.num_predict ?? null, + keepAlive: body.keep_alive + }; + }, async generateReply(model, messagesPayload, options = {}) { const state = ensureModelState(model); state.activeRequests += 1; @@ -206,7 +219,8 @@ export function createModelService(config, overrides = {}) { } touch(); - return readStreamingReply(response, null, options.reasoning === true && supportsReasoning(model) ? options.onThinking : null, touch, signal); + return readStreamingReply(response, null, options.reasoning === true && supportsReasoning(model) ? options.onThinking : null, + touch, signal, options.onRawReply); }, options.signal); lastHealth = { ok: true, checkedAt: new Date().toISOString(), error: null, latencyMs: Date.now() - startedAt }; return fullReply; diff --git a/test/config.test.js b/test/config.test.js index 898346a..27def09 100644 --- a/test/config.test.js +++ b/test/config.test.js @@ -31,13 +31,15 @@ test("test mode disables request and lag logging by default", () => { NODE_ENV: "test", TEST_MODE: null, EVENT_LOOP_LAG_MONITOR_ENABLED: null, - SLOW_REQUEST_LOGGING_ENABLED: null + SLOW_REQUEST_LOGGING_ENABLED: null, + VISION_DEBUG: null }, () => { const config = createConfig(); assert.equal(config.testMode, true); assert.equal(config.eventLoopLagMonitorEnabled, false); assert.equal(config.slowRequestLoggingEnabled, false); + assert.equal(config.visionDebug, false); }); });