From af3b07b80facf9e2cb2676455d4a3191ce1d0b6f Mon Sep 17 00:00:00 2001 From: Meik Date: Fri, 20 Feb 2026 14:10:06 +0100 Subject: [PATCH] Add end-to-end AI timing traces and AI debug view --- backend/server.js | 1055 ++++++++++++++++++++++++++++++++++-------- extension/content.js | 337 +++++++++++++- web/Dockerfile | 4 + web/ai-debug.css | 180 +++++++ web/ai-debug.js | 261 +++++++++++ web/index.html | 78 ++++ 6 files changed, 1705 insertions(+), 210 deletions(-) create mode 100644 web/ai-debug.css create mode 100644 web/ai-debug.js diff --git a/backend/server.js b/backend/server.js index 0185030..e91ea5b 100644 --- a/backend/server.js +++ b/backend/server.js @@ -164,7 +164,14 @@ app.use(cors({ callback(null, origin || false); }, methods: ['GET', 'POST', 'PUT', 'PATCH', 'DELETE', 'OPTIONS'], - allowedHeaders: ['Content-Type', 'Authorization'], + allowedHeaders: [ + 'Content-Type', + 'Authorization', + 'X-AI-Trace-Id', + 'X-AI-Flow-Id', + 'X-AI-Trace-Source' + ], + exposedHeaders: ['X-AI-Trace-Id', 'X-AI-Flow-Id', 'Server-Timing'], credentials: true })); // Allow larger payloads because screenshots from high-res monitors can easily exceed 10 MB @@ -177,7 +184,8 @@ app.use((req, res, next) => { const fallbackOrigin = host ? `${isSecureRequest(req) ? 'https' : 'http'}://${host}` : '*'; res.header('Access-Control-Allow-Origin', origin || fallbackOrigin); res.header('Access-Control-Allow-Methods', 'GET, POST, PUT, PATCH, DELETE, OPTIONS'); - res.header('Access-Control-Allow-Headers', 'Content-Type, Authorization'); + res.header('Access-Control-Allow-Headers', 'Content-Type, Authorization, X-AI-Trace-Id, X-AI-Flow-Id, X-AI-Trace-Source'); + res.header('Access-Control-Expose-Headers', 'X-AI-Trace-Id, X-AI-Flow-Id, Server-Timing'); res.header('Access-Control-Allow-Credentials', 'true'); if (req.method === 'OPTIONS') { @@ -2075,6 +2083,45 @@ db.exec(` CREATE INDEX IF NOT EXISTS idx_ai_usage_events_credential_created ON ai_usage_events(credential_id, created_at DESC); `); + +db.exec(` + CREATE TABLE IF NOT EXISTS ai_debug_traces ( + id INTEGER PRIMARY KEY AUTOINCREMENT, + trace_id TEXT NOT NULL UNIQUE, + flow_id TEXT, + source TEXT, + status TEXT NOT NULL DEFAULT 'created', + origin TEXT, + request_ip TEXT, + user_agent TEXT, + request_meta_json TEXT, + backend_timing_json TEXT, + backend_attempts_json TEXT, + backend_error TEXT, + response_meta_json TEXT, + frontend_timing_json TEXT, + frontend_steps_json TEXT, + frontend_error TEXT, + total_duration_ms REAL, + created_at DATETIME DEFAULT CURRENT_TIMESTAMP, + updated_at DATETIME DEFAULT CURRENT_TIMESTAMP + ); +`); + +db.exec(` + CREATE INDEX IF NOT EXISTS idx_ai_debug_traces_created + ON ai_debug_traces(created_at DESC); +`); + +db.exec(` + CREATE INDEX IF NOT EXISTS idx_ai_debug_traces_flow + ON ai_debug_traces(flow_id, created_at DESC); +`); + +db.exec(` + CREATE INDEX IF NOT EXISTS idx_ai_debug_traces_status + ON ai_debug_traces(status, created_at DESC); +`); db.prepare(` UPDATE posts SET last_change = COALESCE( @@ -2311,6 +2358,10 @@ function extractRateLimitInfo(response, provider) { const RATE_LIMIT_KEYWORDS = ['rate limit', 'ratelimit', 'quota', 'limit', 'too many requests', 'insufficient_quota', 'billing', 'exceeded', 'exceed']; const AI_COMMENT_RETRY_LIMIT = 5; +const AI_DEBUG_TRACE_ID_MAX_LENGTH = 120; +const AI_DEBUG_FLOW_ID_MAX_LENGTH = 120; +const AI_DEBUG_DEFAULT_LIST_LIMIT = 100; +const AI_DEBUG_MAX_LIST_LIMIT = 500; function determineAutoDisable(error) { if (!error) { @@ -3029,6 +3080,301 @@ function recordAIUsageEvent(credentialId, eventType, options = {}) { } } +function safeJsonStringify(value) { + if (value === undefined) { + return null; + } + try { + return JSON.stringify(value); + } catch (error) { + return null; + } +} + +function safeJsonParse(value, fallback = null) { + if (!value || typeof value !== 'string') { + return fallback; + } + try { + return JSON.parse(value); + } catch (error) { + return fallback; + } +} + +function sanitizeAIDebugValue(value, maxLength) { + if (value === undefined || value === null) { + return null; + } + const normalized = String(value).trim(); + if (!normalized) { + return null; + } + if (!Number.isFinite(maxLength) || maxLength <= 0) { + return normalized; + } + return normalized.length > maxLength + ? normalized.slice(0, maxLength) + : normalized; +} + +function buildAIDebugTraceId(prefix = 'trace') { + return `${prefix}-${uuidv4()}`; +} + +function sanitizeTraceStatus(value, fallback = 'created') { + const raw = sanitizeAIDebugValue(value, 40); + if (!raw) { + return fallback; + } + return raw.toLowerCase(); +} + +function normalizeAIDebugRequestMeta(payload = {}) { + if (!payload || typeof payload !== 'object') { + return {}; + } + + const preferredCredential = Number(payload.preferredCredentialId); + + return { + profileNumber: sanitizeProfileNumber(payload.profileNumber), + preferredCredentialId: Number.isNaN(preferredCredential) ? null : preferredCredential, + postTextLength: typeof payload.postText === 'string' ? payload.postText.length : null, + providerHint: sanitizeAIDebugValue(payload.providerHint, 120), + extensionVersion: sanitizeAIDebugValue(payload.extensionVersion, 80), + requestAttempt: Number.isFinite(Number(payload.requestAttempt)) + ? Number(payload.requestAttempt) + : null + }; +} + +function roundTiming(value) { + const numeric = Number(value); + if (!Number.isFinite(numeric) || numeric < 0) { + return null; + } + return Math.round(numeric * 1000) / 1000; +} + +const upsertAIDebugTraceBaseStmt = db.prepare(` + INSERT INTO ai_debug_traces ( + trace_id, + flow_id, + source, + status, + origin, + request_ip, + user_agent, + request_meta_json, + created_at, + updated_at + ) VALUES ( + @trace_id, + @flow_id, + @source, + @status, + @origin, + @request_ip, + @user_agent, + @request_meta_json, + CURRENT_TIMESTAMP, + CURRENT_TIMESTAMP + ) + ON CONFLICT(trace_id) DO UPDATE SET + flow_id = COALESCE(excluded.flow_id, ai_debug_traces.flow_id), + source = COALESCE(excluded.source, ai_debug_traces.source), + status = excluded.status, + origin = COALESCE(excluded.origin, ai_debug_traces.origin), + request_ip = COALESCE(excluded.request_ip, ai_debug_traces.request_ip), + user_agent = COALESCE(excluded.user_agent, ai_debug_traces.user_agent), + request_meta_json = COALESCE(excluded.request_meta_json, ai_debug_traces.request_meta_json), + updated_at = CURRENT_TIMESTAMP +`); + +const updateAIDebugTraceBackendStmt = db.prepare(` + UPDATE ai_debug_traces + SET flow_id = COALESCE(@flow_id, flow_id), + source = COALESCE(@source, source), + status = @status, + backend_timing_json = @backend_timing_json, + backend_attempts_json = @backend_attempts_json, + backend_error = @backend_error, + response_meta_json = @response_meta_json, + total_duration_ms = @total_duration_ms, + updated_at = CURRENT_TIMESTAMP + WHERE trace_id = @trace_id +`); + +const upsertAIDebugTraceFrontendStmt = db.prepare(` + INSERT INTO ai_debug_traces ( + trace_id, + flow_id, + source, + status, + frontend_timing_json, + frontend_steps_json, + frontend_error, + total_duration_ms, + created_at, + updated_at + ) VALUES ( + @trace_id, + @flow_id, + @source, + @status, + @frontend_timing_json, + @frontend_steps_json, + @frontend_error, + @total_duration_ms, + CURRENT_TIMESTAMP, + CURRENT_TIMESTAMP + ) + ON CONFLICT(trace_id) DO UPDATE SET + flow_id = COALESCE(excluded.flow_id, ai_debug_traces.flow_id), + source = COALESCE(excluded.source, ai_debug_traces.source), + status = excluded.status, + frontend_timing_json = COALESCE(excluded.frontend_timing_json, ai_debug_traces.frontend_timing_json), + frontend_steps_json = COALESCE(excluded.frontend_steps_json, ai_debug_traces.frontend_steps_json), + frontend_error = COALESCE(excluded.frontend_error, ai_debug_traces.frontend_error), + total_duration_ms = COALESCE(excluded.total_duration_ms, ai_debug_traces.total_duration_ms), + updated_at = CURRENT_TIMESTAMP +`); + +const getAIDebugTraceByIdStmt = db.prepare(` + SELECT * + FROM ai_debug_traces + WHERE trace_id = @traceId + LIMIT 1 +`); + +const listAIDebugTracesStmt = db.prepare(` + SELECT * + FROM ai_debug_traces + WHERE (@status IS NULL OR status = @status) + AND (@flowId IS NULL OR flow_id = @flowId) + AND (@fromDate IS NULL OR datetime(created_at) >= datetime(@fromDate)) + AND (@toDate IS NULL OR datetime(created_at) <= datetime(@toDate)) + ORDER BY datetime(created_at) DESC + LIMIT @limit + OFFSET @offset +`); + +function upsertAIDebugTraceBase(payload = {}) { + const traceId = sanitizeAIDebugValue(payload.traceId, AI_DEBUG_TRACE_ID_MAX_LENGTH) + || buildAIDebugTraceId(); + const flowId = sanitizeAIDebugValue(payload.flowId, AI_DEBUG_FLOW_ID_MAX_LENGTH); + + upsertAIDebugTraceBaseStmt.run({ + trace_id: traceId, + flow_id: flowId, + source: sanitizeAIDebugValue(payload.source, 80) || 'unknown', + status: sanitizeTraceStatus(payload.status, 'created'), + origin: sanitizeAIDebugValue(payload.origin, 240), + request_ip: sanitizeAIDebugValue(payload.requestIp, 120), + user_agent: sanitizeAIDebugValue(payload.userAgent, 800), + request_meta_json: safeJsonStringify(payload.requestMeta || null) + }); + + return { traceId, flowId }; +} + +function updateAIDebugTraceBackend(payload = {}) { + const traceId = sanitizeAIDebugValue(payload.traceId, AI_DEBUG_TRACE_ID_MAX_LENGTH); + if (!traceId) { + return; + } + + updateAIDebugTraceBackendStmt.run({ + trace_id: traceId, + flow_id: sanitizeAIDebugValue(payload.flowId, AI_DEBUG_FLOW_ID_MAX_LENGTH), + source: sanitizeAIDebugValue(payload.source, 80), + status: sanitizeTraceStatus(payload.status, 'backend_done'), + backend_timing_json: safeJsonStringify(payload.backendTimings || null), + backend_attempts_json: safeJsonStringify(payload.backendAttempts || null), + backend_error: payload.backendError + ? truncateString(String(payload.backendError), 1200) + : null, + response_meta_json: safeJsonStringify(payload.responseMeta || null), + total_duration_ms: roundTiming(payload.totalDurationMs) + }); +} + +function upsertAIDebugTraceFrontend(payload = {}) { + const traceId = sanitizeAIDebugValue(payload.traceId, AI_DEBUG_TRACE_ID_MAX_LENGTH) + || buildAIDebugTraceId(); + const flowId = sanitizeAIDebugValue(payload.flowId, AI_DEBUG_FLOW_ID_MAX_LENGTH); + + upsertAIDebugTraceFrontendStmt.run({ + trace_id: traceId, + flow_id: flowId, + source: sanitizeAIDebugValue(payload.source, 80) || 'extension', + status: sanitizeTraceStatus(payload.status, 'frontend_reported'), + frontend_timing_json: safeJsonStringify(payload.frontendTimings || null), + frontend_steps_json: safeJsonStringify(payload.frontendSteps || null), + frontend_error: payload.frontendError + ? truncateString(String(payload.frontendError), 1200) + : null, + total_duration_ms: roundTiming(payload.totalDurationMs) + }); + + return { traceId, flowId }; +} + +function parseAIDebugTraceRow(row) { + if (!row) { + return null; + } + + return { + id: row.id, + trace_id: row.trace_id, + flow_id: row.flow_id || null, + source: row.source || null, + status: row.status || null, + origin: row.origin || null, + request_ip: row.request_ip || null, + user_agent: row.user_agent || null, + request_meta: safeJsonParse(row.request_meta_json, null), + backend_timings: safeJsonParse(row.backend_timing_json, null), + backend_attempts: safeJsonParse(row.backend_attempts_json, null), + backend_error: row.backend_error || null, + response_meta: safeJsonParse(row.response_meta_json, null), + frontend_timings: safeJsonParse(row.frontend_timing_json, null), + frontend_steps: safeJsonParse(row.frontend_steps_json, null), + frontend_error: row.frontend_error || null, + total_duration_ms: roundTiming(row.total_duration_ms), + created_at: sqliteTimestampToUTC(row.created_at), + updated_at: sqliteTimestampToUTC(row.updated_at) + }; +} + +function buildServerTimingHeader(timingPairs = []) { + if (!Array.isArray(timingPairs) || !timingPairs.length) { + return ''; + } + + const parts = timingPairs + .map((entry) => { + if (!entry || typeof entry !== 'object') { + return null; + } + const name = sanitizeAIDebugValue(entry.name, 24); + const duration = roundTiming(entry.duration); + if (!name || duration === null) { + return null; + } + const normalizedName = name.replace(/[^a-zA-Z0-9_-]/g, '').toLowerCase(); + if (!normalizedName) { + return null; + } + return `${normalizedName};dur=${duration}`; + }) + .filter(Boolean); + + return parts.join(', '); +} + function updateCredentialUsageOnSuccess(credentialId, info = {}) { if (!credentialId) { return; @@ -6372,6 +6718,95 @@ app.put('/api/ai-settings', (req, res) => { } }); +app.get('/api/ai/debug-traces', (req, res) => { + try { + const status = sanitizeTraceStatus(req.query.status, '') || null; + const flowId = sanitizeAIDebugValue(req.query.flowId || req.query.flow_id, AI_DEBUG_FLOW_ID_MAX_LENGTH); + const fromDate = ensureIsoDate(req.query.from || req.query.from_date); + const toDate = ensureIsoDate(req.query.to || req.query.to_date); + const limitRaw = parseInt(req.query.limit, 10); + const offsetRaw = parseInt(req.query.offset, 10); + const limit = Number.isFinite(limitRaw) + ? Math.max(1, Math.min(AI_DEBUG_MAX_LIST_LIMIT, limitRaw)) + : AI_DEBUG_DEFAULT_LIST_LIMIT; + const offset = Number.isFinite(offsetRaw) + ? Math.max(0, offsetRaw) + : 0; + + const rows = listAIDebugTracesStmt.all({ + status, + flowId: flowId || null, + fromDate: fromDate || null, + toDate: toDate || null, + limit, + offset + }); + + res.json({ + items: rows.map(parseAIDebugTraceRow), + limit, + offset + }); + } catch (error) { + res.status(500).json({ error: error.message }); + } +}); + +app.get('/api/ai/debug-traces/:traceId', (req, res) => { + try { + const traceId = sanitizeAIDebugValue(req.params.traceId, AI_DEBUG_TRACE_ID_MAX_LENGTH); + if (!traceId) { + return res.status(400).json({ error: 'traceId is required' }); + } + + const row = getAIDebugTraceByIdStmt.get({ traceId }); + if (!row) { + return res.status(404).json({ error: 'Trace nicht gefunden' }); + } + + res.json(parseAIDebugTraceRow(row)); + } catch (error) { + res.status(500).json({ error: error.message }); + } +}); + +app.post('/api/ai/debug-traces/frontend', (req, res) => { + try { + const payload = req.body || {}; + const traceId = sanitizeAIDebugValue(payload.traceId, AI_DEBUG_TRACE_ID_MAX_LENGTH); + const flowId = sanitizeAIDebugValue(payload.flowId, AI_DEBUG_FLOW_ID_MAX_LENGTH); + const source = sanitizeAIDebugValue(payload.source, 80) || 'extension'; + const status = sanitizeTraceStatus(payload.status, 'frontend_reported'); + + const ensured = upsertAIDebugTraceBase({ + traceId, + flowId, + source, + status, + requestMeta: payload.requestMeta || null + }); + + const upserted = upsertAIDebugTraceFrontend({ + traceId: ensured.traceId, + flowId: flowId || ensured.flowId, + source, + status, + frontendTimings: payload.frontendTimings || null, + frontendSteps: Array.isArray(payload.frontendSteps) ? payload.frontendSteps : null, + frontendError: payload.frontendError || null, + totalDurationMs: payload.totalDurationMs + }); + + const row = getAIDebugTraceByIdStmt.get({ traceId: upserted.traceId }); + res.json({ + success: true, + trace: parseAIDebugTraceRow(row) + }); + } catch (error) { + res.status(500).json({ error: error.message }); + } +}); + app.get('/api/moderation-settings', (req, res) => { try { const settings = loadModerationSettings(); @@ -6505,239 +6940,401 @@ function shouldRetryAIComment(text) { return hasCommentOrCharacter && hasLengthOrCount; } -async function tryGenerateComment(credential, promptPrefix, postText) { +async function tryGenerateComment(credential, promptPrefix, postText, options = {}) { const provider = credential.provider; const apiKey = credential.api_key; const model = credential.model; + const traceId = sanitizeAIDebugValue(options.traceId, AI_DEBUG_TRACE_ID_MAX_LENGTH); + const flowId = sanitizeAIDebugValue(options.flowId, AI_DEBUG_FLOW_ID_MAX_LENGTH); let lastResponse = null; + const providerAttempts = []; try { for (let attempt = 1; attempt <= AI_COMMENT_RETRY_LIMIT; attempt += 1) { + const attemptStartMs = Date.now(); + const attemptStartedAt = new Date(attemptStartMs).toISOString(); + let attemptRecorded = false; + let modelName = model || null; let comment = ''; - if (provider === 'gemini') { - const modelName = model || 'gemini-2.0-flash-exp'; - const prompt = promptPrefix + postText; + const recordAttempt = (status, extra = {}) => { + if (attemptRecorded) { + return; + } + attemptRecorded = true; + providerAttempts.push({ + attempt, + provider, + model: modelName, + traceId: traceId || null, + flowId: flowId || null, + status, + started_at: attemptStartedAt, + duration_ms: roundTiming(Date.now() - attemptStartMs), + ...extra + }); + }; - const response = await fetch( - `https://generativelanguage.googleapis.com/v1beta/models/${modelName}:generateContent?key=${apiKey}`, - { + try { + if (provider === 'gemini') { + modelName = model || 'gemini-2.0-flash-exp'; + const prompt = promptPrefix + postText; + + const response = await fetch( + `https://generativelanguage.googleapis.com/v1beta/models/${modelName}:generateContent?key=${apiKey}`, + { + method: 'POST', + headers: { 'Content-Type': 'application/json' }, + body: JSON.stringify({ + contents: [{ + parts: [{ text: prompt }] + }] + }) + } + ); + + lastResponse = response; + + if (!response.ok) { + let errorPayload = null; + let message = response.statusText; + try { + errorPayload = await response.json(); + message = errorPayload?.error?.message || message; + } catch (jsonError) { + try { + const textBody = await response.text(); + if (textBody) { + message = textBody; + } + } catch (textError) { + // ignore + } + } + + const rateInfo = extractRateLimitInfo(response, provider); + recordAttempt('http_error', { + http_status: response.status, + error: message, + rate_limit_remaining: rateInfo.rateLimitRemaining ?? null, + rate_limit_reset_at: rateInfo.rateLimitResetAt ?? null + }); + + const error = new Error(`Gemini API error: ${message}`); + error.status = response.status; + error.provider = provider; + error.apiError = errorPayload; + if (rateInfo.retryAfterSeconds !== undefined) { + error.retryAfterSeconds = rateInfo.retryAfterSeconds; + } + if (rateInfo.rateLimitResetAt) { + error.rateLimitResetAt = rateInfo.rateLimitResetAt; + } + if (rateInfo.rateLimitRemaining !== undefined) { + error.rateLimitRemaining = rateInfo.rateLimitRemaining; + } + error.rateLimitHeaders = rateInfo.headers; + throw error; + } + + const data = await response.json(); + comment = data.candidates?.[0]?.content?.parts?.[0]?.text || ''; + } else if (provider === 'openai') { + modelName = model || 'gpt-3.5-turbo'; + const prompt = promptPrefix + postText; + + const baseUrl = (credential.base_url || 'https://api.openai.com/v1').trim().replace(/\/+$/, ''); + const endpoint = baseUrl.endsWith('/chat/completions') ? baseUrl : `${baseUrl}/chat/completions`; + + const headers = { + 'Content-Type': 'application/json' + }; + if (apiKey) { + headers.Authorization = `Bearer ${apiKey}`; + } + + const response = await fetch(endpoint, { method: 'POST', - headers: { 'Content-Type': 'application/json' }, + headers, body: JSON.stringify({ - contents: [{ - parts: [{ text: prompt }] - }] + model: modelName, + messages: [{ role: 'user', content: prompt }], + max_tokens: 150 }) - } - ); + }); - lastResponse = response; + lastResponse = response; - if (!response.ok) { - let errorPayload = null; - let message = response.statusText; - try { - errorPayload = await response.json(); - message = errorPayload?.error?.message || message; - } catch (jsonError) { + if (!response.ok) { + let errorPayload = null; + let message = response.statusText; try { - const textBody = await response.text(); - if (textBody) { - message = textBody; + errorPayload = await response.json(); + message = errorPayload?.error?.message || message; + } catch (jsonError) { + try { + const textBody = await response.text(); + if (textBody) { + message = textBody; + } + } catch (textError) { + // ignore } - } catch (textError) { - // ignore } + + const rateInfo = extractRateLimitInfo(response, provider); + recordAttempt('http_error', { + http_status: response.status, + error: message, + rate_limit_remaining: rateInfo.rateLimitRemaining ?? null, + rate_limit_reset_at: rateInfo.rateLimitResetAt ?? null + }); + + const error = new Error(`OpenAI API error: ${message}`); + error.status = response.status; + error.provider = provider; + error.apiError = errorPayload; + if (rateInfo.retryAfterSeconds !== undefined) { + error.retryAfterSeconds = rateInfo.retryAfterSeconds; + } + if (rateInfo.rateLimitResetAt) { + error.rateLimitResetAt = rateInfo.rateLimitResetAt; + } + if (rateInfo.rateLimitRemaining !== undefined) { + error.rateLimitRemaining = rateInfo.rateLimitRemaining; + } + error.rateLimitHeaders = rateInfo.headers; + throw error; } - const rateInfo = extractRateLimitInfo(response, provider); - const error = new Error(`Gemini API error: ${message}`); - error.status = response.status; + const data = await response.json(); + comment = data.choices?.[0]?.message?.content || ''; + } else if (provider === 'claude') { + modelName = model || 'claude-3-5-haiku-20241022'; + const prompt = promptPrefix + postText; + + const response = await fetch('https://api.anthropic.com/v1/messages', { + method: 'POST', + headers: { + 'Content-Type': 'application/json', + 'x-api-key': apiKey, + 'anthropic-version': '2023-06-01' + }, + body: JSON.stringify({ + model: modelName, + max_tokens: 150, + messages: [{ role: 'user', content: prompt }] + }) + }); + + lastResponse = response; + + if (!response.ok) { + let errorPayload = null; + let message = response.statusText; + try { + errorPayload = await response.json(); + message = errorPayload?.error?.message || message; + } catch (jsonError) { + try { + const textBody = await response.text(); + if (textBody) { + message = textBody; + } + } catch (textError) { + // ignore + } + } + + const rateInfo = extractRateLimitInfo(response, provider); + recordAttempt('http_error', { + http_status: response.status, + error: message, + rate_limit_remaining: rateInfo.rateLimitRemaining ?? null, + rate_limit_reset_at: rateInfo.rateLimitResetAt ?? null + }); + + const error = new Error(`Claude API error: ${message}`); + error.status = response.status; + error.provider = provider; + error.apiError = errorPayload; + if (rateInfo.retryAfterSeconds !== undefined) { + error.retryAfterSeconds = rateInfo.retryAfterSeconds; + } + if (rateInfo.rateLimitResetAt) { + error.rateLimitResetAt = rateInfo.rateLimitResetAt; + } + if (rateInfo.rateLimitRemaining !== undefined) { + error.rateLimitRemaining = rateInfo.rateLimitRemaining; + } + error.rateLimitHeaders = rateInfo.headers; + throw error; + } + + const data = await response.json(); + comment = data.content?.[0]?.text || ''; + } else { + throw new Error(`Unsupported AI provider: ${provider}`); + } + + if (shouldRetryAIComment(comment)) { + recordAttempt('retry_filtered', { + http_status: lastResponse ? lastResponse.status : null, + comment_length: comment.length + }); + if (attempt < AI_COMMENT_RETRY_LIMIT) { + continue; + } + const error = new Error('AI response contains forbidden comment length/count metadata'); error.provider = provider; - error.apiError = errorPayload; - if (rateInfo.retryAfterSeconds !== undefined) { - error.retryAfterSeconds = rateInfo.retryAfterSeconds; - } - if (rateInfo.rateLimitResetAt) { - error.rateLimitResetAt = rateInfo.rateLimitResetAt; - } - if (rateInfo.rateLimitRemaining !== undefined) { - error.rateLimitRemaining = rateInfo.rateLimitRemaining; - } - error.rateLimitHeaders = rateInfo.headers; throw error; } - const data = await response.json(); - comment = data.candidates?.[0]?.content?.parts?.[0]?.text || ''; - } else if (provider === 'openai') { - const modelName = model || 'gpt-3.5-turbo'; - const prompt = promptPrefix + postText; + const rateInfo = extractRateLimitInfo(lastResponse, provider); + rateInfo.status = lastResponse ? lastResponse.status : null; - const baseUrl = (credential.base_url || 'https://api.openai.com/v1').trim().replace(/\/+$/, ''); - const endpoint = baseUrl.endsWith('/chat/completions') ? baseUrl : `${baseUrl}/chat/completions`; + recordAttempt('success', { + http_status: lastResponse ? lastResponse.status : null, + comment_length: comment.length, + rate_limit_remaining: rateInfo.rateLimitRemaining ?? null, + rate_limit_reset_at: rateInfo.rateLimitResetAt ?? null + }); - const headers = { - 'Content-Type': 'application/json' + return { + comment: sanitizeAIComment(comment), + rateInfo, + providerAttempts }; - if (apiKey) { - headers['Authorization'] = `Bearer ${apiKey}`; + } catch (error) { + if (!attemptRecorded) { + recordAttempt(error && error.name === 'AbortError' ? 'aborted' : 'error', { + http_status: lastResponse ? lastResponse.status : null, + error: error && error.message ? String(error.message) : 'Unbekannter Fehler' + }); } - - const response = await fetch(endpoint, { - method: 'POST', - headers, - body: JSON.stringify({ - model: modelName, - messages: [{ role: 'user', content: prompt }], - max_tokens: 150 - }) - }); - - lastResponse = response; - - if (!response.ok) { - let errorPayload = null; - let message = response.statusText; - try { - errorPayload = await response.json(); - message = errorPayload?.error?.message || message; - } catch (jsonError) { - try { - const textBody = await response.text(); - if (textBody) { - message = textBody; - } - } catch (textError) { - // ignore - } - } - - const rateInfo = extractRateLimitInfo(response, provider); - const error = new Error(`OpenAI API error: ${message}`); - error.status = response.status; - error.provider = provider; - error.apiError = errorPayload; - if (rateInfo.retryAfterSeconds !== undefined) { - error.retryAfterSeconds = rateInfo.retryAfterSeconds; - } - if (rateInfo.rateLimitResetAt) { - error.rateLimitResetAt = rateInfo.rateLimitResetAt; - } - if (rateInfo.rateLimitRemaining !== undefined) { - error.rateLimitRemaining = rateInfo.rateLimitRemaining; - } - error.rateLimitHeaders = rateInfo.headers; - throw error; - } - - const data = await response.json(); - comment = data.choices?.[0]?.message?.content || ''; - } else if (provider === 'claude') { - const modelName = model || 'claude-3-5-haiku-20241022'; - const prompt = promptPrefix + postText; - - const response = await fetch('https://api.anthropic.com/v1/messages', { - method: 'POST', - headers: { - 'Content-Type': 'application/json', - 'x-api-key': apiKey, - 'anthropic-version': '2023-06-01' - }, - body: JSON.stringify({ - model: modelName, - max_tokens: 150, - messages: [{ role: 'user', content: prompt }] - }) - }); - - lastResponse = response; - - if (!response.ok) { - let errorPayload = null; - let message = response.statusText; - try { - errorPayload = await response.json(); - message = errorPayload?.error?.message || message; - } catch (jsonError) { - try { - const textBody = await response.text(); - if (textBody) { - message = textBody; - } - } catch (textError) { - // ignore - } - } - - const rateInfo = extractRateLimitInfo(response, provider); - const error = new Error(`Claude API error: ${message}`); - error.status = response.status; - error.provider = provider; - error.apiError = errorPayload; - if (rateInfo.retryAfterSeconds !== undefined) { - error.retryAfterSeconds = rateInfo.retryAfterSeconds; - } - if (rateInfo.rateLimitResetAt) { - error.rateLimitResetAt = rateInfo.rateLimitResetAt; - } - if (rateInfo.rateLimitRemaining !== undefined) { - error.rateLimitRemaining = rateInfo.rateLimitRemaining; - } - error.rateLimitHeaders = rateInfo.headers; - throw error; - } - - const data = await response.json(); - comment = data.content?.[0]?.text || ''; - } else { - throw new Error(`Unsupported AI provider: ${provider}`); - } - - if (shouldRetryAIComment(comment)) { - if (attempt < AI_COMMENT_RETRY_LIMIT) { - continue; - } - const error = new Error('AI response contains forbidden comment length/count metadata'); - error.provider = provider; throw error; } - - const rateInfo = extractRateLimitInfo(lastResponse, provider); - rateInfo.status = lastResponse ? lastResponse.status : null; - - return { - comment: sanitizeAIComment(comment), - rateInfo - }; } } catch (error) { if (error && !error.provider) { error.provider = provider; } + if (error && !error.providerAttempts) { + error.providerAttempts = providerAttempts; + } throw error; } } app.post('/api/ai/generate-comment', async (req, res) => { + const requestStartedMs = Date.now(); + const requestBody = req.body || {}; + const requestMeta = normalizeAIDebugRequestMeta(requestBody); + const incomingTraceId = sanitizeAIDebugValue(req.headers['x-ai-trace-id'] || requestBody.traceId, AI_DEBUG_TRACE_ID_MAX_LENGTH); + const incomingFlowId = sanitizeAIDebugValue(req.headers['x-ai-flow-id'] || requestBody.flowId, AI_DEBUG_FLOW_ID_MAX_LENGTH); + const traceId = incomingTraceId || buildAIDebugTraceId(); + const flowId = incomingFlowId || traceId; + const traceSource = sanitizeAIDebugValue(req.headers['x-ai-trace-source'] || requestBody.traceSource, 80) || 'extension-ai-button'; + const backendTimings = {}; + const credentialTimingDetails = []; + + upsertAIDebugTraceBase({ + traceId, + flowId, + source: traceSource, + status: 'backend_in_progress', + origin: req.headers.origin || null, + requestIp: req.ip || req.socket?.remoteAddress || null, + userAgent: req.headers['user-agent'] || null, + requestMeta + }); + + const timingStart = () => Date.now(); + const timingEnd = (key, startedAt) => { + const value = roundTiming(Date.now() - startedAt); + backendTimings[key] = value; + return value; + }; + + const applyTraceHeaders = () => { + res.setHeader('x-ai-trace-id', traceId); + if (flowId) { + res.setHeader('x-ai-flow-id', flowId); + } + }; + + const applyServerTimingHeader = () => { + const header = buildServerTimingHeader([ + { name: 'settings', duration: backendTimings.loadSettingsMs }, + { name: 'reactivate', duration: backendTimings.reactivateCredentialsMs }, + { name: 'credentials', duration: backendTimings.loadCredentialsMs }, + { name: 'prompt', duration: backendTimings.buildPromptMs }, + { name: 'ai', duration: backendTimings.credentialLoopMs }, + { name: 'total', duration: backendTimings.totalMs } + ]); + if (header) { + res.setHeader('Server-Timing', header); + } + }; + + const respondWithTrackedError = (statusCode, message, options = {}) => { + backendTimings.totalMs = roundTiming(Date.now() - requestStartedMs); + + updateAIDebugTraceBackend({ + traceId, + flowId, + source: traceSource, + status: statusCode >= 500 ? 'backend_error' : 'backend_rejected', + backendTimings, + backendAttempts: credentialTimingDetails, + backendError: message, + responseMeta: { + statusCode, + ...options.responseMeta + }, + totalDurationMs: backendTimings.totalMs + }); + + applyTraceHeaders(); + applyServerTimingHeader(); + + const payload = { + error: message, + traceId, + flowId, + timings: { + backend: backendTimings + } + }; + + if (options.attempts) { + payload.attempts = options.attempts; + } + + return res.status(statusCode).json(payload); + }; + try { - const { postText, profileNumber, preferredCredentialId } = req.body; + const { postText, profileNumber, preferredCredentialId } = requestBody; if (!postText) { - return res.status(400).json({ error: 'postText is required' }); + return respondWithTrackedError(400, 'postText is required'); } + const loadSettingsStartedMs = timingStart(); const settings = db.prepare('SELECT * FROM ai_settings WHERE id = 1').get(); + timingEnd('loadSettingsMs', loadSettingsStartedMs); if (!settings || !settings.enabled) { - return res.status(400).json({ error: 'AI comment generation is not enabled' }); + return respondWithTrackedError(400, 'AI comment generation is not enabled'); } + const reactivateStartedMs = timingStart(); reactivateExpiredCredentials(); + timingEnd('reactivateCredentialsMs', reactivateStartedMs); - // Get all active credentials, ordered by priority + const loadCredentialsStartedMs = timingStart(); const credentials = db.prepare(` SELECT * FROM ai_credentials @@ -6745,9 +7342,10 @@ app.post('/api/ai/generate-comment', async (req, res) => { AND COALESCE(auto_disabled, 0) = 0 ORDER BY priority ASC, id ASC `).all(); + timingEnd('loadCredentialsMs', loadCredentialsStartedMs); if (!credentials || credentials.length === 0) { - return res.status(400).json({ error: 'No active AI credentials available' }); + return respondWithTrackedError(400, 'No active AI credentials available'); } let orderedCredentials = credentials; @@ -6762,10 +7360,10 @@ app.post('/api/ai/generate-comment', async (req, res) => { } } + const promptBuildStartedMs = timingStart(); let promptPrefix = settings.prompt_prefix || ''; const normalizedProfileNumber = sanitizeProfileNumber(profileNumber); - // Get friend names for the profile if available if (normalizedProfileNumber) { const friends = db.prepare('SELECT friend_names FROM profile_friends WHERE profile_number = ?').get(normalizedProfileNumber); if (friends && friends.friend_names) { @@ -6782,62 +7380,127 @@ app.post('/api/ai/generate-comment', async (req, res) => { promptPrefix = promptPrefix.replaceAll('{DATUM}', todayDisplay); promptPrefix = applyRandomNumberTemplates(promptPrefix); promptPrefix = applyProfileVariantTemplates(promptPrefix, normalizedProfileNumber); + timingEnd('buildPromptMs', promptBuildStartedMs); - // Try each active credential until one succeeds let lastError = null; const attemptDetails = []; + const credentialLoopStartedMs = timingStart(); + for (const credential of orderedCredentials) { + const credentialStartedMs = Date.now(); try { console.log(`Trying credential: ${credential.name} (ID: ${credential.id})`); - const { comment, rateInfo } = await tryGenerateComment(credential, promptPrefix, postText); - console.log(`Success with credential: ${credential.name}`); + const { comment, rateInfo, providerAttempts } = await tryGenerateComment( + credential, + promptPrefix, + postText, + { traceId, flowId } + ); + const credentialDurationMs = roundTiming(Date.now() - credentialStartedMs); + console.log(`Success with credential: ${credential.name}`); updateCredentialUsageOnSuccess(credential.id, rateInfo || {}); + credentialTimingDetails.push({ + credentialId: credential.id, + credentialName: credential.name, + provider: credential.provider, + model: credential.model || null, + status: 'success', + duration_ms: credentialDurationMs, + provider_attempts: providerAttempts || [] + }); + attemptDetails.push({ credentialId: credential.id, credentialName: credential.name, status: 'success', + durationMs: credentialDurationMs, rateLimitRemaining: rateInfo?.rateLimitRemaining ?? null, rateLimitResetAt: rateInfo?.rateLimitResetAt ?? null }); + backendTimings.credentialLoopMs = roundTiming(Date.now() - credentialLoopStartedMs); + backendTimings.totalMs = roundTiming(Date.now() - requestStartedMs); + + updateAIDebugTraceBackend({ + traceId, + flowId, + source: traceSource, + status: 'backend_success', + backendTimings, + backendAttempts: credentialTimingDetails, + responseMeta: { + usedCredential: credential.name, + usedCredentialId: credential.id, + attempts: attemptDetails + }, + totalDurationMs: backendTimings.totalMs + }); + + applyTraceHeaders(); + applyServerTimingHeader(); + return res.json({ comment, usedCredential: credential.name, usedCredentialId: credential.id, attempts: attemptDetails, - rateLimitInfo: rateInfo || null + rateLimitInfo: rateInfo || null, + traceId, + flowId, + timings: { + backend: backendTimings, + credentials: credentialTimingDetails + } }); } catch (error) { + const credentialDurationMs = roundTiming(Date.now() - credentialStartedMs); console.error(`Failed with credential ${credential.name}:`, error.message); lastError = error; const errorUpdate = updateCredentialUsageOnError(credential.id, error); + credentialTimingDetails.push({ + credentialId: credential.id, + credentialName: credential.name, + provider: credential.provider, + model: credential.model || null, + status: 'error', + duration_ms: credentialDurationMs, + error: error.message, + status_code: error.status || error.statusCode || null, + provider_attempts: error.providerAttempts || [] + }); + attemptDetails.push({ credentialId: credential.id, credentialName: credential.name, status: 'error', + durationMs: credentialDurationMs, message: error.message, statusCode: error.status || error.statusCode || null, autoDisabled: Boolean(errorUpdate.autoDisabled), autoDisabledUntil: errorUpdate.autoDisabledUntil || null }); - // Continue to next credential } } - // If we get here, all credentials failed + backendTimings.credentialLoopMs = roundTiming(Date.now() - credentialLoopStartedMs); + const finalError = lastError || new Error('All AI credentials failed'); finalError.attempts = attemptDetails; throw finalError; - } catch (error) { console.error('AI comment generation error:', error); - if (error && error.attempts) { - res.status(500).json({ error: error.message, attempts: error.attempts }); - } else { - res.status(500).json({ error: error.message }); - } + return respondWithTrackedError( + 500, + error && error.message ? error.message : 'Unbekannter Fehler', + { + attempts: error && error.attempts ? error.attempts : null, + responseMeta: { + attempts: error && error.attempts ? error.attempts : null + } + } + ); } }); diff --git a/extension/content.js b/extension/content.js index 60c33c4..bdc5fb6 100644 --- a/extension/content.js +++ b/extension/content.js @@ -5332,47 +5332,185 @@ function sanitizeAIComment(comment) { return sanitized.trim(); } +function nowPerformanceMs() { + if (typeof performance !== 'undefined' && performance && typeof performance.now === 'function') { + return performance.now(); + } + return Date.now(); +} + +function roundDurationMs(value) { + const numeric = Number(value); + if (!Number.isFinite(numeric) || numeric < 0) { + return null; + } + return Math.round(numeric * 1000) / 1000; +} + +function buildAITraceId(prefix = 'trace') { + const safePrefix = String(prefix || 'trace').trim().replace(/[^a-z0-9_-]/gi, '').toLowerCase() || 'trace'; + if (typeof crypto !== 'undefined' && crypto && typeof crypto.randomUUID === 'function') { + return `${safePrefix}-${crypto.randomUUID()}`; + } + const randomPart = Math.random().toString(36).slice(2, 10); + return `${safePrefix}-${Date.now().toString(36)}-${randomPart}`; +} + +async function reportAIDebugFrontendTrace(payload = {}) { + try { + const body = { + traceId: payload.traceId || null, + flowId: payload.flowId || null, + source: payload.source || 'extension-ai-button', + status: payload.status || 'frontend_reported', + requestMeta: payload.requestMeta || null, + frontendTimings: payload.frontendTimings || null, + frontendSteps: Array.isArray(payload.frontendSteps) ? payload.frontendSteps : null, + frontendError: payload.frontendError || null, + totalDurationMs: payload.totalDurationMs + }; + + await backendFetch(`${API_URL}/ai/debug-traces/frontend`, { + method: 'POST', + headers: { 'Content-Type': 'application/json' }, + body: JSON.stringify(body) + }); + } catch (error) { + console.warn('[FB Tracker] Failed to submit AI frontend trace:', error); + } +} + /** * Generate AI comment for a post */ async function generateAIComment(postText, profileNumber, options = {}) { - const { signal = null, preferredCredentialId = null, maxAttempts = 3 } = options; - const payload = { + const { + signal = null, + preferredCredentialId = null, + maxAttempts = 3, + flowId = null, + source = 'extension-ai-button', + returnMeta = false + } = options; + const normalizedFlowId = typeof flowId === 'string' && flowId.trim() + ? flowId.trim() + : buildAITraceId('flow'); + const basePayload = { postText, - profileNumber + profileNumber, + flowId: normalizedFlowId, + traceSource: source }; - if (typeof preferredCredentialId === 'number') { - payload.preferredCredentialId = preferredCredentialId; + if (typeof preferredCredentialId === 'number' && !Number.isNaN(preferredCredentialId)) { + basePayload.preferredCredentialId = preferredCredentialId; } + const requestAttempts = []; let lastError = null; + let lastTraceId = null; const attempts = Math.max(1, maxAttempts); for (let attempt = 1; attempt <= attempts; attempt += 1) { + const requestTraceId = `${normalizedFlowId}-r${attempt}`; + const startedAt = new Date().toISOString(); + const attemptStartedMs = nowPerformanceMs(); + const payload = { + ...basePayload, + traceId: requestTraceId, + requestAttempt: attempt + }; + try { const response = await backendFetch(`${API_URL}/ai/generate-comment`, { method: 'POST', - headers: { 'Content-Type': 'application/json' }, + headers: { + 'Content-Type': 'application/json', + 'x-ai-trace-id': requestTraceId, + 'x-ai-flow-id': normalizedFlowId, + 'x-ai-trace-source': source + }, body: JSON.stringify(payload), signal }); + const durationMs = roundDurationMs(nowPerformanceMs() - attemptStartedMs); + const responseTraceId = response.headers.get('x-ai-trace-id') || requestTraceId; + const responseFlowId = response.headers.get('x-ai-flow-id') || normalizedFlowId; + lastTraceId = responseTraceId || lastTraceId; if (!response.ok) { - const errorData = await response.json(); - throw new Error(errorData.error || 'Failed to generate comment'); + const errorData = await response.json().catch(() => ({})); + const message = errorData.error || 'Failed to generate comment'; + requestAttempts.push({ + attempt, + traceId: responseTraceId, + flowId: responseFlowId, + status: 'http_error', + startedAt, + durationMs, + httpStatus: response.status, + error: message + }); + const error = new Error(message); + error.aiTrace = { + traceId: responseTraceId, + flowId: responseFlowId, + requestAttempts: requestAttempts.slice() + }; + throw error; } const data = await response.json(); const sanitizedComment = sanitizeAIComment(data.comment); + const effectiveTraceId = data.traceId || responseTraceId; + const effectiveFlowId = data.flowId || responseFlowId; + lastTraceId = effectiveTraceId || lastTraceId; + + requestAttempts.push({ + attempt, + traceId: effectiveTraceId, + flowId: effectiveFlowId, + status: sanitizedComment ? 'success' : 'empty', + startedAt, + durationMs, + httpStatus: response.status, + backendTimings: data.timings && data.timings.backend ? data.timings.backend : null + }); if (sanitizedComment) { - return sanitizedComment; + const result = { + comment: sanitizedComment, + traceId: effectiveTraceId, + flowId: effectiveFlowId, + requestAttempts, + backendTimings: data.timings && data.timings.backend ? data.timings.backend : null + }; + return returnMeta ? result : sanitizedComment; } lastError = new Error('AI response empty'); } catch (error) { + const durationMs = roundDurationMs(nowPerformanceMs() - attemptStartedMs); + const cancelled = error && (error.name === 'AbortError' || isCancellationError(error)); + + if (!error || !error.aiTrace) { + requestAttempts.push({ + attempt, + traceId: requestTraceId, + flowId: normalizedFlowId, + status: cancelled ? 'cancelled' : 'request_error', + startedAt, + durationMs, + error: error && error.message ? String(error.message) : 'Unbekannter Fehler' + }); + } else if (error.aiTrace && error.aiTrace.traceId) { + lastTraceId = error.aiTrace.traceId; + } + lastError = error; + if (cancelled) { + break; + } } if (attempt < attempts) { @@ -5381,8 +5519,27 @@ async function generateAIComment(postText, profileNumber, options = {}) { } } + if (lastError) { + if (!lastError.aiTrace) { + lastError.aiTrace = { + traceId: lastTraceId, + flowId: normalizedFlowId, + requestAttempts: requestAttempts.slice() + }; + } + if (lastError.name === 'AbortError' || isCancellationError(lastError)) { + throw lastError; + } + } + console.error('[FB Tracker] AI comment generation failed after retries:', lastError); - throw new Error('AI-Antwort konnte nicht erzeugt werden. Bitte später erneut versuchen.'); + const finalError = new Error('AI-Antwort konnte nicht erzeugt werden. Bitte später erneut versuchen.'); + finalError.aiTrace = { + traceId: lastTraceId, + flowId: normalizedFlowId, + requestAttempts: requestAttempts.slice() + }; + throw finalError; } async function handleSelectionAIRequest(selectionText, sendResponse) { @@ -5402,7 +5559,9 @@ async function handleSelectionAIRequest(selectionText, sendResponse) { sendResponse({ error: 'profile-missing' }); return; } - const comment = await generateAIComment(normalizedSelection, profileNumber, {}); + const comment = await generateAIComment(normalizedSelection, profileNumber, { + source: 'selection-ai' + }); if (!comment) { throw new Error('Keine Antwort vom AI-Dienst erhalten'); @@ -6081,6 +6240,73 @@ async function addAICommentButton(container, postElement) { } }; + const flowTrace = { + source: 'extension-ai-button', + flowId: buildAITraceId('flow'), + traceId: null, + status: 'processing', + startedAt: new Date().toISOString(), + finishedAt: null, + frontendTimings: {}, + frontendSteps: [], + frontendError: null, + totalDurationMs: null, + requestMeta: { + preferredCredentialId: typeof preferredCredentialId === 'number' && !Number.isNaN(preferredCredentialId) + ? preferredCredentialId + : null + }, + backend: null + }; + const flowStartMs = nowPerformanceMs(); + const phaseStartTimes = {}; + + const addStep = (step, payload = {}) => { + flowTrace.frontendSteps.push({ + step, + at: new Date().toISOString(), + ...(payload && typeof payload === 'object' ? payload : {}) + }); + }; + + const beginPhase = (name) => { + phaseStartTimes[name] = nowPerformanceMs(); + }; + + const endPhase = (name, payload = null) => { + if (!Object.prototype.hasOwnProperty.call(phaseStartTimes, name)) { + return null; + } + const durationMs = roundDurationMs(nowPerformanceMs() - phaseStartTimes[name]); + flowTrace.frontendTimings[name] = durationMs; + if (payload && typeof payload === 'object') { + addStep(name, payload); + } + return durationMs; + }; + + const mergeTraceInfo = (tracePayload) => { + if (!tracePayload || typeof tracePayload !== 'object') { + return; + } + if (tracePayload.traceId) { + flowTrace.traceId = tracePayload.traceId; + } + if (tracePayload.flowId) { + flowTrace.flowId = tracePayload.flowId; + } + const backend = {}; + if (Array.isArray(tracePayload.requestAttempts)) { + backend.requestAttempts = tracePayload.requestAttempts; + } + if (tracePayload.backendTimings && typeof tracePayload.backendTimings === 'object') { + backend.timings = tracePayload.backendTimings; + } + if (Object.keys(backend).length) { + flowTrace.backend = backend; + } + }; + const throwIfCancelled = () => { if (aiContext.cancelled) { const cancelError = new Error('AI_CANCELLED'); @@ -6170,6 +6396,7 @@ async function addAICommentButton(container, postElement) { return null; }; + beginPhase('extractPostTextMs'); let postText = ''; const cachedSelection = resolveRecentSelection(); if (cachedSelection) { @@ -6219,25 +6446,43 @@ async function addAICommentButton(container, postElement) { postText = `${postText}\n\nZusatzinfo:\n${additionalNote}`; } + flowTrace.requestMeta.postTextLength = postText.length; + endPhase('extractPostTextMs', { postTextLength: postText.length }); + throwIfCancelled(); console.log('[FB Tracker] Generating AI comment for:', postText.substring(0, 100)); + beginPhase('profileLookupMs'); const profileNumber = await getProfileNumber(); + endPhase('profileLookupMs', { profileNumber: profileNumber || null }); if (!profileNumber) { + flowTrace.status = 'profile_missing'; + flowTrace.frontendError = 'Profilstatus nicht geladen'; showToast('Profilstatus nicht geladen. Bitte Tracker neu laden.', 'error'); + restoreIdle(originalText); return; } throwIfCancelled(); - const comment = await generateAIComment(postText, profileNumber, { + beginPhase('aiRequestMs'); + const aiResult = await generateAIComment(postText, profileNumber, { signal: aiContext.abortController.signal, - preferredCredentialId + preferredCredentialId, + flowId: flowTrace.flowId, + source: flowTrace.source, + returnMeta: true }); + endPhase('aiRequestMs', { + traceId: aiResult.traceId || null, + requestAttempts: Array.isArray(aiResult.requestAttempts) ? aiResult.requestAttempts.length : 0 + }); + mergeTraceInfo(aiResult); throwIfCancelled(); + const comment = aiResult.comment; console.log('[FB Tracker] Generated comment:', comment); const dialogRoot = container.closest(DIALOG_ROOT_SELECTOR) @@ -6245,6 +6490,7 @@ async function addAICommentButton(container, postElement) { let commentInput = findCommentInput(postContext, { preferredRoot: dialogRoot }); let waitedForInput = false; + let waitStartedMs = null; if (!commentInput) { console.log('[FB Tracker] Comment input not found, trying to click comment button'); @@ -6261,6 +6507,7 @@ async function addAICommentButton(container, postElement) { updateProcessingText(buttonClicked ? '⏳ Öffne Kommentare...' : '⏳ Suche Kommentarfeld...'); waitedForInput = true; + waitStartedMs = nowPerformanceMs(); commentInput = await waitForCommentInput(postContext, { encodedPostUrl, timeout: buttonClicked ? 8000 : 5000, @@ -6273,6 +6520,7 @@ async function addAICommentButton(container, postElement) { if (!commentInput && !waitedForInput) { updateProcessingText('⏳ Suche Kommentarfeld...'); waitedForInput = true; + waitStartedMs = nowPerformanceMs(); commentInput = await waitForCommentInput(postContext, { encodedPostUrl, timeout: 4000, @@ -6282,15 +6530,30 @@ async function addAICommentButton(container, postElement) { }); } + if (waitStartedMs !== null) { + flowTrace.frontendTimings.waitForCommentInputMs = roundDurationMs(nowPerformanceMs() - waitStartedMs); + addStep('waitForCommentInputMs', { + durationMs: flowTrace.frontendTimings.waitForCommentInputMs, + found: Boolean(commentInput) + }); + } + + flowTrace.requestMeta.waitedForInput = waitedForInput; + flowTrace.requestMeta.commentInputFound = Boolean(commentInput); + throwIfCancelled(); if (!commentInput) { - throwIfCancelled(); + beginPhase('clipboardWriteMs'); await navigator.clipboard.writeText(comment); + endPhase('clipboardWriteMs', { reason: 'input_missing' }); throwIfCancelled(); showToast('📋 Kommentarfeld nicht gefunden - In Zwischenablage kopiert', 'info'); restoreIdle('📋 Kopiert', 2000); + flowTrace.status = 'clipboard_fallback'; + beginPhase('confirmParticipationMs'); await confirmParticipationAfterAI(profileNumber); + endPhase('confirmParticipationMs'); return; } @@ -6298,33 +6561,79 @@ async function addAICommentButton(container, postElement) { updateProcessingText('⏳ Füge Kommentar ein...'); } + beginPhase('setCommentTextMs'); const success = await setCommentText(commentInput, comment, { context: aiContext }); + endPhase('setCommentTextMs', { success: Boolean(success) }); throwIfCancelled(); if (success) { showToast('✓ Kommentar wurde eingefügt', 'success'); restoreIdle('✓ Eingefügt', 2000); + flowTrace.status = 'success'; + beginPhase('confirmParticipationMs'); await confirmParticipationAfterAI(profileNumber); + endPhase('confirmParticipationMs'); } else { + beginPhase('clipboardWriteMs'); await navigator.clipboard.writeText(comment); + endPhase('clipboardWriteMs', { reason: 'set_comment_failed' }); throwIfCancelled(); showToast('📋 Einfügen fehlgeschlagen - In Zwischenablage kopiert', 'info'); restoreIdle('📋 Kopiert', 2000); + flowTrace.status = 'clipboard_fallback'; + beginPhase('confirmParticipationMs'); await confirmParticipationAfterAI(profileNumber); + endPhase('confirmParticipationMs'); } } catch (error) { + if (error && error.aiTrace) { + mergeTraceInfo(error.aiTrace); + } + const cancelled = aiContext.cancelled || isCancellationError(error); if (cancelled) { console.log('[FB Tracker] AI comment operation cancelled'); + flowTrace.status = 'cancelled'; + flowTrace.frontendError = 'AI_CANCELLED'; restoreIdle('✋ Abgebrochen', 1500); showToast('⏹️ Vorgang abgebrochen', 'info'); return; } console.error('[FB Tracker] AI comment error:', error); + flowTrace.status = 'error'; + flowTrace.frontendError = error && error.message ? String(error.message) : 'Unbekannter Fehler'; showToast(`❌ ${error.message}`, 'error'); restoreIdle(originalText); + } finally { + flowTrace.finishedAt = new Date().toISOString(); + flowTrace.totalDurationMs = roundDurationMs(nowPerformanceMs() - flowStartMs); + flowTrace.frontendTimings.totalMs = flowTrace.totalDurationMs; + if (!flowTrace.status || flowTrace.status === 'processing') { + flowTrace.status = 'finished'; + } + addStep('flowComplete', { + status: flowTrace.status, + totalDurationMs: flowTrace.totalDurationMs + }); + + void reportAIDebugFrontendTrace({ + traceId: flowTrace.traceId, + flowId: flowTrace.flowId, + source: flowTrace.source, + status: flowTrace.status, + requestMeta: { + ...flowTrace.requestMeta, + startedAt: flowTrace.startedAt, + finishedAt: flowTrace.finishedAt, + backend: flowTrace.backend + }, + frontendTimings: flowTrace.frontendTimings, + frontendSteps: flowTrace.frontendSteps, + frontendError: flowTrace.frontendError, + totalDurationMs: flowTrace.totalDurationMs + }); } }; diff --git a/web/Dockerfile b/web/Dockerfile index 70b6696..140373a 100644 --- a/web/Dockerfile +++ b/web/Dockerfile @@ -12,11 +12,13 @@ COPY login.html /usr/share/nginx/html/ COPY style.css /usr/share/nginx/html/ COPY dashboard.css /usr/share/nginx/html/ COPY settings.css /usr/share/nginx/html/ +COPY ai-debug.css /usr/share/nginx/html/ COPY daily-bookmarks.css /usr/share/nginx/html/ COPY automation.css /usr/share/nginx/html/ COPY app.js /usr/share/nginx/html/ COPY dashboard.js /usr/share/nginx/html/ COPY settings.js /usr/share/nginx/html/ +COPY ai-debug.js /usr/share/nginx/html/ COPY daily-bookmarks.js /usr/share/nginx/html/ COPY automation.js /usr/share/nginx/html/ COPY login.js /usr/share/nginx/html/ @@ -28,6 +30,7 @@ RUN set -e; \ /usr/share/nginx/html/app.js \ /usr/share/nginx/html/dashboard.js \ /usr/share/nginx/html/settings.js \ + /usr/share/nginx/html/ai-debug.js \ /usr/share/nginx/html/daily-bookmarks.js \ /usr/share/nginx/html/automation.js \ /usr/share/nginx/html/login.js \ @@ -35,6 +38,7 @@ RUN set -e; \ /usr/share/nginx/html/style.css \ /usr/share/nginx/html/dashboard.css \ /usr/share/nginx/html/settings.css \ + /usr/share/nginx/html/ai-debug.css \ /usr/share/nginx/html/daily-bookmarks.css \ /usr/share/nginx/html/automation.css \ | sha256sum | awk '{print $1}')"; \ diff --git a/web/ai-debug.css b/web/ai-debug.css new file mode 100644 index 0000000..d9b2679 --- /dev/null +++ b/web/ai-debug.css @@ -0,0 +1,180 @@ +.ai-debug-shell { + display: flex; + flex-direction: column; + gap: 16px; +} + +.ai-debug-header { + display: flex; + justify-content: space-between; + align-items: flex-start; + gap: 16px; + flex-wrap: wrap; +} + +.ai-debug-header h2 { + margin: 0; +} + +.ai-debug-subtitle { + margin: 6px 0 0; + color: #64748b; +} + +.ai-debug-toolbar { + display: flex; + gap: 10px; + align-items: flex-end; + flex-wrap: wrap; +} + +.ai-debug-toolbar__item { + display: flex; + flex-direction: column; + gap: 4px; + font-size: 13px; + color: #334155; +} + +.ai-debug-toolbar__item select { + min-width: 120px; + border: 1px solid #cbd5e1; + border-radius: 8px; + padding: 7px 10px; + background: #fff; +} + +.ai-debug-status { + min-height: 20px; + color: #1f2937; + font-size: 14px; +} + +.ai-debug-status--error { + color: #b91c1c; +} + +.ai-debug-layout { + display: grid; + grid-template-columns: minmax(0, 1.15fr) minmax(0, 1fr); + gap: 16px; +} + +.ai-debug-list-panel, +.ai-debug-detail-panel { + border: 1px solid #e2e8f0; + border-radius: 12px; + background: #fff; + padding: 12px; + box-shadow: 0 1px 2px rgba(0, 0, 0, 0.05); +} + +.ai-debug-table { + width: 100%; + border-collapse: collapse; + font-size: 13px; +} + +.ai-debug-table th, +.ai-debug-table td { + padding: 9px 8px; + border-bottom: 1px solid #eef2f7; + text-align: left; + vertical-align: top; +} + +.ai-debug-table th { + font-size: 12px; + letter-spacing: 0.02em; + text-transform: uppercase; + color: #64748b; +} + +.ai-debug-table tbody tr { + cursor: pointer; +} + +.ai-debug-table tbody tr:hover { + background: #f8fafc; +} + +.ai-debug-table tbody tr.is-selected { + background: #e0f2fe; +} + +.ai-debug-empty { + text-align: center; + color: #64748b; +} + +.ai-debug-badge { + display: inline-flex; + align-items: center; + border-radius: 999px; + padding: 2px 8px; + font-size: 11px; + line-height: 1.6; + background: #e2e8f0; + color: #0f172a; +} + +.ai-debug-badge--success { + background: #dcfce7; + color: #166534; +} + +.ai-debug-badge--clipboard_fallback { + background: #ffedd5; + color: #9a3412; +} + +.ai-debug-badge--cancelled { + background: #f1f5f9; + color: #334155; +} + +.ai-debug-badge--error, +.ai-debug-badge--backend_error { + background: #fee2e2; + color: #991b1b; +} + +.ai-debug-badge--backend_rejected { + background: #fef3c7; + color: #92400e; +} + +.ai-debug-detail-panel h3 { + margin: 0 0 8px; +} + +.ai-debug-detail-meta { + color: #475569; + font-size: 13px; + margin-bottom: 10px; +} + +.ai-debug-json { + margin: 0; + max-height: 60vh; + overflow: auto; + border: 1px solid #e2e8f0; + border-radius: 8px; + background: #0f172a; + color: #e2e8f0; + padding: 12px; + font-size: 12px; + line-height: 1.45; + white-space: pre-wrap; + word-break: break-word; +} + +@media (max-width: 1080px) { + .ai-debug-layout { + grid-template-columns: 1fr; + } + + .ai-debug-json { + max-height: 42vh; + } +} diff --git a/web/ai-debug.js b/web/ai-debug.js new file mode 100644 index 0000000..d863493 --- /dev/null +++ b/web/ai-debug.js @@ -0,0 +1,261 @@ +(function () { + let active = false; + let initialized = false; + + const API_URL = (() => { + if (window.API_URL) return window.API_URL; + try { + return `${window.location.origin}/api`; + } catch (error) { + return 'https://fb.srv.medeba-media.de/api'; + } + })(); + const LOGIN_PAGE = 'login.html'; + + const state = { + traces: [], + selectedTraceId: null, + loading: false + }; + + const tableBody = document.getElementById('aiDebugTableBody'); + const statusEl = document.getElementById('aiDebugStatus'); + const detailMeta = document.getElementById('aiDebugDetailMeta'); + const detailJson = document.getElementById('aiDebugDetailJson'); + const refreshBtn = document.getElementById('aiDebugRefreshBtn'); + const statusFilter = document.getElementById('aiDebugStatusFilter'); + const limitFilter = document.getElementById('aiDebugLimitFilter'); + + function handleUnauthorized(response) { + if (response && response.status === 401) { + if (typeof redirectToLogin === 'function') { + redirectToLogin(); + } else { + window.location.href = LOGIN_PAGE; + } + return true; + } + return false; + } + + async function apiFetchJSON(path, options = {}) { + const response = await fetch(`${API_URL}${path}`, { + credentials: 'include', + ...options + }); + + if (handleUnauthorized(response)) { + throw new Error('Nicht angemeldet'); + } + + if (!response.ok) { + const payload = await response.json().catch(() => ({})); + throw new Error(payload.error || 'Unbekannter Fehler'); + } + + return response.json(); + } + + function setStatus(message, isError = false) { + if (!statusEl) return; + statusEl.textContent = message || ''; + statusEl.classList.toggle('ai-debug-status--error', !!isError); + } + + function formatDate(value) { + if (!value) return '—'; + const date = new Date(value); + if (Number.isNaN(date.getTime())) return '—'; + return date.toLocaleString('de-DE', { + day: '2-digit', + month: '2-digit', + year: 'numeric', + hour: '2-digit', + minute: '2-digit', + second: '2-digit' + }); + } + + function formatMs(value) { + const numeric = Number(value); + if (!Number.isFinite(numeric) || numeric < 0) { + return '—'; + } + return `${Math.round(numeric)} ms`; + } + + function compactId(value) { + if (!value || typeof value !== 'string') return '—'; + if (value.length <= 16) return value; + return `${value.slice(0, 8)}…${value.slice(-6)}`; + } + + function getBackendTotalMs(item) { + return item + && item.backend_timings + && typeof item.backend_timings === 'object' + ? item.backend_timings.totalMs + : null; + } + + function getAiRequestMs(item) { + return item + && item.frontend_timings + && typeof item.frontend_timings === 'object' + ? item.frontend_timings.aiRequestMs + : null; + } + + function renderTable() { + if (!tableBody) return; + tableBody.innerHTML = ''; + + if (!state.traces.length) { + const tr = document.createElement('tr'); + tr.innerHTML = 'Keine Debug-Läufe gefunden.'; + tableBody.appendChild(tr); + return; + } + + state.traces.forEach((item) => { + const tr = document.createElement('tr'); + tr.dataset.traceId = item.trace_id; + if (item.trace_id === state.selectedTraceId) { + tr.classList.add('is-selected'); + } + + tr.innerHTML = ` + ${formatDate(item.created_at)} + ${item.status || '—'} + ${formatMs(item.total_duration_ms)} + ${formatMs(getBackendTotalMs(item))} + ${formatMs(getAiRequestMs(item))} + ${compactId(item.flow_id)} / ${compactId(item.trace_id)} + `; + + tableBody.appendChild(tr); + }); + } + + function renderDetail(trace) { + if (!detailMeta || !detailJson) { + return; + } + if (!trace) { + detailMeta.textContent = 'Bitte einen Eintrag auswählen.'; + detailJson.textContent = ''; + return; + } + + detailMeta.textContent = `${trace.status || '—'} · ${formatDate(trace.created_at)} · Trace ${trace.trace_id || '—'}`; + detailJson.textContent = JSON.stringify(trace, null, 2); + } + + async function loadTraceDetail(traceId) { + if (!traceId) { + renderDetail(null); + return; + } + try { + const trace = await apiFetchJSON(`/ai/debug-traces/${encodeURIComponent(traceId)}`); + if (!active) return; + renderDetail(trace); + } catch (error) { + if (!active) return; + setStatus(`Details konnten nicht geladen werden: ${error.message}`, true); + } + } + + async function loadTraces() { + if (!active || state.loading) { + return; + } + + state.loading = true; + setStatus('Lade Debug-Läufe...'); + + try { + const params = new URLSearchParams(); + const status = statusFilter ? statusFilter.value.trim() : ''; + const limit = limitFilter ? parseInt(limitFilter.value, 10) : 50; + if (status) { + params.set('status', status); + } + if (Number.isFinite(limit) && limit > 0) { + params.set('limit', String(limit)); + } + + const data = await apiFetchJSON(`/ai/debug-traces?${params.toString()}`); + if (!active) return; + + state.traces = Array.isArray(data.items) ? data.items : []; + if (!state.selectedTraceId || !state.traces.some((item) => item.trace_id === state.selectedTraceId)) { + state.selectedTraceId = state.traces.length ? state.traces[0].trace_id : null; + } + + renderTable(); + await loadTraceDetail(state.selectedTraceId); + setStatus(`${state.traces.length} Lauf/Läufe geladen.`); + } catch (error) { + if (!active) return; + state.traces = []; + renderTable(); + renderDetail(null); + setStatus(`Debug-Läufe konnten nicht geladen werden: ${error.message}`, true); + } finally { + state.loading = false; + } + } + + function setupEvents() { + if (refreshBtn) { + refreshBtn.addEventListener('click', () => loadTraces()); + } + + if (statusFilter) { + statusFilter.addEventListener('change', () => loadTraces()); + } + + if (limitFilter) { + limitFilter.addEventListener('change', () => loadTraces()); + } + + if (tableBody) { + tableBody.addEventListener('click', (event) => { + const row = event.target.closest('tr[data-trace-id]'); + if (!row) return; + const traceId = row.dataset.traceId; + if (!traceId) return; + state.selectedTraceId = traceId; + renderTable(); + loadTraceDetail(traceId); + }); + } + } + + function init() { + if (initialized) return; + setupEvents(); + initialized = true; + } + + function activate() { + init(); + active = true; + loadTraces(); + } + + function deactivate() { + active = false; + } + + window.AIDebugPage = { + activate, + deactivate + }; + + const section = document.querySelector('[data-view="ai-debug"]'); + if (section && section.classList.contains('app-view--active')) { + activate(); + } +})(); diff --git a/web/index.html b/web/index.html index 5a99b4b..6e706a4 100644 --- a/web/index.html +++ b/web/index.html @@ -22,6 +22,7 @@ { href: 'style.css' }, { href: 'dashboard.css' }, { href: 'settings.css' }, + { href: 'ai-debug.css' }, { href: 'automation.css' }, { href: 'daily-bookmarks.css', id: 'dailyBookmarksCss', disabled: true } ]; @@ -29,6 +30,7 @@ 'app.js', 'dashboard.js', 'settings.js', + 'ai-debug.js', 'vendor/list.min.js', 'automation.js', 'daily-bookmarks.js' @@ -1098,6 +1100,9 @@ + + 🧭 AI-Debug öffnen + @@ -1392,6 +1397,68 @@ +
+
+
+
+
+

