Add extensive memory logging.

This commit is contained in:
Patrick Fic
2025-10-20 14:25:46 -07:00
parent cf0d457d1c
commit 19bd41375e
5 changed files with 391 additions and 1 deletions

View File

@@ -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",

View File

@@ -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();

View File

@@ -9,6 +9,7 @@ const store = new Store({
emsOutFilePath: null,
qbFilePath: "",
runWatcherOnStartup: true,
enableMemDebug: false,
polling: {
enabled: false,
interval: 30000,

304
src/util/memUsage.ts Normal file
View File

@@ -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<import("v8").HeapSpaceInfo>;
heapSnapshotFile?: string;
custom?: Record<string, unknown>;
};
// (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<MemoryUsageStats> {
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;

62
tests/heapPrune.test.ts Normal file
View File

@@ -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 });
});