From 7db370fb877bfaa7bc7cd57764895fb4ab6d493c Mon Sep 17 00:00:00 2001 From: Kristóf Marussy Date: Thu, 30 Dec 2021 02:37:44 +0100 Subject: refactor: Improve logging --- packages/main/package.json | 1 + packages/main/src/controllers/config.ts | 32 ++++++------------ packages/main/src/controllers/nativeTheme.ts | 10 +++--- .../main/src/services/ConfigPersistenceService.ts | 39 ++++++++++++++++++---- packages/main/src/utils/logging.ts | 31 +++++++++++------ 5 files changed, 70 insertions(+), 43 deletions(-) (limited to 'packages/main') diff --git a/packages/main/package.json b/packages/main/package.json index 76eff8e..a1af489 100644 --- a/packages/main/package.json +++ b/packages/main/package.json @@ -11,6 +11,7 @@ "dependencies": { "@sophie/service-shared": "workspace:*", "@sophie/shared": "workspace:*", + "chalk": "^5.0.0", "electron": "16.0.5", "json5": "^2.2.0", "lodash-es": "^4.17.21", diff --git a/packages/main/src/controllers/config.ts b/packages/main/src/controllers/config.ts index f2467c7..600a142 100644 --- a/packages/main/src/controllers/config.ts +++ b/packages/main/src/controllers/config.ts @@ -28,17 +28,16 @@ import { Disposer, getLogger } from '../utils'; const DEFAULT_CONFIG_DEBOUNCE_TIME = ms('1s'); -const logger = getLogger('controller:config'); +const log = getLogger('config'); export async function initConfig( config: Config, persistenceService: ConfigPersistenceService, debounceTime: number = DEFAULT_CONFIG_DEBOUNCE_TIME, ): Promise { - logger.debug('Initializing controller'); + log.trace('Initializing config controller'); let lastSnapshotOnDisk: ConfigSnapshotOut | null = null; - let writingConfig: boolean = false; async function readConfig(): Promise { const result = await persistenceService.readConfig(); @@ -46,9 +45,8 @@ export async function initConfig( try { applySnapshot(config, result.data); lastSnapshotOnDisk = getSnapshot(config); - logger.debug('Loaded config'); } catch (err) { - logger.error('Failed to read config', result.data, err); + log.error('Failed to apply config snapshot', result.data, err); } } return result.found; @@ -56,23 +54,17 @@ export async function initConfig( async function writeConfig(): Promise { const snapshot = getSnapshot(config); - writingConfig = true; - try { - await persistenceService.writeConfig(snapshot); - lastSnapshotOnDisk = snapshot; - logger.debug('Wrote config'); - } finally { - writingConfig = false; - } + await persistenceService.writeConfig(snapshot); + lastSnapshotOnDisk = snapshot; } if (!await readConfig()) { - logger.info('Config file was not found'); + log.info('Config file was not found'); try { await writeConfig(); - logger.info('Created config file'); + log.info('Created config file'); } catch (err) { - logger.error('Failed to initialize config'); + log.error('Failed to initialize config', err); } } @@ -80,19 +72,17 @@ export async function initConfig( // We can compare snapshots by reference, since it is only recreated on store changes. if (lastSnapshotOnDisk !== snapshot) { writeConfig().catch((err) => { - logger.error('Failed to write config on config change', err); + log.error('Failed to write config on config change', err); }) } }, debounceTime)); const disposeWatcher = persistenceService.watchConfig(async () => { - if (!writingConfig) { - await readConfig(); - } + await readConfig(); }, debounceTime); return () => { - logger.debug('Disposing controller'); + log.trace('Disposing config controller'); disposeWatcher(); disposeOnSnapshot(); }; diff --git a/packages/main/src/controllers/nativeTheme.ts b/packages/main/src/controllers/nativeTheme.ts index 9f9bc21..9edb4e8 100644 --- a/packages/main/src/controllers/nativeTheme.ts +++ b/packages/main/src/controllers/nativeTheme.ts @@ -24,25 +24,25 @@ import { autorun } from 'mobx'; import type { MainStore } from '../stores/MainStore'; import { Disposer, getLogger } from '../utils'; -const logger = getLogger('controller:nativeTheme'); +const log = getLogger('nativeTheme'); export function initNativeTheme(store: MainStore): Disposer { - logger.debug('Initializing controller'); + log.trace('Initializing nativeTheme controller'); const disposeThemeSourceReaction = autorun(() => { nativeTheme.themeSource = store.config.themeSource; - logger.debug('Set theme source:', store.config.themeSource); + log.debug('Set theme source:', store.config.themeSource); }); store.setShouldUseDarkColors(nativeTheme.shouldUseDarkColors); const shouldUseDarkColorsListener = () => { store.setShouldUseDarkColors(nativeTheme.shouldUseDarkColors); - logger.debug('Set should use dark colors:', nativeTheme.shouldUseDarkColors); + log.debug('Set should use dark colors:', nativeTheme.shouldUseDarkColors); }; nativeTheme.on('updated', shouldUseDarkColorsListener); return () => { - logger.debug('Disposing controller'); + log.trace('Disposing nativeTheme controller'); nativeTheme.off('updated', shouldUseDarkColorsListener); disposeThemeSourceReaction(); }; diff --git a/packages/main/src/services/ConfigPersistenceService.ts b/packages/main/src/services/ConfigPersistenceService.ts index ee5eb9f..b2109f6 100644 --- a/packages/main/src/services/ConfigPersistenceService.ts +++ b/packages/main/src/services/ConfigPersistenceService.ts @@ -24,13 +24,17 @@ import throttle from 'lodash-es/throttle'; import { join } from 'path'; import type { ConfigSnapshotOut } from '../stores/Config'; -import { Disposer } from '../utils'; +import { Disposer, getLogger } from '../utils'; + +const log = getLogger('configPersistence'); export type ReadConfigResult = { found: true; data: unknown; } | { found: false; }; export class ConfigPersistenceService { private readonly configFilePath: string; + private writingConfig = false; + private timeLastWritten: Date | null = null; constructor( @@ -47,10 +51,12 @@ export class ConfigPersistenceService { configStr = await readFile(this.configFilePath, 'utf8'); } catch (err) { if ((err as NodeJS.ErrnoException).code === 'ENOENT') { + log.debug('Config file', this.configFilePath, 'was not found'); return { found: false }; } throw err; } + log.info('Read config file', this.configFilePath); return { found: true, data: JSON5.parse(configStr), @@ -61,24 +67,42 @@ export class ConfigPersistenceService { const configJson = JSON5.stringify(configSnapshot, { space: 2, }); - await writeFile(this.configFilePath, configJson, 'utf8'); - const stats = await stat(this.configFilePath); - this.timeLastWritten = stats.mtime; + this.writingConfig = true; + try { + await writeFile(this.configFilePath, configJson, 'utf8'); + const { mtime } = await stat(this.configFilePath); + log.trace('Config file', this.configFilePath, 'last written at', mtime); + this.timeLastWritten = mtime; + } finally { + this.writingConfig = false; + } + log.info('Wrote config file', this.configFilePath); } watchConfig(callback: () => Promise, throttleMs: number): Disposer { + log.debug('Installing watcher for', this.userDataDir); + const configChanged = throttle(async () => { let mtime: Date; try { const stats = await stat(this.configFilePath); mtime = stats.mtime; + log.trace('Config file last modified at', mtime); } catch (err) { if ((err as NodeJS.ErrnoException).code === 'ENOENT') { + log.debug('Config file', this.configFilePath, 'was deleted after being changed'); return; } throw err; } - if (this.timeLastWritten === null || mtime > this.timeLastWritten) { + if (!this.writingConfig + && (this.timeLastWritten === null || mtime > this.timeLastWritten)) { + log.debug( + 'Found a config file modified at', + mtime, + 'whish is newer than last written', + this.timeLastWritten, + ); return callback(); } }, throttleMs); @@ -96,6 +120,9 @@ export class ConfigPersistenceService { } }); - return () => watcher.close(); + return () => { + log.trace('Removing watcher for', this.configFilePath); + watcher.close(); + }; } } diff --git a/packages/main/src/utils/logging.ts b/packages/main/src/utils/logging.ts index 5cb5d21..6c4cba2 100644 --- a/packages/main/src/utils/logging.ts +++ b/packages/main/src/utils/logging.ts @@ -18,28 +18,37 @@ * SPDX-License-Identifier: AGPL-3.0-only */ +import chalk, { ChalkInstance } from 'chalk'; import loglevel, { Logger } from 'loglevel'; import prefix from 'loglevel-plugin-prefix'; -const isDevelopment = import.meta.env.MODE === 'development'; +if (import.meta.env.DEV) { + loglevel.setLevel('debug'); +} else { + loglevel.setLevel('info'); +} + +const COLORS: Partial> = { + TRACE: chalk.magenta, + DEBUG: chalk.cyan, + INFO: chalk.blue, + WARN: chalk.yellow, + ERROR: chalk.red, + CRITICAL: chalk.red, +}; -if (isDevelopment) { - loglevel.enableAll(); +function getColor(level: string): ChalkInstance { + return COLORS[level] ?? chalk.gray; } prefix.reg(loglevel); prefix.apply(loglevel, { format(level, name, timestamp) { - let shortName = 'global'; - if (name !== undefined) { - const nameSegments = name.split(':'); - const lastSegment = nameSegments.pop(); - shortName = [...nameSegments.map((segment) => segment[0]), lastSegment].join(':'); - } - return `[${timestamp}] ${level} (${shortName})`; + const levelColor = getColor(level); + return `${chalk.gray(`[${timestamp}]`)} ${levelColor(level)} ${chalk.green(`${name}:`)}`; }, }); export function getLogger(loggerName: string): Logger { - return loglevel.getLogger(`sophie:${loggerName}`); + return loglevel.getLogger(loggerName); } -- cgit v1.2.3-54-g00ecf