diff --git a/eslint.config.js b/eslint.config.js new file mode 100644 index 0000000..d752960 --- /dev/null +++ b/eslint.config.js @@ -0,0 +1,12 @@ +import pluginConfig from '@elizaos/config/eslint/eslint.config.plugin.js'; + +/** + * ESLint configuration for plugin-knowledge + * Extends the standard ElizaOS plugin configuration which includes: + * - @elizaos/structured-logging rule (enforces LOGGING_SPEC.md) + * - TypeScript support + * - Standard code quality rules + */ +export default [ + ...pluginConfig, +]; diff --git a/package.json b/package.json index 47046a5..16052f2 100644 --- a/package.json +++ b/package.json @@ -1,7 +1,7 @@ { "name": "@elizaos/plugin-knowledge", "description": "Plugin for Knowledge", - "version": "1.5.15", + "version": "1.5.16", "type": "module", "main": "dist/index.js", "module": "dist/index.js", @@ -47,15 +47,20 @@ "zod": "3.25.76" }, "devDependencies": { + "@elizaos/config": "^1.6.4", + "@eslint/js": "^9.17.0", "@radix-ui/react-tabs": "^1.1.12", "@tailwindcss/vite": "^4.1.0", "@types/bun": "^1.2.22", "@types/multer": "^2.0.0", "@types/react": "^19.1.8", "@types/react-dom": "^19.1.6", + "@typescript-eslint/eslint-plugin": "^8.22.0", + "@typescript-eslint/parser": "^8.22.0", "@vitejs/plugin-react-swc": "^3.10.0", "autoprefixer": "^10.4.19", "esbuild-plugin-copy": "^2.1.1", + "eslint": "^9.17.0", "postcss": "^8.5.3", "prettier": "3.6.2", "tailwindcss": "^4.1.0", @@ -66,8 +71,9 @@ "scripts": { "dev": "tsup --watch", "build": "vite build && tsup", - "lint": "prettier --write ./src", "test": "elizaos test", + "lint": "eslint ./src --fix && prettier --write ./src", + "lint:check": "eslint ./src", "format": "prettier --write ./src", "format:check": "prettier --check ./src", "clean": "rm -rf dist .turbo node_modules .turbo-tsconfig.json tsconfig.tsbuildinfo" diff --git a/src/actions.ts b/src/actions.ts index 7006cbe..349422d 100644 --- a/src/actions.ts +++ b/src/actions.ts @@ -81,7 +81,7 @@ export const processKnowledgeAction: Action = { // Check if service is available const service = runtime.getService(KnowledgeService.serviceType); if (!service) { - logger.warn('Knowledge service not available for PROCESS_KNOWLEDGE action'); + logger.warn({ src: 'plugin:knowledge:action:process' }, 'Knowledge service not available'); return false; } @@ -196,7 +196,7 @@ export const processKnowledgeAction: Action = { await callback(response); } } catch (error) { - logger.error({ error }, 'Error in PROCESS_KNOWLEDGE action'); + logger.error({ src: 'plugin:knowledge:action:process', error }, 'Error processing knowledge'); const errorResponse: Content = { text: `I encountered an error while processing the knowledge: ${error instanceof Error ? error.message : 'Unknown error'}`, @@ -326,7 +326,7 @@ export const searchKnowledgeAction: Action = { await callback(response); } } catch (error) { - logger.error({ error }, 'Error in SEARCH_KNOWLEDGE action'); + logger.error({ src: 'plugin:knowledge:action:search', error }, 'Error searching knowledge'); const errorResponse: Content = { text: `I encountered an error while searching the knowledge base: ${error instanceof Error ? error.message : 'Unknown error'}`, diff --git a/src/config.ts b/src/config.ts index 88442c7..0e5964e 100644 --- a/src/config.ts +++ b/src/config.ts @@ -28,7 +28,8 @@ export function validateModelConfig(runtime?: IAgentRuntime): ModelConfig { // Log configuration once during validation (not per chunk) logger.debug( - `[Document Processor] CTX_KNOWLEDGE_ENABLED: '${ctxKnowledgeEnabled} (runtime: ${!!runtime})` + { src: 'plugin:knowledge', agentId: runtime?.agentId, ctxKnowledgeEnabled, hasRuntime: !!runtime }, + 'CTX_KNOWLEDGE_ENABLED configuration' ); // If EMBEDDING_PROVIDER is not provided, assume we're using plugin-openai @@ -41,11 +42,13 @@ export function validateModelConfig(runtime?: IAgentRuntime): ModelConfig { if (openaiApiKey && openaiEmbeddingModel) { logger.debug( - '[Document Processor] EMBEDDING_PROVIDER not specified, using configuration from plugin-openai' + { src: 'plugin:knowledge', agentId: runtime?.agentId }, + 'EMBEDDING_PROVIDER not specified, using configuration from plugin-openai' ); } else { logger.debug( - '[Document Processor] EMBEDDING_PROVIDER not specified. Assuming embeddings are provided by another plugin (e.g., plugin-google-genai).' + { src: 'plugin:knowledge', agentId: runtime?.agentId }, + 'EMBEDDING_PROVIDER not specified, assuming embeddings are provided by another plugin' ); } } @@ -89,7 +92,7 @@ export function validateModelConfig(runtime?: IAgentRuntime): ModelConfig { LOAD_DOCS_ON_STARTUP: parseBooleanEnv(getSetting('LOAD_DOCS_ON_STARTUP')), CTX_KNOWLEDGE_ENABLED: ctxKnowledgeEnabled, }); - validateConfigRequirements(config, assumePluginOpenAI); + validateConfigRequirements(config, assumePluginOpenAI, runtime); return config; } catch (error) { if (error instanceof z.ZodError) { @@ -108,7 +111,7 @@ export function validateModelConfig(runtime?: IAgentRuntime): ModelConfig { * @param assumePluginOpenAI Whether we're assuming plugin-openai is being used * @throws Error if a required configuration value is missing */ -function validateConfigRequirements(config: ModelConfig, assumePluginOpenAI: boolean): void { +function validateConfigRequirements(config: ModelConfig, assumePluginOpenAI: boolean, runtime?: IAgentRuntime): void { // Only validate embedding requirements if EMBEDDING_PROVIDER is explicitly set const embeddingProvider = config.EMBEDDING_PROVIDER; @@ -123,7 +126,8 @@ function validateConfigRequirements(config: ModelConfig, assumePluginOpenAI: boo // If no embedding provider is set, skip validation - let runtime handle it if (!embeddingProvider) { logger.debug( - '[Document Processor] No EMBEDDING_PROVIDER specified. Embeddings will be handled by the runtime.' + { src: 'plugin:knowledge', agentId: runtime?.agentId }, + 'No EMBEDDING_PROVIDER specified. Embeddings will be handled by the runtime.' ); } @@ -136,7 +140,7 @@ function validateConfigRequirements(config: ModelConfig, assumePluginOpenAI: boo // If Contextual Knowledge is enabled, we need additional validations if (config.CTX_KNOWLEDGE_ENABLED) { // Only log validation once during config init (not per document) - logger.debug('[Document Processor] CTX validation: Checking text generation settings...'); + logger.debug({ src: 'plugin:knowledge', agentId: runtime?.agentId }, 'CTX validation: Checking text generation settings'); // Validate API keys based on the text provider if (config.TEXT_PROVIDER === 'openai' && !config.OPENAI_API_KEY) { @@ -157,21 +161,24 @@ function validateConfigRequirements(config: ModelConfig, assumePluginOpenAI: boo const modelName = config.TEXT_MODEL?.toLowerCase() || ''; if (modelName.includes('claude') || modelName.includes('gemini')) { logger.debug( - `[Document Processor] Using ${modelName} with OpenRouter. This configuration supports document caching for improved performance.` + { src: 'plugin:knowledge', agentId: runtime?.agentId, modelName, provider: 'openrouter' }, + 'Using model with OpenRouter. This configuration supports document caching for improved performance.' ); } } } else { // Log appropriate message based on where embedding config came from - logger.info('[Document Processor] Contextual Knowledge is DISABLED!'); - logger.info('[Document Processor] This means documents will NOT be enriched with context.'); + logger.info({ src: 'plugin:knowledge', agentId: runtime?.agentId }, 'Contextual Knowledge is DISABLED'); + logger.info({ src: 'plugin:knowledge', agentId: runtime?.agentId }, 'Documents will NOT be enriched with context'); if (assumePluginOpenAI) { logger.info( - '[Document Processor] Embeddings will be handled by the runtime (e.g., plugin-openai, plugin-google-genai).' + { src: 'plugin:knowledge', agentId: runtime?.agentId }, + 'Embeddings will be handled by the runtime (e.g., plugin-openai, plugin-google-genai)' ); } else { logger.info( - '[Document Processor] Using configured embedding provider for basic embeddings only.' + { src: 'plugin:knowledge', agentId: runtime?.agentId }, + 'Using configured embedding provider for basic embeddings only' ); } } @@ -204,7 +211,8 @@ export async function getProviderRateLimits(runtime?: IAgentRuntime): Promise { if (!fullDocumentText || fullDocumentText.trim() === '') { - logger.warn(`No text content available to chunk for document ${documentId}.`); + logger.warn({ src: 'plugin:knowledge', agentId: agentId, documentId }, 'No text content available to chunk'); return 0; } @@ -138,12 +138,12 @@ export async function processFragmentsSynchronously({ const chunks = await splitDocumentIntoChunks(fullDocumentText); if (chunks.length === 0) { - logger.warn(`No chunks generated from text for ${documentId}. No fragments to save.`); + logger.warn({ src: 'plugin:knowledge', agentId: agentId, documentId }, 'No chunks generated from text'); return 0; } const docName = documentTitle || documentId.substring(0, 8); - logger.info(`[Document Processor] "${docName}": Split into ${chunks.length} chunks`); + logger.info({ src: 'plugin:knowledge', agentId: agentId, documentId, documentTitle: docName, chunksCount: chunks.length }, 'Document split into chunks'); // Get provider limits for rate limiting const providerLimits = await getProviderRateLimits(); @@ -154,7 +154,8 @@ export async function processFragmentsSynchronously({ ); logger.debug( - `[Document Processor] Rate limits: ${providerLimits.requestsPerMinute} RPM, ${providerLimits.tokensPerMinute} TPM (${providerLimits.provider}, concurrency: ${CONCURRENCY_LIMIT})` + { src: 'plugin:knowledge', agentId: agentId, rpm: providerLimits.requestsPerMinute, tpm: providerLimits.tokensPerMinute, provider: providerLimits.provider, concurrency: CONCURRENCY_LIMIT }, + 'Rate limits configured' ); // Process and save fragments @@ -178,12 +179,14 @@ export async function processFragmentsSynchronously({ if (failedCount > 0) { logger.warn( - `[Document Processor] "${docName}": ${failedCount}/${chunks.length} chunks failed processing` + { src: 'plugin:knowledge', agentId: agentId, documentId, documentTitle: docName, failedCount, totalChunks: chunks.length }, + 'Some chunks failed processing' ); } logger.info( - `[Document Processor] "${docName}" complete: ${savedCount}/${chunks.length} fragments saved (${successRate}% success)` + { src: 'plugin:knowledge', agentId: agentId, documentId, documentTitle: docName, savedCount, totalChunks: chunks.length, successRate }, + 'Document processing complete' ); // Provide comprehensive end summary @@ -223,10 +226,10 @@ export async function extractTextFromDocument( try { if (contentType === 'application/pdf') { - logger.debug(`Extracting text from PDF: ${originalFilename}`); + logger.debug({ src: 'plugin:knowledge', filename: originalFilename }, 'Extracting text from PDF'); return await convertPdfToTextFromBuffer(fileBuffer, originalFilename); } else { - logger.debug(`Extracting text from non-PDF: ${originalFilename} (Type: ${contentType})`); + logger.debug({ src: 'plugin:knowledge', filename: originalFilename, contentType }, 'Extracting text from non-PDF'); // For plain text files, try UTF-8 decoding first if ( @@ -238,7 +241,8 @@ export async function extractTextFromDocument( return fileBuffer.toString('utf8'); } catch (textError) { logger.warn( - `Failed to decode ${originalFilename} as UTF-8, falling back to binary extraction` + { src: 'plugin:knowledge', filename: originalFilename }, + 'Failed to decode as UTF-8, falling back to binary extraction' ); } } @@ -247,7 +251,7 @@ export async function extractTextFromDocument( return await extractTextFromFileBuffer(fileBuffer, contentType, originalFilename); } } catch (error: any) { - logger.error(`Error extracting text from ${originalFilename}: ${error.message}`); + logger.error({ src: 'plugin:knowledge', filename: originalFilename, error: error.message }, 'Error extracting text'); throw new Error(`Failed to extract text from ${originalFilename}: ${error.message}`); } } @@ -326,8 +330,8 @@ async function splitDocumentIntoChunks(documentText: string): Promise const targetCharChunkOverlap = Math.round(tokenChunkOverlap * DEFAULT_CHARS_PER_TOKEN); logger.debug( - `Using core splitChunks with settings: tokenChunkSize=${tokenChunkSize}, tokenChunkOverlap=${tokenChunkOverlap}, ` + - `charChunkSize=${targetCharChunkSize}, charChunkOverlap=${targetCharChunkOverlap}` + { src: 'plugin:knowledge', tokenChunkSize, tokenChunkOverlap, charChunkSize: targetCharChunkSize, charChunkOverlap: targetCharChunkOverlap }, + 'Using core splitChunks' ); // Split the text into chunks @@ -380,7 +384,8 @@ async function processAndSaveFragments({ const batchOriginalIndices = Array.from({ length: batchChunks.length }, (_, k) => i + k); logger.debug( - `[Document Processor] Batch ${Math.floor(i / concurrencyLimit) + 1}/${Math.ceil(chunks.length / concurrencyLimit)}: processing ${batchChunks.length} chunks (${batchOriginalIndices[0]}-${batchOriginalIndices[batchOriginalIndices.length - 1]})` + { src: 'plugin:knowledge', agentId: agentId, batchNumber: Math.floor(i / concurrencyLimit) + 1, totalBatches: Math.ceil(chunks.length / concurrencyLimit), chunksInBatch: batchChunks.length, chunkRange: `${batchOriginalIndices[0]}-${batchOriginalIndices[batchOriginalIndices.length - 1]}` }, + 'Processing batch' ); // Process context generation in an optimized batch @@ -407,7 +412,7 @@ async function processAndSaveFragments({ if (!result.success) { failedCount++; failedChunks.push(originalChunkIndex); - logger.warn(`Failed to process chunk ${originalChunkIndex} for document ${documentId}`); + logger.warn({ src: 'plugin:knowledge', agentId: agentId, documentId, chunkIndex: originalChunkIndex }, 'Failed to process chunk'); continue; } @@ -416,7 +421,8 @@ async function processAndSaveFragments({ if (!embedding || embedding.length === 0) { logger.warn( - `Zero vector detected for chunk ${originalChunkIndex} (document ${documentId}). Embedding: ${JSON.stringify(result.embedding)}` + { src: 'plugin:knowledge', agentId: agentId, documentId, chunkIndex: originalChunkIndex }, + 'Zero vector detected' ); failedCount++; failedChunks.push(originalChunkIndex); @@ -446,14 +452,15 @@ async function processAndSaveFragments({ if (originalChunkIndex === chunks.length - 1) { const docName = documentTitle || documentId.substring(0, 8); logger.info( - `[Document Processor] "${docName}": All ${chunks.length} chunks processed successfully` + { src: 'plugin:knowledge', agentId: agentId, documentId, documentTitle: docName, chunksCount: chunks.length }, + 'All chunks processed successfully' ); } savedCount++; } catch (saveError: any) { logger.error( - `Error saving chunk ${originalChunkIndex} to database: ${saveError.message}`, - saveError.stack + { src: 'plugin:knowledge', agentId: agentId, documentId, chunkIndex: originalChunkIndex, error: saveError.message }, + 'Error saving chunk to database' ); failedCount++; failedChunks.push(originalChunkIndex); @@ -544,7 +551,8 @@ async function generateEmbeddingsForChunks( }; } catch (error: any) { logger.error( - `Error generating embedding for chunk ${contextualizedChunk.index}: ${error.message}` + { src: 'plugin:knowledge', agentId: runtime.agentId, chunkIndex: contextualizedChunk.index, error: error.message }, + 'Error generating embedding for chunk' ); return { success: false, @@ -580,7 +588,8 @@ async function getContextualizedChunks( const provider = runtime?.getSetting('TEXT_PROVIDER') || process.env.TEXT_PROVIDER; const model = runtime?.getSetting('TEXT_MODEL') || process.env.TEXT_MODEL; logger.info( - `[Document Processor] "${docName}": CTX enrichment ${ctxEnabled ? 'ENABLED' : 'DISABLED'}${ctxEnabled ? ` (${provider}/${model})` : ''}` + { src: 'plugin:knowledge', agentId: runtime.agentId, documentTitle: docName, ctxEnabled, provider, model }, + 'CTX enrichment configuration' ); } @@ -596,7 +605,8 @@ async function getContextualizedChunks( ); } else if (!ctxEnabled && batchOriginalIndices[0] === 0) { logger.debug( - `[Document Processor] To enable CTX: Set CTX_KNOWLEDGE_ENABLED=true and configure TEXT_PROVIDER/TEXT_MODEL` + { src: 'plugin:knowledge', agentId: runtime.agentId }, + 'To enable CTX: Set CTX_KNOWLEDGE_ENABLED=true and configure TEXT_PROVIDER/TEXT_MODEL' ); } @@ -638,7 +648,8 @@ async function generateContextsInBatch( config.TEXT_MODEL?.toLowerCase().includes('gemini')); logger.debug( - `[Document Processor] Contextualizing ${chunks.length} chunks with ${config.TEXT_PROVIDER}/${config.TEXT_MODEL} (cache: ${isUsingCacheCapableModel})` + { src: 'plugin:knowledge', agentId: runtime.agentId, chunksCount: chunks.length, provider: config.TEXT_PROVIDER, model: config.TEXT_MODEL, cacheEnabled: isUsingCacheCapableModel }, + 'Contextualizing chunks' ); // Prepare prompts or system messages in parallel @@ -715,7 +726,8 @@ async function generateContextsInBatch( ) { const docName = documentTitle || 'Document'; logger.debug( - `[Document Processor] "${docName}": Context added for ${item.originalIndex + 1}/${chunks.length} chunks` + { src: 'plugin:knowledge', agentId: runtime.agentId, documentTitle: docName, processedChunks: item.originalIndex + 1, totalChunks: chunks.length }, + 'Context added for chunks' ); } @@ -726,8 +738,8 @@ async function generateContextsInBatch( }; } catch (error: any) { logger.error( - `Error generating context for chunk ${item.originalIndex}: ${error.message}`, - error.stack + { src: 'plugin:knowledge', agentId: runtime.agentId, chunkIndex: item.originalIndex, error: error.message }, + 'Error generating context for chunk' ); return { contextualizedText: item.chunkText, @@ -764,7 +776,8 @@ function prepareContextPrompts( // If there was an error in prompt generation if (cachingPromptInfo.prompt.startsWith('Error:')) { logger.warn( - `Skipping contextualization for chunk ${originalIndex} due to: ${cachingPromptInfo.prompt}` + { src: 'plugin:knowledge', chunkIndex: originalIndex, reason: cachingPromptInfo.prompt }, + 'Skipping contextualization for chunk' ); return { originalIndex, @@ -790,7 +803,7 @@ function prepareContextPrompts( : getContextualizationPrompt(fullDocumentText, chunkText); if (prompt.startsWith('Error:')) { - logger.warn(`Skipping contextualization for chunk ${originalIndex} due to: ${prompt}`); + logger.warn({ src: 'plugin:knowledge', chunkIndex: originalIndex, reason: prompt }, 'Skipping contextualization for chunk'); return { prompt: null, originalIndex, @@ -810,8 +823,8 @@ function prepareContextPrompts( } } catch (error: any) { logger.error( - `Error preparing prompt for chunk ${originalIndex}: ${error.message}`, - error.stack + { src: 'plugin:knowledge', chunkIndex: originalIndex, error: error.message }, + 'Error preparing prompt for chunk' ); return { prompt: null, @@ -852,7 +865,7 @@ async function generateEmbeddingWithValidation( // Validate embedding if (!embedding || embedding.length === 0) { - logger.warn(`Zero vector detected. Embedding result: ${JSON.stringify(embedding)}`); + logger.warn({ src: 'plugin:knowledge', agentId: runtime.agentId }, 'Zero vector detected'); return { embedding: null, success: false, @@ -880,14 +893,14 @@ async function withRateLimitRetry( if (error.status === 429) { // Handle rate limiting with exponential backoff const delay = retryDelay || error.headers?.['retry-after'] || 5; - logger.warn(`Rate limit hit for ${errorContext}. Retrying after ${delay}s`); + logger.warn({ src: 'plugin:knowledge', errorContext, retryDelay: delay }, 'Rate limit hit, retrying'); await new Promise((resolve) => setTimeout(resolve, delay * 1000)); // Try one more time try { return await operation(); } catch (retryError: any) { - logger.error(`Failed after retry for ${errorContext}: ${retryError.message}`); + logger.error({ src: 'plugin:knowledge', errorContext, error: retryError.message }, 'Failed after retry'); throw retryError; } } @@ -941,11 +954,13 @@ function createRateLimiter(requestsPerMinute: number, tokensPerMinute?: number) // Only log significant waits to reduce spam if (timeToWait > 5000) { logger.info( - `[Document Processor] Rate limiting: waiting ${Math.round(timeToWait / 1000)}s due to ${reason} limit` + { src: 'plugin:knowledge', waitTimeSeconds: Math.round(timeToWait / 1000), reason }, + 'Rate limiting: waiting' ); } else { logger.debug( - `[Document Processor] Rate limiting: ${timeToWait}ms wait (${reason} limit)` + { src: 'plugin:knowledge', waitTimeMs: timeToWait, reason }, + 'Rate limiting: waiting' ); } await new Promise((resolve) => setTimeout(resolve, timeToWait)); @@ -982,11 +997,12 @@ function logKnowledgeGenerationSummary({ if (failedCount > 0 || process.env.NODE_ENV === 'development') { const status = failedCount > 0 ? 'PARTIAL' : 'SUCCESS'; logger.info( - `[Document Processor] ${status}: ${savedCount}/${totalChunks} chunks, CTX: ${ctxEnabled ? 'ON' : 'OFF'}, Provider: ${providerLimits.provider}` + { src: 'plugin:knowledge', status, savedCount, totalChunks, ctxEnabled, provider: providerLimits.provider }, + 'Knowledge generation summary' ); } if (failedCount > 0) { - logger.warn(`[Document Processor] ${failedCount} chunks failed processing`); + logger.warn({ src: 'plugin:knowledge', failedCount }, 'Chunks failed processing'); } } diff --git a/src/documents-provider.ts b/src/documents-provider.ts index 05203df..0de0952 100644 --- a/src/documents-provider.ts +++ b/src/documents-provider.ts @@ -23,7 +23,7 @@ export const documentsProvider: Provider = { const knowledgeService = runtime.getService('knowledge') as KnowledgeService; if (!knowledgeService) { - logger.warn('Knowledge service not available for documents provider'); + logger.warn({ src: 'plugin:knowledge:provider:documents', agentId: runtime.agentId }, 'Knowledge service not available'); return { data: { documents: [] }, values: { @@ -119,7 +119,7 @@ export const documentsProvider: Provider = { text: documentsText, }; } catch (error: any) { - logger.error('Error in documents provider:', error.message); + logger.error({ src: 'plugin:knowledge:provider:documents', agentId: runtime.agentId, error: error.message }, 'Error retrieving documents'); return { data: { documents: [], error: error.message }, values: { diff --git a/src/index.ts b/src/index.ts index 4984f08..6c12920 100644 --- a/src/index.ts +++ b/src/index.ts @@ -80,9 +80,9 @@ export function createKnowledgePlugin(config: KnowledgePluginConfig = {}): Plugi // Add routes only if UI or routes are enabled if (enableUI || enableRoutes) { plugin.routes = knowledgeRoutes; - logger.debug('[Knowledge Plugin] Routes enabled'); + logger.debug({ src: 'plugin:knowledge' }, 'Routes enabled'); } else { - logger.info('[Knowledge Plugin] Running in headless mode (no routes or UI)'); + logger.info({ src: 'plugin:knowledge' }, 'Running in headless mode'); } // Add actions if enabled diff --git a/src/llm.ts b/src/llm.ts index 031a67d..b43440f 100644 --- a/src/llm.ts +++ b/src/llm.ts @@ -26,14 +26,14 @@ export async function generateTextEmbedding( try { if (config.EMBEDDING_PROVIDER === 'openai') { - return await generateOpenAIEmbedding(text, config, dimensions); + return await generateOpenAIEmbedding(runtime, text, config, dimensions); } else if (config.EMBEDDING_PROVIDER === 'google') { - return await generateGoogleEmbedding(text, config); + return await generateGoogleEmbedding(runtime, text, config); } throw new Error(`Unsupported embedding provider: ${config.EMBEDDING_PROVIDER}`); } catch (error) { - logger.error({ error }, `[Document Processor] ${config.EMBEDDING_PROVIDER} embedding error`); + logger.error({ src: 'plugin:knowledge', agentId: runtime.agentId, provider: config.EMBEDDING_PROVIDER, error }, 'Embedding error'); throw error; } } @@ -58,7 +58,8 @@ export async function generateTextEmbeddingsBatch( }> = []; logger.debug( - `[Document Processor] Processing ${texts.length} embeddings in batches of ${batchSize}` + { src: 'plugin:knowledge', agentId: runtime.agentId, textsCount: texts.length, batchSize }, + 'Processing embeddings in batches' ); // Process texts in batches @@ -67,7 +68,8 @@ export async function generateTextEmbeddingsBatch( const batchStartIndex = i; logger.debug( - `[Document Processor] Batch ${Math.floor(i / batchSize) + 1}/${Math.ceil(texts.length / batchSize)} (${batch.length} items)` + { src: 'plugin:knowledge', agentId: runtime.agentId, batchNumber: Math.floor(i / batchSize) + 1, totalBatches: Math.ceil(texts.length / batchSize), batchItems: batch.length }, + 'Processing batch' ); // Process batch in parallel @@ -81,7 +83,7 @@ export async function generateTextEmbeddingsBatch( index: globalIndex, }; } catch (error) { - logger.error({ error }, `[Document Processor] Embedding error for item ${globalIndex}`); + logger.error({ src: 'plugin:knowledge', agentId: runtime.agentId, itemIndex: globalIndex, error }, 'Embedding error for item'); return { embedding: null, success: false, @@ -104,7 +106,8 @@ export async function generateTextEmbeddingsBatch( const failureCount = results.length - successCount; logger.debug( - `[Document Processor] Embedding batch complete: ${successCount} success, ${failureCount} failures` + { src: 'plugin:knowledge', agentId: runtime.agentId, successCount, failureCount }, + 'Embedding batch complete' ); return results; @@ -114,6 +117,7 @@ export async function generateTextEmbeddingsBatch( * Generates an embedding using OpenAI */ async function generateOpenAIEmbedding( + runtime: IAgentRuntime, text: string, config: ModelConfig, dimensions: number @@ -142,9 +146,9 @@ async function generateOpenAIEmbedding( const { embedding, usage } = await embed(embedOptions); const totalTokens = (usage as { totalTokens?: number })?.totalTokens; - const usageMessage = totalTokens ? `${totalTokens} total tokens` : 'Usage details N/A'; logger.debug( - `[Document Processor] OpenAI embedding ${config.TEXT_EMBEDDING_MODEL}${embedOptions.dimensions ? ` (${embedOptions.dimensions}D)` : ''}: ${usageMessage}` + { src: 'plugin:knowledge', agentId: runtime.agentId, model: config.TEXT_EMBEDDING_MODEL, dimensions: embedOptions.dimensions, totalTokens }, + 'OpenAI embedding generated' ); return { embedding }; @@ -154,6 +158,7 @@ async function generateOpenAIEmbedding( * Generates an embedding using Google */ async function generateGoogleEmbedding( + runtime: IAgentRuntime, text: string, config: ModelConfig ): Promise<{ embedding: number[] }> { @@ -172,9 +177,9 @@ async function generateGoogleEmbedding( }); const totalTokens = (usage as { totalTokens?: number })?.totalTokens; - const usageMessage = totalTokens ? `${totalTokens} total tokens` : 'Usage details N/A'; logger.debug( - `[Document Processor] Google embedding ${config.TEXT_EMBEDDING_MODEL}: ${usageMessage}` + { src: 'plugin:knowledge', agentId: runtime.agentId, model: config.TEXT_EMBEDDING_MODEL, totalTokens }, + 'Google embedding generated' ); return { embedding }; @@ -227,11 +232,12 @@ export async function generateText( try { switch (provider) { case 'anthropic': - return await generateAnthropicText(config, prompt, system, modelName!, maxTokens); + return await generateAnthropicText(runtime, config, prompt, system, modelName!, maxTokens); case 'openai': - return await generateOpenAIText(config, prompt, system, modelName!, maxTokens); + return await generateOpenAIText(runtime, config, prompt, system, modelName!, maxTokens); case 'openrouter': return await generateOpenRouterText( + runtime, config, prompt, system, @@ -242,12 +248,12 @@ export async function generateText( autoCacheContextualRetrieval ); case 'google': - return await generateGoogleText(prompt, system, modelName!, maxTokens, config); + return await generateGoogleText(runtime, config, prompt, system, modelName!, maxTokens); default: throw new Error(`Unsupported text provider: ${provider}`); } } catch (error) { - logger.error({ error }, `[Document Processor] ${provider} ${modelName} error`); + logger.error({ src: 'plugin:knowledge', agentId: runtime.agentId, provider, model: modelName, error }, 'Text generation error'); throw error; } } @@ -256,6 +262,7 @@ export async function generateText( * Generates text using the Anthropic API with exponential backoff retry */ async function generateAnthropicText( + runtime: IAgentRuntime, config: ModelConfig, prompt: string, system: string | undefined, @@ -283,7 +290,8 @@ async function generateAnthropicText( const totalTokens = (result.usage.inputTokens || 0) + (result.usage.outputTokens || 0); logger.debug( - `[Document Processor] ${modelName}: ${totalTokens} tokens (${result.usage.inputTokens || 0}→${result.usage.outputTokens || 0})` + { src: 'plugin:knowledge', agentId: runtime.agentId, model: modelName, totalTokens, inputTokens: result.usage.inputTokens, outputTokens: result.usage.outputTokens }, + 'Anthropic text generated' ); return result; @@ -298,7 +306,8 @@ async function generateAnthropicText( // Exponential backoff: 2^attempt seconds (2s, 4s, 8s) const delay = Math.pow(2, attempt + 1) * 1000; logger.warn( - `[Document Processor] Rate limit hit (${modelName}): attempt ${attempt + 1}/${maxRetries}, retrying in ${Math.round(delay / 1000)}s` + { src: 'plugin:knowledge', agentId: runtime.agentId, model: modelName, attempt: attempt + 1, maxRetries, delayMs: delay }, + 'Rate limit hit, retrying' ); await new Promise((resolve) => setTimeout(resolve, delay)); continue; @@ -316,6 +325,7 @@ async function generateAnthropicText( * Generates text using the OpenAI API */ async function generateOpenAIText( + runtime: IAgentRuntime, config: ModelConfig, prompt: string, system: string | undefined, @@ -339,7 +349,8 @@ async function generateOpenAIText( const totalTokens = (result.usage.inputTokens || 0) + (result.usage.outputTokens || 0); logger.debug( - `[Document Processor] OpenAI ${modelName}: ${totalTokens} tokens (${result.usage.inputTokens || 0}→${result.usage.outputTokens || 0})` + { src: 'plugin:knowledge', agentId: runtime.agentId, provider: 'openai', model: modelName, totalTokens, inputTokens: result.usage.inputTokens, outputTokens: result.usage.outputTokens }, + 'OpenAI text generated' ); return result; @@ -349,11 +360,12 @@ async function generateOpenAIText( * Generates text using Google's API */ async function generateGoogleText( + runtime: IAgentRuntime, + config: ModelConfig, prompt: string, system: string | undefined, modelName: string, - maxTokens: number, - config: ModelConfig + maxTokens: number ): Promise> { // Use the google provider directly const googleProvider = google; @@ -375,7 +387,8 @@ async function generateGoogleText( const totalTokens = (result.usage.inputTokens || 0) + (result.usage.outputTokens || 0); logger.debug( - `[Document Processor] Google ${modelName}: ${totalTokens} tokens (${result.usage.inputTokens || 0}→${result.usage.outputTokens || 0})` + { src: 'plugin:knowledge', agentId: runtime.agentId, provider: 'google', model: modelName, totalTokens, inputTokens: result.usage.inputTokens, outputTokens: result.usage.outputTokens }, + 'Google text generated' ); return result; @@ -400,6 +413,7 @@ async function generateGoogleText( * @private */ async function generateOpenRouterText( + runtime: IAgentRuntime, config: ModelConfig, prompt: string, system: string | undefined, @@ -431,7 +445,8 @@ async function generateOpenRouterText( if (docMatch && docMatch[1]) { documentForCaching = docMatch[1].trim(); logger.debug( - `[Document Processor] Auto-detected document for caching (${documentForCaching.length} chars)` + { src: 'plugin:knowledge', agentId: runtime.agentId, documentChars: documentForCaching.length }, + 'Auto-detected document for caching' ); } } @@ -446,6 +461,7 @@ async function generateOpenRouterText( if (isClaudeModel) { return await generateClaudeWithCaching( + runtime, promptText, system, modelInstance, @@ -455,6 +471,7 @@ async function generateOpenRouterText( ); } else if (isGeminiModel) { return await generateGeminiWithCaching( + runtime, promptText, system, modelInstance, @@ -467,14 +484,15 @@ async function generateOpenRouterText( } // Standard request without caching - logger.debug('[Document Processor] Using standard request without caching'); - return await generateStandardOpenRouterText(prompt, system, modelInstance, modelName, maxTokens); + logger.debug({ src: 'plugin:knowledge', agentId: runtime.agentId }, 'Using standard request without caching'); + return await generateStandardOpenRouterText(runtime, prompt, system, modelInstance, modelName, maxTokens); } /** * Generates text using Claude with caching via OpenRouter */ async function generateClaudeWithCaching( + runtime: IAgentRuntime, promptText: string, system: string | undefined, modelInstance: any, @@ -482,7 +500,7 @@ async function generateClaudeWithCaching( maxTokens: number, documentForCaching: string ): Promise> { - logger.debug(`[Document Processor] Using explicit prompt caching with Claude ${modelName}`); + logger.debug({ src: 'plugin:knowledge', agentId: runtime.agentId, model: modelName }, 'Using explicit prompt caching with Claude'); // Structure for Claude models const messages = [ @@ -539,8 +557,6 @@ async function generateClaudeWithCaching( : null, ].filter(Boolean); - logger.debug('[Document Processor] Using Claude-specific caching structure'); - // Generate text with cache-enabled structured messages const result = await aiGenerateText({ model: modelInstance, @@ -556,10 +572,11 @@ async function generateClaudeWithCaching( }, }); - logCacheMetrics(result); + logCacheMetrics(runtime, result); const totalTokens = (result.usage.inputTokens || 0) + (result.usage.outputTokens || 0); logger.debug( - `[Document Processor] OpenRouter ${modelName}: ${totalTokens} tokens (${result.usage.inputTokens || 0}→${result.usage.outputTokens || 0})` + { src: 'plugin:knowledge', agentId: runtime.agentId, provider: 'openrouter', model: modelName, totalTokens, inputTokens: result.usage.inputTokens, outputTokens: result.usage.outputTokens }, + 'OpenRouter Claude text generated with caching' ); return result; @@ -569,6 +586,7 @@ async function generateClaudeWithCaching( * Generates text using Gemini with caching via OpenRouter */ async function generateGeminiWithCaching( + runtime: IAgentRuntime, promptText: string, system: string | undefined, modelInstance: any, @@ -587,24 +605,14 @@ async function generateGeminiWithCaching( const likelyTriggersCaching = estimatedDocTokens >= minTokensForImplicitCache; if (usingImplicitCaching) { - logger.debug(`[Document Processor] Using Gemini 2.5 implicit caching with ${modelName}`); logger.debug( - `[Document Processor] Gemini 2.5 models automatically cache large prompts (no cache_control needed)` + { src: 'plugin:knowledge', agentId: runtime.agentId, model: modelName, estimatedDocTokens, minTokensForImplicitCache, likelyTriggersCaching }, + 'Using Gemini 2.5 implicit caching' ); - - if (likelyTriggersCaching) { - logger.debug( - `[Document Processor] Document ~${estimatedDocTokens} tokens exceeds ${minTokensForImplicitCache} token threshold for caching` - ); - } else { - logger.debug( - `[Document Processor] Document ~${estimatedDocTokens} tokens may not meet ${minTokensForImplicitCache} token threshold for caching` - ); - } } else { - logger.debug(`[Document Processor] Using standard prompt format with Gemini ${modelName}`); logger.debug( - `[Document Processor] Note: Only Gemini 2.5 models support automatic implicit caching` + { src: 'plugin:knowledge', agentId: runtime.agentId, model: modelName }, + 'Using standard prompt format with Gemini (only 2.5 models support implicit caching)' ); } @@ -630,11 +638,12 @@ async function generateGeminiWithCaching( }, }); - logCacheMetrics(result); + logCacheMetrics(runtime, result); const totalTokens = (result.usage.inputTokens || 0) + (result.usage.outputTokens || 0); const cachingType = usingImplicitCaching ? 'implicit' : 'standard'; logger.debug( - `[Document Processor] OpenRouter ${modelName} (${cachingType} caching): ${totalTokens} tokens (${result.usage.inputTokens || 0}→${result.usage.outputTokens || 0})` + { src: 'plugin:knowledge', agentId: runtime.agentId, provider: 'openrouter', model: modelName, cachingType, totalTokens, inputTokens: result.usage.inputTokens, outputTokens: result.usage.outputTokens }, + 'OpenRouter Gemini text generated' ); return result; @@ -644,6 +653,7 @@ async function generateGeminiWithCaching( * Generates text using standard OpenRouter API (no caching) */ async function generateStandardOpenRouterText( + runtime: IAgentRuntime, prompt: string, system: string | undefined, modelInstance: any, @@ -667,7 +677,8 @@ async function generateStandardOpenRouterText( const totalTokens = (result.usage.inputTokens || 0) + (result.usage.outputTokens || 0); logger.debug( - `[Document Processor] OpenRouter ${modelName}: ${totalTokens} tokens (${result.usage.inputTokens || 0}→${result.usage.outputTokens || 0})` + { src: 'plugin:knowledge', agentId: runtime.agentId, provider: 'openrouter', model: modelName, totalTokens, inputTokens: result.usage.inputTokens, outputTokens: result.usage.outputTokens }, + 'OpenRouter text generated' ); return result; @@ -676,10 +687,11 @@ async function generateStandardOpenRouterText( /** * Logs cache metrics if available in the result */ -function logCacheMetrics(result: GenerateTextResult): void { +function logCacheMetrics(runtime: IAgentRuntime, result: GenerateTextResult): void { if (result.usage && (result.usage as any).cacheTokens) { logger.debug( - `[Document Processor] Cache metrics - tokens: ${(result.usage as any).cacheTokens}, discount: ${(result.usage as any).cacheDiscount}` + { src: 'plugin:knowledge', agentId: runtime.agentId, cacheTokens: (result.usage as any).cacheTokens, cacheDiscount: (result.usage as any).cacheDiscount }, + 'Cache metrics' ); } } diff --git a/src/provider.ts b/src/provider.ts index bb7179d..b427e90 100644 --- a/src/provider.ts +++ b/src/provider.ts @@ -67,12 +67,12 @@ export const knowledgeProvider: Provider = { try { await knowledgeService.enrichRecentMemoriesWithPendingRAG(); } catch (error: any) { - logger.warn('RAG memory enrichment failed:', error.message); + logger.warn({ src: 'plugin:knowledge:provider:knowledge', agentId: runtime.agentId, error: error.message }, 'RAG memory enrichment failed'); } }, 2000); // 2 second delay } catch (error: any) { // Don't fail the provider if enrichment fails - logger.warn('RAG memory enrichment failed:', error.message); + logger.warn({ src: 'plugin:knowledge:provider:knowledge', agentId: runtime.agentId, error: error.message }, 'RAG memory enrichment failed'); } } diff --git a/src/routes.ts b/src/routes.ts index f99a353..4db09b7 100644 --- a/src/routes.ts +++ b/src/routes.ts @@ -74,7 +74,7 @@ const cleanupFile = (filePath: string) => { try { fs.unlinkSync(filePath); } catch (error) { - logger.error({ error }, `Error cleaning up file ${filePath}`); + logger.error({ src: 'http', error, filePath }, 'Error cleaning up file'); } } }; @@ -114,19 +114,19 @@ async function uploadKnowledgeHandler(req: any, res: any, runtime: IAgentRuntime const invalidFiles = files.filter((file) => { // Check for empty files if (file.size === 0) { - logger.warn(`File ${file.originalname} is empty`); + logger.warn({ src: 'http', method: req.method, path: req.path, filename: file.originalname }, 'File is empty'); return true; } // Check if file has a name if (!file.originalname || file.originalname.trim() === '') { - logger.warn(`File has no name`); + logger.warn({ src: 'http', method: req.method, path: req.path }, 'File has no name'); return true; } // Check if file has valid path if (!file.path) { - logger.warn(`File ${file.originalname} has no path`); + logger.warn({ src: 'http', method: req.method, path: req.path, filename: file.originalname }, 'File has no path'); return true; } @@ -149,7 +149,7 @@ async function uploadKnowledgeHandler(req: any, res: any, runtime: IAgentRuntime const agentId = (req.body.agentId as UUID) || (req.query.agentId as UUID); if (!agentId) { - logger.error('[Document Processor] ❌ No agent ID provided in upload request'); + logger.error({ src: 'http', method: req.method, path: req.path }, 'No agent ID provided in upload request'); return sendError( res, 400, @@ -159,15 +159,13 @@ async function uploadKnowledgeHandler(req: any, res: any, runtime: IAgentRuntime } const worldId = (req.body.worldId as UUID) || agentId; - logger.info(`[Document Processor] 📤 Processing file upload for agent: ${agentId}`); + logger.info({ src: 'http', method: req.method, path: req.path, agentId }, 'Processing file upload'); const processingPromises = files.map(async (file, index) => { const originalFilename = file.originalname; const filePath = file.path; - logger.debug( - `[Document Processor] 📄 Processing file: ${originalFilename} (agent: ${agentId})` - ); + logger.debug({ src: 'http', method: req.method, path: req.path, agentId, filename: originalFilename }, 'Processing file'); try { const fileBuffer = await fs.promises.readFile(filePath); @@ -199,10 +197,7 @@ async function uploadKnowledgeHandler(req: any, res: any, runtime: IAgentRuntime status: 'success', }; } catch (fileError: any) { - logger.error( - `[Document Processor] ❌ Error processing file ${file.originalname}:`, - fileError - ); + logger.error({ src: 'http', method: req.method, path: req.path, filename: file.originalname, error: fileError }, 'Error processing file'); cleanupFile(filePath); return { id: '', // No ID since processing failed @@ -234,7 +229,7 @@ async function uploadKnowledgeHandler(req: any, res: any, runtime: IAgentRuntime const agentId = (req.body.agentId as UUID) || (req.query.agentId as UUID); if (!agentId) { - logger.error('[Document Processor] ❌ No agent ID provided in URL request'); + logger.error({ src: 'http', method: req.method, path: req.path }, 'No agent ID provided in URL request'); return sendError( res, 400, @@ -243,7 +238,7 @@ async function uploadKnowledgeHandler(req: any, res: any, runtime: IAgentRuntime ); } - logger.info(`[Document Processor] 📤 Processing URL upload for agent: ${agentId}`); + logger.info({ src: 'http', method: req.method, path: req.path, agentId }, 'Processing URL upload'); // Process each URL as a distinct file const processingPromises = fileUrls.map(async (fileUrl: string) => { @@ -260,7 +255,7 @@ async function uploadKnowledgeHandler(req: any, res: any, runtime: IAgentRuntime const encodedFilename = pathSegments[pathSegments.length - 1] || 'document.pdf'; const originalFilename = decodeURIComponent(encodedFilename); - logger.debug(`[Document Processor] 🌐 Fetching content from URL: ${fileUrl}`); + logger.debug({ src: 'http', method: req.method, path: req.path, fileUrl }, 'Fetching content from URL'); // Fetch the content from the URL const { content, contentType: fetchedContentType } = await fetchUrlContent(fileUrl); @@ -306,9 +301,7 @@ async function uploadKnowledgeHandler(req: any, res: any, runtime: IAgentRuntime }, }; - logger.debug( - `[Document Processor] 📄 Processing knowledge from URL: ${originalFilename} (type: ${contentType})` - ); + logger.debug({ src: 'http', method: req.method, path: req.path, filename: originalFilename, contentType }, 'Processing knowledge from URL'); const result = await service.addKnowledge(addKnowledgeOpts); return { @@ -321,7 +314,7 @@ async function uploadKnowledgeHandler(req: any, res: any, runtime: IAgentRuntime status: 'success', }; } catch (urlError: any) { - logger.error(`[Document Processor] ❌ Error processing URL ${fileUrl}:`, urlError); + logger.error({ src: 'http', method: req.method, path: req.path, fileUrl, error: urlError }, 'Error processing URL'); return { fileUrl: fileUrl, status: 'error_processing', @@ -334,7 +327,7 @@ async function uploadKnowledgeHandler(req: any, res: any, runtime: IAgentRuntime sendSuccess(res, results); } } catch (error: any) { - logger.error({ error }, '[Document Processor] ❌ Error processing knowledge'); + logger.error({ src: 'http', method: req.method, path: req.path, error }, 'Error processing knowledge'); if (hasUploadedFiles) { cleanupFiles(req.files as MulterFile[]); } @@ -353,11 +346,12 @@ async function getKnowledgeDocumentsHandler(req: any, res: any, runtime: IAgentR ); } + const agentId = req.query.agentId as UUID | undefined; + try { const limit = req.query.limit ? Number.parseInt(req.query.limit as string, 10) : 10000; const before = req.query.before ? Number.parseInt(req.query.before as string, 10) : Date.now(); const includeEmbedding = req.query.includeEmbedding === 'true'; - const agentId = req.query.agentId as UUID | undefined; // Retrieve fileUrls if they are provided in the request const fileUrls = req.query.fileUrls @@ -393,9 +387,7 @@ async function getKnowledgeDocumentsHandler(req: any, res: any, runtime: IAgentR normalizedRequestUrls.includes(normalizeS3Url(memory.metadata.url))) ); - logger.debug( - `[Document Processor] 🔍 Filtered documents by URLs: ${fileUrls.length} URLs, found ${filteredMemories.length} matching documents` - ); + logger.debug({ src: 'http', method: req.method, path: req.path, agentId: agentId, urlCount: fileUrls.length, matchCount: filteredMemories.length }, 'Filtered documents by URLs'); } const cleanMemories = includeEmbedding @@ -411,13 +403,13 @@ async function getKnowledgeDocumentsHandler(req: any, res: any, runtime: IAgentR totalRequested: fileUrls ? fileUrls.length : 0, }); } catch (error: any) { - logger.error({ error }, '[Document Processor] ❌ Error retrieving documents'); + logger.error({ src: 'http', method: req.method, path: req.path, agentId: agentId, error: error.message }, 'Error retrieving documents'); sendError(res, 500, 'RETRIEVAL_ERROR', 'Failed to retrieve documents', error.message); } } async function deleteKnowledgeDocumentHandler(req: any, res: any, runtime: IAgentRuntime) { - logger.debug(`[Document Processor] 🗑️ DELETE request for document: ${req.params.knowledgeId}`); + logger.debug({ src: 'http', method: req.method, path: req.path, knowledgeId: req.params.knowledgeId }, 'Delete document request'); const service = runtime.getService(KnowledgeService.serviceType); if (!service) { @@ -433,26 +425,26 @@ async function deleteKnowledgeDocumentHandler(req: any, res: any, runtime: IAgen const knowledgeId = req.params.knowledgeId; if (!knowledgeId || knowledgeId.length < 36) { - logger.error(`[Document Processor] ❌ Invalid knowledge ID format: ${knowledgeId}`); + logger.error({ src: 'http', method: req.method, path: req.path, knowledgeId }, 'Invalid knowledge ID format'); return sendError(res, 400, 'INVALID_ID', 'Invalid Knowledge ID format'); } try { // Use type conversion with template string to ensure the typing is correct const typedKnowledgeId = knowledgeId as `${string}-${string}-${string}-${string}-${string}`; - logger.debug(`[Document Processor] 🗑️ Deleting document: ${typedKnowledgeId}`); + logger.debug({ src: 'http', method: req.method, path: req.path, knowledgeId: typedKnowledgeId }, 'Deleting document'); await service.deleteMemory(typedKnowledgeId); - logger.info(`[Document Processor] ✅ Successfully deleted document: ${typedKnowledgeId}`); + logger.info({ src: 'http', method: req.method, path: req.path, knowledgeId: typedKnowledgeId }, 'Document deleted'); sendSuccess(res, null, 204); } catch (error: any) { - logger.error({ error }, `[Document Processor] ❌ Error deleting document ${knowledgeId}`); + logger.error({ src: 'http', method: req.method, path: req.path, knowledgeId, error }, 'Error deleting document'); sendError(res, 500, 'DELETE_ERROR', 'Failed to delete document', error.message); } } async function getKnowledgeByIdHandler(req: any, res: any, runtime: IAgentRuntime) { - logger.debug(`[Document Processor] 🔍 GET request for document: ${req.params.knowledgeId}`); + logger.debug({ src: 'http', method: req.method, path: req.path, knowledgeId: req.params.knowledgeId }, 'Get document request'); const service = runtime.getService(KnowledgeService.serviceType); if (!service) { @@ -467,14 +459,15 @@ async function getKnowledgeByIdHandler(req: any, res: any, runtime: IAgentRuntim // Get the ID directly from the route parameters const knowledgeId = req.params.knowledgeId; + const agentId = req.query.agentId as UUID | undefined; + if (!knowledgeId || knowledgeId.length < 36) { - logger.error(`[Document Processor] ❌ Invalid knowledge ID format: ${knowledgeId}`); + logger.error({ src: 'http', method: req.method, path: req.path, agentId: agentId, knowledgeId }, 'Invalid knowledge ID format'); return sendError(res, 400, 'INVALID_ID', 'Invalid Knowledge ID format'); } try { - logger.debug(`[Document Processor] 🔍 Retrieving document: ${knowledgeId}`); - const agentId = req.query.agentId as UUID | undefined; + logger.debug({ src: 'http', method: req.method, path: req.path, agentId: agentId, knowledgeId }, 'Retrieving document'); // Use the service methods instead of calling runtime directly // We can't use getMemoryById directly because it's not exposed by the service @@ -502,7 +495,7 @@ async function getKnowledgeByIdHandler(req: any, res: any, runtime: IAgentRuntim sendSuccess(res, { document: cleanDocument }); } catch (error: any) { - logger.error({ error }, `[Document Processor] ❌ Error retrieving document ${knowledgeId}`); + logger.error({ src: 'http', method: req.method, path: req.path, agentId: agentId, knowledgeId, error: error.message }, 'Error retrieving document'); sendError(res, 500, 'RETRIEVAL_ERROR', 'Failed to retrieve document', error.message); } } @@ -511,7 +504,7 @@ async function getKnowledgeByIdHandler(req: any, res: any, runtime: IAgentRuntim async function knowledgePanelHandler(req: any, res: any, runtime: IAgentRuntime) { const agentId = runtime.agentId; // Get from runtime context - logger.debug(`[Document Processor] 🌐 Serving knowledge panel for agent ${agentId}`); + logger.debug({ src: 'http', method: req.method, path: req.path, agentId }, 'Serving knowledge panel'); // Extract the plugin API base path from the request path // Request path will be like: /api/agents/[uuid]/plugins/knowledge/display @@ -519,14 +512,14 @@ async function knowledgePanelHandler(req: any, res: any, runtime: IAgentRuntime) const requestPath = req.originalUrl || req.url || req.path; const pluginBasePath = requestPath.replace(/\/display.*$/, ''); - logger.debug(`[Document Processor] 🌐 Plugin base path: ${pluginBasePath}`); + logger.debug({ src: 'http', method: req.method, path: req.path, pluginBasePath }, 'Plugin base path'); try { const currentDir = path.dirname(new URL(import.meta.url).pathname); // Serve the main index.html from Vite's build output const frontendPath = path.join(currentDir, '../dist/index.html'); - logger.debug(`[Document Processor] 🌐 Looking for frontend at: ${frontendPath}`); + logger.debug({ src: 'http', method: req.method, path: req.path, frontendPath }, 'Looking for frontend'); if (fs.existsSync(frontendPath)) { const html = await fs.promises.readFile(frontendPath, 'utf8'); @@ -573,12 +566,12 @@ async function knowledgePanelHandler(req: any, res: any, runtime: IAgentRuntime) } } } catch (manifestError) { - logger.error({ error: manifestError }, '[Document Processor] ❌ Error reading manifest'); + logger.error({ src: 'http', method: req.method, path: req.path, error: manifestError }, 'Error reading manifest'); // Continue with default filenames if manifest can't be read } } - logger.debug(`[Document Processor] 🌐 Using fallback with CSS: ${cssFile}, JS: ${jsFile}`); + logger.debug({ src: 'http', method: req.method, path: req.path, cssFile, jsFile }, 'Using fallback assets'); const html = ` @@ -613,17 +606,17 @@ async function knowledgePanelHandler(req: any, res: any, runtime: IAgentRuntime) res.end(html); } } catch (error: any) { - logger.error({ error }, '[Document Processor] ❌ Error serving frontend'); + logger.error({ src: 'http', method: req.method, path: req.path, error }, 'Error serving frontend'); sendError(res, 500, 'FRONTEND_ERROR', 'Failed to load knowledge panel', error.message); } } // Generic handler to serve static assets from the dist/assets directory -async function frontendAssetHandler(req: any, res: any, runtime: IAgentRuntime) { +async function frontendAssetHandler(req: any, res: any, _runtime: IAgentRuntime) { try { // Use originalUrl or url first, fallback to path const fullPath = req.originalUrl || req.url || req.path; - logger.debug(`[Document Processor] 🌐 Asset request: ${fullPath}`); + logger.debug({ src: 'http', method: req.method, path: req.path, fullPath }, 'Asset request'); const currentDir = path.dirname(new URL(import.meta.url).pathname); // The path will be like: /api/agents/X/plugins/knowledge/assets/file.js @@ -652,7 +645,7 @@ async function frontendAssetHandler(req: any, res: any, runtime: IAgentRuntime) } const assetPath = path.join(currentDir, '../dist/assets', assetName); - logger.debug(`[Document Processor] 🌐 Serving asset: ${assetPath}`); + logger.debug({ src: 'http', method: req.method, path: req.path, assetPath }, 'Serving asset'); if (fs.existsSync(assetPath)) { const fileStream = fs.createReadStream(assetPath); @@ -668,7 +661,7 @@ async function frontendAssetHandler(req: any, res: any, runtime: IAgentRuntime) sendError(res, 404, 'NOT_FOUND', `Asset not found: ${req.url}`); } } catch (error: any) { - logger.error({ error }, `[Document Processor] ❌ Error serving asset ${req.url}`); + logger.error({ src: 'http', method: req.method, path: req.path, error }, 'Error serving asset'); sendError(res, 500, 'ASSET_ERROR', `Failed to load asset ${req.url}`, error.message); } } @@ -744,7 +737,7 @@ async function getKnowledgeChunksHandler(req: any, res: any, runtime: IAgentRunt }, }); } catch (error: any) { - logger.error({ error }, '[Document Processor] ❌ Error retrieving chunks'); + logger.error({ src: 'http', method: req.method, path: req.path, error }, 'Error retrieving chunks'); sendError(res, 500, 'RETRIEVAL_ERROR', 'Failed to retrieve knowledge chunks', error.message); } } @@ -755,6 +748,8 @@ async function searchKnowledgeHandler(req: any, res: any, runtime: IAgentRuntime return sendError(res, 500, 'SERVICE_NOT_FOUND', 'KnowledgeService not found'); } + const agentId = (req.query.agentId as UUID) || runtime.agentId; + try { const searchText = req.query.q as string; @@ -774,8 +769,6 @@ async function searchKnowledgeHandler(req: any, res: any, runtime: IAgentRuntime // Clamp limit between 1 and 100 limit = Math.max(1, Math.min(100, limit)); - const agentId = (req.query.agentId as UUID) || runtime.agentId; - if (!searchText || searchText.trim().length === 0) { return sendError(res, 400, 'INVALID_QUERY', 'Search query cannot be empty'); } @@ -783,15 +776,20 @@ async function searchKnowledgeHandler(req: any, res: any, runtime: IAgentRuntime // Log if values were clamped if (req.query.threshold && (parsedThreshold < 0 || parsedThreshold > 1)) { logger.debug( - `[Document Processor] 🔍 Threshold value ${parsedThreshold} was clamped to ${matchThreshold}` + { src: 'http', method: req.method, path: req.path, agentId, originalThreshold: parsedThreshold, clampedThreshold: matchThreshold }, + 'Threshold value was clamped' ); } if (req.query.limit && (parsedLimit < 1 || parsedLimit > 100)) { - logger.debug(`[Document Processor] 🔍 Limit value ${parsedLimit} was clamped to ${limit}`); + logger.debug( + { src: 'http', method: req.method, path: req.path, agentId, originalLimit: parsedLimit, clampedLimit: limit }, + 'Limit value was clamped' + ); } logger.debug( - `[Document Processor] 🔍 Searching: "${searchText}" (threshold: ${matchThreshold}, limit: ${limit})` + { src: 'http', method: req.method, path: req.path, agentId, searchText, threshold: matchThreshold, limit }, + 'Searching knowledge' ); // First get the embedding for the search text @@ -832,7 +830,7 @@ async function searchKnowledgeHandler(req: any, res: any, runtime: IAgentRuntime documentFilename = (document.metadata as any).filename || documentFilename; } } catch (e) { - logger.debug(`Could not fetch document ${documentId} for fragment`); + logger.debug({ src: 'http', method: req.method, path: req.path, agentId: agentId, documentId }, 'Could not fetch document for fragment'); } } @@ -850,7 +848,8 @@ async function searchKnowledgeHandler(req: any, res: any, runtime: IAgentRuntime ); logger.info( - `[Document Processor] 🔍 Found ${enhancedResults.length} results for: "${searchText}"` + { src: 'http', method: req.method, path: req.path, agentId: agentId, resultsCount: enhancedResults.length, searchText }, + 'Search completed' ); sendSuccess(res, { @@ -860,7 +859,7 @@ async function searchKnowledgeHandler(req: any, res: any, runtime: IAgentRuntime count: enhancedResults.length, }); } catch (error: any) { - logger.error({ error }, '[Document Processor] ❌ Error searching knowledge'); + logger.error({ src: 'http', method: req.method, path: req.path, agentId: agentId, error: error.message }, 'Error searching knowledge'); sendError(res, 500, 'SEARCH_ERROR', 'Failed to search knowledge', error.message); } } @@ -873,19 +872,21 @@ async function getGraphNodesHandler(req: any, res: any, runtime: IAgentRuntime) return sendError(res, 500, 'SERVICE_NOT_FOUND', 'KnowledgeService not found'); } + const agentId = (req.query.agentId as UUID) || runtime.agentId; + try { // Parse pagination parameters const parsedPage = req.query.page ? Number.parseInt(req.query.page as string, 10) : 1; const parsedLimit = req.query.limit ? Number.parseInt(req.query.limit as string, 10) : 20; const type = req.query.type as 'document' | 'fragment' | undefined; - const agentId = (req.query.agentId as UUID) || runtime.agentId; const page = Number.isNaN(parsedPage) || parsedPage < 1 ? 1 : parsedPage; const limit = Number.isNaN(parsedLimit) || parsedLimit < 1 ? 20 : Math.min(parsedLimit, 50); const offset = (page - 1) * limit; logger.debug( - `[Graph API] 📊 Fetching graph nodes: page=${page}, limit=${limit}, type=${type || 'all'}, agent=${agentId}` + { src: 'http', method: req.method, path: req.path, page, limit, type: type || 'all', agentId }, + 'Fetching graph nodes' ); // Get total count of documents for pagination metadata @@ -914,7 +915,7 @@ async function getGraphNodesHandler(req: any, res: any, runtime: IAgentRuntime) // Add document nodes (filter out any without IDs) paginatedDocuments.forEach((doc) => { if (!doc.id) { - logger.warn(`[Graph API] ⚠️ Skipping document without ID`); + logger.warn({ src: 'http', method: req.method, path: req.path, agentId: agentId }, 'Skipping document without ID'); return; } nodes.push({ id: doc.id, type: 'document' }); @@ -930,17 +931,13 @@ async function getGraphNodesHandler(req: any, res: any, runtime: IAgentRuntime) count: 50000, // Reduced from 100000 - still high enough for large documents }); - logger.debug(`[Graph API] 📊 Total fragments found: ${allFragments.length}`); + logger.debug({ src: 'http', method: req.method, path: req.path, agentId: agentId, fragmentsCount: allFragments.length }, 'Total fragments found'); // Debug: Log the first few fragment metadata to understand structure if (allFragments.length > 0) { logger.debug( - `[Graph API] 📊 Sample fragment metadata: ${JSON.stringify( - allFragments.slice(0, 3).map((f) => ({ - id: f.id, - metadata: f.metadata, - })) - )}` + { src: 'http', method: req.method, path: req.path, agentId: agentId, sampleFragments: allFragments.slice(0, 3).map((f) => ({ id: f.id, metadata: f.metadata })) }, + 'Sample fragment metadata' ); } @@ -965,7 +962,7 @@ async function getGraphNodesHandler(req: any, res: any, runtime: IAgentRuntime) }); if (docFragments.length > 0) { - logger.debug(`[Graph API] 📊 Document ${doc.id} has ${docFragments.length} fragments`); + logger.debug({ src: 'http', method: req.method, path: req.path, agentId: agentId, documentId: doc.id, fragmentsCount: docFragments.length }, 'Document fragments found'); } // Add fragment nodes and links (filter out any without IDs) @@ -974,7 +971,8 @@ async function getGraphNodesHandler(req: any, res: any, runtime: IAgentRuntime) const docId = doc.id; if (!frag.id || !docId) { logger.warn( - `[Graph API] ⚠️ Skipping fragment without ID for document ${docId || 'unknown'}` + { src: 'http', method: req.method, path: req.path, agentId: agentId, documentId: docId || 'unknown' }, + 'Skipping fragment without ID' ); return; } @@ -984,7 +982,8 @@ async function getGraphNodesHandler(req: any, res: any, runtime: IAgentRuntime) }); logger.info( - `[Graph API] 📊 Final graph: ${nodes.length} nodes (${paginatedDocuments.length} documents), ${links.length} links` + { src: 'http', method: req.method, path: req.path, agentId: agentId, nodesCount: nodes.length, documentsCount: paginatedDocuments.length, linksCount: links.length }, + 'Final graph built' ); } @@ -1000,7 +999,7 @@ async function getGraphNodesHandler(req: any, res: any, runtime: IAgentRuntime) }, }); } catch (error: any) { - logger.error('[Graph API] ❌ Error fetching graph nodes:', error); + logger.error({ src: 'http', method: req.method, path: req.path, agentId: agentId, error: error.message }, 'Error fetching graph nodes'); sendError(res, 500, 'GRAPH_ERROR', 'Failed to fetch graph nodes', error.message); } } @@ -1019,7 +1018,7 @@ async function getGraphNodeDetailsHandler(req: any, res: any, runtime: IAgentRun } try { - logger.info(`[Graph API] 📊 Fetching node details for: ${nodeId}, agent: ${agentId}`); + logger.info({ src: 'http', method: req.method, path: req.path, agentId: agentId, nodeId }, 'Fetching node details'); // Try to find in documents first - don't filter by roomId initially to see if node exists at all const allDocuments = await service.getMemories({ @@ -1027,24 +1026,25 @@ async function getGraphNodeDetailsHandler(req: any, res: any, runtime: IAgentRun count: 10000, }); - logger.debug(`[Graph API] 📊 Total documents in DB: ${allDocuments.length}`); + logger.debug({ src: 'http', method: req.method, path: req.path, agentId: agentId, documentsCount: allDocuments.length }, 'Total documents in DB'); // First try exact match with roomId filter let document = allDocuments.find((doc) => doc.id === nodeId && doc.roomId === agentId); // If not found with roomId filter, try without filter (for backward compatibility) if (!document) { - logger.debug(`[Graph API] 📊 Document not found with roomId filter, trying without filter`); + logger.debug({ src: 'http', method: req.method, path: req.path, agentId: agentId, nodeId }, 'Document not found with roomId filter, trying without filter'); document = allDocuments.find((doc) => doc.id === nodeId); if (document) { logger.warn( - `[Graph API] ⚠️ Document ${nodeId} found but has different roomId: ${document.roomId} vs ${agentId}` + { src: 'http', method: req.method, path: req.path, agentId: agentId, nodeId, documentRoomId: document.roomId }, + 'Document found but has different roomId' ); } } if (document) { - logger.info(`[Graph API] ✅ Found document: ${nodeId}`); + logger.info({ src: 'http', method: req.method, path: req.path, agentId: agentId, nodeId }, 'Found document'); // Return document details without embedding sendSuccess(res, { id: document.id, @@ -1061,31 +1061,32 @@ async function getGraphNodeDetailsHandler(req: any, res: any, runtime: IAgentRun } // If not found in documents, try fragments - logger.debug(`[Graph API] 📊 Document not found, searching in fragments`); + logger.debug({ src: 'http', method: req.method, path: req.path, agentId: agentId, nodeId }, 'Document not found, searching in fragments'); // High limit to support documents with many fragments, but reduced from 100k to prevent memory issues const allFragments = await service.getMemories({ tableName: 'knowledge', count: 50000, // Reduced from 100000 - still high enough for large documents }); - logger.debug(`[Graph API] 📊 Total fragments in DB: ${allFragments.length}`); + logger.debug({ src: 'http', method: req.method, path: req.path, agentId: agentId, fragmentsCount: allFragments.length }, 'Total fragments in DB'); // First try exact match with roomId filter let fragment = allFragments.find((frag) => frag.id === nodeId && frag.roomId === agentId); // If not found with roomId filter, try without filter if (!fragment) { - logger.debug(`[Graph API] 📊 Fragment not found with roomId filter, trying without filter`); + logger.debug({ src: 'http', method: req.method, path: req.path, agentId: agentId, nodeId }, 'Fragment not found with roomId filter, trying without filter'); fragment = allFragments.find((frag) => frag.id === nodeId); if (fragment) { logger.warn( - `[Graph API] ⚠️ Fragment ${nodeId} found but has different roomId: ${fragment.roomId} vs ${agentId}` + { src: 'http', method: req.method, path: req.path, agentId: agentId, nodeId, fragmentRoomId: fragment.roomId }, + 'Fragment found but has different roomId' ); } } if (fragment) { - logger.info(`[Graph API] ✅ Found fragment: ${nodeId}`); + logger.info({ src: 'http', method: req.method, path: req.path, agentId: agentId, nodeId }, 'Found fragment'); sendSuccess(res, { id: fragment.id, type: 'fragment', @@ -1100,10 +1101,10 @@ async function getGraphNodeDetailsHandler(req: any, res: any, runtime: IAgentRun return; } - logger.error(`[Graph API] ❌ Node ${nodeId} not found in documents or fragments`); + logger.error({ src: 'http', method: req.method, path: req.path, agentId: agentId, nodeId }, 'Node not found in documents or fragments'); sendError(res, 404, 'NOT_FOUND', `Node with ID ${nodeId} not found`); } catch (error: any) { - logger.error(`[Graph API] ❌ Error fetching node details for ${nodeId}:`, error); + logger.error({ src: 'http', method: req.method, path: req.path, agentId: agentId, nodeId, error: error.message }, 'Error fetching node details'); sendError(res, 500, 'GRAPH_ERROR', 'Failed to fetch node details', error.message); } } @@ -1122,7 +1123,7 @@ async function expandDocumentGraphHandler(req: any, res: any, runtime: IAgentRun } try { - logger.debug(`[Graph API] 📊 Expanding document: ${documentId}, agent: ${agentId}`); + logger.debug({ src: 'http', method: req.method, path: req.path, agentId: agentId, documentId }, 'Expanding document'); // Get all fragments for this document // High limit to support documents with many fragments, but reduced from 100k to prevent memory issues @@ -1132,18 +1133,20 @@ async function expandDocumentGraphHandler(req: any, res: any, runtime: IAgentRun count: 50000, // Reduced from 100000 - still high enough for large documents }); - logger.debug(`[Graph API] 📊 Total fragments in knowledge table: ${allFragments.length}`); + logger.debug({ src: 'http', method: req.method, path: req.path, agentId: agentId, fragmentsCount: allFragments.length }, 'Total fragments in knowledge table'); // Log a sample fragment to see its structure (only in development/debug mode) if (allFragments.length > 0 && process.env.NODE_ENV !== 'production') { logger.debug( - `[Graph API] 📊 Sample fragment metadata: ${JSON.stringify(allFragments[0].metadata)}` + { src: 'http', method: req.method, path: req.path, agentId: agentId, sampleMetadata: allFragments[0].metadata }, + 'Sample fragment metadata' ); // Log all unique metadata types found const uniqueTypes = new Set(allFragments.map((f) => (f.metadata as any)?.type)); logger.debug( - `[Graph API] 📊 Unique metadata types found in knowledge table: ${JSON.stringify(Array.from(uniqueTypes))}` + { src: 'http', method: req.method, path: req.path, agentId: agentId, uniqueTypes: Array.from(uniqueTypes) }, + 'Unique metadata types found in knowledge table' ); // Log metadata of all fragments for this specific document @@ -1152,14 +1155,16 @@ async function expandDocumentGraphHandler(req: any, res: any, runtime: IAgentRun const hasDocumentId = metadata?.documentId === documentId; if (hasDocumentId) { logger.debug( - `[Graph API] 📊 Fragment ${fragment.id} metadata: ${JSON.stringify(metadata)}` + { src: 'http', method: req.method, path: req.path, agentId: agentId, fragmentId: fragment.id, metadata }, + 'Fragment metadata' ); } return hasDocumentId; }); logger.debug( - `[Graph API] 📊 Fragments with matching documentId: ${relevantFragments.length}` + { src: 'http', method: req.method, path: req.path, agentId: agentId, documentId, matchingFragmentsCount: relevantFragments.length }, + 'Fragments with matching documentId' ); } @@ -1191,7 +1196,7 @@ async function expandDocumentGraphHandler(req: any, res: any, runtime: IAgentRun target: frag.id as UUID, })); - logger.info(`[Graph API] 📊 Found ${nodes.length} fragments for document ${documentId}`); + logger.info({ src: 'http', method: req.method, path: req.path, agentId: agentId, documentId, fragmentsCount: nodes.length }, 'Found fragments for document'); sendSuccess(res, { documentId, @@ -1200,7 +1205,7 @@ async function expandDocumentGraphHandler(req: any, res: any, runtime: IAgentRun fragmentCount: nodes.length, }); } catch (error: any) { - logger.error(`[Graph API] ❌ Error expanding document ${documentId}:`, error); + logger.error({ src: 'http', method: req.method, path: req.path, agentId: agentId, documentId, error: error.message }, 'Error expanding document'); sendError(res, 500, 'GRAPH_ERROR', 'Failed to expand document', error.message); } } @@ -1216,7 +1221,7 @@ async function uploadKnowledgeWithMulter(req: any, res: any, runtime: IAgentRunt // Apply multer middleware manually uploadArray(req, res, (err: any) => { if (err) { - logger.error({ error: err }, '[Document Processor] ❌ File upload error'); + logger.error({ src: 'http', method: req.method, path: req.path, error: err.message }, 'File upload error'); return sendError(res, 400, 'UPLOAD_ERROR', err.message); } // If multer succeeded, call the actual handler diff --git a/src/service.ts b/src/service.ts index e79884e..a819202 100644 --- a/src/service.ts +++ b/src/service.ts @@ -22,15 +22,10 @@ import { } from './document-processor.ts'; import { validateModelConfig } from './config'; import { AddKnowledgeOptions } from './types.ts'; -import type { KnowledgeConfig, LoadResult } from './types'; +import type { LoadResult } from './types'; import { loadDocsFromPath } from './docs-loader'; import { isBinaryContentType, looksLikeBase64, generateContentBasedId } from './utils.ts'; -const parseBooleanEnv = (value: any): boolean => { - if (typeof value === 'boolean') return value; - if (typeof value === 'string') return value.toLowerCase() === 'true'; - return false; // Default to false if undefined or other type -}; /** * Knowledge Service - Provides retrieval augmented generation capabilities @@ -38,7 +33,6 @@ const parseBooleanEnv = (value: any): boolean => { export class KnowledgeService extends Service { static readonly serviceType = 'knowledge'; public override config: Metadata = {}; - private knowledgeConfig: KnowledgeConfig = {} as KnowledgeConfig; capabilityDescription = 'Provides Retrieval Augmented Generation capabilities, including knowledge upload and querying.'; @@ -48,14 +42,15 @@ export class KnowledgeService extends Service { * Create a new Knowledge service * @param runtime Agent runtime */ - constructor(runtime: IAgentRuntime, config?: Partial) { + constructor(runtime: IAgentRuntime) { super(runtime); this.knowledgeProcessingSemaphore = new Semaphore(10); } private async loadInitialDocuments(): Promise { logger.info( - `KnowledgeService: Checking for documents to load on startup for agent ${this.runtime.agentId}` + { src: 'plugin:knowledge', agentId: this.runtime.agentId }, + 'Checking for documents to load on startup' ); try { // Use a small delay to ensure runtime is fully ready if needed, though constructor implies it should be. @@ -73,17 +68,19 @@ export class KnowledgeService extends Service { if (result.successful > 0) { logger.info( - `KnowledgeService: Loaded ${result.successful} documents from docs folder on startup for agent ${this.runtime.agentId}` + { src: 'plugin:knowledge', agentId: this.runtime.agentId, count: result.successful }, + 'Documents loaded from docs folder on startup' ); } else { - logger.info( - `KnowledgeService: No new documents found to load on startup for agent ${this.runtime.agentId}` + logger.debug( + { src: 'plugin:knowledge', agentId: this.runtime.agentId }, + 'No new documents found on startup' ); } } catch (error) { logger.error( - { error }, - `KnowledgeService: Error loading documents on startup for agent ${this.runtime.agentId}` + { src: 'plugin:knowledge', agentId: this.runtime.agentId, error }, + 'Error loading documents on startup' ); } } @@ -94,81 +91,37 @@ export class KnowledgeService extends Service { * @returns Initialized Knowledge service */ static async start(runtime: IAgentRuntime): Promise { - logger.info(`Starting Knowledge service for agent: ${runtime.agentId}`); - - logger.info('Initializing Knowledge Plugin...'); + logger.info({ src: 'plugin:knowledge', agentId: runtime.agentId }, 'Starting service'); let validatedConfig: any = {}; try { - // Validate the model configuration - logger.info('Validating model configuration for Knowledge plugin...'); - - logger.debug(`[Knowledge Plugin] INIT DEBUG:`); - logger.debug( - `[Knowledge Plugin] - process.env.CTX_KNOWLEDGE_ENABLED: '${process.env.CTX_KNOWLEDGE_ENABLED}'` - ); + validatedConfig = validateModelConfig(runtime); - // just for debug/check - const config = { - CTX_KNOWLEDGE_ENABLED: parseBooleanEnv(runtime.getSetting('CTX_KNOWLEDGE_ENABLED')), - }; + const finalCtxEnabled = validatedConfig.CTX_KNOWLEDGE_ENABLED; logger.debug( - `[Knowledge Plugin] - config.CTX_KNOWLEDGE_ENABLED: '${config.CTX_KNOWLEDGE_ENABLED}'` - ); - logger.debug( - `[Knowledge Plugin] - runtime.getSetting('CTX_KNOWLEDGE_ENABLED'): '${runtime.getSetting('CTX_KNOWLEDGE_ENABLED')}'` + { src: 'plugin:knowledge', agentId: runtime.agentId, ctxEnabled: finalCtxEnabled }, + 'Model configuration validated' ); - validatedConfig = validateModelConfig(runtime); - - // Help inform how this was detected - const ctxEnabledFromEnv = parseBooleanEnv(process.env.CTX_KNOWLEDGE_ENABLED); - const ctxEnabledFromRuntime = parseBooleanEnv(runtime.getSetting('CTX_KNOWLEDGE_ENABLED')); - const ctxEnabledFromValidated = validatedConfig.CTX_KNOWLEDGE_ENABLED; - - // Use the most permissive check during initialization - const finalCtxEnabled = ctxEnabledFromValidated; - - logger.debug(`[Knowledge Plugin] CTX_KNOWLEDGE_ENABLED sources:`); - logger.debug(`[Knowledge Plugin] - From env: ${ctxEnabledFromEnv}`); - logger.debug(`[Knowledge Plugin] - From runtime: ${ctxEnabledFromRuntime}`); - logger.debug(`[Knowledge Plugin] - FINAL RESULT: ${finalCtxEnabled}`); - // Log the operational mode if (finalCtxEnabled) { - logger.info('Running in Contextual Knowledge mode with text generation capabilities.'); logger.info( - `Using ${validatedConfig.EMBEDDING_PROVIDER || 'auto-detected'} for embeddings and ${validatedConfig.TEXT_PROVIDER} for text generation.` + { src: 'plugin:knowledge', agentId: runtime.agentId, provider: validatedConfig.TEXT_PROVIDER, model: validatedConfig.TEXT_MODEL }, + 'Running in Contextual Knowledge mode' ); - logger.info(`Text model: ${validatedConfig.TEXT_MODEL}`); } else { - const usingPluginOpenAI = !process.env.EMBEDDING_PROVIDER; - logger.warn( - 'Running in Basic Embedding mode - documents will NOT be enriched with context!' + { src: 'plugin:knowledge', agentId: runtime.agentId }, + 'Running in Basic Embedding mode - documents will NOT be enriched with context' ); - logger.info('To enable contextual enrichment:'); - logger.info(' - Set CTX_KNOWLEDGE_ENABLED=true'); - logger.info(' - Configure TEXT_PROVIDER (anthropic/openai/openrouter/google)'); - logger.info(' - Configure TEXT_MODEL and API key'); - - if (usingPluginOpenAI) { - logger.info('Using auto-detected configuration from plugin-openai for embeddings.'); - } else { - logger.info( - `Using ${validatedConfig.EMBEDDING_PROVIDER} for embeddings with ${validatedConfig.TEXT_EMBEDDING_MODEL}.` - ); - } } - logger.info('Model configuration validated successfully.'); - logger.info(`Knowledge Plugin initialized for agent: ${runtime.character.name}`); - logger.info( - 'Knowledge Plugin initialized. Frontend panel should be discoverable via its public route.' + { src: 'plugin:knowledge', agentId: runtime.agentId, agentName: runtime.character.name }, + 'Service initialized' ); } catch (error) { - logger.error({ error }, 'Failed to initialize Knowledge plugin'); + logger.error({ src: 'plugin:knowledge', agentId: runtime.agentId, error }, 'Failed to initialize'); throw error; } @@ -176,18 +129,17 @@ export class KnowledgeService extends Service { service.config = validatedConfig; // as Metadata if (service.config.LOAD_DOCS_ON_STARTUP) { - logger.info('LOAD_DOCS_ON_STARTUP is enabled. Loading documents from docs folder...'); + logger.debug({ src: 'plugin:knowledge', agentId: runtime.agentId }, 'Auto-loading documents from docs folder'); service.loadInitialDocuments().catch((error) => { - logger.error({ error }, 'Error during initial document loading in KnowledgeService'); + logger.error({ src: 'plugin:knowledge', agentId: runtime.agentId, error }, 'Error during initial document loading'); }); - } else { - logger.info('LOAD_DOCS_ON_STARTUP is disabled. Skipping automatic document loading.'); } // Process character knowledge AFTER service is initialized if (service.runtime.character?.knowledge && service.runtime.character.knowledge.length > 0) { - logger.info( - `KnowledgeService: Processing ${service.runtime.character.knowledge.length} character knowledge items.` + logger.debug( + { src: 'plugin:knowledge', agentId: runtime.agentId, count: service.runtime.character.knowledge.length }, + 'Processing character knowledge items' ); const stringKnowledge = service.runtime.character.knowledge.filter( (item): item is string => typeof item === 'string' @@ -195,14 +147,10 @@ export class KnowledgeService extends Service { // Run in background, don't await here to prevent blocking startup await service.processCharacterKnowledge(stringKnowledge).catch((err) => { logger.error( - { error: err }, - 'KnowledgeService: Error processing character knowledge during startup' + { src: 'plugin:knowledge', agentId: runtime.agentId, error: err }, + 'Error processing character knowledge during startup' ); }); - } else { - logger.info( - `KnowledgeService: No character knowledge to process for agent ${runtime.agentId}.` - ); } return service; } @@ -212,10 +160,10 @@ export class KnowledgeService extends Service { * @param runtime Agent runtime */ static async stop(runtime: IAgentRuntime): Promise { - logger.info(`Stopping Knowledge service for agent: ${runtime.agentId}`); + logger.info({ src: 'plugin:knowledge', agentId: runtime.agentId }, 'Stopping service'); const service = runtime.getService(KnowledgeService.serviceType); if (!service) { - logger.warn(`KnowledgeService not found for agent ${runtime.agentId} during stop.`); + logger.warn({ src: 'plugin:knowledge', agentId: runtime.agentId }, 'Service not found during stop'); } // If we need to perform specific cleanup on the KnowledgeService instance if (service instanceof KnowledgeService) { @@ -227,7 +175,7 @@ export class KnowledgeService extends Service { * Stop the service */ async stop(): Promise { - logger.info(`Knowledge service stopping for agent: ${this.runtime.character?.name}`); + logger.info({ src: 'plugin:knowledge', agentId: this.runtime.agentId }, 'Service stopped'); } /** @@ -250,13 +198,19 @@ export class KnowledgeService extends Service { maxChars: 2000, // Use first 2KB of content for ID generation }) as UUID; - logger.info(`Processing "${options.originalFilename}" (${options.contentType})`); + logger.info( + { src: 'plugin:knowledge', agentId, filename: options.originalFilename, contentType: options.contentType }, + 'Processing document' + ); // Check if document already exists in database using content-based ID try { const existingDocument = await this.runtime.getMemoryById(contentBasedId); if (existingDocument && existingDocument.metadata?.type === MemoryType.DOCUMENT) { - logger.info(`"${options.originalFilename}" already exists - skipping`); + logger.debug( + { src: 'plugin:knowledge', agentId, filename: options.originalFilename }, + 'Document already exists - skipping' + ); // Count existing fragments for this document const fragments = await this.runtime.getMemories({ @@ -279,7 +233,8 @@ export class KnowledgeService extends Service { } catch (error) { // Document doesn't exist or other error, continue with processing logger.debug( - `Document ${contentBasedId} not found or error checking existence, proceeding with processing: ${error instanceof Error ? error.message : String(error)}` + { src: 'plugin:knowledge', agentId, documentId: contentBasedId }, + 'Document not found, proceeding with processing' ); } @@ -315,7 +270,8 @@ export class KnowledgeService extends Service { try { logger.debug( - `KnowledgeService: Processing document ${originalFilename} (type: ${contentType}) via processDocument for agent: ${agentId}` + { src: 'plugin:knowledge', agentId, filename: originalFilename, contentType }, + 'Processing document via processDocument' ); let fileBuffer: Buffer | null = null; @@ -330,8 +286,8 @@ export class KnowledgeService extends Service { fileBuffer = Buffer.from(content, 'base64'); } catch (e: any) { logger.error( - { error: e }, - `KnowledgeService: Failed to convert base64 to buffer for ${originalFilename}` + { src: 'plugin:knowledge', agentId, filename: originalFilename, error: e }, + 'Failed to convert base64 to buffer' ); throw new Error(`Invalid base64 content for PDF file ${originalFilename}`); } @@ -343,8 +299,8 @@ export class KnowledgeService extends Service { fileBuffer = Buffer.from(content, 'base64'); } catch (e: any) { logger.error( - { error: e }, - `KnowledgeService: Failed to convert base64 to buffer for ${originalFilename}` + { src: 'plugin:knowledge', agentId, filename: originalFilename, error: e }, + 'Failed to convert base64 to buffer for binary file' ); throw new Error(`Invalid base64 content for binary file ${originalFilename}`); } @@ -371,11 +327,11 @@ export class KnowledgeService extends Service { throw new Error('Decoded content contains too many invalid characters'); } - logger.debug(`Successfully decoded base64 content for text file: ${originalFilename}`); + logger.debug({ src: 'plugin:knowledge', agentId, filename: originalFilename }, 'Decoded base64 content'); extractedText = decodedText; documentContentToStore = decodedText; } catch (e) { - logger.error({ error: e as any }, `Failed to decode base64 for ${originalFilename}`); + logger.error({ src: 'plugin:knowledge', agentId, filename: originalFilename, error: e as any }, 'Failed to decode base64'); // If it looked like base64 but failed to decode properly, this is an error throw new Error( `File ${originalFilename} appears to be corrupted or incorrectly encoded` @@ -383,18 +339,18 @@ export class KnowledgeService extends Service { } } else { // Content doesn't look like base64, treat as plain text - logger.debug(`Treating content as plain text for file: ${originalFilename}`); + logger.debug({ src: 'plugin:knowledge', agentId, filename: originalFilename }, 'Treating content as plain text'); extractedText = content; documentContentToStore = content; } } if (!extractedText || extractedText.trim() === '') { - const noTextError = new Error( - `KnowledgeService: No text content extracted from ${originalFilename} (type: ${contentType}).` + logger.warn( + { src: 'plugin:knowledge', agentId, filename: originalFilename, contentType }, + 'No text content extracted from document' ); - logger.warn(noTextError.message); - throw noTextError; + throw new Error(`No text content extracted from ${originalFilename} (type: ${contentType}).`); } // Create document memory using the clientDocumentId as the memory ID @@ -419,16 +375,15 @@ export class KnowledgeService extends Service { }; logger.debug( - `KnowledgeService: Creating memory with agentId=${agentId}, entityId=${entityId}, roomId=${roomId}, this.runtime.agentId=${this.runtime.agentId}` - ); - logger.debug( - `KnowledgeService: memoryWithScope agentId=${memoryWithScope.agentId}, entityId=${memoryWithScope.entityId}` + { src: 'plugin:knowledge', agentId, entityId, roomId }, + 'Creating document memory' ); await this.runtime.createMemory(memoryWithScope, 'documents'); logger.debug( - `KnowledgeService: Stored document ${originalFilename} (Memory ID: ${memoryWithScope.id})` + { src: 'plugin:knowledge', agentId, filename: originalFilename, memoryId: memoryWithScope.id }, + 'Document stored' ); const fragmentCount = await processFragmentsSynchronously({ @@ -443,7 +398,10 @@ export class KnowledgeService extends Service { documentTitle: originalFilename, }); - logger.debug(`"${originalFilename}" stored with ${fragmentCount} fragments`); + logger.debug( + { src: 'plugin:knowledge', agentId, filename: originalFilename, fragmentCount }, + 'Document processed with fragments' + ); return { clientDocumentId, @@ -452,8 +410,8 @@ export class KnowledgeService extends Service { }; } catch (error: any) { logger.error( - { error, stack: error.stack }, - `KnowledgeService: Error processing document ${originalFilename}` + { src: 'plugin:knowledge', agentId, filename: originalFilename, error }, + 'Error processing document' ); throw error; } @@ -462,7 +420,7 @@ export class KnowledgeService extends Service { // --- Knowledge methods moved from AgentRuntime --- private async handleProcessingError(error: any, context: string) { - logger.error({ error }, `KnowledgeService: Error ${context}`); + logger.error({ src: 'plugin:knowledge', error, context }, 'Processing error'); throw error; } @@ -477,9 +435,9 @@ export class KnowledgeService extends Service { message: Memory, scope?: { roomId?: UUID; worldId?: UUID; entityId?: UUID } ): Promise { - logger.debug(`KnowledgeService: getKnowledge called for message id: ${message.id}`); + logger.debug({ src: 'plugin:knowledge', messageId: message.id }, 'Getting knowledge for message'); if (!message?.content?.text || message?.content?.text.trim().length === 0) { - logger.warn('KnowledgeService: Invalid or empty message content for knowledge query.'); + logger.warn({ src: 'plugin:knowledge' }, 'Invalid or empty message content for knowledge query'); return []; } @@ -536,7 +494,7 @@ export class KnowledgeService extends Service { // Get the existing memory const existingMemory = await this.runtime.getMemoryById(memoryId); if (!existingMemory) { - logger.warn(`Cannot enrich memory ${memoryId} - memory not found`); + logger.warn({ src: 'plugin:knowledge', memoryId }, 'Cannot enrich memory - not found'); return; } @@ -562,11 +520,13 @@ export class KnowledgeService extends Service { }); logger.debug( - `Enriched conversation memory ${memoryId} with RAG data: ${ragMetadata.totalFragments} fragments` + { src: 'plugin:knowledge', memoryId, fragmentCount: ragMetadata.totalFragments }, + 'Enriched conversation memory with RAG data' ); } catch (error: any) { logger.warn( - `Failed to enrich conversation memory ${memoryId} with RAG data: ${error.message}` + { src: 'plugin:knowledge', memoryId, error: error.message }, + 'Failed to enrich conversation memory with RAG data' ); } } @@ -597,7 +557,7 @@ export class KnowledgeService extends Service { timestamp: now, }); - logger.debug(`Stored pending RAG metadata for next conversation memory`); + logger.debug({ src: 'plugin:knowledge' }, 'Stored pending RAG metadata for next conversation memory'); } /** @@ -644,15 +604,16 @@ export class KnowledgeService extends Service { } } } catch (error: any) { - logger.warn(`Error enriching recent memories with RAG data: ${error.message}`); + logger.warn({ src: 'plugin:knowledge', error: error.message }, 'Error enriching recent memories with RAG data'); } } async processCharacterKnowledge(items: string[]): Promise { // Wait briefly to allow services to initialize fully await new Promise((resolve) => setTimeout(resolve, 1000)); - logger.info( - `KnowledgeService: Processing ${items.length} character knowledge items for agent ${this.runtime.agentId}` + logger.debug( + { src: 'plugin:knowledge', agentId: this.runtime.agentId, count: items.length }, + 'Processing character knowledge items' ); const processingPromises = items.map(async (item) => { @@ -666,13 +627,15 @@ export class KnowledgeService extends Service { if (await this.checkExistingKnowledge(knowledgeId)) { logger.debug( - `KnowledgeService: Character knowledge item with ID ${knowledgeId} already exists. Skipping.` + { src: 'plugin:knowledge', knowledgeId }, + 'Character knowledge item already exists - skipping' ); return; } logger.debug( - `KnowledgeService: Processing character knowledge for ${this.runtime.character?.name} - ${item.slice(0, 100)}` + { src: 'plugin:knowledge', agentId: this.runtime.agentId }, + 'Processing character knowledge item' ); let metadata: MemoryMetadata = { @@ -723,8 +686,9 @@ export class KnowledgeService extends Service { }); await Promise.all(processingPromises); - logger.info( - `KnowledgeService: Finished processing character knowledge for agent ${this.runtime.agentId}.` + logger.debug( + { src: 'plugin:knowledge', agentId: this.runtime.agentId }, + 'Finished processing character knowledge' ); } @@ -748,7 +712,7 @@ export class KnowledgeService extends Service { entityId: scope?.entityId ?? this.runtime.agentId, }; - logger.debug(`KnowledgeService: _internalAddKnowledge called for item ID ${item.id}`); + logger.debug({ src: 'plugin:knowledge', itemId: item.id }, 'Internal add knowledge called'); // For _internalAddKnowledge, we assume item.content.text is always present // and it's not a binary file needing Knowledge plugin's special handling for extraction. @@ -773,7 +737,8 @@ export class KnowledgeService extends Service { const existingDocument = await this.runtime.getMemoryById(item.id); if (existingDocument) { logger.debug( - `KnowledgeService: Document ${item.id} already exists in _internalAddKnowledge, updating...` + { src: 'plugin:knowledge', documentId: item.id }, + 'Document already exists, updating' ); await this.runtime.updateMemory({ ...documentMemory, @@ -797,13 +762,14 @@ export class KnowledgeService extends Service { fragmentsProcessed++; } catch (error) { logger.error( - { error }, - `KnowledgeService: Error processing fragment ${fragment.id} for document ${item.id}` + { src: 'plugin:knowledge', fragmentId: fragment.id, documentId: item.id, error }, + 'Error processing fragment' ); } } logger.debug( - `KnowledgeService: Processed ${fragmentsProcessed}/${fragments.length} fragments for document ${item.id}.` + { src: 'plugin:knowledge', documentId: item.id, processed: fragmentsProcessed, total: fragments.length }, + 'Fragments processed' ); } @@ -816,7 +782,7 @@ export class KnowledgeService extends Service { // Store the fragment in the knowledge table await this.runtime.createMemory(fragment, 'knowledge'); } catch (error) { - logger.error({ error }, `KnowledgeService: Error processing fragment ${fragment.id}`); + logger.error({ src: 'plugin:knowledge', fragmentId: fragment.id, error }, 'Error processing fragment'); throw error; } } @@ -911,8 +877,9 @@ export class KnowledgeService extends Service { // If it needs a tableName, and we are sure it's 'documents', it could be passed. // However, the previous error indicated runtime.deleteMemory takes 1 argument. await this.runtime.deleteMemory(memoryId); - logger.info( - `KnowledgeService: Deleted memory ${memoryId} for agent ${this.runtime.agentId}. Assumed it was a document or related fragment.` + logger.debug( + { src: 'plugin:knowledge', agentId: this.runtime.agentId, memoryId }, + 'Memory deleted' ); } // ADDED METHODS END