Merge pull request #224 from objectstack-ai/copilot/improve-logging-structure

Author: hotlong

DEVELOPMENT_WORKFLOW.md

@@ -303,6 +303,68 @@ pnpm typecheck
 pnpm test
 ```
 
+## 📝 Logging
+
+HotCRM uses **structured logging** via [pino](https://getpino.io). All log output is JSON, making it easy to search, filter, and aggregate in production.
+
+### Creating a Logger
+
+```typescript
+import { createLogger } from '@hotcrm/core';
+
+const logger = createLogger('crm:account');
+```
+
+The module name follows the convention `package:module` (e.g. `crm:account`, `finance:invoice`, `ai:cache-manager`).
+
+### Log Levels
+
+| Level | Method | When to use |
+|-------|--------|-------------|
+| `debug` | `logger.debug(...)` | Verbose development-time tracing |
+| `info` | `logger.info(...)` | Normal operational events |
+| `warn` | `logger.warn(...)` | Something unexpected but recoverable |
+| `error` | `logger.error(...)` | Failures that need attention |
+
+### Structured Data
+
+Always pass structured data as the **first argument** (object), and a short message string as the **second**:
+
+```typescript
+// Good — structured data is machine-parseable
+logger.info({ accountId, healthScore: 85 }, 'Account scored');
+logger.error({ err }, 'Failed to update account');
+
+// Bad — don't embed data in the message string
+logger.info(`Account ${accountId} scored 85`);
+```
+
+### Controlling Log Level
+
+Set the `LOG_LEVEL` environment variable:
+
+```bash
+LOG_LEVEL=debug pnpm dev    # See all log output
+LOG_LEVEL=warn pnpm start   # Only warnings and errors in production
+```
+
+### Testing with Logger
+
+In tests, mock `@hotcrm/core` so log calls delegate to `console.*` (allowing existing `vi.spyOn(console, ...)` patterns):
+
+```typescript
+vi.mock('@hotcrm/core', () => ({
+  createLogger: () => ({
+    info: (...args: any[]) => console.log(...args),
+    warn: (...args: any[]) => console.warn(...args),
+    error: (...args: any[]) => console.error(...args),
+    debug: (...args: any[]) => console.debug(...args),
+  }),
+}));
+```
+
+> **Note:** Do not use `console.log` directly in production source code. Always use `createLogger` from `@hotcrm/core`.
+
 ## ❓ Troubleshooting FAQ
 
 ### `pnpm install` fails

ROADMAP.md

@@ -65,7 +65,7 @@
 | Studio Builder Configs | 4 (Interface Builder, Page Builder, Canvas Snap, Element Palette) |
 | Navigation Areas | 3 (header, sidebar, utility bar) |
 | Packages Registered in Root Config | 13 of 13 (all packages registered) |
-| Test Files | 192 files, 3799 tests (all passing) |
+| Test Files | 194 files, 3813 tests (all passing) |
 | TypeScript Compliance | 100% (zero type errors) |
 | Protocol Compliance | 100% (all objects pass ObjectSchema.create()) |
 | Spec Schema Adoption | ~95 of ~95 application-level schemas used (~100%) |
@@ -193,8 +193,10 @@ These items were deferred during Phase 13 and have been completed:
 
 #### Deferred / Future
 
-- [ ] **Structured logging migration** — Replace `console.log` with pino logger across hook files
-- [ ] **Legacy API cleanup** — Remove `db.ts` references and migrate to broker/ObjectQL
+- [x] **Structured logging migration** — Replaced `console.log` with pino logger (`createLogger` from `@hotcrm/core`) across 154 hook/action/service files in all 13 packages; removed emoji from log output; added 9 logger unit tests
+- [x] **CacheManager test isolation** — Added `CacheManager.resetInstance()` for test isolation; 5 dedicated tests
+- [x] **Legacy API cleanup (Phase 1)** — Added `@deprecated` annotations and migration guide to all 13 `db.ts` files; `db` export marked for removal
+- [ ] **Legacy API cleanup (Phase 2)** — Remove `db.ts` exports entirely once all consumers migrated to broker/ObjectQL
 - [ ] **E2E test coverage** — Build API-layer end-to-end tests for Feed API / MCP API
 - [ ] **FormView `as any` cleanup** — Remove `as any` casts once `@objectstack/spec` aligns FormView column types
 
@@ -204,6 +206,7 @@ These items were deferred during Phase 13 and have been completed:
 
 | Date | From | To | Breaking Changes | Tests |
 |------|------|----|-----------------|-------|
+| 2026-02-21 | v3.0.8 | v3.0.8 | None (Phase 15 continued: Structured pino logging across 154 files, CacheManager test isolation, db.ts deprecation annotations, emoji removal from logs) | 3813 ✅ |
 | 2026-02-21 | v3.0.8 | v3.0.8 | None (Phase 15: Repository quality improvements — hook `any` type migration, CI typecheck, ESLint version alignment, documentation updates, code-quality workflow fixes) | 3799 ✅ |
 | 2027-02-21 | v3.0.8 | v3.0.8 | None (Phase 14 complete: Activity Feed/Chatter across 6 clouds, 4 Interface Builder blank pages, Dashboard headers & global filters on 6 clouds, ViewTabs on 18 views, Feed API 8 endpoints, Feed service contract, System metadata, Studio builder configs, Navigation areas, 327 new tests) | 3707 ✅ |
 | 2026-02-21 | v3.0.6 | v3.0.8 | None (New: Activity Feed/Chatter system, Interface Builder/Blank Pages, Dashboard headers & global filters, Feed API contracts, Studio builder configs, Oclif CLI plugin, Package conventions; Phase 14 roadmap added) | 3318 ✅ |

packages/ai/__tests__/unit/cache-manager-isolation.test.ts

@@ -0,0 +1,52 @@
+import { describe, it, expect, beforeEach, afterEach } from 'vitest';
+import { CacheManager } from '../../src/cache-manager';
+
+describe('CacheManager — resetInstance test isolation', () => {
+  afterEach(() => {
+    CacheManager.resetInstance();
+  });
+
+  it('should fully reset singleton so next getInstance creates fresh instance', async () => {
+    const cm1 = CacheManager.getInstance();
+    await cm1.set('key', 'value', 60);
+    expect(await cm1.get('key')).toBe('value');
+
+    CacheManager.resetInstance();
+
+    const cm2 = CacheManager.getInstance();
+    // After reset, the new instance should have an empty cache
+    expect(await cm2.get('key')).toBeNull();
+    expect(cm2.getStats().size).toBe(0);
+  });
+
+  it('should allow a different config after reset', () => {
+    const cm1 = CacheManager.getInstance({ defaultTtl: 300 });
+    CacheManager.resetInstance();
+
+    const cm2 = CacheManager.getInstance({ defaultTtl: 600 });
+    // Should be a brand new instance (not same reference as cm1)
+    expect(cm2).not.toBe(cm1);
+  });
+
+  it('should not throw when called before any getInstance', () => {
+    // Fresh state — no instance exists yet
+    expect(() => CacheManager.resetInstance()).not.toThrow();
+  });
+
+  it('should not throw when called twice in a row', () => {
+    CacheManager.getInstance();
+    CacheManager.resetInstance();
+    expect(() => CacheManager.resetInstance()).not.toThrow();
+  });
+
+  it('should isolate cache state between test runs', async () => {
+    // Simulate test A
+    const cmA = CacheManager.getInstance();
+    await cmA.set('shared', 'from-test-a', 60);
+    CacheManager.resetInstance();
+
+    // Simulate test B — should not see test A's data
+    const cmB = CacheManager.getInstance();
+    expect(await cmB.get('shared')).toBeNull();
+  });
+});

packages/ai/src/benchmark.ts

@@ -7,9 +7,12 @@
  * Usage:
  *   const bench = new Benchmark('lead_scoring');
  *   const result = await bench.run(() => scoreLead(lead), { iterations: 100 });
- *   console.log(result.summary());
+ *   logger.info(result.summary());
  */
 
+import { createLogger } from '@hotcrm/core';
+const logger = createLogger('ai:benchmark');
+
 // ---------------------------------------------------------------------------
 // Types
 // ---------------------------------------------------------------------------

packages/ai/src/cache-manager.ts

@@ -5,6 +5,9 @@
  * Falls back to in-memory cache if Redis is not available
  */
 
+import { createLogger } from '@hotcrm/core';
+const logger = createLogger('ai:cache-manager');
+
 export interface CacheConfig {
   /** Redis connection URL */
   redisUrl?: string;
@@ -57,12 +60,25 @@ export class CacheManager {
     return CacheManager.instance;
   }
 
+  /**
+   * Reset singleton instance for test isolation.
+   * Call in beforeEach/afterEach to ensure a clean slate between tests.
+   */
+  static resetInstance(): void {
+    if (CacheManager.instance) {
+      CacheManager.instance.memoryCache.clear();
+      CacheManager.instance.redisClient = null;
+      CacheManager.instance.useRedis = false;
+    }
+    CacheManager.instance = undefined as unknown as CacheManager;
+  }
+  
   /**
    * Initialize Redis client
    */
   private async initializeRedis(): Promise<void> {
     if (!this.config.redisUrl) {
-      console.log('[Cache] No Redis URL provided, using in-memory cache');
+      logger.info('[Cache] No Redis URL provided, using in-memory cache');
       return;
     }
 
@@ -72,14 +88,14 @@ export class CacheManager {
       // this.redisClient = createClient({ url: this.config.redisUrl });
       // await this.redisClient.connect();
       // this.useRedis = true;
-      // console.log('[Cache] Redis connected successfully');
+      // logger.info('[Cache] Redis connected successfully');
 
-      console.log('[Cache] Redis initialization placeholder - using in-memory cache');
+      logger.info('[Cache] Redis initialization placeholder - using in-memory cache');
     } catch (error) {
-      console.error('[Cache] Redis initialization failed:', error);
+      logger.error('[Cache] Redis initialization failed:', error);
 
       if (this.config.useMemoryFallback) {
-        console.log('[Cache] Falling back to in-memory cache');
+        logger.info('[Cache] Falling back to in-memory cache');
       }
     }
   }
@@ -120,7 +136,7 @@ export class CacheManager {
 
       return entry.data as T;
     } catch (error) {
-      console.error('[Cache] Get error:', error);
+      logger.error('[Cache] Get error:', error);
       return null;
     }
   }
@@ -153,7 +169,7 @@ export class CacheManager {
       // Clean up expired entries periodically
       this.cleanupExpired();
     } catch (error) {
-      console.error('[Cache] Set error:', error);
+      logger.error('[Cache] Set error:', error);
     }
   }
 
@@ -169,7 +185,7 @@ export class CacheManager {
 
       this.memoryCache.delete(key);
     } catch (error) {
-      console.error('[Cache] Delete error:', error);
+      logger.error('[Cache] Delete error:', error);
     }
   }
 
@@ -185,7 +201,7 @@ export class CacheManager {
 
       this.memoryCache.clear();
     } catch (error) {
-      console.error('[Cache] Clear error:', error);
+      logger.error('[Cache] Clear error:', error);
     }
   }
 

packages/ai/src/prediction-service.ts

@@ -11,6 +11,9 @@ import { BaseMLProvider } from './providers/base-provider.js';
 import CacheManager from './cache-manager.js';
 import PerformanceMonitor from './performance-monitor.js';
 
+import { createLogger } from '@hotcrm/core';
+const logger = createLogger('ai:prediction-service');
+
 export interface PredictionRequest {
   /** Model ID to use */
   modelId: string;
@@ -191,7 +194,7 @@ export class PredictionService {
           metadata: result.metadata
         }));
       } catch (error) {
-        console.warn('[PredictionService] Batch prediction failed, falling back to sequential:', error);
+        logger.warn('[PredictionService] Batch prediction failed, falling back to sequential:', error);
       }
     }
 
@@ -238,7 +241,7 @@ export class PredictionService {
         const result = await provider.predict<T>(model.id, { features, context });
         return result;
       } catch (error) {
-        console.warn(`[PredictionService] Provider prediction failed for ${model.id}, falling back to mock:`, error);
+        logger.warn(`[PredictionService] Provider prediction failed for ${model.id}, falling back to mock:`, error);
       }
     }
 

packages/ai/src/providers/aws-sagemaker-provider.ts

@@ -6,6 +6,9 @@
 
 import BaseMLProvider, { MLProviderConfig, PredictionInput, PredictionOutput } from './base-provider.js';
 
+import { createLogger } from '@hotcrm/core';
+const logger = createLogger('ai:aws-sagemaker-provider');
+
 export interface SageMakerConfig extends MLProviderConfig {
   provider: 'aws-sagemaker';
   credentials: {
@@ -46,7 +49,7 @@ export class AWSSageMakerProvider extends BaseMLProvider {
     this.client = {
       send: async (command: any) => {
         // Mock implementation
-        console.log('[SageMaker] Would invoke endpoint:', command.input?.EndpointName);
+        logger.info('[SageMaker] Would invoke endpoint:', command.input?.EndpointName);
         const mockBody = JSON.stringify({ predictions: [0.85] });
         return { Body: { toString: () => mockBody } };
       }
@@ -66,7 +69,7 @@ export class AWSSageMakerProvider extends BaseMLProvider {
 
       return true;
     } catch (error) {
-      console.error('[SageMaker] Validation failed:', error);
+      logger.error('[SageMaker] Validation failed:', error);
       return false;
     }
   }
@@ -112,7 +115,7 @@ export class AWSSageMakerProvider extends BaseMLProvider {
         }
       };
     } catch (error) {
-      console.error('[SageMaker] Prediction error:', error);
+      logger.error('[SageMaker] Prediction error:', error);
       throw new Error(`SageMaker prediction failed: ${error instanceof Error ? error.message : 'Unknown error'}`);
     }
   }

packages/ai/src/providers/azure-ml-provider.ts

@@ -6,6 +6,9 @@
 
 import BaseMLProvider, { MLProviderConfig, PredictionInput, PredictionOutput } from './base-provider.js';
 
+import { createLogger } from '@hotcrm/core';
+const logger = createLogger('ai:azure-ml-provider');
+
 // Type stubs for when axios is not available
 interface AxiosInstance {
   post(url: string, data: any): Promise<any>;
@@ -83,7 +86,7 @@ export class AzureMLProvider extends BaseMLProvider {
 
       return true;
     } catch (error) {
-      console.error('[Azure ML] Validation failed:', error);
+      logger.error('[Azure ML] Validation failed:', error);
       return false;
     }
   }
@@ -128,7 +131,7 @@ export class AzureMLProvider extends BaseMLProvider {
         }
       };
     } catch (error) {
-      console.error('[Azure ML] Prediction error:', error);
+      logger.error('[Azure ML] Prediction error:', error);
 
       const err = error as any;
       if (err.isAxiosError) {
@@ -175,7 +178,7 @@ export class AzureMLProvider extends BaseMLProvider {
         }
       }));
     } catch (error) {
-      console.error('[Azure ML] Batch prediction error:', error);
+      logger.error('[Azure ML] Batch prediction error:', error);
       throw new Error(`Azure ML batch prediction failed: ${error instanceof Error ? error.message : 'Unknown error'}`);
     }
   }

packages/ai/src/providers/openai-provider.ts

@@ -6,6 +6,9 @@
 
 import BaseMLProvider, { MLProviderConfig, PredictionInput, PredictionOutput } from './base-provider.js';
 
+import { createLogger } from '@hotcrm/core';
+const logger = createLogger('ai:openai-provider');
+
 // Type stubs for when axios is not available
 interface AxiosInstance {
   post(url: string, data: any): Promise<any>;
@@ -86,7 +89,7 @@ export class OpenAIProvider extends BaseMLProvider {
 
       return true;
     } catch (error) {
-      console.error('[OpenAI] Validation failed:', error);
+      logger.error('[OpenAI] Validation failed:', error);
       return false;
     }
   }
@@ -128,7 +131,7 @@ export class OpenAIProvider extends BaseMLProvider {
         }
       };
     } catch (error) {
-      console.error('[OpenAI] Prediction error:', error);
+      logger.error('[OpenAI] Prediction error:', error);
 
       const err = error as any;
       if (err.isAxiosError) {