🧭 AI-Debug

+

Zeitliche Ablaufanalyse für AI-Kommentar-Generierung (Backend + Extension).

+
+
+ + + +
+
+ +
+ +
+
+ + + + + + + + + + + + +
ZeitStatusTotal (ms)Backend (ms)AI-Request (ms)Flow/Trace
+
+ +
+

Ablaufdetails

+
Bitte einen Eintrag auswählen.
+ 

+              

+            

+          

+        

+      

       

         

             

@@ -1468,6 +1535,7 @@
         posts: 'Beiträge',
         dashboard: 'Dashboard',
         settings: 'Einstellungen',
+        'ai-debug': 'AI-Debug',
         bookmarks: 'Bookmarks',
         automation: 'Automationen',
         'daily-bookmarks': 'Daily Bookmarks'
@@ -1549,6 +1617,7 @@
     (function() {
       const AUTOMATION_VIEW = 'automation';
       const DAILY_VIEW = 'daily-bookmarks';
+      const AI_DEBUG_VIEW = 'ai-debug';
       function handleViewChange(event) {
         const view = event?.detail?.view;
         if (view === AUTOMATION_VIEW) {
@@ -1561,6 +1630,11 @@
         } else {
           window.DailyBookmarksPage?.deactivate?.();
         }
+        if (view === AI_DEBUG_VIEW) {
+          window.AIDebugPage?.activate?.();
+        } else {
+          window.AIDebugPage?.deactivate?.();
+        }
       }
 
       window.addEventListener('app:view-change', handleViewChange);
@@ -1573,6 +1647,10 @@
       if (dailySection && dailySection.classList.contains('app-view--active')) {
         window.DailyBookmarksPage?.activate?.();
       }
+      const aiDebugSection = document.querySelector('[data-view="ai-debug"]');
+      if (aiDebugSection && aiDebugSection.classList.contains('app-view--active')) {
+        window.AIDebugPage?.activate?.();
+      }
     })();