Skip to content

Commit 570ef34

Browse files
authored
Startup speed, event filtering, log hygiene & reliability (#272)
* Startup speed + event filtering + memory leak fixes - Parallelize persona initialization: batched 6-concurrent (18-36s → 3-6s) - Parallelize PersonaUser.initialize(): genome sync, rate limiter, corpus load run concurrently - EventsDaemonBrowser: filter-first DOM dispatch (only events with registered interest) - Events.subscribe(): registers DOM interest automatically in browser - BaseWidget/BaseContentWidget: register DOM interest for event dispatchers - WidgetEventServiceBrowser: track and cleanup document listeners on disconnect - ResponseCorrelator: periodic cleanup timer (60s sweep) + destroy() on disconnect - JTAGClient.disconnect(): calls correlator.destroy() to stop orphaned timers * significant logging reliabiilty and speed improvements * UserEntityCache + reduced monitoring: eliminate 515 ORM timeouts - UserEntityCache: in-memory TTL cache for UserEntity reads, 60s expiry - CallerDetector: use cached reads instead of raw ORM.read per command - SessionDaemonServer: getUserById uses cached UserEntity reads - UserDaemonServer: monitoring loop 5s→30s, populates cache on query - Combined with Round 1 (LogBatcher, EventRateLimiter, ORM race guards), total errors eliminated: ~2,200 → 0 per session * Health check exponential backoff + log throttling for failing providers AdapterHealthMonitor: per-adapter backoff (base × 2^failures, 5min ceiling) so unhealthy providers don't spam checks every 30s but still recover. BaseOpenAICompatibleAdapter: throttle insufficient_funds/rate_limited logs to once per 5 minutes per status instead of every API call. * Log hygiene: eliminate 87% of npm-start.log noise (7596 → 936 lines) - Remove 45+ debug console.error calls left from session identity investigation - Raise ORM SLOW thresholds 50ms/100ms → 1000ms (5689 → 192 lines) - Exclude fire-and-forget log/write-batch from TimingHarness slow logging - Remove per-init console.logs: DatabaseHandleRegistry, ResourceManager, AIAudioInjector TTS subscribe, AIGenerateServerCommand - Steady-state log growth: continuous → 0 lines/30s * Remove EntityScroller debug logging that spams browser console Every entity update event was logging two console.log calls per entity, flooding the browser console with update notifications.
1 parent 21dc801 commit 570ef34

File tree

36 files changed

+569
-235
lines changed

36 files changed

+569
-235
lines changed

src/commands/ai/generate/server/AIGenerateServerCommand.ts

Lines changed: 1 addition & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -38,7 +38,6 @@ export class AIGenerateServerCommand extends AIGenerateCommand {
3838
// Mode selection: RAG context building OR direct messages
3939
if (params.roomId) {
4040
// RAG MODE: Build context from chat room (SAME code path as PersonaUser)
41-
console.log(`🤖 AI Generate: Building RAG context for room ${params.roomId.slice(0, 8)}...`);
4241

4342
// Find persona if not specified
4443
let targetPersonaId = params.personaId;
@@ -57,7 +56,6 @@ export class AIGenerateServerCommand extends AIGenerateCommand {
5756
const personaRecord = usersResult.data[0];
5857
targetPersonaId = personaRecord.id;
5958
personaDisplayName = personaRecord.data.displayName;
60-
console.log(`✅ AI Generate: Using persona "${personaRecord.data.displayName}" (${targetPersonaId.slice(0, 8)})`);
6159
}
6260

6361
// Build RAG context (SAME code as PersonaUser.respondToMessage line 207-215)
@@ -134,7 +132,6 @@ export class AIGenerateServerCommand extends AIGenerateCommand {
134132

135133
} else if (params.messages) {
136134
// DIRECT MODE: Use provided messages
137-
console.log(`🤖 AI Generate: Using provided messages (${params.messages.length})...`);
138135
request = paramsToRequest(params);
139136

140137
} else {
@@ -143,7 +140,6 @@ export class AIGenerateServerCommand extends AIGenerateCommand {
143140

144141
// PREVIEW MODE: Return request without calling LLM
145142
if (params.preview) {
146-
console.log(`👁️ AI Generate: Preview mode - returning request without LLM call`);
147143
const formatted = this.formatRequestPreview(request, ragContext);
148144

149145
return createAIGenerateResultFromParams(params, {
@@ -156,15 +152,9 @@ export class AIGenerateServerCommand extends AIGenerateCommand {
156152
}
157153

158154
// GENERATION MODE: Call AIProviderDaemon
159-
console.log(`🤖 AI Generate: Calling LLM with ${request.messages.length} messages...`);
160155
const response = await AIProviderDaemon.generateText(request);
161-
162-
const result = responseToResult(response, params);
163-
console.log(`✅ AI Generate: Generated ${result.usage?.outputTokens} tokens in ${result.responseTimeMs}ms`);
164-
165-
return result;
156+
return responseToResult(response, params);
166157
} catch (error) {
167-
console.error(`❌ AI Generate: Execution failed:`, error);
168158
return createErrorResult(params, error instanceof Error ? error.message : String(error));
169159
}
170160
}

src/daemons/ai-provider-daemon/server/AdapterHealthMonitor.ts

Lines changed: 29 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -173,6 +173,25 @@ export class AdapterHealthMonitor {
173173
await Promise.allSettled(checks);
174174
}
175175

176+
/**
177+
* Compute per-adapter check interval with exponential backoff.
178+
* Healthy adapters use base interval. Failed adapters back off exponentially
179+
* up to a ceiling, so they still recover when network returns.
180+
*
181+
* Backoff schedule (with 30s base):
182+
* 0 failures → 30s
183+
* 1 failure → 60s
184+
* 2 failures → 120s
185+
* 3 failures → 240s (4 min)
186+
* 5+ failures → 300s (5 min ceiling)
187+
*/
188+
private adapterCheckInterval(state: AdapterHealthState, baseInterval: number): number {
189+
if (state.consecutiveFailures === 0) return baseInterval;
190+
const backoff = baseInterval * Math.pow(2, state.consecutiveFailures);
191+
const ceiling = 5 * 60 * 1000; // 5-minute max — ensures recovery from transient network issues
192+
return Math.min(backoff, ceiling);
193+
}
194+
176195
/**
177196
* Check a single adapter's health
178197
* Concurrent-safe with per-adapter lock
@@ -188,8 +207,11 @@ export class AdapterHealthMonitor {
188207
return;
189208
}
190209

210+
// Exponential backoff for failing adapters (still retries at ceiling for recovery)
211+
const effectiveInterval = this.adapterCheckInterval(state, checkInterval);
212+
191213
// Check if enough time has passed since last check
192-
if (now - state.lastCheckTime < checkInterval) {
214+
if (now - state.lastCheckTime < effectiveInterval) {
193215
return; // Too soon for this adapter
194216
}
195217

@@ -211,7 +233,12 @@ export class AdapterHealthMonitor {
211233
state.consecutiveFailures = 0;
212234
} else {
213235
state.consecutiveFailures++;
214-
log.warn(`⚠️ ${state.adapter.providerId}: Health check failed (${state.consecutiveFailures} consecutive failures)`);
236+
const nextRetryMs = this.adapterCheckInterval(state, checkInterval);
237+
const nextRetrySec = Math.round(nextRetryMs / 1000);
238+
// Only log on first failure and at backoff milestones (powers of 2) to reduce noise
239+
if (state.consecutiveFailures === 1 || (state.consecutiveFailures & (state.consecutiveFailures - 1)) === 0) {
240+
log.warn(`⚠️ ${state.adapter.providerId}: Health check failed (${state.consecutiveFailures} consecutive, next retry in ${nextRetrySec}s)`);
241+
}
215242

216243
// Get max failures threshold from SystemDaemon
217244
const systemDaemon = SystemDaemon.sharedInstance();

src/daemons/ai-provider-daemon/shared/adapters/BaseOpenAICompatibleAdapter.ts

Lines changed: 11 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -151,6 +151,10 @@ export abstract class BaseOpenAICompatibleAdapter extends BaseAIProviderAdapter
151151
protected readonly config: OpenAICompatibleConfig;
152152
protected isInitialized = false;
153153

154+
// Throttle per-status log messages (avoid spamming same error every call)
155+
private _lastStatusLogTime: Map<string, number> = new Map();
156+
private readonly _statusLogThrottleMs = 5 * 60 * 1000; // 5 minutes
157+
154158
constructor(config: OpenAICompatibleConfig) {
155159
super();
156160
this.config = config;
@@ -731,7 +735,13 @@ export abstract class BaseOpenAICompatibleAdapter extends BaseAIProviderAdapter
731735
timestamp: Date.now(),
732736
});
733737

734-
this.log(null, 'error', `💰 ${this.providerName}: ${status} - ${errorBody.slice(0, 200)}`);
738+
// Throttle log to once per 5 minutes per status (avoid spamming same error)
739+
const now = Date.now();
740+
const lastLog = this._lastStatusLogTime.get(status) ?? 0;
741+
if (now - lastLog >= this._statusLogThrottleMs) {
742+
this._lastStatusLogTime.set(status, now);
743+
this.log(null, 'error', `💰 ${this.providerName}: ${status} - ${errorBody.slice(0, 200)}`);
744+
}
735745
}
736746

737747
throw new Error(`HTTP ${response.status}: ${errorBody}`);

src/daemons/data-daemon/server/DatabaseHandleRegistry.ts

Lines changed: 0 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -161,7 +161,6 @@ export class DatabaseHandleRegistry {
161161

162162
// Initialize default handle metadata
163163
const expandedDbPath = getDatabasePath();
164-
console.log(`📦 DatabaseHandleRegistry: Path registry initialized (default db: ${expandedDbPath})`);
165164

166165
this.handleMetadata.set(DEFAULT_HANDLE, {
167166
adapter: 'rust' as AdapterType, // All I/O goes through Rust
@@ -218,7 +217,6 @@ export class DatabaseHandleRegistry {
218217
throw new Error('SQLite config requires either "path" or "filename" property');
219218
}
220219
// Just register the path - Rust handles actual connections
221-
console.log(`📦 DatabaseHandleRegistry: Registered handle ${handle.substring(0, 8)}... → ${dbPath}`);
222220
break;
223221
}
224222

src/daemons/data-daemon/server/ORMRustClient.ts

Lines changed: 2 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -143,7 +143,6 @@ export class ORMRustClient {
143143
this.socket.on('connect', () => {
144144
this.connected = true;
145145
this.connecting = false;
146-
console.log('[ORMRustClient] Connected to continuum-core');
147146
resolve();
148147
});
149148

@@ -223,8 +222,8 @@ export class ORMRustClient {
223222
const networkAndRustMs = totalMs - timing.stringifyMs - timing.writeMs - parseMs;
224223
this.pendingTimings.delete(response.requestId);
225224

226-
// Log slow operations (>50ms threshold matches Rust)
227-
if (totalMs > 50) {
225+
// Log slow operations (>1000ms — raised from 50ms to reduce startup noise)
226+
if (totalMs > 1000) {
228227
console.warn(`[ORMRustClient] SLOW IPC: ${timing.command} total=${totalMs}ms (stringify=${timing.stringifyMs}ms write=${timing.writeMs}ms network+rust=${networkAndRustMs}ms parse=${parseMs}ms)`);
229228
}
230229
}

src/daemons/data-daemon/shared/ORMLogger.ts

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -84,8 +84,8 @@ export function logOperationStart(
8484
console.log(`[ORM] ${operation} ${collection} completed in ${durationMs}ms`);
8585
}
8686

87-
// Warn on slow operations
88-
if (durationMs > 100) {
87+
// Warn on slow operations (>1000ms — raised from 100ms to reduce startup noise)
88+
if (durationMs > 1000) {
8989
console.warn(`[ORM] SLOW: ${operation} ${collection} took ${durationMs}ms`);
9090
}
9191
};

src/daemons/events-daemon/browser/EventsDaemonBrowser.ts

Lines changed: 59 additions & 21 deletions
Original file line numberDiff line numberDiff line change
@@ -32,15 +32,16 @@ export class EventsDaemonBrowser extends EventsDaemon implements IEventSubscript
3232
private domEventBridge: DOMEventBridge;
3333
private subscriptionManager = new EventSubscriptionManager();
3434

35+
/**
36+
* Registry of event names with active DOM listeners.
37+
* DOM CustomEvent dispatch is skipped for events not in this set.
38+
* Widgets register via registerDOMInterest() when they need document-level events.
39+
*/
40+
private static _domInterest = new Set<string>();
41+
3542
constructor(context: JTAGContext, router: JTAGRouter) {
3643
super(context, router);
3744

38-
// Reduce log spam - debug logs removed
39-
// console.log(`🔥 CLAUDE-BROWSER-DAEMON-DEBUG-${Date.now()}: EventsDaemonBrowser constructor called!`);
40-
// console.log(`🔥 Context: ${context.environment}/${context.uuid}`);
41-
// console.log(`🔥 ENDPOINT-DEBUG: EventsDaemonBrowser.subpath = "${this.subpath}"`);
42-
// console.log(`🔥 ENDPOINT-DEBUG: Expected browser endpoint should be "browser/${this.subpath}"`);
43-
4445
// Setup DOM event bridge for widget communication
4546
this.domEventBridge = new DOMEventBridge(this.eventManager);
4647
verbose() && console.log('🌉 EventsDaemonBrowser: DOM event bridge initialized');
@@ -56,33 +57,70 @@ export class EventsDaemonBrowser extends EventsDaemon implements IEventSubscript
5657
}
5758

5859
/**
59-
* Handle local event bridging - emit to event system AND DOM for BaseWidget
60+
* Register interest in receiving DOM CustomEvents for a specific event name.
61+
* Only events with registered interest will be dispatched to the document.
62+
* Returns an unregister function.
6063
*/
61-
protected handleLocalEventBridge(eventName: string, eventData: unknown): void {
62-
// 1. Emit to local event system - DOMEventBridge will automatically handle DOM dispatch
63-
this.eventManager.events.emit(eventName, eventData);
64+
public static registerDOMInterest(eventName: string): () => void {
65+
EventsDaemonBrowser._domInterest.add(eventName);
66+
return () => {
67+
EventsDaemonBrowser._domInterest.delete(eventName);
68+
};
69+
}
6470

65-
// 2. Dispatch DOM event for BaseWidget integration (backward compatibility)
66-
const domEvent = new CustomEvent(eventName, {
67-
detail: eventData
68-
});
71+
/**
72+
* Check if anything has registered DOM interest for this event name.
73+
* Checks both:
74+
* - Events.domInterest (populated by Events.subscribe() in browser)
75+
* - _domInterest (populated by registerDOMInterest() from BaseWidget/WidgetEventServiceBrowser)
76+
* Uses prefix matching: 'data:chat_messages' matches 'data:chat_messages:created'.
77+
*/
78+
private hasDOMInterest(eventName: string): boolean {
79+
// Direct match in either registry
80+
if (Events.domInterest.has(eventName)) return true;
81+
if (EventsDaemonBrowser._domInterest.has(eventName)) return true;
6982

70-
// Type-safe document access for browser environment
71-
if (typeof globalThis !== 'undefined' && 'document' in globalThis) {
72-
(globalThis as typeof globalThis & { document: Document }).document.dispatchEvent(domEvent);
83+
// Prefix match against both registries
84+
for (const interest of Events.domInterest) {
85+
if (eventName.startsWith(interest + ':') || interest.startsWith(eventName + ':')) return true;
7386
}
87+
for (const interest of EventsDaemonBrowser._domInterest) {
88+
if (eventName.startsWith(interest + ':') || interest.startsWith(eventName + ':')) return true;
89+
}
90+
return false;
91+
}
92+
93+
/**
94+
* Handle local event bridging - emit to event system AND DOM for BaseWidget
95+
*
96+
* Dispatch order:
97+
* 1. Internal EventEmitter (DOMEventBridge handles mapped events)
98+
* 2. SubscriptionManager (exact, wildcard, elegant pattern matching)
99+
* 3. Legacy wildcard subscriptions
100+
* 4. DOM CustomEvent ONLY if a widget registered interest (filter-first, not spam-then-filter)
101+
*/
102+
protected handleLocalEventBridge(eventName: string, eventData: unknown): void {
103+
// 1. Emit to local event system — DOMEventBridge handles its mapped events
104+
this.eventManager.events.emit(eventName, eventData);
74105

75-
// 3. Trigger unified subscription manager (NEW!)
76-
// This handles exact, wildcard, and elegant pattern subscriptions
106+
// 2. Trigger unified subscription manager (exact, wildcard, and elegant patterns)
77107
this.subscriptionManager.trigger(eventName, eventData);
78108

79-
// 4. Legacy: Also check wildcard subscriptions from Events.subscribe()
80-
// TODO: Migrate to unified subscription manager
109+
// 3. Legacy: Also check wildcard subscriptions from Events.subscribe()
81110
try {
82111
Events.checkWildcardSubscriptions(eventName, eventData);
83112
} catch (error) {
84113
console.error('Failed to check wildcard subscriptions:', error);
85114
}
115+
116+
// 4. DOM dispatch — ONLY if a widget registered interest for this event namespace
117+
// This prevents creating DOM CustomEvents for high-frequency events no widget cares about
118+
if (this.hasDOMInterest(eventName)) {
119+
if (typeof globalThis !== 'undefined' && 'document' in globalThis) {
120+
const domEvent = new CustomEvent(eventName, { detail: eventData });
121+
(globalThis as typeof globalThis & { document: Document }).document.dispatchEvent(domEvent);
122+
}
123+
}
86124
}
87125

88126
/**

src/daemons/events-daemon/shared/EventsDaemon.ts

Lines changed: 6 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -17,9 +17,9 @@ import { DaemonBase } from '../../command-daemon/shared/DaemonBase';
1717
class EventRateLimiter {
1818
private counts = new Map<string, number>();
1919
private windowStart = Date.now();
20-
private readonly windowMs = 100; // 100ms window
21-
private readonly maxPerWindow = 20; // Max 20 of same event per window
22-
private readonly warnThreshold = 10; // Warn at 10+ per window
20+
private readonly windowMs = 1000; // 1-second window (matches Rust-side rate limiter)
21+
private readonly maxPerWindow = 200; // Max 200 of same event per second
22+
private readonly warnThreshold = 100; // Warn at 100+ per second
2323
private blocked = new Set<string>();
2424
private warned = new Set<string>(); // Track warned events to avoid spam
2525

@@ -40,7 +40,7 @@ class EventRateLimiter {
4040
.sort((a, b) => b[1] - a[1]);
4141

4242
if (hotEvents.length > 0) {
43-
console.warn(`⚠️ EVENT ACTIVITY: ${hotEvents.map(([e, c]) => `${e}(${c})`).join(', ')}`);
43+
console.warn(`[EventRateLimiter] EVENT ACTIVITY: ${hotEvents.map(([e, c]) => `${e}(${c})`).join(', ')}`);
4444
}
4545
}
4646

@@ -63,7 +63,7 @@ class EventRateLimiter {
6363
if (count === this.warnThreshold && !this.warned.has(eventName)) {
6464
this.warned.add(eventName);
6565
this.totalWarned++;
66-
console.warn(`⚠️ EVENT TRENDING: "${eventName}" at ${count}x in ${this.windowMs}ms (blocking at ${this.maxPerWindow})`);
66+
console.warn(`[EventRateLimiter] EVENT TRENDING: "${eventName}" at ${count}x in ${this.windowMs}ms (blocking at ${this.maxPerWindow})`);
6767
}
6868

6969
// Block if over threshold
@@ -75,7 +75,7 @@ class EventRateLimiter {
7575
if (this.blockedHistory.length > 100) {
7676
this.blockedHistory.shift();
7777
}
78-
console.error(`🛑 EVENT CASCADE BLOCKED: "${eventName}" fired ${count}x in ${this.windowMs}ms`);
78+
console.error(`[EventRateLimiter] EVENT CASCADE BLOCKED: "${eventName}" fired ${count}x in ${this.windowMs}ms`);
7979
return true;
8080
}
8181

0 commit comments

Comments
 (0)