From 340e718199f0a75784448a1cef7ac25085fd90ab Mon Sep 17 00:00:00 2001 From: Matthew Raymer Date: Tue, 3 Jun 2025 13:05:40 +0000 Subject: [PATCH] feat(logging): enhance SQLite logging and IPC handler management - Add Winston-based structured logging system with: - Separate console and file output formats - Custom SQLite and migration loggers - Configurable log levels and verbosity - Log rotation and file management - Type-safe logger extensions - Improve IPC handler management: - Add handler registration tracking - Implement proper cleanup before re-registration - Fix handler registration conflicts - Add better error handling for IPC operations - Add migration logging controls: - Configurable via DEBUG_MIGRATIONS env var - Reduced console noise while maintaining file logs - Structured migration status reporting Security: - Add proper log file permissions (0o755) - Implement log rotation to prevent disk space issues - Add type safety for all logging operations - Prevent handler registration conflicts Dependencies: - Add winston for enhanced logging - Remove deprecated @types/winston This change improves debugging capabilities while reducing console noise and fixing IPC handler registration issues that could cause database operation failures. --- electron/package-lock.json | 221 ++++++++++++++++++- electron/package.json | 3 +- electron/src/rt/logger.ts | 189 ++++++++++------ electron/src/rt/sqlite-init.ts | 388 +++++++++++++++------------------ electron/src/setup.ts | 50 ++++- 5 files changed, 571 insertions(+), 280 deletions(-) diff --git a/electron/package-lock.json b/electron/package-lock.json index 7d14dbbc..a94e6c0d 100644 --- a/electron/package-lock.json +++ b/electron/package-lock.json @@ -22,7 +22,8 @@ "electron-updater": "^5.3.0", "electron-window-state": "^5.0.3", "jszip": "^3.10.1", - "node-fetch": "^2.6.7" + "node-fetch": "^2.6.7", + "winston": "^3.17.0" }, "devDependencies": { "@types/better-sqlite3": "^7.6.13", @@ -134,6 +135,26 @@ "tslib": "^2.1.0" } }, + "node_modules/@colors/colors": { + "version": "1.6.0", + "resolved": "https://registry.npmjs.org/@colors/colors/-/colors-1.6.0.tgz", + "integrity": "sha512-Ir+AOibqzrIsL6ajt3Rz3LskB7OiMVHqltZmspbW/TJuTVuyOMirVqAkjfY6JISiLHgyNqicAC8AyHHGzNd/dA==", + "license": "MIT", + "engines": { + "node": ">=0.1.90" + } + }, + "node_modules/@dabh/diagnostics": { + "version": "2.0.3", + "resolved": "https://registry.npmjs.org/@dabh/diagnostics/-/diagnostics-2.0.3.tgz", + "integrity": "sha512-hrlQOIi7hAfzsMqlGSFyVucrx38O+j6wiGOf//H2ecvIEqYN4ADBSS2iLMh5UFyDunCNniUIPk/q3riFv45xRA==", + "license": "MIT", + "dependencies": { + "colorspace": "1.1.x", + "enabled": "2.0.x", + "kuler": "^2.0.0" + } + }, "node_modules/@develar/schema-utils": { "version": "2.6.5", "resolved": "https://registry.npmjs.org/@develar/schema-utils/-/schema-utils-2.6.5.tgz", @@ -878,6 +899,12 @@ "integrity": "sha512-+OpjSaq85gvlZAYINyzKpLeiFkSC4EsC6IIiT6v6TLSU5k5U83fHGj9Lel8oKEXM0HqgrMVCjXPDPVICtxF7EQ==", "license": "MIT" }, + "node_modules/@types/triple-beam": { + "version": "1.3.5", + "resolved": "https://registry.npmjs.org/@types/triple-beam/-/triple-beam-1.3.5.tgz", + "integrity": "sha512-6WaYesThRMCl19iryMYP7/x2OVgCtbIVflDGFpWnb9irXI3UjYE4AzmYuiUKY1AJstGijoY+MgUszMgRxIYTYw==", + "license": "MIT" + }, "node_modules/@types/verror": { "version": "1.10.11", "resolved": "https://registry.npmjs.org/@types/verror/-/verror-1.10.11.tgz", @@ -1143,7 +1170,6 @@ "version": "3.2.6", "resolved": "https://registry.npmjs.org/async/-/async-3.2.6.tgz", "integrity": "sha512-htCUDlxyyCLMgaM3xXg0C0LW2xqfuQ6p05pCEIsXuyQ+a1koYKTuBMzRNwmybfLgvJDMd0r1LTn4+E0Ti6C2AA==", - "dev": true, "license": "MIT" }, "node_modules/async-exit-hook": { @@ -1690,6 +1716,16 @@ "url": "https://github.com/sponsors/sindresorhus" } }, + "node_modules/color": { + "version": "3.2.1", + "resolved": "https://registry.npmjs.org/color/-/color-3.2.1.tgz", + "integrity": "sha512-aBl7dZI9ENN6fUGC7mWpMTPNHmWUSNan9tuWN6ahh5ZLNk9baLJOnSMlrQkHcrfFgz2/RigjUVAjdx36VcemKA==", + "license": "MIT", + "dependencies": { + "color-convert": "^1.9.3", + "color-string": "^1.6.0" + } + }, "node_modules/color-convert": { "version": "2.0.1", "resolved": "https://registry.npmjs.org/color-convert/-/color-convert-2.0.1.tgz", @@ -1708,6 +1744,31 @@ "integrity": "sha512-dOy+3AuW3a2wNbZHIuMZpTcgjGuLU/uBL/ubcZF9OXbDo8ff4O8yVp5Bf0efS8uEoYo5q4Fx7dY9OgQGXgAsQA==", "license": "MIT" }, + "node_modules/color-string": { + "version": "1.9.1", + "resolved": "https://registry.npmjs.org/color-string/-/color-string-1.9.1.tgz", + "integrity": "sha512-shrVawQFojnZv6xM40anx4CkoDP+fZsw/ZerEMsW/pyzsRbElpsL/DBVW7q3ExxwusdNXI3lXpuhEZkzs8p5Eg==", + "license": "MIT", + "dependencies": { + "color-name": "^1.0.0", + "simple-swizzle": "^0.2.2" + } + }, + "node_modules/color/node_modules/color-convert": { + "version": "1.9.3", + "resolved": "https://registry.npmjs.org/color-convert/-/color-convert-1.9.3.tgz", + "integrity": "sha512-QfAUtd+vFdAtFQcC8CCyYt1fYWxSqAiK2cSD6zDB8N3cpsEBAvRxp9zOGg6G/SHHJYAT88/az/IuDGALsNVbGg==", + "license": "MIT", + "dependencies": { + "color-name": "1.1.3" + } + }, + "node_modules/color/node_modules/color-name": { + "version": "1.1.3", + "resolved": "https://registry.npmjs.org/color-name/-/color-name-1.1.3.tgz", + "integrity": "sha512-72fSenhMw2HZMTVHeCA9KCmpEIbzWiQsjN+BHcBbS9vr1mtt+vJjPdksIBNUmKAW8TFUDPJK5SUU3QhE9NEXDw==", + "license": "MIT" + }, "node_modules/colors": { "version": "1.0.3", "resolved": "https://registry.npmjs.org/colors/-/colors-1.0.3.tgz", @@ -1718,6 +1779,16 @@ "node": ">=0.1.90" } }, + "node_modules/colorspace": { + "version": "1.1.4", + "resolved": "https://registry.npmjs.org/colorspace/-/colorspace-1.1.4.tgz", + "integrity": "sha512-BgvKJiuVu1igBUF2kEjRCZXol6wiiGbY5ipL/oVPwm0BL9sIpMIzM8IK7vwuxIIzOXMV3Ey5w+vxhm0rR/TN8w==", + "license": "MIT", + "dependencies": { + "color": "^3.1.3", + "text-hex": "1.0.x" + } + }, "node_modules/combined-stream": { "version": "1.0.8", "resolved": "https://registry.npmjs.org/combined-stream/-/combined-stream-1.0.8.tgz", @@ -2464,6 +2535,12 @@ "integrity": "sha512-MSjYzcWNOA0ewAHpz0MxpYFvwg6yjy1NG3xteoqz644VCo/RPgnr1/GGt+ic3iJTzQ8Eu3TdM14SawnVUmGE6A==", "license": "MIT" }, + "node_modules/enabled": { + "version": "2.0.0", + "resolved": "https://registry.npmjs.org/enabled/-/enabled-2.0.0.tgz", + "integrity": "sha512-AKrN98kuwOzMIdAizXGI86UFBoo26CL21UM763y1h/GMSJ4/OHU9k2YlsmBpyScFo/wbLzWQJBMCW4+IO3/+OQ==", + "license": "MIT" + }, "node_modules/encoding": { "version": "0.1.13", "resolved": "https://registry.npmjs.org/encoding/-/encoding-0.1.13.tgz", @@ -2656,6 +2733,12 @@ "pend": "~1.2.0" } }, + "node_modules/fecha": { + "version": "4.2.3", + "resolved": "https://registry.npmjs.org/fecha/-/fecha-4.2.3.tgz", + "integrity": "sha512-OP2IUU6HeYKJi3i0z4A19kHMQoLVs4Hc+DPqqxI2h/DPZHTm/vjsfC6P0b4jCMy14XizLBqvndQ+UilD7707Jw==", + "license": "MIT" + }, "node_modules/file-uri-to-path": { "version": "1.0.0", "resolved": "https://registry.npmjs.org/file-uri-to-path/-/file-uri-to-path-1.0.0.tgz", @@ -2707,6 +2790,12 @@ "node": ">=8" } }, + "node_modules/fn.name": { + "version": "1.1.0", + "resolved": "https://registry.npmjs.org/fn.name/-/fn.name-1.1.0.tgz", + "integrity": "sha512-GRnmB5gPyJpAhTQdSZTSp9uaPSvl09KoYcMQtsB9rQoOmzs9dH6ffeccH+Z+cv6P68Hu5bC6JjRh4Ah/mHSNRw==", + "license": "MIT" + }, "node_modules/foreground-child": { "version": "3.3.1", "resolved": "https://registry.npmjs.org/foreground-child/-/foreground-child-3.3.1.tgz", @@ -3269,6 +3358,12 @@ "node": "^14.17.0 || ^16.13.0 || >=18.0.0" } }, + "node_modules/is-arrayish": { + "version": "0.3.2", + "resolved": "https://registry.npmjs.org/is-arrayish/-/is-arrayish-0.3.2.tgz", + "integrity": "sha512-eVRqCvVlZbuw3GrM63ovNSNAeA1K16kaR/LRY/92w0zxQ5/1YzwblUX652i4Xs9RwAGjW9d9y6X88t8OaAJfWQ==", + "license": "MIT" + }, "node_modules/is-binary-path": { "version": "2.1.0", "resolved": "https://registry.npmjs.org/is-binary-path/-/is-binary-path-2.1.0.tgz", @@ -3357,6 +3452,18 @@ "node": ">=0.12.0" } }, + "node_modules/is-stream": { + "version": "2.0.1", + "resolved": "https://registry.npmjs.org/is-stream/-/is-stream-2.0.1.tgz", + "integrity": "sha512-hFoiJiTl63nn+kstHGBtewWSKnQLpyb155KHheA1l39uvtO9nWIop1p3udqPcUd/xbF1VLMO4n7OI6p7RbngDg==", + "license": "MIT", + "engines": { + "node": ">=8" + }, + "funding": { + "url": "https://github.com/sponsors/sindresorhus" + } + }, "node_modules/is-unicode-supported": { "version": "0.1.0", "resolved": "https://registry.npmjs.org/is-unicode-supported/-/is-unicode-supported-0.1.0.tgz", @@ -3568,6 +3675,12 @@ "node": ">=6" } }, + "node_modules/kuler": { + "version": "2.0.0", + "resolved": "https://registry.npmjs.org/kuler/-/kuler-2.0.0.tgz", + "integrity": "sha512-Xq9nH7KlWZmXAtodXDDRE7vs6DU1gTU8zYDHDiWLSip45Egwq3plLHzPn27NgvzL2r1LMPC1vdqh98sQxtqj4A==", + "license": "MIT" + }, "node_modules/lazy-val": { "version": "1.0.5", "resolved": "https://registry.npmjs.org/lazy-val/-/lazy-val-1.0.5.tgz", @@ -3651,6 +3764,23 @@ "url": "https://github.com/sponsors/sindresorhus" } }, + "node_modules/logform": { + "version": "2.7.0", + "resolved": "https://registry.npmjs.org/logform/-/logform-2.7.0.tgz", + "integrity": "sha512-TFYA4jnP7PVbmlBIfhlSe+WKxs9dklXMTEGcBCIvLhE/Tn3H6Gk1norupVW7m5Cnd4bLcr08AytbyV/xj7f/kQ==", + "license": "MIT", + "dependencies": { + "@colors/colors": "1.6.0", + "@types/triple-beam": "^1.3.2", + "fecha": "^4.2.0", + "ms": "^2.1.1", + "safe-stable-stringify": "^2.3.1", + "triple-beam": "^1.3.0" + }, + "engines": { + "node": ">= 12.0.0" + } + }, "node_modules/lowercase-keys": { "version": "2.0.0", "resolved": "https://registry.npmjs.org/lowercase-keys/-/lowercase-keys-2.0.0.tgz", @@ -3934,6 +4064,15 @@ "wrappy": "1" } }, + "node_modules/one-time": { + "version": "1.0.0", + "resolved": "https://registry.npmjs.org/one-time/-/one-time-1.0.0.tgz", + "integrity": "sha512-5DXOiRKwuSEcQ/l0kGCF6Q3jcADFv5tSmRaJck/OqkVFcOzutB134KRSfF0xDrL39MNnqxbHBbUUcjZIhTgb2g==", + "license": "MIT", + "dependencies": { + "fn.name": "1.x.x" + } + }, "node_modules/onetime": { "version": "5.1.2", "resolved": "https://registry.npmjs.org/onetime/-/onetime-5.1.2.tgz", @@ -4423,6 +4562,15 @@ ], "license": "MIT" }, + "node_modules/safe-stable-stringify": { + "version": "2.5.0", + "resolved": "https://registry.npmjs.org/safe-stable-stringify/-/safe-stable-stringify-2.5.0.tgz", + "integrity": "sha512-b3rppTKm9T+PsVCBEOUR46GWI7fdOs00VKZ1+9c1EWDaDMvjQc6tUwuFyIprgGgTcWoVHSKrU8H31ZHA2e0RHA==", + "license": "MIT", + "engines": { + "node": ">=10" + } + }, "node_modules/safer-buffer": { "version": "2.1.2", "resolved": "https://registry.npmjs.org/safer-buffer/-/safer-buffer-2.1.2.tgz", @@ -4559,6 +4707,15 @@ "simple-concat": "^1.0.0" } }, + "node_modules/simple-swizzle": { + "version": "0.2.2", + "resolved": "https://registry.npmjs.org/simple-swizzle/-/simple-swizzle-0.2.2.tgz", + "integrity": "sha512-JA//kQgZtbuY83m+xT+tXJkmJncGMTFT+C+g2h2R9uxkYIrE2yy9sgmcLhCnw57/WSD+Eh3J97FPEDFnbXnDUg==", + "license": "MIT", + "dependencies": { + "is-arrayish": "^0.3.1" + } + }, "node_modules/simple-update-notifier": { "version": "1.1.0", "resolved": "https://registry.npmjs.org/simple-update-notifier/-/simple-update-notifier-1.1.0.tgz", @@ -4661,6 +4818,15 @@ "integrity": "sha512-RJbVP1HRDlUUXahJ7VMTcu9Rm1Nzw+EBpoPr94vnbD4LwR715F3CcxE2G2k45PewcaZ57pjetYa+LoSJLAASgA==", "license": "MIT" }, + "node_modules/stack-trace": { + "version": "0.0.10", + "resolved": "https://registry.npmjs.org/stack-trace/-/stack-trace-0.0.10.tgz", + "integrity": "sha512-KGzahc7puUKkzyMt+IqAep+TVNbKP+k2Lmwhub39m1AsTSkaDutx56aDCo+HLDzf/D26BIHTJWNiTG1KAJiQCg==", + "license": "MIT", + "engines": { + "node": "*" + } + }, "node_modules/stat-mode": { "version": "1.0.0", "resolved": "https://registry.npmjs.org/stat-mode/-/stat-mode-1.0.0.tgz", @@ -4879,6 +5045,12 @@ "graceful-fs": "^4.1.6" } }, + "node_modules/text-hex": { + "version": "1.0.0", + "resolved": "https://registry.npmjs.org/text-hex/-/text-hex-1.0.0.tgz", + "integrity": "sha512-uuVGNWzgJ4yhRaNSiubPY7OjISw4sw4E5Uv0wbjp+OzcbmVU/rsT8ujgcXJhn9ypzsgr5vlzpPqP+MBBKcGvbg==", + "license": "MIT" + }, "node_modules/through2": { "version": "4.0.2", "resolved": "https://registry.npmjs.org/through2/-/through2-4.0.2.tgz", @@ -4935,6 +5107,15 @@ "tree-kill": "cli.js" } }, + "node_modules/triple-beam": { + "version": "1.4.1", + "resolved": "https://registry.npmjs.org/triple-beam/-/triple-beam-1.4.1.tgz", + "integrity": "sha512-aZbgViZrg1QNcG+LULa7nhZpJTZSLm/mXnHXnbAbjmN5aSa0y7V+wvv6+4WaBtpISJzThKy+PIPxc1Nq1EJ9mg==", + "license": "MIT", + "engines": { + "node": ">= 14.0.0" + } + }, "node_modules/truncate-utf8-bytes": { "version": "1.0.2", "resolved": "https://registry.npmjs.org/truncate-utf8-bytes/-/truncate-utf8-bytes-1.0.2.tgz", @@ -5101,6 +5282,42 @@ "node": ">= 8" } }, + "node_modules/winston": { + "version": "3.17.0", + "resolved": "https://registry.npmjs.org/winston/-/winston-3.17.0.tgz", + "integrity": "sha512-DLiFIXYC5fMPxaRg832S6F5mJYvePtmO5G9v9IgUFPhXm9/GkXarH/TUrBAVzhTCzAj9anE/+GjrgXp/54nOgw==", + "license": "MIT", + "dependencies": { + "@colors/colors": "^1.6.0", + "@dabh/diagnostics": "^2.0.2", + "async": "^3.2.3", + "is-stream": "^2.0.0", + "logform": "^2.7.0", + "one-time": "^1.0.0", + "readable-stream": "^3.4.0", + "safe-stable-stringify": "^2.3.1", + "stack-trace": "0.0.x", + "triple-beam": "^1.3.0", + "winston-transport": "^4.9.0" + }, + "engines": { + "node": ">= 12.0.0" + } + }, + "node_modules/winston-transport": { + "version": "4.9.0", + "resolved": "https://registry.npmjs.org/winston-transport/-/winston-transport-4.9.0.tgz", + "integrity": "sha512-8drMJ4rkgaPo1Me4zD/3WLfI/zPdA9o2IipKODunnGDcuqbHwjsbB79ylv04LCGGzU0xQ6vTznOMpQGaLhhm6A==", + "license": "MIT", + "dependencies": { + "logform": "^2.7.0", + "readable-stream": "^3.6.2", + "triple-beam": "^1.3.0" + }, + "engines": { + "node": ">= 12.0.0" + } + }, "node_modules/wrap-ansi": { "version": "7.0.0", "resolved": "https://registry.npmjs.org/wrap-ansi/-/wrap-ansi-7.0.0.tgz", diff --git a/electron/package.json b/electron/package.json index 0eeec6d2..47c4b6ee 100644 --- a/electron/package.json +++ b/electron/package.json @@ -33,7 +33,8 @@ "electron-updater": "^5.3.0", "electron-window-state": "^5.0.3", "jszip": "^3.10.1", - "node-fetch": "^2.6.7" + "node-fetch": "^2.6.7", + "winston": "^3.17.0" }, "devDependencies": { "@types/better-sqlite3": "^7.6.13", diff --git a/electron/src/rt/logger.ts b/electron/src/rt/logger.ts index a1a41417..827f9067 100644 --- a/electron/src/rt/logger.ts +++ b/electron/src/rt/logger.ts @@ -1,77 +1,140 @@ /** - * Structured logging system for TimeSafari + * Enhanced logging system for TimeSafari Electron + * Provides structured logging with proper levels and formatting + * Supports both console and file output with different verbosity levels * - * Provides consistent logging across the application with: - * - Timestamp tracking - * - Log levels (debug, info, warn, error) - * - Structured data support - * - Component tagging - * - * @author Matthew Raymer - * @version 1.0.0 - * @since 2025-06-01 + * @author Matthew Raymer */ -// Log levels -export enum LogLevel { - DEBUG = 'DEBUG', - INFO = 'INFO', - WARN = 'WARN', - ERROR = 'ERROR' -} +import winston from 'winston'; +import path from 'path'; +import os from 'os'; +import fs from 'fs'; -// Log entry interface -interface LogEntry { - timestamp: string; - level: LogLevel; - component: string; - message: string; - data?: unknown; +// Extend Winston Logger type with our custom loggers +declare module 'winston' { + interface Logger { + sqlite: { + debug: (message: string, ...args: unknown[]) => void; + info: (message: string, ...args: unknown[]) => void; + warn: (message: string, ...args: unknown[]) => void; + error: (message: string, ...args: unknown[]) => void; + }; + migration: { + debug: (message: string, ...args: unknown[]) => void; + info: (message: string, ...args: unknown[]) => void; + warn: (message: string, ...args: unknown[]) => void; + error: (message: string, ...args: unknown[]) => void; + }; + } } -// Format log entry -const formatLogEntry = (entry: LogEntry): string => { - const { timestamp, level, component, message, data } = entry; - const dataStr = data ? ` ${JSON.stringify(data, null, 2)}` : ''; - return `[${timestamp}] [${level}] [${component}] ${message}${dataStr}`; -}; - -// Create logger for a specific component -export const createLogger = (component: string) => { - const log = (level: LogLevel, message: string, data?: unknown) => { - const entry: LogEntry = { - timestamp: new Date().toISOString(), - level, - component, - message, - data - }; +// Ensure log directory exists +const logDir = path.join(os.homedir(), 'Logs', 'TimeSafari'); +if (!fs.existsSync(logDir)) { + fs.mkdirSync(logDir, { recursive: true, mode: 0o755 }); +} - const formatted = formatLogEntry(entry); +// Custom format for console output +const consoleFormat = winston.format.combine( + winston.format.timestamp(), + winston.format.colorize(), + winston.format.printf(({ level, message, timestamp, ...metadata }) => { + // Skip debug logs for migrations unless explicitly enabled + if (level === 'debug' && + typeof message === 'string' && + message.includes('Migration') && + !process.env.DEBUG_MIGRATIONS) { + return ''; + } - switch (level) { - case LogLevel.DEBUG: - console.debug(formatted); - break; - case LogLevel.INFO: - console.info(formatted); - break; - case LogLevel.WARN: - console.warn(formatted); - break; - case LogLevel.ERROR: - console.error(formatted); - break; + let msg = `${timestamp} [${level}] ${message}`; + if (Object.keys(metadata).length > 0) { + msg += ` ${JSON.stringify(metadata, null, 2)}`; } - }; + return msg; + }) +); + +// Custom format for file output +const fileFormat = winston.format.combine( + winston.format.timestamp(), + winston.format.json() +); - return { - debug: (message: string, data?: unknown) => log(LogLevel.DEBUG, message, data), - info: (message: string, data?: unknown) => log(LogLevel.INFO, message, data), - warn: (message: string, data?: unknown) => log(LogLevel.WARN, message, data), - error: (message: string, data?: unknown) => log(LogLevel.ERROR, message, data) +// Create logger instance +export const logger = winston.createLogger({ + level: process.env.NODE_ENV === 'development' ? 'debug' : 'info', + format: fileFormat, + defaultMeta: { service: 'timesafari-electron' }, + transports: [ + // Console transport with custom format + new winston.transports.Console({ + format: consoleFormat, + level: process.env.NODE_ENV === 'development' ? 'debug' : 'info' + }), + // File transport for all logs + new winston.transports.File({ + filename: path.join(logDir, 'error.log'), + level: 'error', + maxsize: 5242880, // 5MB + maxFiles: 5 + }), + // File transport for all logs including debug + new winston.transports.File({ + filename: path.join(logDir, 'combined.log'), + maxsize: 5242880, // 5MB + maxFiles: 5 + }) + ] +}) as winston.Logger & { + sqlite: { + debug: (message: string, ...args: unknown[]) => void; + info: (message: string, ...args: unknown[]) => void; + warn: (message: string, ...args: unknown[]) => void; + error: (message: string, ...args: unknown[]) => void; }; + migration: { + debug: (message: string, ...args: unknown[]) => void; + info: (message: string, ...args: unknown[]) => void; + warn: (message: string, ...args: unknown[]) => void; + error: (message: string, ...args: unknown[]) => void; + }; +}; + +// Add SQLite specific logger +logger.sqlite = { + debug: (message: string, ...args: unknown[]) => { + logger.debug(`[SQLite] ${message}`, ...args); + }, + info: (message: string, ...args: unknown[]) => { + logger.info(`[SQLite] ${message}`, ...args); + }, + warn: (message: string, ...args: unknown[]) => { + logger.warn(`[SQLite] ${message}`, ...args); + }, + error: (message: string, ...args: unknown[]) => { + logger.error(`[SQLite] ${message}`, ...args); + } +}; + +// Add migration specific logger +logger.migration = { + debug: (message: string, ...args: unknown[]) => { + if (process.env.DEBUG_MIGRATIONS) { + logger.debug(`[Migration] ${message}`, ...args); + } + }, + info: (message: string, ...args: unknown[]) => { + logger.info(`[Migration] ${message}`, ...args); + }, + warn: (message: string, ...args: unknown[]) => { + logger.warn(`[Migration] ${message}`, ...args); + }, + error: (message: string, ...args: unknown[]) => { + logger.error(`[Migration] ${message}`, ...args); + } }; -// Create default logger for SQLite operations -export const logger = createLogger('SQLite'); \ No newline at end of file +// Export logger instance +export default logger; \ No newline at end of file diff --git a/electron/src/rt/sqlite-init.ts b/electron/src/rt/sqlite-init.ts index 579d690f..f06c2c7c 100644 --- a/electron/src/rt/sqlite-init.ts +++ b/electron/src/rt/sqlite-init.ts @@ -9,9 +9,9 @@ * - Plugin initialization and state verification * - Connection lifecycle management * - PRAGMA configuration for optimal performance - * - Migration system integration + * - Migration system integration with configurable logging * - Error handling and recovery - * - IPC communication layer + * - IPC communication layer with proper cleanup * * Database Configuration: * - Uses WAL journal mode for better concurrency @@ -56,6 +56,7 @@ import path from 'path'; import os from 'os'; import { runMigrations } from './sqlite-migrations'; import { logger } from './logger'; +import { startDatabaseOperation, endDatabaseOperation } from '../setup'; // Types for state management interface PluginState { @@ -597,255 +598,218 @@ export async function initializeSQLite(): Promise { } } +// Add IPC handler tracking +const registeredHandlers = new Set(); + /** - * Sets up IPC handlers for SQLite operations - * - * Registers handlers for: - * - Plugin availability checks - * - Connection management - * - Query execution - * - Error retrieval - * - * Each handler includes: - * - State verification - * - Error handling - * - Detailed logging - * - Transaction safety - * - * Security: - * - Validates all incoming requests - * - Verifies plugin state - * - Maintains connection isolation - * - * @throws {Error} If handler registration fails + * Removes all registered SQLite IPC handlers + * Called before re-registering handlers to prevent duplicates */ -export function setupSQLiteHandlers(): void { - // Remove existing handlers - const handlers = [ - 'sqlite-is-available', - 'sqlite-echo', - 'sqlite-create-connection', - 'sqlite-execute', - 'sqlite-query', - 'sqlite-run', - 'sqlite-close-connection', - 'sqlite-get-error' - ]; - - handlers.forEach(handler => { +const cleanupSQLiteHandlers = (): void => { + logger.debug('Cleaning up SQLite IPC handlers'); + for (const channel of registeredHandlers) { try { - ipcMain.removeHandler(handler); + ipcMain.removeHandler(channel); + logger.debug(`Removed handler for channel: ${channel}`); } catch (error) { - logger.warn(`Error removing handler ${handler}:`, error); + logger.warn(`Failed to remove handler for channel ${channel}:`, error); } - }); + } + registeredHandlers.clear(); +}; + +/** + * Registers an IPC handler with tracking + * @param channel The IPC channel to register + * @param handler The handler function + */ +const registerHandler = (channel: string, handler: (...args: any[]) => Promise): void => { + if (registeredHandlers.has(channel)) { + logger.debug(`Handler already registered for channel: ${channel}, removing first`); + ipcMain.removeHandler(channel); + } + ipcMain.handle(channel, handler); + registeredHandlers.add(channel); + logger.debug(`Registered handler for channel: ${channel}`); +}; + +/** + * Sets up IPC handlers for SQLite operations + * Registers handlers for all SQLite operations defined in VALID_CHANNELS.invoke + * Tracks database operations to prevent reloads during critical operations + * Implements proper handler cleanup to prevent duplicates + * + * @author Matthew Raymer + */ +export function setupSQLiteHandlers(): void { + logger.info('Setting up SQLite IPC handlers'); - // Register handlers - ipcMain.handle('sqlite-is-available', async () => { + // Clean up any existing handlers first + cleanupSQLiteHandlers(); + + // Handler for checking SQLite availability + registerHandler('sqlite-is-available', async () => { + logger.debug('Checking SQLite availability'); try { + startDatabaseOperation(); const isAvailable = await verifyPluginState(); - logger.debug('Plugin availability check:', { isAvailable }); + logger.debug('SQLite availability check:', { isAvailable }); return isAvailable; } catch (error) { - logger.error('Error checking plugin availability:', error); - return false; + logger.error('SQLite availability check failed:', error); + throw error; + } finally { + endDatabaseOperation(); } }); - // Enhanced sqlite-echo handler - ipcMain.handle('sqlite-echo', async (_event, options) => { + // Handler for echo test + registerHandler('sqlite-echo', async (_event, { value }) => { + logger.debug('SQLite echo test:', { value }); try { - if (!await verifyPluginState()) { - throw new SQLiteError( - 'Plugin not available', - 'sqlite-echo', - 'SQLITE_PLUGIN_UNAVAILABLE', - null, - { pluginState } - ); - } - - if (!options || typeof options !== 'object' || !('value' in options)) { - throw new SQLiteError( - 'Invalid echo options', - 'sqlite-echo', - 'SQLITE_INVALID_OPTIONS', - null, - { options } - ); + startDatabaseOperation(); + if (!pluginState.instance) { + throw new SQLiteError('Plugin not initialized', 'sqlite-echo'); } - - const { value } = options as { value: unknown }; - if (typeof value !== 'string') { - throw new SQLiteError( - 'Echo value must be a string', - 'sqlite-echo', - 'SQLITE_INVALID_VALUE', - null, - { value, type: typeof value } - ); - } - - logger.debug('Echo test:', { value, timestamp: new Date().toISOString() }); const result = await pluginState.instance.echo({ value }); - - if (!result || typeof result !== 'object' || !('value' in result)) { - throw new SQLiteError( - 'Invalid echo result', - 'sqlite-echo', - 'SQLITE_INVALID_RESULT', - null, - { result } - ); - } - - if (result.value !== value) { - throw new SQLiteError( - 'Echo test failed - value mismatch', - 'sqlite-echo', - 'SQLITE_ECHO_MISMATCH', - null, - { expected: value, received: result.value } - ); - } - - return result as SQLiteEchoResult; + logger.debug('SQLite echo result:', result); + return result; } catch (error) { - throw handleError(error, 'sqlite-echo', { options }); + logger.error('SQLite echo failed:', error); + throw error; + } finally { + endDatabaseOperation(); } }); - - ipcMain.handle('sqlite-get-error', async () => { - return pluginState.lastError ? { - message: pluginState.lastError.message, - stack: pluginState.lastError.stack, - name: pluginState.lastError.name, - context: (pluginState.lastError as SQLiteError).context - } : null; - }); - - // Add other handlers with proper state verification - ipcMain.handle('sqlite-create-connection', async (_event, options) => { + + // Handler for creating database connection + registerHandler('sqlite-create-connection', async (_event, options: SQLiteConnectionOptions) => { + logger.debug('Creating SQLite connection:', options); try { - if (!await verifyPluginState()) { - throw new SQLiteError('Plugin not available', 'sqlite-create-connection'); + startDatabaseOperation(); + if (!pluginState.instance) { + throw new SQLiteError('Plugin not initialized', 'sqlite-create-connection'); } - - // ... rest of connection creation logic ... - + const validatedOptions = validateConnectionOptions(options); + await pluginState.instance.createConnection(validatedOptions); + logger.debug('SQLite connection created successfully'); + return true; } catch (error) { - throw handleError(error, 'sqlite-create-connection'); + logger.error('SQLite connection creation failed:', error); + throw error; + } finally { + endDatabaseOperation(); } }); - - // Enhanced sqlite-run handler - ipcMain.handle('sqlite-run', async (_event, options) => { - try { - if (!await verifyPluginState()) { - throw new SQLiteError( - 'Plugin not available', - 'sqlite-run', - 'SQLITE_PLUGIN_UNAVAILABLE', - null, - { pluginState } - ); - } - - const runOptions = validateQueryOptions(options); - const runWithDb = { - database: 'timesafari', - ...runOptions - }; - - logger.debug('Running SQL statement:', { - ...runWithDb, - timestamp: new Date().toISOString() - }); - - const result = await pluginState.instance.run(runWithDb); - if (!result) { - throw new SQLiteError( - 'Run operation returned no result', - 'sqlite-run', - 'SQLITE_NO_RESULT', - null, - { run: runWithDb } - ); - } - - // Validate result structure - if (!('changes' in result)) { - throw new SQLiteError( - 'Invalid run result structure', - 'sqlite-run', - 'SQLITE_INVALID_RESULT', - null, - { result } - ); + // Handler for executing SQL statements + registerHandler('sqlite-execute', async (_event, options: SQLiteExecuteOptions) => { + logger.debug('Executing SQL statements:', options); + try { + startDatabaseOperation(); + if (!pluginState.instance) { + throw new SQLiteError('Plugin not initialized', 'sqlite-execute'); } - - return result as SQLiteResult; + const result = await pluginState.instance.execute(options); + logger.debug('SQL execution result:', result); + return result; } catch (error) { - throw handleError(error, 'sqlite-run', { options }); + logger.error('SQL execution failed:', error); + throw error; + } finally { + endDatabaseOperation(); } }); - // Enhanced sqlite-query handler - ipcMain.handle('sqlite-query', async (_event, options) => { + // Handler for querying data + registerHandler('sqlite-query', async (_event, options: SQLiteQueryOptions) => { + logger.debug('Querying SQLite:', options); try { - if (!await verifyPluginState()) { - throw new SQLiteError( - 'Plugin not available', - 'sqlite-query', - 'SQLITE_PLUGIN_UNAVAILABLE', - null, - { pluginState } - ); + startDatabaseOperation(); + if (!pluginState.instance) { + throw new SQLiteError('Plugin not initialized', 'sqlite-query'); } + const result = await pluginState.instance.query(options); + logger.debug('SQL query result:', result); + return result; + } catch (error) { + logger.error('SQL query failed:', error); + throw error; + } finally { + endDatabaseOperation(); + } + }); - const queryOptions = validateQueryOptions(options); - const queryWithDb = { - database: 'timesafari', - ...queryOptions - }; - - logger.debug('Executing SQL query:', { - ...queryWithDb, - timestamp: new Date().toISOString() - }); - - const result = await pluginState.instance.query(queryWithDb); - - if (!result) { - throw new SQLiteError( - 'Query operation returned no result', - 'sqlite-query', - 'SQLITE_NO_RESULT', - null, - { query: queryWithDb } - ); + // Handler for running SQL statements + registerHandler('sqlite-run', async (_event, options: SQLiteQueryOptions) => { + logger.debug('Running SQL statement:', options); + try { + startDatabaseOperation(); + if (!pluginState.instance) { + throw new SQLiteError('Plugin not initialized', 'sqlite-run'); } + const result = await pluginState.instance.run(options); + logger.debug('SQL run result:', result); + return result; + } catch (error) { + logger.error('SQL run failed:', error); + throw error; + } finally { + endDatabaseOperation(); + } + }); - // Validate result structure - if (!('values' in result) && !('changes' in result)) { - throw new SQLiteError( - 'Invalid query result structure', - 'sqlite-query', - 'SQLITE_INVALID_RESULT', - null, - { result } - ); + // Handler for closing database connection + registerHandler('sqlite-close-connection', async (_event, options: { database: string }) => { + logger.debug('Closing SQLite connection:', options); + try { + startDatabaseOperation(); + if (!pluginState.instance) { + throw new SQLiteError('Plugin not initialized', 'sqlite-close-connection'); } + await pluginState.instance.closeConnection(options); + logger.debug('SQLite connection closed successfully'); + return true; + } catch (error) { + logger.error('SQLite connection close failed:', error); + throw error; + } finally { + endDatabaseOperation(); + } + }); - return result as SQLiteResult; + // Handler for getting database path + registerHandler('get-path', async () => { + logger.debug('Getting database path'); + try { + startDatabaseOperation(); + const dbDir = await initializeDatabasePaths(); + const dbPath = path.join(dbDir, 'timesafariSQLite.db'); + logger.debug('Database path:', dbPath); + return dbPath; } catch (error) { - throw handleError(error, 'sqlite-query', { options }); + logger.error('Failed to get database path:', error); + throw error; + } finally { + endDatabaseOperation(); } }); - - logger.info('SQLite IPC handlers registered successfully', { - handlers: handlers.join(', '), - timestamp: new Date().toISOString() + + // Handler for getting base path + registerHandler('get-base-path', async () => { + logger.debug('Getting base path'); + try { + startDatabaseOperation(); + const dbDir = await initializeDatabasePaths(); + logger.debug('Base path:', dbDir); + return dbDir; + } catch (error) { + logger.error('Failed to get base path:', error); + throw error; + } finally { + endDatabaseOperation(); + } }); + + logger.info('SQLite IPC handlers setup complete'); } \ No newline at end of file diff --git a/electron/src/setup.ts b/electron/src/setup.ts index fd7ee1a6..ac0e7ca9 100644 --- a/electron/src/setup.ts +++ b/electron/src/setup.ts @@ -15,6 +15,7 @@ import { join } from 'path'; /** * Reload watcher configuration and state management * Prevents infinite reload loops and implements rate limiting + * Also prevents reloads during critical database operations * * @author Matthew Raymer */ @@ -22,7 +23,38 @@ const RELOAD_CONFIG = { DEBOUNCE_MS: 1500, COOLDOWN_MS: 5000, MAX_RELOADS_PER_MINUTE: 10, - MAX_RELOADS_PER_SESSION: 100 + MAX_RELOADS_PER_SESSION: 100, + DATABASE_OPERATION_TIMEOUT_MS: 10000 // 10 second timeout for database operations +}; + +// Track database operation state +let isDatabaseOperationInProgress = false; +let lastDatabaseOperationTime = 0; + +/** + * Checks if a database operation is in progress or recently completed + * @returns {boolean} Whether a database operation is active + */ +const isDatabaseOperationActive = (): boolean => { + const now = Date.now(); + return isDatabaseOperationInProgress || + (now - lastDatabaseOperationTime < RELOAD_CONFIG.DATABASE_OPERATION_TIMEOUT_MS); +}; + +/** + * Marks the start of a database operation + */ +export const startDatabaseOperation = (): void => { + isDatabaseOperationInProgress = true; + lastDatabaseOperationTime = Date.now(); +}; + +/** + * Marks the end of a database operation + */ +export const endDatabaseOperation = (): void => { + isDatabaseOperationInProgress = false; + lastDatabaseOperationTime = Date.now(); }; const reloadWatcher = { @@ -45,12 +77,18 @@ const resetReloadCounter = () => { }; /** - * Checks if a reload is allowed based on rate limits and cooldown + * Checks if a reload is allowed based on rate limits, cooldown, and database state * @returns {boolean} Whether a reload is allowed */ const canReload = (): boolean => { const now = Date.now(); + // Check if database operation is active + if (isDatabaseOperationActive()) { + console.warn('[Reload Watcher] Skipping reload - database operation in progress'); + return false; + } + // Check cooldown period if (now - reloadWatcher.lastReloadTime < RELOAD_CONFIG.COOLDOWN_MS) { console.warn('[Reload Watcher] Skipping reload - cooldown period active'); @@ -342,6 +380,14 @@ export class ElectronCapacitorApp { if (!this.CapacitorFileConfig.electron?.hideMainWindowOnLaunch) { this.MainWindow.show(); } + + // Re-register SQLite handlers after reload + if (electronIsDev) { + console.log('[Electron Main Process] Re-registering SQLite handlers after reload'); + const { setupSQLiteHandlers } = require('./rt/sqlite-init'); + setupSQLiteHandlers(); + } + setTimeout(() => { if (electronIsDev) { this.MainWindow.webContents.openDevTools();