Add end-to-end AI timing traces and AI debug view

This commit is contained in:
2026-02-20 14:10:06 +01:00
parent 4c187dab3c
commit af3b07b80f
6 changed files with 1705 additions and 210 deletions

View File

@@ -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
});
}
};