feat: Add comprehensive logging system

arabold · arabold · commit ba8a6f112b1e · 2025-03-09T16:19:26.000-07:00
- Create logger utility in src/utils/logger.ts
- Add logging to scraping operations with progress tracking
- Add logging to store operations for document indexing
- Add logging to search operations
- Improve error visibility with detailed retry logging
diff --git a/ARCHITECTURE.md b/ARCHITECTURE.md
@@ -97,6 +97,34 @@ Tools that involve long-running operations support progress reporting through ca
 - CLI: Console output with progress information
 - MCP: Structured progress updates through the MCP protocol
 
+### 5. Logging Strategy
+
+The project uses a centralized logging system through `utils/logger.ts` that maps to console methods. The logging follows a hierarchical approach:
+
+1. **Tools Layer (Highest)**
+
+   - Primary user-facing operations
+   - Final results and overall progress
+   - Example: Search queries and result counts
+
+2. **Core Components (Middle)**
+
+   - Unique operational logs
+   - Store creation and management
+   - Example: Vector store operations
+
+3. **Strategy Layer (Lowest)**
+   - Detailed progress (page crawling)
+   - Error conditions and retries
+   - Example: Individual page scraping status
+
+This hierarchy ensures:
+
+- Clear operation visibility
+- No duplicate logging between layers
+- Consistent emoji usage for better readability
+- Error logging preserved at all levels for debugging
+
 ## Benefits
 
 1. **Maintainability**
diff --git a/src/scraper/index.ts b/src/scraper/index.ts
@@ -3,6 +3,7 @@ import type {
   ScrapingProgressCallback,
   DocContent,
 } from "../types";
+import { logger } from "../utils/logger";
 import { validateUrl } from "../utils/url";
 import { DefaultScraperStrategy } from "./strategies/default-strategy";
 import { NpmScraperStrategy } from "./strategies/npm-strategy";
@@ -51,7 +52,15 @@ export class DocumentationScraperDispatcher {
     // Validate config URL before proceeding
     validateUrl(config.url);
     const strategy = this.determineStrategy(config.url);
-    return strategy.scrape(config, progressCallback);
+
+    try {
+      return await strategy.scrape(config, progressCallback);
+    } catch (error) {
+      logger.error(
+        `❌ Scraping failed: ${error instanceof Error ? error.message : "Unknown error"}`
+      );
+      throw error;
+    }
   }
 }
 
diff --git a/src/scraper/strategies/default-strategy.ts b/src/scraper/strategies/default-strategy.ts
@@ -2,6 +2,7 @@ import TurndownService from "turndown";
 import scrapeIt from "scrape-it";
 import { ScraperError } from "../../utils/errors";
 import { validateUrl } from "../../utils/url";
