From 19bd41375e7b48b7471b9ae3817e65d92db1bd41 Mon Sep 17 00:00:00 2001 From: Patrick Fic Date: Mon, 20 Oct 2025 14:25:46 -0700 Subject: [PATCH] Add extensive memory logging. --- package.json | 2 +- src/main/index.ts | 23 +++ src/main/store/store.ts | 1 + src/util/memUsage.ts | 304 ++++++++++++++++++++++++++++++++++++++++ tests/heapPrune.test.ts | 62 ++++++++ 5 files changed, 391 insertions(+), 1 deletion(-) create mode 100644 src/util/memUsage.ts create mode 100644 tests/heapPrune.test.ts diff --git a/package.json b/package.json index 2be1f31..4aef937 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "bodyshop-desktop", - "version": "1.0.6", + "version": "1.0.7", "description": "Shop Management System Partner", "main": "./out/main/index.js", "author": "Convenient Brands, LLC", diff --git a/src/main/index.ts b/src/main/index.ts index 436d2fa..8ea52d1 100644 --- a/src/main/index.ts +++ b/src/main/index.ts @@ -36,6 +36,7 @@ import { setupKeepAliveTask, } from "./setup-keep-alive-task"; import ensureWindowOnScreen from "./util/ensureWindowOnScreen"; +import ongoingMemoryDump, { dumpMemoryStatsToFile } from "../util/memUsage"; const appIconToUse = import.meta.env.VITE_COMPANY === "IMEX" ? imexAppIcon : romeAppIcon; @@ -252,6 +253,27 @@ function createWindow(): void { { type: "separator", }, + { + label: "Enable Memory Logging", + checked: store.get("settings.enableMemDebug") as boolean, + type: "checkbox", + click: (): void => { + const currentSetting = store.get( + "settings.enableMemDebug", + ) as boolean; + store.set("settings.enableMemDebug", !currentSetting); + log.info("Enable Memory Logging set to", !currentSetting); + }, + }, + { + label: "Dump Memory Stats Now", + click: (): void => { + dumpMemoryStatsToFile(); + }, + }, + { + type: "separator", + }, // { // label: "Decode Hardcoded Estimate", // click: (): void => { @@ -578,6 +600,7 @@ app.whenReady().then(async () => { //The update itself will run when the bodyshop record is queried to know what release channel to use. createWindow(); + ongoingMemoryDump(); app.on("activate", function () { openMainWindow(); diff --git a/src/main/store/store.ts b/src/main/store/store.ts index ed5ece2..62968bd 100644 --- a/src/main/store/store.ts +++ b/src/main/store/store.ts @@ -9,6 +9,7 @@ const store = new Store({ emsOutFilePath: null, qbFilePath: "", runWatcherOnStartup: true, + enableMemDebug: false, polling: { enabled: false, interval: 30000, diff --git a/src/util/memUsage.ts b/src/util/memUsage.ts new file mode 100644 index 0000000..c257b84 --- /dev/null +++ b/src/util/memUsage.ts @@ -0,0 +1,304 @@ +import { BrowserWindow } from "electron"; +import log from "electron-log/main"; +import fs from "fs"; +import os from "os"; +import path from "path"; +import Store from "../main/store/store"; +/** + * Human-readable memory/cpu/resource snapshot. + */ +export type MemoryUsageStats = { + timestamp: string; + label?: string; + uptimeSeconds: number; + pid: number; + memory: { + rss: number; + heapTotal: number; + heapUsed: number; + external: number; + arrayBuffers?: number; + }; + memoryPretty: { + rss: string; + heapTotal: string; + heapUsed: string; + external: string; + arrayBuffers?: string; + }; + os: { + totalMem: number; + freeMem: number; + freeMemPercent: number; + }; + cpuUsage?: NodeJS.CpuUsage; + resourceUsage?: NodeJS.ResourceUsage; + heapSpaces?: Array; + heapSnapshotFile?: string; + custom?: Record; +}; +// (merged into top import) + +/** + * Options for dumpMemoryStats. + */ +export type DumpOptions = { + /** + * Call global.gc() before sampling if available (requires node run with --expose-gc). + */ + runGc?: boolean; + /** + * Optional label to include in the returned snapshot. + */ + label?: string; + includeHeapSpaces?: boolean; + writeHeapSnapshot?: boolean; + heapSnapshotDir?: string; +}; + +/** + * Convert bytes to a compact human readable string. + */ +function formatBytes(bytes: number): string { + if (!isFinite(bytes)) return String(bytes); + const units = ["B", "KB", "MB", "GB", "TB"]; + let i = 0; + let val = bytes; + while (val >= 1024 && i < units.length - 1) { + val /= 1024; + i++; + } + return `${val.toFixed(2)} ${units[i]}`; +} + +/** + * Asynchronously produce a memory / cpu / os snapshot. + * + * Example: + * const stats = await dumpMemoryStats({ runGc: true, label: 'before-heavy-task' }); + */ +export async function dumpMemoryStats( + options: DumpOptions = {}, +): Promise { + const { + runGc = false, + label, + includeHeapSpaces = true, + writeHeapSnapshot = true, + heapSnapshotDir, + } = options; + + // Allow GC if requested and available to get a cleaner snapshot + if (runGc && typeof (global as any).gc === "function") { + try { + (global as any).gc(); + } catch { + // ignore GC errors + } + } + + // Let the event loop settle a tick so GC can complete if run + await new Promise((resolve) => setImmediate(resolve)); + + const mem = process.memoryUsage(); + const totalMem = os.totalmem(); + const freeMem = os.freemem(); + + const stats: MemoryUsageStats = { + timestamp: new Date().toISOString(), + label, + uptimeSeconds: Math.floor(process.uptime()), + pid: process.pid, + memory: { + rss: mem.rss, + heapTotal: mem.heapTotal, + heapUsed: mem.heapUsed, + external: mem.external, + arrayBuffers: mem.arrayBuffers, + }, + memoryPretty: { + rss: formatBytes(mem.rss), + heapTotal: formatBytes(mem.heapTotal), + heapUsed: formatBytes(mem.heapUsed), + external: formatBytes(mem.external), + arrayBuffers: + mem.arrayBuffers !== undefined + ? formatBytes(mem.arrayBuffers) + : undefined, + }, + os: { + totalMem, + freeMem, + freeMemPercent: Math.round((freeMem / totalMem) * 10000) / 100, + }, + cpuUsage: process.cpuUsage ? process.cpuUsage() : undefined, + resourceUsage: + typeof process.resourceUsage === "function" + ? process.resourceUsage() + : undefined, + custom: { + numBrowserWindows: BrowserWindow.getAllWindows().length, + }, + }; + + if (includeHeapSpaces) { + try { + // eslint-disable-next-line @typescript-eslint/no-var-requires + const v8: typeof import("v8") = require("v8"); + if (typeof v8.getHeapSpaceStatistics === "function") { + stats.heapSpaces = v8.getHeapSpaceStatistics(); + } + } catch (err) { + log.warn("Failed to get heap space stats", err); + } + } + + if (writeHeapSnapshot) { + try { + if (!runGc && typeof (global as any).gc === "function") { + try { + (global as any).gc(); + } catch { + /* ignore */ + } + } + // eslint-disable-next-line @typescript-eslint/no-var-requires + const v8: typeof import("v8") = require("v8"); + if (typeof v8.writeHeapSnapshot === "function") { + const baseDir = + heapSnapshotDir || path.dirname(log.transports.file.getFile().path); + + const dir = path.join(baseDir, "heap-snapshots"); + fs.mkdirSync(dir, { recursive: true }); + const fileName = `heap-${Date.now()}-${process.pid}.heapsnapshot`; + const filePath = path.join(dir, fileName); + const snapshotPath = v8.writeHeapSnapshot(filePath); + stats.heapSnapshotFile = snapshotPath; + } else { + log.warn("v8.writeHeapSnapshot not available"); + } + } catch (err) { + log.warn("Failed to write heap snapshot", err); + } + } + + return stats; +} + +const memLogger = log.create({ logId: "mem-stat" }); +memLogger.transports.file.resolvePathFn = () => { + const filePath = path.join( + path.dirname(log.transports.file.getFile().path), + "memory-stats.log", + ); + return filePath; +}; + +export async function dumpMemoryStatsToFile() { + try { + const stats = await dumpMemoryStats({ includeHeapSpaces: false }); + memLogger.debug("[MemStat]:", stats); + } catch (error) { + log.warn("Unexpected error while writing memory stats log", error); + } +} + +function ongoingMemoryDump() { + console.log( + `Memory logging set to ${Store.get("settings.enableMemDebug")}. Log file at ${memLogger.transports.file.getFile().path}`, + ); + + setInterval( + async () => { + // Also write each snapshot to a dedicated memory stats log file as JSON lines. + try { + const loggingEnabled = Store.get("settings.enableMemDebug"); + log.debug( + "Checking if memory stats logging is enabled.", + loggingEnabled, + ); + if (loggingEnabled) { + // Enforce heap snapshot folder size limit (< 1GB) before writing a new snapshot. + const MAX_DIR_BYTES = 1024 * 1024 * 1024; // 1GB + const TARGET_REDUCED_BYTES = Math.floor(MAX_DIR_BYTES * 0.9); // prune down to 90% + const baseDir = path.dirname(log.transports.file.getFile().path); + const heapDir = path.join(baseDir, "heap-snapshots"); + try { + fs.mkdirSync(heapDir, { recursive: true }); + const files = fs + .readdirSync(heapDir) + .filter((f) => f.endsWith(".heapsnapshot")); + let totalSize = 0; + const fileStats: Array<{ + file: string; + size: number; + mtimeMs: number; + }> = []; + for (const file of files) { + try { + const stat = fs.statSync(path.join(heapDir, file)); + if (stat.isFile()) { + totalSize += stat.size; + fileStats.push({ + file, + size: stat.size, + mtimeMs: stat.mtimeMs, + }); + } + } catch (e) { + log.warn("Failed to stat heap snapshot file", file, e); + } + } + if (totalSize > MAX_DIR_BYTES) { + // Sort oldest first and delete until below TARGET_REDUCED_BYTES. + fileStats.sort((a, b) => a.mtimeMs - b.mtimeMs); + let bytesAfter = totalSize; + for (const info of fileStats) { + if (bytesAfter <= TARGET_REDUCED_BYTES) break; + try { + fs.unlinkSync(path.join(heapDir, info.file)); + bytesAfter -= info.size; + log.warn( + `Pruned heap snapshot '${info.file}' (${formatBytes(info.size)}) to reduce directory size. New size: ${formatBytes(bytesAfter)}.`, + ); + } catch (errDel) { + log.warn( + "Failed to delete heap snapshot file", + info.file, + errDel, + ); + } + } + if (bytesAfter > MAX_DIR_BYTES) { + // Still above hard cap; skip writing a new snapshot this cycle. + log.warn( + `Heap snapshot directory still above hard cap (${formatBytes(bytesAfter)} > ${formatBytes(MAX_DIR_BYTES)}). Skipping new heap snapshot this cycle.`, + ); + const stats = await dumpMemoryStats({ + includeHeapSpaces: false, + writeHeapSnapshot: false, + }); + memLogger.debug("[MemStat]:", stats); + return; // skip remainder; we already logged stats without snapshot. + } + } + } catch (dirErr) { + log.warn( + "Unexpected error while enforcing heap snapshot directory size limit", + dirErr, + ); + // Continue; failure to enforce limit should not stop memory stats. + } + // Directory is within allowed bounds (or pruning succeeded); proceed normally. + const stats = await dumpMemoryStats({ includeHeapSpaces: false }); + memLogger.debug("[MemStat]:", stats); + } + } catch (err) { + log.warn("Unexpected error while writing memory stats log", err); + } + }, + 5000, // 60 * 60 * 1000, + ); // every 60 minutes +} + +export default ongoingMemoryDump; diff --git a/tests/heapPrune.test.ts b/tests/heapPrune.test.ts new file mode 100644 index 0000000..153b7f1 --- /dev/null +++ b/tests/heapPrune.test.ts @@ -0,0 +1,62 @@ +import { test, expect } from "@playwright/test"; +import fs from "fs"; +import path from "path"; + +// We import the module after setting up a temporary log path by monkey patching electron-log. +// Since the project primarily uses Playwright for tests, we leverage its expect assertion library. + +// NOTE: This is a lightweight test that simulates the pruning logic indirectly by invoking the exported ongoingMemoryDump +// function and creating artificial heap snapshot files exceeding the threshold. + +// Because ongoingMemoryDump sets an interval, we invoke its internal logic by importing the file and manually calling dumpMemoryStats. +// For simplicity and to avoid altering production code for testability, we replicate the size enforcement logic here and assert behavior. + +function createDummySnapshots(dir: string, count: number, sizeBytes: number) { + fs.mkdirSync(dir, { recursive: true }); + for (let i = 0; i < count; i++) { + const file = path.join(dir, `dummy-${i}.heapsnapshot`); + const fd = fs.openSync(file, "w"); + // Write sizeBytes of zeros + const buf = Buffer.alloc(1024 * 1024, 0); // 1MB chunk + let written = 0; + while (written < sizeBytes) { + fs.writeSync(fd, buf, 0, Math.min(buf.length, sizeBytes - written)); + written += Math.min(buf.length, sizeBytes - written); + } + fs.closeSync(fd); + // Stagger mtime for deterministic pruning ordering + const mtime = new Date(Date.now() - (count - i) * 1000); + fs.utimesSync(file, mtime, mtime); + } +} + +test("heap snapshot directory pruning reduces size below simulated hard cap", async () => { + const baseDir = fs.mkdtempSync(path.join(process.cwd(), "heap-test-")); + const heapDir = path.join(baseDir, "heap-snapshots"); + // Simulate oversize: 15 files of 5MB each = 75MB + createDummySnapshots(heapDir, 15, 5 * 1024 * 1024); + // Use smaller cap to keep test resource usage low. + const MAX_DIR_BYTES = 50 * 1024 * 1024; // 50MB simulated cap + const TARGET_REDUCED_BYTES = Math.floor(MAX_DIR_BYTES * 0.9); + const files = fs + .readdirSync(heapDir) + .filter((f) => f.endsWith(".heapsnapshot")); + let totalSize = 0; + const fileStats: Array<{ file: string; size: number; mtimeMs: number }> = []; + for (const file of files) { + const stat = fs.statSync(path.join(heapDir, file)); + totalSize += stat.size; + fileStats.push({ file, size: stat.size, mtimeMs: stat.mtimeMs }); + } + expect(totalSize).toBeGreaterThan(MAX_DIR_BYTES); + fileStats.sort((a, b) => a.mtimeMs - b.mtimeMs); + let bytesAfter = totalSize; + for (const info of fileStats) { + if (bytesAfter <= TARGET_REDUCED_BYTES) break; + fs.unlinkSync(path.join(heapDir, info.file)); + bytesAfter -= info.size; + } + expect(bytesAfter).toBeLessThanOrEqual(TARGET_REDUCED_BYTES); + // Cleanup + fs.rmSync(baseDir, { recursive: true, force: true }); +});