From 7f3cd17488433f0c012da4f1c296f7adef6b6928 Mon Sep 17 00:00:00 2001 From: Jason Woltje Date: Thu, 5 Feb 2026 16:26:30 -0600 Subject: [PATCH] fix(#338): Add structured logging for embedding failures - Replace console.error with NestJS Logger - Include entry ID and workspace ID in error context - Easier to track and debug embedding issues Refs #338 Co-Authored-By: Claude Opus 4.5 --- ...knowledge.service.embedding-errors.spec.ts | 286 ++++++++++++++++++ apps/api/src/knowledge/knowledge.service.ts | 12 +- 2 files changed, 296 insertions(+), 2 deletions(-) create mode 100644 apps/api/src/knowledge/knowledge.service.embedding-errors.spec.ts diff --git a/apps/api/src/knowledge/knowledge.service.embedding-errors.spec.ts b/apps/api/src/knowledge/knowledge.service.embedding-errors.spec.ts new file mode 100644 index 0000000..05c6831 --- /dev/null +++ b/apps/api/src/knowledge/knowledge.service.embedding-errors.spec.ts @@ -0,0 +1,286 @@ +import { describe, it, expect, beforeEach, vi } from "vitest"; +import { Test, TestingModule } from "@nestjs/testing"; +import { KnowledgeService } from "./knowledge.service"; +import { PrismaService } from "../prisma/prisma.service"; +import { LinkSyncService } from "./services/link-sync.service"; +import { KnowledgeCacheService } from "./services/cache.service"; +import { EmbeddingService } from "./services/embedding.service"; +import { OllamaEmbeddingService } from "./services/ollama-embedding.service"; +import { EmbeddingQueueService } from "./queues/embedding-queue.service"; + +describe("KnowledgeService - Embedding Error Logging", () => { + let service: KnowledgeService; + let mockEmbeddingQueueService: { + queueEmbeddingJob: ReturnType; + }; + + const workspaceId = "workspace-123"; + const userId = "user-456"; + const entryId = "entry-789"; + const slug = "test-entry"; + + const mockCreatedEntry = { + id: entryId, + workspaceId, + slug, + title: "Test Entry", + content: "# Test Content", + contentHtml: "

Test Content

", + summary: "Test summary", + status: "DRAFT", + visibility: "PRIVATE", + createdAt: new Date("2026-01-01"), + updatedAt: new Date("2026-01-01"), + createdBy: userId, + updatedBy: userId, + tags: [], + }; + + const mockPrismaService = { + knowledgeEntry: { + findUnique: vi.fn(), + create: vi.fn(), + update: vi.fn(), + count: vi.fn(), + findMany: vi.fn(), + }, + knowledgeEntryVersion: { + create: vi.fn(), + count: vi.fn(), + findMany: vi.fn(), + }, + knowledgeEntryTag: { + deleteMany: vi.fn(), + }, + knowledgeTag: { + findUnique: vi.fn(), + create: vi.fn(), + }, + $transaction: vi.fn(), + }; + + const mockLinkSyncService = { + syncLinks: vi.fn().mockResolvedValue(undefined), + }; + + const mockCacheService = { + getEntry: vi.fn().mockResolvedValue(null), + setEntry: vi.fn().mockResolvedValue(undefined), + invalidateEntry: vi.fn().mockResolvedValue(undefined), + invalidateSearches: vi.fn().mockResolvedValue(undefined), + invalidateGraphs: vi.fn().mockResolvedValue(undefined), + invalidateGraphsForEntry: vi.fn().mockResolvedValue(undefined), + }; + + const mockEmbeddingService = { + isConfigured: vi.fn().mockReturnValue(false), + prepareContentForEmbedding: vi.fn().mockReturnValue("prepared content"), + batchGenerateEmbeddings: vi.fn().mockResolvedValue(0), + }; + + const mockOllamaEmbeddingService = { + isConfigured: vi.fn().mockResolvedValue(false), + prepareContentForEmbedding: vi.fn().mockReturnValue("prepared content"), + generateAndStoreEmbedding: vi.fn().mockResolvedValue(undefined), + }; + + beforeEach(async () => { + mockEmbeddingQueueService = { + queueEmbeddingJob: vi.fn(), + }; + + const module: TestingModule = await Test.createTestingModule({ + providers: [ + KnowledgeService, + { + provide: PrismaService, + useValue: mockPrismaService, + }, + { + provide: LinkSyncService, + useValue: mockLinkSyncService, + }, + { + provide: KnowledgeCacheService, + useValue: mockCacheService, + }, + { + provide: EmbeddingService, + useValue: mockEmbeddingService, + }, + { + provide: OllamaEmbeddingService, + useValue: mockOllamaEmbeddingService, + }, + { + provide: EmbeddingQueueService, + useValue: mockEmbeddingQueueService, + }, + ], + }).compile(); + + service = module.get(KnowledgeService); + + vi.clearAllMocks(); + }); + + describe("create - embedding failure logging", () => { + it("should log structured warning when embedding generation fails during create", async () => { + // Setup: transaction returns created entry + mockPrismaService.$transaction.mockResolvedValue(mockCreatedEntry); + mockPrismaService.knowledgeEntry.findUnique.mockResolvedValue(null); // For slug uniqueness check + + // Make embedding queue fail + const embeddingError = new Error("Ollama service unavailable"); + mockEmbeddingQueueService.queueEmbeddingJob.mockRejectedValue(embeddingError); + + // Spy on the logger + const loggerWarnSpy = vi.spyOn(service["logger"], "warn"); + + // Create entry + await service.create(workspaceId, userId, { + title: "Test Entry", + content: "# Test Content", + }); + + // Wait for async embedding generation to complete (and fail) + await new Promise((resolve) => setTimeout(resolve, 10)); + + // Verify structured logging was called + expect(loggerWarnSpy).toHaveBeenCalledWith( + expect.stringContaining("Failed to generate embedding for entry"), + expect.objectContaining({ + entryId, + workspaceId, + error: "Ollama service unavailable", + }) + ); + }); + + it("should include entry ID and workspace ID in error context during create", async () => { + mockPrismaService.$transaction.mockResolvedValue(mockCreatedEntry); + mockPrismaService.knowledgeEntry.findUnique.mockResolvedValue(null); + + mockEmbeddingQueueService.queueEmbeddingJob.mockRejectedValue( + new Error("Connection timeout") + ); + + const loggerWarnSpy = vi.spyOn(service["logger"], "warn"); + + await service.create(workspaceId, userId, { + title: "Test Entry", + content: "# Test Content", + }); + + await new Promise((resolve) => setTimeout(resolve, 10)); + + // Verify the structured context contains required fields + const callArgs = loggerWarnSpy.mock.calls[0]; + expect(callArgs[1]).toHaveProperty("entryId", entryId); + expect(callArgs[1]).toHaveProperty("workspaceId", workspaceId); + expect(callArgs[1]).toHaveProperty("error", "Connection timeout"); + }); + + it("should handle non-Error objects in embedding failure during create", async () => { + mockPrismaService.$transaction.mockResolvedValue(mockCreatedEntry); + mockPrismaService.knowledgeEntry.findUnique.mockResolvedValue(null); + + // Reject with a string instead of Error + mockEmbeddingQueueService.queueEmbeddingJob.mockRejectedValue("String error message"); + + const loggerWarnSpy = vi.spyOn(service["logger"], "warn"); + + await service.create(workspaceId, userId, { + title: "Test Entry", + content: "# Test Content", + }); + + await new Promise((resolve) => setTimeout(resolve, 10)); + + // Should convert non-Error to string + expect(loggerWarnSpy).toHaveBeenCalledWith( + expect.any(String), + expect.objectContaining({ + error: "String error message", + }) + ); + }); + }); + + describe("update - embedding failure logging", () => { + const existingEntry = { + ...mockCreatedEntry, + versions: [{ version: 1 }], + }; + + const updatedEntry = { + ...mockCreatedEntry, + title: "Updated Title", + content: "# Updated Content", + }; + + it("should log structured warning when embedding generation fails during update", async () => { + mockPrismaService.knowledgeEntry.findUnique.mockResolvedValue(existingEntry); + mockPrismaService.$transaction.mockResolvedValue(updatedEntry); + + const embeddingError = new Error("Embedding model not loaded"); + mockEmbeddingQueueService.queueEmbeddingJob.mockRejectedValue(embeddingError); + + const loggerWarnSpy = vi.spyOn(service["logger"], "warn"); + + await service.update(workspaceId, slug, userId, { + content: "# Updated Content", + }); + + await new Promise((resolve) => setTimeout(resolve, 10)); + + expect(loggerWarnSpy).toHaveBeenCalledWith( + expect.stringContaining("Failed to generate embedding for entry"), + expect.objectContaining({ + entryId, + workspaceId, + error: "Embedding model not loaded", + }) + ); + }); + + it("should include entry ID and workspace ID in error context during update", async () => { + mockPrismaService.knowledgeEntry.findUnique.mockResolvedValue(existingEntry); + mockPrismaService.$transaction.mockResolvedValue(updatedEntry); + + mockEmbeddingQueueService.queueEmbeddingJob.mockRejectedValue( + new Error("Rate limit exceeded") + ); + + const loggerWarnSpy = vi.spyOn(service["logger"], "warn"); + + await service.update(workspaceId, slug, userId, { + title: "New Title", + }); + + await new Promise((resolve) => setTimeout(resolve, 10)); + + const callArgs = loggerWarnSpy.mock.calls[0]; + expect(callArgs[1]).toHaveProperty("entryId", entryId); + expect(callArgs[1]).toHaveProperty("workspaceId", workspaceId); + expect(callArgs[1]).toHaveProperty("error", "Rate limit exceeded"); + }); + + it("should not trigger embedding generation if only status is updated", async () => { + mockPrismaService.knowledgeEntry.findUnique.mockResolvedValue(existingEntry); + mockPrismaService.$transaction.mockResolvedValue({ + ...existingEntry, + status: "PUBLISHED", + }); + + await service.update(workspaceId, slug, userId, { + status: "PUBLISHED", + }); + + await new Promise((resolve) => setTimeout(resolve, 10)); + + // Embedding should not be called when only status changes + expect(mockEmbeddingQueueService.queueEmbeddingJob).not.toHaveBeenCalled(); + }); + }); +}); diff --git a/apps/api/src/knowledge/knowledge.service.ts b/apps/api/src/knowledge/knowledge.service.ts index 552b6fa..0625e34 100644 --- a/apps/api/src/knowledge/knowledge.service.ts +++ b/apps/api/src/knowledge/knowledge.service.ts @@ -244,7 +244,11 @@ export class KnowledgeService { // Generate and store embedding asynchronously (don't block the response) this.generateEntryEmbedding(result.id, result.title, result.content).catch((error: unknown) => { - console.error(`Failed to generate embedding for entry ${result.id}:`, error); + this.logger.warn(`Failed to generate embedding for entry - embedding will be missing`, { + entryId: result.id, + workspaceId, + error: error instanceof Error ? error.message : String(error), + }); }); // Invalidate search and graph caches (new entry affects search results) @@ -407,7 +411,11 @@ export class KnowledgeService { if (updateDto.content !== undefined || updateDto.title !== undefined) { this.generateEntryEmbedding(result.id, result.title, result.content).catch( (error: unknown) => { - console.error(`Failed to generate embedding for entry ${result.id}:`, error); + this.logger.warn(`Failed to generate embedding for entry - embedding will be missing`, { + entryId: result.id, + workspaceId, + error: error instanceof Error ? error.message : String(error), + }); } ); }