From dc995af34b84de0133309ff67c5d8207346eca53 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=E3=82=A8=E3=82=A4=E3=82=AB=E3=82=AF?= <62183434+zouyonghe@users.noreply.github.com> Date: Wed, 11 Feb 2026 20:17:57 +0900 Subject: [PATCH] =?UTF-8?q?fix(desktop):=20=E4=B8=BA=20Electron=20?= =?UTF-8?q?=E4=B8=8E=E5=90=8E=E7=AB=AF=E6=97=A5=E5=BF=97=E5=A2=9E=E5=8A=A0?= =?UTF-8?q?=E6=8C=89=E5=A4=A7=E5=B0=8F=E8=BD=AE=E8=BD=AC=20(#5029)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * fix(desktop): rotate electron and backend logs * refactor(desktop): centralize log rotation defaults and debug fs errors * fix(desktop): harden rotation fs ops and buffer backend log writes * refactor(desktop): extract buffered logger and reduce sync stat calls * refactor(desktop): simplify rotation flow and harden logger config * fix(desktop): make app logging async and flush-safe * fix: harden app log path switching and debug-gated rotation errors * fix: cap buffered log chunk size during path switch --- desktop/README.md | 9 ++ desktop/lib/backend-manager.js | 100 +++++++------ desktop/lib/buffered-rotating-logger.js | 162 +++++++++++++++++++++ desktop/lib/common.js | 37 +++++ desktop/lib/electron-logger.js | 29 +++- desktop/lib/rotating-log-writer.js | 178 ++++++++++++++++++++++++ desktop/main.js | 8 +- 7 files changed, 473 insertions(+), 50 deletions(-) create mode 100644 desktop/lib/buffered-rotating-logger.js create mode 100644 desktop/lib/rotating-log-writer.js diff --git a/desktop/README.md b/desktop/README.md index b5698e3ee..48dcb341a 100644 --- a/desktop/README.md +++ b/desktop/README.md @@ -91,6 +91,15 @@ Runtime logs: - Electron shell log: `~/.astrbot/logs/electron.log` - Backend stdout/stderr log: `~/.astrbot/logs/backend.log` +- Both files rotate by size by default: `20MB` per file, keep `3` backups. +- Electron log rotation envs: + - `ASTRBOT_ELECTRON_LOG_MAX_MB` + - `ASTRBOT_ELECTRON_LOG_BACKUP_COUNT` +- Backend log rotation envs: + - `ASTRBOT_BACKEND_LOG_MAX_MB` + - `ASTRBOT_BACKEND_LOG_BACKUP_COUNT` +- Rotation debug logging: + - `ASTRBOT_LOG_ROTATION_DEBUG=1` (or `NODE_ENV=development`) to print filesystem errors from rotation operations. - On backend startup failure, the app dialog also shows the backend reason and backend log path. Timeout and loading controls: diff --git a/desktop/lib/backend-manager.js b/desktop/lib/backend-manager.js index 477995027..0ca56931e 100644 --- a/desktop/lib/backend-manager.js +++ b/desktop/lib/backend-manager.js @@ -4,10 +4,20 @@ const fs = require('fs'); const os = require('os'); const path = require('path'); const { spawn, spawnSync } = require('child_process'); -const { delay, ensureDir, normalizeUrl, waitForProcessExit } = require('./common'); +const { BufferedRotatingLogger } = require('./buffered-rotating-logger'); +const { + delay, + ensureDir, + normalizeUrl, + parseLogBackupCount, + parseLogMaxBytes, + waitForProcessExit, +} = require('./common'); const PACKAGED_BACKEND_TIMEOUT_FALLBACK_MS = 5 * 60 * 1000; const GRACEFUL_RESTART_WAIT_FALLBACK_MS = 20 * 1000; +const BACKEND_LOG_FLUSH_INTERVAL_MS = 120; +const BACKEND_LOG_MAX_BUFFER_BYTES = 128 * 1024; function parseBackendTimeoutMs(app) { const defaultTimeoutMs = app.isPackaged ? 0 : 20000; @@ -34,10 +44,22 @@ class BackendManager { ); this.backendAutoStart = process.env.ASTRBOT_BACKEND_AUTO_START !== '0'; this.backendTimeoutMs = parseBackendTimeoutMs(app); + this.backendLogMaxBytes = parseLogMaxBytes( + process.env.ASTRBOT_BACKEND_LOG_MAX_MB, + ); + this.backendLogBackupCount = parseLogBackupCount( + process.env.ASTRBOT_BACKEND_LOG_BACKUP_COUNT, + ); this.backendProcess = null; this.backendConfig = null; - this.backendLogFd = null; + this.backendLogger = new BufferedRotatingLogger({ + logPath: null, + maxBytes: this.backendLogMaxBytes, + backupCount: this.backendLogBackupCount, + flushIntervalMs: BACKEND_LOG_FLUSH_INTERVAL_MS, + maxBufferBytes: BACKEND_LOG_MAX_BUFFER_BYTES, + }); this.backendLastExitReason = null; this.backendStartupFailureReason = null; this.backendSpawning = false; @@ -195,14 +217,8 @@ class BackendManager { return Boolean(this.getBackendConfig().cmd); } - closeBackendLogFd() { - if (this.backendLogFd === null) { - return; - } - try { - fs.closeSync(this.backendLogFd); - } catch {} - this.backendLogFd = null; + async flushLogs() { + await this.backendLogger.flush(); } async pingBackend(timeoutMs = 800) { @@ -355,7 +371,7 @@ class BackendManager { } } - startBackend() { + async startBackend() { if (this.shouldSkipStart()) { this.log('Skip backend start because app is quitting.'); return; @@ -379,61 +395,61 @@ class BackendManager { if (backendConfig.webuiDir) { env.ASTRBOT_WEBUI_DIR = backendConfig.webuiDir; } + let backendLogPath = null; if (backendConfig.rootDir) { env.ASTRBOT_ROOT = backendConfig.rootDir; const logsDir = path.join(backendConfig.rootDir, 'logs'); ensureDir(logsDir); - const logPath = path.join(logsDir, 'backend.log'); - try { - this.backendLogFd = fs.openSync(logPath, 'a'); - } catch { - this.backendLogFd = null; - } + backendLogPath = path.join(logsDir, 'backend.log'); } + await this.backendLogger.setLogPath(backendLogPath); + const usePipedLogging = Boolean(backendLogPath); this.backendProcess = spawn(backendConfig.cmd, backendConfig.args || [], { cwd: backendConfig.cwd, env, shell: backendConfig.shell, - stdio: - this.backendLogFd === null - ? 'ignore' - : ['ignore', this.backendLogFd, this.backendLogFd], + stdio: usePipedLogging ? ['ignore', 'pipe', 'pipe'] : 'ignore', windowsHide: true, }); - if (this.backendLogFd !== null) { + if (usePipedLogging) { + if (this.backendProcess.stdout) { + this.backendProcess.stdout.on('data', (chunk) => { + this.backendLogger.log(chunk); + }); + } + if (this.backendProcess.stderr) { + this.backendProcess.stderr.on('data', (chunk) => { + this.backendLogger.log(chunk); + }); + } + } + + if (usePipedLogging) { const launchLine = [backendConfig.cmd, ...(backendConfig.args || [])] .map((item) => JSON.stringify(item)) .join(' '); - try { - fs.writeSync( - this.backendLogFd, - `[${new Date().toISOString()}] [Electron] Start backend ${launchLine}\n`, - ); - } catch {} + this.backendLogger.log( + `[${new Date().toISOString()}] [Electron] Start backend ${launchLine}\n`, + ); } this.backendProcess.on('error', (error) => { this.backendLastExitReason = error instanceof Error ? error.message : String(error); - if (this.backendLogFd !== null) { - try { - fs.writeSync( - this.backendLogFd, - `[${new Date().toISOString()}] [Electron] Backend spawn error: ${ - error instanceof Error ? error.message : String(error) - }\n`, - ); - } catch {} - } - this.closeBackendLogFd(); + this.backendLogger.log( + `[${new Date().toISOString()}] [Electron] Backend spawn error: ${ + error instanceof Error ? error.message : String(error) + }\n`, + ); + void this.backendLogger.flush(); this.backendProcess = null; }); this.backendProcess.on('exit', (code, signal) => { this.backendLastExitReason = `Backend process exited (code=${code ?? 'null'}, signal=${signal ?? 'null'}).`; - this.closeBackendLogFd(); + void this.backendLogger.flush(); this.backendProcess = null; }); } @@ -447,7 +463,7 @@ class BackendManager { } this.backendSpawning = true; try { - this.startBackend(); + await this.startBackend(); return await this.waitForBackend(maxWaitMs, true); } finally { this.backendSpawning = false; @@ -506,7 +522,7 @@ class BackendManager { await waitForProcessExit(processToStop, 1500); } } - this.closeBackendLogFd(); + await this.backendLogger.flush(); } findListeningPidsOnWindows(port) { diff --git a/desktop/lib/buffered-rotating-logger.js b/desktop/lib/buffered-rotating-logger.js new file mode 100644 index 000000000..7a443a97d --- /dev/null +++ b/desktop/lib/buffered-rotating-logger.js @@ -0,0 +1,162 @@ +'use strict'; + +const { RotatingLogWriter } = require('./rotating-log-writer'); +const { parseEnvInt } = require('./common'); + +const DEFAULT_FLUSH_INTERVAL_MS = 120; +const DEFAULT_MAX_BUFFER_BYTES = 128 * 1024; +const MIN_FLUSH_INTERVAL_MS = 10; +const MIN_MAX_BUFFER_BYTES = 4 * 1024; +const MAX_MAX_BUFFER_BYTES = 16 * 1024 * 1024; + +function clampIntOption(raw, { defaultValue, min, max }) { + const value = parseEnvInt(raw, defaultValue); + return Math.min(Math.max(value, min), max); +} + +class BufferedRotatingLogger { + constructor({ + logPath = null, + maxBytes, + backupCount, + flushIntervalMs, + maxBufferBytes, + label = 'buffered-log', + }) { + this.logPath = logPath || null; + this.flushIntervalMs = clampIntOption(flushIntervalMs, { + defaultValue: DEFAULT_FLUSH_INTERVAL_MS, + min: MIN_FLUSH_INTERVAL_MS, + max: 60 * 1000, + }); + this.maxBufferBytes = clampIntOption(maxBufferBytes, { + defaultValue: DEFAULT_MAX_BUFFER_BYTES, + min: MIN_MAX_BUFFER_BYTES, + max: MAX_MAX_BUFFER_BYTES, + }); + this.buffer = []; + this.bufferBytes = 0; + this.flushTimer = null; + this.pathSwitch = Promise.resolve(); + this.writer = new RotatingLogWriter({ + logPath: this.logPath, + maxBytes, + backupCount, + label, + }); + } + + setLogPath(logPath) { + const nextLogPath = logPath || null; + this.pathSwitch = this.pathSwitch.then(async () => { + if (nextLogPath === this.logPath) { + await this.flush(); + return; + } + + const previousLogPath = this.logPath; + if (previousLogPath) { + await this.flush(); + } + + this.logPath = null; + await this.writer.setLogPath(nextLogPath); + this.logPath = nextLogPath; + await this.flush(); + }); + return this.pathSwitch; + } + + log(payload) { + if (payload === undefined || payload === null) { + return; + } + const chunk = Buffer.isBuffer(payload) + ? payload + : Buffer.from(String(payload), 'utf8'); + if (!chunk.length) { + return; + } + + if (!this.logPath) { + const boundedChunk = this.clipChunkToBufferLimit(chunk); + this.dropOldestUntilWithinLimit(boundedChunk.length); + this.buffer.push(boundedChunk); + this.bufferBytes += boundedChunk.length; + return; + } + + this.buffer.push(chunk); + this.bufferBytes += chunk.length; + + if (this.bufferBytes >= this.maxBufferBytes) { + void this.flush(); + return; + } + this.scheduleFlush(); + } + + flush() { + this.clearFlushTimer(); + if (!this.buffer.length) { + return this.writer.flush(); + } + if (!this.logPath) { + // Path is switching or temporarily unavailable; keep buffered data. + this.dropOldestUntilWithinLimit(0); + return this.writer.flush(); + } + + const chunks = this.buffer; + this.buffer = []; + this.bufferBytes = 0; + const payload = chunks.length === 1 ? chunks[0] : Buffer.concat(chunks); + this.writer.append(payload); + return this.writer.flush(); + } + + dropOldestUntilWithinLimit(incomingBytes = 0) { + while ( + this.buffer.length && + this.bufferBytes + Math.max(0, incomingBytes) > this.maxBufferBytes + ) { + const removed = this.buffer.shift(); + if (removed) { + this.bufferBytes -= removed.length; + } + } + if (this.bufferBytes < 0) { + this.bufferBytes = 0; + } + } + + clipChunkToBufferLimit(chunk) { + if (chunk.length <= this.maxBufferBytes) { + return chunk; + } + return chunk.subarray(chunk.length - this.maxBufferBytes); + } + + scheduleFlush() { + if (this.flushTimer !== null) { + return; + } + this.flushTimer = setTimeout(() => { + this.flushTimer = null; + void this.flush(); + }, this.flushIntervalMs); + this.flushTimer.unref?.(); + } + + clearFlushTimer() { + if (this.flushTimer === null) { + return; + } + clearTimeout(this.flushTimer); + this.flushTimer = null; + } +} + +module.exports = { + BufferedRotatingLogger, +}; diff --git a/desktop/lib/common.js b/desktop/lib/common.js index 561eca39e..e592aff7f 100644 --- a/desktop/lib/common.js +++ b/desktop/lib/common.js @@ -2,6 +2,9 @@ const fs = require('fs'); +const LOG_ROTATION_DEFAULT_MAX_MB = 20; +const LOG_ROTATION_DEFAULT_BACKUP_COUNT = 3; + function normalizeUrl(value) { try { const url = new URL(value); @@ -24,6 +27,33 @@ function ensureDir(value) { fs.mkdirSync(value, { recursive: true }); } +function parseEnvInt(raw, defaultValue) { + const parsed = Number.parseInt(`${raw ?? ''}`, 10); + return Number.isFinite(parsed) ? parsed : defaultValue; +} + +function isLogRotationDebugEnabled() { + return ( + process.env.ASTRBOT_LOG_ROTATION_DEBUG === '1' || + process.env.NODE_ENV === 'development' + ); +} + +function parseLogMaxBytes(envValue) { + const mb = parseEnvInt(envValue, LOG_ROTATION_DEFAULT_MAX_MB); + const maxMb = mb > 0 ? mb : LOG_ROTATION_DEFAULT_MAX_MB; + return maxMb * 1024 * 1024; +} + +function parseLogBackupCount(envValue) { + const count = parseEnvInt(envValue, LOG_ROTATION_DEFAULT_BACKUP_COUNT); + return count >= 0 ? count : LOG_ROTATION_DEFAULT_BACKUP_COUNT; +} + +function isIgnorableFsError(error) { + return Boolean(error && typeof error === 'object' && error.code === 'ENOENT'); +} + function delay(ms) { return new Promise((resolve) => setTimeout(resolve, ms)); } @@ -52,8 +82,15 @@ function waitForProcessExit(child, timeoutMs = 5000) { } module.exports = { + LOG_ROTATION_DEFAULT_BACKUP_COUNT, + LOG_ROTATION_DEFAULT_MAX_MB, delay, ensureDir, + isIgnorableFsError, + isLogRotationDebugEnabled, normalizeUrl, + parseEnvInt, + parseLogBackupCount, + parseLogMaxBytes, waitForProcessExit, }; diff --git a/desktop/lib/electron-logger.js b/desktop/lib/electron-logger.js index b8dc73bc6..b9328ef44 100644 --- a/desktop/lib/electron-logger.js +++ b/desktop/lib/electron-logger.js @@ -1,10 +1,23 @@ 'use strict'; -const fs = require('fs'); const path = require('path'); -const { ensureDir } = require('./common'); +const { RotatingLogWriter } = require('./rotating-log-writer'); +const { parseLogBackupCount, parseLogMaxBytes } = require('./common'); function createElectronLogger({ app, getRootDir }) { + const electronLogMaxBytes = parseLogMaxBytes( + process.env.ASTRBOT_ELECTRON_LOG_MAX_MB, + ); + const electronLogBackupCount = parseLogBackupCount( + process.env.ASTRBOT_ELECTRON_LOG_BACKUP_COUNT, + ); + const writer = new RotatingLogWriter({ + logPath: null, + maxBytes: electronLogMaxBytes, + backupCount: electronLogBackupCount, + label: 'electron-log', + }); + function getElectronLogPath() { const rootDir = process.env.ASTRBOT_ROOT || @@ -15,19 +28,23 @@ function createElectronLogger({ app, getRootDir }) { function logElectron(message) { const logPath = getElectronLogPath(); - ensureDir(path.dirname(logPath)); const line = `[${new Date().toISOString()}] ${message}\n`; - try { - fs.appendFileSync(logPath, line, 'utf8'); - } catch {} + void writer.setLogPath(logPath); + void writer.append(line); + } + + async function flushElectron() { + await writer.flush(); } return { getElectronLogPath, logElectron, + flushElectron, }; } module.exports = { createElectronLogger, }; + diff --git a/desktop/lib/rotating-log-writer.js b/desktop/lib/rotating-log-writer.js new file mode 100644 index 000000000..c6c8f8fb1 --- /dev/null +++ b/desktop/lib/rotating-log-writer.js @@ -0,0 +1,178 @@ +'use strict'; + +const fs = require('fs/promises'); +const path = require('path'); +const { isIgnorableFsError, isLogRotationDebugEnabled } = require('./common'); + +class RotatingLogWriter { + constructor({ logPath = null, maxBytes = 0, backupCount = 0, label = 'log' }) { + this.logPath = logPath || null; + this.maxBytes = Number.isFinite(maxBytes) && maxBytes > 0 ? maxBytes : 0; + this.backupCount = Number.isFinite(backupCount) && backupCount >= 0 ? backupCount : 0; + this.label = label; + this.cachedSize = null; + this.dirReadyForPath = null; + this.queue = Promise.resolve(); + } + + setLogPath(logPath) { + const nextPath = logPath || null; + if (nextPath === this.logPath) { + return this.queue; + } + return this.enqueue(async () => { + this.logPath = nextPath; + this.cachedSize = null; + this.dirReadyForPath = null; + }); + } + + append(payload) { + if (payload === undefined || payload === null) { + return this.queue; + } + const content = Buffer.isBuffer(payload) + ? payload + : Buffer.from(String(payload), 'utf8'); + if (!content.length) { + return this.queue; + } + return this.enqueue(async () => { + if (!this.logPath) { + return; + } + await this.ensureDirReady(); + await this.ensureSizeLoaded(); + await this.rotateIfNeeded(content.length); + await fs.appendFile(this.logPath, content); + if (!Number.isFinite(this.cachedSize)) { + this.cachedSize = await this.readSize(); + } else { + this.cachedSize += content.length; + } + }); + } + + flush() { + return this.queue; + } + + enqueue(task) { + const run = async () => { + try { + await task(); + } catch (error) { + this.reportError('write', this.logPath || 'unknown', error); + } + }; + this.queue = this.queue.then(run, run); + return this.queue; + } + + async ensureSizeLoaded() { + if (Number.isFinite(this.cachedSize)) { + return; + } + this.cachedSize = await this.readSize(); + } + + async ensureDirReady() { + if (!this.logPath) { + return; + } + if (this.dirReadyForPath === this.logPath) { + return; + } + const dirPath = path.dirname(this.logPath); + try { + await fs.mkdir(dirPath, { recursive: true }); + this.dirReadyForPath = this.logPath; + } catch (error) { + this.reportError('mkdir', dirPath, error); + } + } + + async readSize() { + if (!this.logPath) { + return 0; + } + try { + const stat = await fs.stat(this.logPath); + return stat.size; + } catch (error) { + if (isIgnorableFsError(error)) { + return 0; + } + this.reportError('stat', this.logPath, error); + return 0; + } + } + + async rotateIfNeeded(incomingBytes) { + if (!this.logPath || this.maxBytes <= 0) { + return; + } + + const currentSize = Number.isFinite(this.cachedSize) ? this.cachedSize : 0; + if (currentSize + Math.max(0, incomingBytes) <= this.maxBytes) { + return; + } + + if (this.backupCount <= 0) { + try { + await fs.truncate(this.logPath, 0); + } catch (error) { + if (!isIgnorableFsError(error)) { + this.reportError('truncate', this.logPath, error); + } + } + this.cachedSize = await this.readSize(); + return; + } + + const oldestPath = `${this.logPath}.${this.backupCount}`; + try { + await fs.unlink(oldestPath); + } catch (error) { + if (!isIgnorableFsError(error)) { + this.reportError('unlink', oldestPath, error); + } + } + + for (let index = this.backupCount - 1; index >= 1; index -= 1) { + const sourcePath = `${this.logPath}.${index}`; + const targetPath = `${this.logPath}.${index + 1}`; + try { + await fs.rename(sourcePath, targetPath); + } catch (error) { + if (!isIgnorableFsError(error)) { + this.reportError('rename', `${sourcePath} -> ${targetPath}`, error); + } + } + } + + try { + await fs.rename(this.logPath, `${this.logPath}.1`); + } catch (error) { + if (!isIgnorableFsError(error)) { + this.reportError('rename', `${this.logPath} -> ${this.logPath}.1`, error); + } + } + + this.cachedSize = await this.readSize(); + } + + reportError(action, targetPath, error) { + if (!isLogRotationDebugEnabled()) { + return; + } + const details = error instanceof Error ? error.message : String(error); + console.error( + `[astrbot][${this.label}] ${action} failed for ${targetPath}: ${details}`, + ); + } +} + +module.exports = { + RotatingLogWriter, +}; diff --git a/desktop/main.js b/desktop/main.js index 6118c4360..5adff38b3 100644 --- a/desktop/main.js +++ b/desktop/main.js @@ -36,7 +36,7 @@ let backendManager = null; app.commandLine.appendSwitch('disable-http-cache'); -const { logElectron } = createElectronLogger({ +const { logElectron, flushElectron } = createElectronLogger({ app, getRootDir: () => (backendManager ? backendManager.getRootDir() : null), }); @@ -387,8 +387,12 @@ app.on('before-quit', (event) => { } }), ) - .finally(() => { + .finally(async () => { logElectron('Backend stop finished, exiting app.'); + await Promise.allSettled([ + flushElectron(), + backendManager ? backendManager.flushLogs() : Promise.resolve(), + ]); app.exit(0); }); });