From e31ba022e3cbdf56fdbc6d034e8076afc98142cb Mon Sep 17 00:00:00 2001 From: Audric Ackermann Date: Fri, 9 Aug 2024 11:50:29 +1000 Subject: [PATCH] fix: logs rotating file are broken, don't use them --- package.json | 3 - ts/mains/main_renderer.tsx | 3 - ts/node/logging.ts | 235 ++++++++++++++----------------------- 3 files changed, 87 insertions(+), 154 deletions(-) diff --git a/package.json b/package.json index 724ecee4a..814dfc96f 100644 --- a/package.json +++ b/package.json @@ -91,7 +91,6 @@ "electron-updater": "^4.2.2", "emoji-mart": "^5.5.2", "filesize": "3.6.1", - "firstline": "1.2.1", "focus-trap-react": "^10.2.3", "framer-motion": "^11.0.3", "fs-extra": "9.0.0", @@ -125,7 +124,6 @@ "react-toastify": "^6.0.9", "react-use": "^17.5.0", "react-virtualized": "^9.22.4", - "read-last-lines-ts": "^1.2.1", "redux": "4.2.1", "redux-logger": "3.0.6", "redux-persist": "^6.0.0", @@ -157,7 +155,6 @@ "@types/dompurify": "^2.0.0", "@types/electron-localshortcut": "^3.1.0", "@types/filesize": "3.6.0", - "@types/firstline": "^2.0.2", "@types/fs-extra": "5.0.5", "@types/jsdom": "^21.1.6", "@types/libsodium-wrappers-sumo": "^0.7.5", diff --git a/ts/mains/main_renderer.tsx b/ts/mains/main_renderer.tsx index 6a46e3341..9867eceea 100644 --- a/ts/mains/main_renderer.tsx +++ b/ts/mains/main_renderer.tsx @@ -13,7 +13,6 @@ import { Data } from '../data/data'; import { OpenGroupData } from '../data/opengroups'; import { SettingsKey } from '../data/settings-key'; import { MessageModel } from '../models/message'; -import { deleteAllLogs } from '../node/logs'; import { queueAllCached } from '../receiver/receiver'; import { loadKnownBlindedKeys } from '../session/apis/open_group_api/sogsv3/knownBlindedkeys'; import { getConversationController } from '../session/conversations'; @@ -203,8 +202,6 @@ Storage.onready(async () => { window.log.info(`New version detected: ${currentVersion}; previous: ${lastVersion}`); await Data.cleanupOrphanedAttachments(); - - await deleteAllLogs(); } const themeSetting = window.Events.getThemeSetting(); diff --git a/ts/node/logging.ts b/ts/node/logging.ts index 1f141bedb..95fc04d77 100644 --- a/ts/node/logging.ts +++ b/ts/node/logging.ts @@ -7,10 +7,9 @@ import fs from 'fs'; import { app, ipcMain as ipc } from 'electron'; import Logger from 'bunyan'; import _ from 'lodash'; -import firstline from 'firstline'; -import { readLastLinesEnc } from 'read-last-lines-ts'; import rimraf from 'rimraf'; +import { readFile } from 'fs-extra'; import { redactAll } from '../util/privacy'; const LEVELS = ['fatal', 'error', 'warn', 'info', 'debug', 'trace']; @@ -28,68 +27,71 @@ export async function initializeLogger() { } const basePath = app.getPath('userData'); - const logPath = path.join(basePath, 'logs'); - fs.mkdirSync(logPath, { recursive: true }); + const logFolder = path.join(basePath, 'logs'); + const logFile = path.join(logFolder, 'log.log'); - return cleanupLogs(logPath).then(() => { - if (logger) { - return; - } + fs.mkdirSync(logFolder, { recursive: true }); - const logFile = path.join(logPath, 'log.log'); - logger = Logger.createLogger({ - name: 'log', - streams: [ - { - level: 'debug', - stream: process.stdout, - }, - { - type: 'rotating-file', - path: logFile, - period: '1d', - count: 1, - }, - ], - }); + await cleanupLogs(logFile, logFolder); - LEVELS.forEach(level => { - ipc.on(`log-${level}`, (_first, ...rest) => { - (logger as any)[level](...rest); - }); - }); + console.warn('logFile', logFile); + + logger = Logger.createLogger({ + name: 'log', + level: 'debug', + streams: [ + { + stream: process.stdout, + }, + { + path: logFile, + }, + ], + }); - ipc.on('fetch-log', event => { - fs.mkdirSync(logPath, { recursive: true }); - console.info('fetching logs from logPath'); + logger.level('debug'); + // eslint-disable-next-line dot-notation + (logger as any)['warn']('app start: logger created'); // keep this so we always have restart indications in the app - fetchLogFile(logPath).then( - data => { - event.sender.send('fetched-log', data); - }, - error => { - logger?.error(`Problem loading log from disk: ${error.stack}`); - } - ); + LEVELS.forEach(level => { + ipc.on(`log-${level}`, (_first, ...rest) => { + (logger as any)[level](...rest); }); + }); - // eslint-disable-next-line @typescript-eslint/no-misused-promises - ipc.on('delete-all-logs', async event => { - try { - await deleteAllLogs(logPath); - } catch (error) { - logger?.error(`Problem deleting all logs: ${error.stack}`); + ipc.on('fetch-log', event => { + if (!fs.existsSync(logFolder)) { + fs.mkdirSync(logFolder, { recursive: true }); + } + + console.info('fetching logs from logPath'); + + fetchLogFile(logFile).then( + data => { + event.sender.send('fetched-log', data); + }, + error => { + logger?.error(`Problem loading log from disk: ${error.stack}`); } + ); + }); - event.sender.send('delete-all-logs-complete'); - }); + // eslint-disable-next-line @typescript-eslint/no-misused-promises + ipc.on('delete-all-logs', async event => { + try { + await deleteAllLogs(logFile); + } catch (error) { + logger?.error(`Problem deleting all logs: ${error.stack}`); + } + + event.sender.send('delete-all-logs-complete'); }); } -async function deleteAllLogs(logPath: string) { +async function deleteAllLogs(logFile: string) { return new Promise((resolve, reject) => { rimraf( - logPath, + logFile, { disableGlob: true, }, @@ -105,85 +107,33 @@ async function deleteAllLogs(logPath: string) { }); } -async function cleanupLogs(logPath: string) { +async function cleanupLogs(logFile: string, logFolder: string) { const now = new Date(); const earliestDate = new Date( - Date.UTC(now.getUTCFullYear(), now.getUTCMonth(), now.getUTCDate() - 6) + Date.UTC(now.getUTCFullYear(), now.getUTCMonth(), now.getUTCDate() - 2) // keeping 2 days worth of logs at most ); try { - const remaining = await eliminateOutOfDateFiles(logPath, earliestDate); - const files = _.filter(remaining, file => !file.start && file.end); - - if (!files.length) { - return; - } - - await eliminateOldEntries(files, earliestDate); + await eliminateOldEntries(logFile, earliestDate); } catch (error) { console.error('Error cleaning logs; deleting and starting over from scratch.', error.stack); - - // delete and re-create the log directory - await deleteAllLogs(logPath); - fs.mkdirSync(logPath, { recursive: true }); + fs.mkdirSync(logFolder, { recursive: true }); } } -function isLineAfterDate(line: string, date: Date) { - if (!line) { - return false; - } +async function eliminateOldEntries(logFile: string, date: Date) { + const earliest = date.getTime(); - try { - const data = JSON.parse(line); - return new Date(data.time).getTime() > date.getTime(); - } catch (e) { - console.log('error parsing log line', e.stack, line); - return false; + if (!fs.existsSync(logFile)) { + return; } -} - -async function eliminateOutOfDateFiles(logPath: string, date: Date) { - const files = fs.readdirSync(logPath); - const paths = files.map(file => path.join(logPath, file)); - - return Promise.all( - _.map(paths, target => - Promise.all([firstline(target), readLastLinesEnc('utf8')(target, 2)]).then(results => { - const start = results[0]; - const end = results[1].split('\n'); - - const file = { - path: target, - start: isLineAfterDate(start, date), - end: - isLineAfterDate(end[end.length - 1], date) || - isLineAfterDate(end[end.length - 2], date), - }; - - if (!file.start && !file.end) { - fs.unlinkSync(file.path); - } - return file; - }) - ) - ); -} + const lines = await fetchLog(logFile); -async function eliminateOldEntries(files: any, date: Date) { - const earliest = date.getTime(); + const recent = _.filter(lines, line => new Date(line.time).getTime() >= earliest); + const text = _.map(recent, line => JSON.stringify(line)).join('\n'); - return Promise.all( - _.map(files, file => - fetchLog(file.path).then((lines: any) => { - const recent = _.filter(lines, line => new Date(line.time).getTime() >= earliest); - const text = _.map(recent, line => JSON.stringify(line)).join('\n'); - - fs.writeFileSync(file.path, `${text}\n`); - }) - ) - ); + fs.writeFileSync(logFile, `${text}\n`); } export function getLogger() { @@ -194,56 +144,45 @@ export function getLogger() { return logger; } -async function fetchLog(logFile: string) { - return new Promise((resolve, reject) => { - fs.readFile(logFile, { encoding: 'utf8' }, (err, text) => { - if (err) { - reject(err); - return; +type LogEntry = { level: number; time: string; msg: string }; + +async function fetchLog(logFile: string): Promise> { + const text = await readFile(logFile, { encoding: 'utf8' }); + + const lines = _.compact(text.split('\n')); + const data = _.compact( + lines.map(line => { + try { + return _.pick(JSON.parse(line), ['level', 'time', 'msg']); + } catch (e) { + return null; } + }) + ); - const lines = _.compact(text.split('\n')); - const data = _.compact( - lines.map(line => { - try { - return _.pick(JSON.parse(line), ['level', 'time', 'msg']); - } catch (e) { - return null; - } - }) - ); - - resolve(data); - }); - }); + return data; } -export async function fetchLogFile(logPath: string) { +async function fetchLogFile(logFile: string) { // Check that the file exists locally - if (!fs.existsSync(logPath)) { - (console as ConsoleCustom)._log( - 'Log folder not found while fetching its content. Quick! Creating it.' - ); - fs.mkdirSync(logPath, { recursive: true }); + if (!fs.existsSync(logFile)) { + throw new Error('Log folder not found while fetching its content'); } - const files = fs.readdirSync(logPath); - const paths = files.map(file => path.join(logPath, file)); // creating a manual log entry for the final log result const now = new Date(); const fileListEntry = { level: 30, // INFO time: now.toJSON(), - msg: `Loaded this list of log files from logPath: ${files.join(', ')}`, + msg: `Loaded this from logfile: "${logFile}"`, }; - return Promise.all(paths.map(fetchLog)).then(results => { - const data = _.flatten(results); + const read = await fetchLog(logFile); + const data = _.flatten(read); - data.push(fileListEntry); + data.push(fileListEntry); - return _.sortBy(data, 'time'); - }); + return _.sortBy(data, 'time'); } function logAtLevel(level: string, ...args: any) {