+import { logger } from "../../utils/logger";
 import type {
   ScraperConfig,
   PageResult,
@@ -148,6 +149,9 @@ export class DefaultScraperStrategy implements ScraperStrategy {
       // Only retry on 4xx errors
       if (status !== undefined && status >= 400 && status < 500) {
         for (let attempt = 1; attempt < this.MAX_RETRIES; attempt++) {
+          logger.warn(
+            `⚠️ Retry ${attempt}/${this.MAX_RETRIES - 1} for ${url} (Status: ${status})`
+          );
           try {
             await this.delay(this.BASE_DELAY * 2 ** attempt);
             return await this.scrapePageContent(url);
@@ -162,6 +166,12 @@ export class DefaultScraperStrategy implements ScraperStrategy {
               );
             }
             // Otherwise continue to next retry
+            const retryStatus = (
+              retryError as { response?: { status: number } }
+            )?.response?.status;
+            logger.warn(
+              `⚠️ Attempt ${attempt} failed (Status: ${retryStatus || "unknown"})`
+            );
           }
         }
       }
@@ -214,6 +224,10 @@ export class DefaultScraperStrategy implements ScraperStrategy {
     this.pageCount++;
     this.reportProgress(normalizedUrl, depth);
 
+    logger.info(
+      `🌐 Crawling page ${this.pageCount}/${config.maxPages} (depth ${depth}/${config.maxDepth}): ${normalizedUrl}`
+    );
+
     const result = await this.scrapePageContentWithRetry(url, config);
     const results = [result];
 
diff --git a/src/store/index.ts b/src/store/index.ts
@@ -3,6 +3,7 @@ import { OpenAIEmbeddings } from "@langchain/openai";
 import path from "node:path";
 import fs from "node:fs/promises";
 import semver from "semver";
+import { logger } from "../utils/logger";
 import type { SearchResult, VectorStoreProgressCallback } from "../types";
 import type { Document } from "@langchain/core/documents";
 import { RecursiveCharacterTextSplitter } from "langchain/text_splitter";
@@ -46,6 +47,7 @@ export class VectorStoreManager {
     library: string,
     version: string
   ): Promise<MemoryVectorStore> {
+    logger.info(`💾 Creating store for ${library}@${version}`);
     const storePath = this.getStorePath(library, version);
     await fs.mkdir(storePath, { recursive: true });
 
@@ -56,6 +58,9 @@ export class VectorStoreManager {
     library: string,
     targetVersion?: string
   ): Promise<string | null> {
+    logger.info(
+      `🔍 Finding best version for ${library}${targetVersion ? `@${targetVersion}` : ""}`
+    );
     try {
       const libraryPath = path.join(this.baseDir, library);
       const versions = await fs.readdir(libraryPath);
@@ -79,13 +84,24 @@ export class VectorStoreManager {
         )
       ).filter((v): v is string => v !== null);
 
-      if (validVersions.length === 0) return null;
+      if (validVersions.length === 0) {
+        logger.warn(`⚠️ No valid versions found for ${library}`);
+        return null;
+      }
+
+      const result = !targetVersion
+        ? semver.maxSatisfying(validVersions, "*")
+        : semver.maxSatisfying(validVersions, `<=${targetVersion}`);
 
-      if (!targetVersion) {
-        return semver.maxSatisfying(validVersions, "*") || null;
+      if (result) {
+        logger.info(`✅ Found version ${result} for ${library}`);
+      } else {
+        logger.warn(
+          `⚠️ No matching version found for ${library}${targetVersion ? `@${targetVersion}` : ""}`
+        );
       }
 
-      return semver.maxSatisfying(validVersions, `<=${targetVersion}`) || null;
+      return result || null;
     } catch (error) {
       if ((error as NodeJS.ErrnoException).code === "ENOENT") {
         return null;
@@ -95,6 +111,7 @@ export class VectorStoreManager {
   }
 
   async clearStore(library: string, version: string): Promise<void> {
+    logger.info(`🗑️ Clearing store for ${library}@${version}`);
     const storePath = this.getStorePath(library, version);
     const storeFile = path.join(storePath, STORE_FILENAME);
     try {
@@ -112,6 +129,9 @@ export class VectorStoreManager {
     version: string,
     document: Document
   ): Promise<void> {
+    logger.info(
+      `📚 Adding document: ${document.metadata.title} for ${library}@${version}`
+    );
     const store = await this.createStore(library, version);
     const splitter = new RecursiveCharacterTextSplitter({
       chunkSize: 4000,
@@ -125,6 +145,7 @@ export class VectorStoreManager {
 
     // Split document into smaller chunks
     const splitDocs = await splitter.splitDocuments([document]);
+    logger.info(`📄 Split document into ${splitDocs.length} chunks`);
 
     // Report progress
     if (this.onProgress) {
@@ -174,20 +195,23 @@ export class VectorStoreManager {
         k: limit * 2,
         searchType: "similarity",
       });
-      const results = await retriever.invoke(query);
-      const rerankedResults = await BM25Retriever.fromDocuments(results, {
-        k: limit,
-        includeScore: true,
-      }).invoke(query);
+      const initialResults = await retriever.invoke(query);
+      const rerankedResults = await BM25Retriever.fromDocuments(
+        initialResults,
+        {
+          k: limit,
+          includeScore: true,
+        }
+      ).invoke(query);
 
       return rerankedResults.map((doc) => ({
         content: doc.pageContent,
         score: (doc.metadata.bm25Score as number) ?? 0,
         metadata: {
-          url: doc.metadata.url,
-          title: doc.metadata.title,
-          library: doc.metadata.library,
-          version: doc.metadata.version,
+          url: doc.metadata.url as string,
+          title: doc.metadata.title as string,
+          library: doc.metadata.library as string,
+          version: doc.metadata.version as string,
         },
       }));
     } catch (error) {
diff --git a/src/tools/library.ts b/src/tools/library.ts
@@ -1,4 +1,5 @@
 import type { VectorStoreManager } from "../store/index.js";
+import { logger } from "../utils/logger";
 
 export interface ListLibrariesOptions {
   store: VectorStoreManager;
@@ -29,15 +30,16 @@ export const listLibraries = async (
 ): Promise<ListLibrariesResult> => {
   const { store } = options;
   const rawLibraries = await store.listLibraries();
-  return {
-    libraries: rawLibraries.map(({ library, versions }) => ({
-      name: library,
-      versions: versions.map((v) => ({
-        version: v.version,
-        indexed: v.indexed,
-      })),
+
+  const libraries = rawLibraries.map(({ library, versions }) => ({
+    name: library,
+    versions: versions.map((v) => ({
+      version: v.version,
+      indexed: v.indexed,
     })),
-  };
+  }));
+
+  return { libraries };
 };
 
 export const findVersion = async (
diff --git a/src/tools/scrape.ts b/src/tools/scrape.ts
@@ -6,6 +6,7 @@ import type {
   ProgressResponse,
 } from "../types/index.js";
 import { Document } from "@langchain/core/documents";
+import { logger } from "../utils/logger";
 
 export interface ScrapeOptions {
   url: string;
@@ -35,6 +36,10 @@ export const scrape = async (options: ScrapeOptions): Promise<ScrapeResult> => {
     subpagesOnly,
   } = options;
 
+  logger.info(
+    `🕷️ Starting documentation scrape for ${library}@${version} from ${url}`
+  );
+
   const scraper = new DocumentationScraperDispatcher({
     onProgress,
   });
@@ -48,31 +53,41 @@ export const scrape = async (options: ScrapeOptions): Promise<ScrapeResult> => {
     subpagesOnly,
   };
 
-  // Clear existing vector store data before scraping
-  await store.clearStore(library, version);
+  try {
+    // Clear existing vector store data before scraping
+    await store.clearStore(library, version);
 
-  const results = await scraper.scrape(config);
+    const results = await scraper.scrape(config);
+    let totalDocuments = 0;
 
-  let totalDocuments = 0;
+    // Convert each result to a Document and add it to the store
+    for (const result of results) {
+      const doc = new Document({
+        pageContent: result.content,
+        metadata: {
+          url: result.metadata.url,
+          title: result.metadata.title,
+          library,
+          version,
+        },
+      });
 
-  // Convert each result to a Document and add it to the store
-  for (const result of results) {
-    const doc = new Document({
-      pageContent: result.content,
-      metadata: {
-        url: result.metadata.url,
-        title: result.metadata.title,
-        library,
-        version,
-      },
-    });
+      await store.addDocument(library, version, doc);
+      totalDocuments++;
+    }
 
-    await store.addDocument(library, version, doc);
-    totalDocuments++;
-  }
+    logger.info(
+      `✨ Scraping completed: ${results.length} pages retrieved and indexed`
+    );
 
-  return {
-    pagesScraped: results.length,
-    documentsIndexed: totalDocuments,
-  };
+    return {
+      pagesScraped: results.length,
+      documentsIndexed: totalDocuments,
+    };
+  } catch (error) {
+    logger.error(
+      `❌ Scraping failed: ${error instanceof Error ? error.message : "Unknown error"}`
+    );
+    throw error;
+  }
 };
diff --git a/src/tools/search.ts b/src/tools/search.ts
@@ -1,5 +1,6 @@
 import type { VectorStoreManager } from "../store/index.js";
 import type { SearchResult } from "../types/index.js";
+import { logger } from "../utils/logger";
 
 export interface SearchOptions {
   library: string;
@@ -18,9 +19,16 @@ export const search = async (
 ): Promise<SearchToolResult> => {
   const { library, version, query, limit, store } = options;
 
-  const results = await store.search(library, version, query, limit);
+  logger.info(`🔍 Searching ${library}@${version} for: ${query}`);
 
-  return {
-    results,
-  };
+  try {
+    const results = await store.search(library, version, query, limit);
+    logger.info(`✅ Found ${results.length} matching results`);
+    return { results };
+  } catch (error) {
+    logger.error(
+      `❌ Search failed: ${error instanceof Error ? error.message : "Unknown error"}`
+    );
+    throw error;
+  }
 };
diff --git a/src/utils/logger.ts b/src/utils/logger.ts
@@ -0,0 +1,5 @@
+export const logger = {
+  info: (message: string) => console.log(message),
+  warn: (message: string) => console.warn(message),
+  error: (message: string) => console.error(message),
+};
