diff --git a/src/api/routes/deliveryParse.js b/src/api/routes/deliveryParse.js index 080aee6..047603e 100644 --- a/src/api/routes/deliveryParse.js +++ b/src/api/routes/deliveryParse.js @@ -212,6 +212,11 @@ async function parseDocumentManifest({ req, res, pages, sourceLabel }) { }, }, invoke: async (args) => { + const basedataKeys = args.basedata && typeof args.basedata === 'object' ? Object.keys(args.basedata) : []; + const notesCount = Array.isArray(args.notes) ? args.notes.length : 0; + const itemsCount = args.items?.items && Array.isArray(args.items.items) ? args.items.items.length : 0; + console.log(`[llmorbiter] Tool invoke output_manifest: basedata=[${basedataKeys.join(', ')}], notes=${notesCount}, items=${itemsCount}`); + // Merge basedata if (args.basedata && typeof args.basedata === 'object') { for (const key of ['date', 'kLieferant', 'lieferantName', 'manifestNr', 'manifestType']) { @@ -259,35 +264,78 @@ async function parseDocumentManifest({ req, res, pages, sourceLabel }) { const model = '~openai/gpt-luna-latest:floor'; const provider = new OpenRouterProvider({ apiKey }); const orbiter = new LLMOrbiter(provider, { - onStatus: (status) => sseWrite(res, 'status', { message: status }), - onLLMCall: (call) => + onStatus: (status) => { + console.log(`[llmorbiter] Status: ${status}`); + sseWrite(res, 'status', { message: status }); + }, + onLLMCall: (call) => { + console.log( + `[llmorbiter] LLM call (iteration ${call.iteration}): model=${call.model}, promptSize=${call.promptSize} chars, messages=${call.messageCount || call.messages}` + ); sseWrite(res, 'llm_call', { model: call.model, promptSize: call.promptSize, messages: call.messages, - }), - onToolCall: (call) => sseWrite(res, 'tool_call', { name: call.name }), - onUsage: (usage) => + }); + }, + onToolCall: (call) => { + const details = []; + if (call.args?.basedata) details.push(`basedata: [${Object.keys(call.args.basedata).join(', ')}]`); + if (call.args?.items?.items) details.push(`items: ${call.args.items.items.length}`); + if (call.args?.notes) details.push(`notes: ${call.args.notes.length}`); + const suffix = details.length ? ` (${details.join(', ')})` : ''; + console.log(`[llmorbiter] Tool call: ${call.name}${suffix}`); + sseWrite(res, 'tool_call', { name: call.name }); + }, + onToolResult: (call) => { + console.log(`[llmorbiter] Tool result: ${call.name}`); + }, + onToolError: (call) => { + console.error(`[llmorbiter] Tool error in ${call.name}:`, call.error); + }, + onUsage: (usage) => { + const costStr = usage.cost != null ? `, cost=$${usage.cost.toFixed(4)}` : ''; + console.log( + `[llmorbiter] Usage: input=${usage.input}, cached=${usage.cached}, output=${usage.output}${costStr}` + ); sseWrite(res, 'usage', { input: usage.input, cached: usage.cached, output: usage.output, cost: usage.cost, - }), + }); + }, }); + const abortController = new AbortController(); + abortController.signal.addEventListener('abort', () => { + const reason = abortController.signal.reason; + const msg = reason instanceof Error ? reason.message : String(reason || 'aborted'); + console.log(`[llmorbiter] Abort signal triggered: ${msg}`); + }); + + const originalAbort = orbiter.abort.bind(orbiter); + orbiter.abort = (reason) => { + const reasonMsg = reason instanceof Error ? reason.message : String(reason || 'aborted'); + console.log(`[llmorbiter] orbiter.abort() called (reason: ${reasonMsg})`); + return originalAbort(reason); + }; + const onDisconnect = () => { - if (!res.writableEnded) { - orbiter.abort(); + if (!res.writableEnded && !abortController.signal.aborted) { + console.log('[llmorbiter] Client connection closed, aborting request'); + abortController.abort('Client connection closed'); + orbiter.abort('Client connection closed'); } }; - req.on('close', onDisconnect); res.on('close', onDisconnect); // ── Process all pages in one batch ─────────────────────────────── try { - if (res.destroyed || req.destroyed) { - orbiter.abort(); + if (res.destroyed || res.writableEnded) { + console.log('[llmorbiter] Response already closed or destroyed before run, aborting'); + abortController.abort('Response closed before run'); + orbiter.abort('Response closed before run'); return; } @@ -311,22 +359,30 @@ ${JSON.stringify(manifestItems, null, 2)} Page content: ${pageContent}`; + console.log(`[llmorbiter] Starting run: model=${model}, pages=${pages.length} (${sourceLabel})`); currentPage = 1; - await orbiter.run({ prompt, model, tools: [outputManifestTool] }); + await orbiter.run({ prompt, model, tools: [outputManifestTool], signal: abortController.signal }); + console.log(`[llmorbiter] Run completed successfully. Extracted ${manifestItems.items.length} item(s), ${manifestNotes.length} note(s)`); } catch (err) { + if (err.name === 'AbortError' || abortController.signal.aborted) { + console.log(`[llmorbiter] Run aborted: ${err.message || abortController.signal.reason?.message || 'AbortError'}`); + } else { + console.error('[llmorbiter] Run failed with error:', err); + } if (!res.writableEnded && !res.destroyed) { sseWrite(res, 'error', { message: 'LLM processing failed: ' + err.message }); } } finally { - req.off('close', onDisconnect); res.off('close', onDisconnect); } if (res.writableEnded || res.destroyed) { + console.log('[llmorbiter] Response ended or destroyed, skipping final result'); return; } // ── Final result ───────────────────────────────────────────────── + console.log(`[llmorbiter] Emitting final result event and closing stream`); sseWrite(res, 'result', { basedata: manifestBasedata, notes: manifestNotes, @@ -462,13 +518,18 @@ export function register(app, basePath = '') { return res.status(400).json({ error: 'A document file is required (field name: file)' }); } + const sourceLabel = isPdfUpload(req.file) ? 'PDF' : 'Text'; + console.log(`[deliveryParse] Received file "${req.file.originalname}" (${req.file.size} bytes, type=${sourceLabel})`); + let pages; try { - pages = isPdfUpload(req.file) ? readPdfPages(req.file.buffer) : readTxtPages(req.file.buffer); + pages = sourceLabel === 'PDF' ? readPdfPages(req.file.buffer) : readTxtPages(req.file.buffer); } catch (err) { + console.error(`[deliveryParse] Failed to parse document: ${err.message}`); return res.status(400).json({ error: 'Failed to parse document: ' + err.message }); } if (pages.length === 0) { + console.warn('[deliveryParse] Document content is empty'); return res.status(400).json({ error: 'Document content is empty' }); } @@ -476,7 +537,7 @@ export function register(app, basePath = '') { req, res, pages, - sourceLabel: isPdfUpload(req.file) ? 'PDF' : 'Text', + sourceLabel, }); }, );