diff --git a/app/attachment_channel.ts b/app/attachment_channel.ts index c2b6e82ecb..b15e325fe7 100644 --- a/app/attachment_channel.ts +++ b/app/attachment_channel.ts @@ -42,6 +42,7 @@ import { safeParseInteger } from '../ts/util/numbers'; import { parseLoose } from '../ts/util/schemas'; import { sleep } from '../ts/util/sleep'; import { toWebStream } from '../ts/util/toWebStream'; +import * as log from '../ts/logging/log'; import { deleteAll as deleteAllAttachments, deleteAllBadges, @@ -127,7 +128,7 @@ async function safeDecryptToSink( timeout: GROWING_FILE_TIMEOUT, }); file.on('error', (error: Error) => { - console.warn( + log.warn( 'safeDecryptToSync/incremental: growing-file emitted an error:', Errors.toLogFormat(error) ); @@ -215,7 +216,7 @@ async function safeDecryptToSink( return; } - console.error( + log.error( 'handleAttachmentRequest: decryption error', Errors.toLogFormat(error) ); @@ -307,13 +308,13 @@ async function cleanupOrphanedAttachments({ }); const orphanedAttachments = new Set(await getAllAttachments(userDataPath)); - console.log( + log.info( 'cleanupOrphanedAttachments: found ' + `${orphanedAttachments.size} attachments on disk` ); const orphanedDownloads = new Set(await getAllDownloads(userDataPath)); - console.log( + log.info( 'cleanupOrphanedAttachments: found ' + `${orphanedDownloads.size} downloads on disk` ); @@ -330,13 +331,13 @@ async function cleanupOrphanedAttachments({ } } - console.log( + log.info( `cleanupOrphanedAttachments: Got ${conversationAttachments.length} conversation attachments,` + ` ${orphanedAttachments.size} remain` ); if (missingConversationAttachments > 0) { - console.warn( + log.warn( `cleanupOrphanedAttachments: ${missingConversationAttachments} conversation attachments were not found on disk` ); } @@ -352,13 +353,13 @@ async function cleanupOrphanedAttachments({ } } - console.log( + log.info( `cleanupOrphanedAttachments: found ${downloads.length} known downloads, ` + `${orphanedDownloads.size} remain` ); if (missing > 0) { - console.warn( + log.warn( `cleanupOrphanedAttachments: ${missing} downloads were not found on disk` ); } @@ -433,13 +434,13 @@ function deleteOrphanedAttachments({ } } - console.log( + log.info( `cleanupOrphanedAttachments: ${totalAttachmentsFound} message ` + `attachments; ${orphanedAttachments.size} remain` ); if (totalMissing > 0) { - console.warn( + log.warn( `cleanupOrphanedAttachments: ${totalMissing} message attachments were not found on disk` ); } @@ -449,7 +450,7 @@ function deleteOrphanedAttachments({ attachments: Array.from(orphanedAttachments), }); - console.log( + log.info( `cleanupOrphanedAttachments: found ${totalDownloadsFound} downloads ` + `${orphanedDownloads.size} remain` ); @@ -464,13 +465,10 @@ function deleteOrphanedAttachments({ try { await runWithPossibleException(); } catch (error) { - console.error( - 'deleteOrphanedAttachments: error', - Errors.toLogFormat(error) - ); + log.error('deleteOrphanedAttachments: error', Errors.toLogFormat(error)); } finally { const duration = Date.now() - start; - console.log(`deleteOrphanedAttachments: took ${duration}ms`); + log.info(`deleteOrphanedAttachments: took ${duration}ms`); } } @@ -534,7 +532,7 @@ export function initialize({ _block, }); const duration = Date.now() - start; - console.log(`cleanupOrphanedAttachments: took ${duration}ms`); + log.info(`cleanupOrphanedAttachments: took ${duration}ms`); } ); @@ -542,7 +540,7 @@ export function initialize({ const start = Date.now(); await deleteStaleDownloads(configDir); const duration = Date.now() - start; - console.log(`cleanupDownloads: took ${duration}ms`); + log.info(`cleanupDownloads: took ${duration}ms`); }); protocol.handle('attachment', handleAttachmentRequest); @@ -680,7 +678,7 @@ export async function handleAttachmentRequest(req: Request): Promise { context, }); } catch (error) { - console.error('handleAttachmentRequest: error', Errors.toLogFormat(error)); + log.error('handleAttachmentRequest: error', Errors.toLogFormat(error)); throw error; } } @@ -733,13 +731,13 @@ function handleRangeRequest({ // Chromium only sends open-ended ranges: "start-" const match = range.match(/^bytes=(\d+)-$/); if (match == null) { - console.error(`attachment_channel: invalid range header: ${range}`); + log.error(`attachment_channel: invalid range header: ${range}`); return create200Response(); } const startParam = safeParseInteger(match[1]); if (startParam == null) { - console.error(`attachment_channel: invalid range header: ${range}`); + log.error(`attachment_channel: invalid range header: ${range}`); return create200Response(); } diff --git a/app/attachments.ts b/app/attachments.ts index ef87fde32d..435ac19218 100644 --- a/app/attachments.ts +++ b/app/attachments.ts @@ -20,6 +20,7 @@ import { } from '../ts/AttachmentCrypto'; import type { LocalAttachmentV2Type } from '../ts/types/Attachment'; import * as Errors from '../ts/types/errors'; +import * as log from '../ts/logging/log'; const PATH = 'attachments.noindex'; const AVATAR_PATH = 'avatars.noindex'; @@ -155,7 +156,7 @@ export const deleteStaleDownloads = async ( if (error.code === 'ENOENT') { return; } - console.error( + log.error( 'deleteStaleDownloads: failed to get file stats', Errors.toLogFormat(error) ); @@ -169,7 +170,7 @@ export const deleteStaleDownloads = async ( if (stale.length === 0) { return; } - console.log(`deleteStaleDownloads: found ${stale.length}`); + log.info(`deleteStaleDownloads: found ${stale.length}`); await deleteAllDownloads({ userDataPath, downloads: stale }); }; @@ -184,7 +185,7 @@ export const deleteAll = async ({ await pMap(attachments, deleteFromDisk, { concurrency: FS_CONCURRENCY }); - console.log(`deleteAll: deleted ${attachments.length} files`); + log.info(`deleteAll: deleted ${attachments.length} files`); }; export const deleteAllDownloads = async ({ @@ -198,7 +199,7 @@ export const deleteAllDownloads = async ({ await pMap(downloads, deleteFromDisk, { concurrency: FS_CONCURRENCY }); - console.log(`deleteAllDownloads: deleted ${downloads.length} files`); + log.info(`deleteAllDownloads: deleted ${downloads.length} files`); }; export const deleteAllStickers = async ({ @@ -212,7 +213,7 @@ export const deleteAllStickers = async ({ await pMap(stickers, deleteFromDisk, { concurrency: FS_CONCURRENCY }); - console.log(`deleteAllStickers: deleted ${stickers.length} files`); + log.info(`deleteAllStickers: deleted ${stickers.length} files`); }; export const deleteAllBadges = async ({ @@ -233,7 +234,7 @@ export const deleteAllBadges = async ({ } } - console.log(`deleteAllBadges: deleted ${filesDeleted} files`); + log.info(`deleteAllBadges: deleted ${filesDeleted} files`); }; export const deleteAllDraftAttachments = async ({ @@ -247,7 +248,7 @@ export const deleteAllDraftAttachments = async ({ await pMap(attachments, deleteFromDisk, { concurrency: FS_CONCURRENCY }); - console.log(`deleteAllDraftAttachments: deleted ${attachments.length} files`); + log.info(`deleteAllDraftAttachments: deleted ${attachments.length} files`); }; export const readAndDecryptDataFromDisk = async ({ diff --git a/app/base_config.ts b/app/base_config.ts index 821518884a..16fa135d24 100644 --- a/app/base_config.ts +++ b/app/base_config.ts @@ -7,6 +7,7 @@ import { sync as writeFileSync } from 'write-file-atomic'; import { get } from 'lodash'; import { set } from 'lodash/fp'; import { strictAssert } from '../ts/util/assert'; +import * as log from '../ts/logging/log'; const ENCODING = 'utf8'; @@ -36,10 +37,10 @@ export function start({ try { incomingJson = readFileSync(targetPath, ENCODING); cachedValue = incomingJson ? JSON.parse(incomingJson) : undefined; - console.log(`config/get: Successfully read ${name} config file`); + log.info(`config/get: Successfully read ${name} config file`); if (!cachedValue) { - console.log( + log.info( `config/start: ${name} config value was falsy, cache is now empty object` ); cachedValue = Object.create(null); @@ -50,11 +51,11 @@ export function start({ } if (incomingJson) { - console.log( + log.info( `config/start: ${name} config file was malformed, starting afresh` ); } else { - console.log( + log.info( `config/start: Did not find ${name} config file (or it was empty), cache is now empty object` ); } @@ -68,7 +69,7 @@ export function start({ function ourSet(keyPath: string, value: unknown): void { const newCachedValue = set(keyPath, value, cachedValue); - console.log(`config/set: Saving ${name} config to disk`); + log.info(`config/set: Saving ${name} config to disk`); if (!throwOnFilesystemErrors) { cachedValue = newCachedValue; @@ -76,13 +77,13 @@ export function start({ const outgoingJson = JSON.stringify(newCachedValue, null, ' '); try { writeFileSync(targetPath, outgoingJson, ENCODING); - console.log(`config/set: Saved ${name} config to disk`); + log.info(`config/set: Saved ${name} config to disk`); cachedValue = newCachedValue; } catch (err: unknown) { if (throwOnFilesystemErrors) { throw err; } else { - console.warn( + log.warn( `config/set: Failed to save ${name} config to disk; only updating in-memory data` ); } @@ -90,17 +91,17 @@ export function start({ } function remove(): void { - console.log(`config/remove: Deleting ${name} config from disk`); + log.info(`config/remove: Deleting ${name} config from disk`); try { unlinkSync(targetPath); - console.log(`config/remove: Deleted ${name} config from disk`); + log.info(`config/remove: Deleted ${name} config from disk`); } catch (err: unknown) { const errCode: unknown = get(err, 'code'); if (throwOnFilesystemErrors) { strictAssert(errCode === 'ENOENT', 'Expected deletion of no file'); - console.log(`config/remove: No ${name} config on disk, did nothing`); + log.info(`config/remove: No ${name} config on disk, did nothing`); } else { - console.warn( + log.warn( `config/remove: Got ${String( errCode )} when removing ${name} config from disk` diff --git a/app/config.ts b/app/config.ts index b3f34038c1..5133d685d0 100644 --- a/app/config.ts +++ b/app/config.ts @@ -12,6 +12,7 @@ import { setEnvironment, parseEnvironment, } from '../ts/environment'; +import * as log from '../ts/logging/log'; // In production mode, NODE_ENV cannot be customized by the user if (app.isPackaged) { @@ -51,7 +52,7 @@ const config: IConfig = require('config'); if (getEnvironment() !== Environment.PackagedApp) { config.util.getConfigSources().forEach(source => { - console.log(`config: Using config source ${basename(source.name)}`); + log.info(`config: Using config source ${basename(source.name)}`); }); } diff --git a/app/crashReports.ts b/app/crashReports.ts index 4fdc276d73..55103c21a5 100644 --- a/app/crashReports.ts +++ b/app/crashReports.ts @@ -99,14 +99,14 @@ async function eraseDumps( } export function setup( - getLogger: () => LoggerType, + logger: LoggerType, showDebugLogWindow: () => Promise, forceEnable = false ): void { const isEnabled = !isProduction(app.getVersion()) || forceEnable; if (isEnabled) { - getLogger().info(`crashReporter: ${forceEnable ? 'force ' : ''}enabled`); + logger.info(`crashReporter: ${forceEnable ? 'force ' : ''}enabled`); crashReporter.start({ uploadToServer: false }); } @@ -127,7 +127,7 @@ export function setup( return fullPath; } } catch (error) { - getLogger().error( + logger.error( `crashReports: failed to read crash report ${fullPath} due to error`, Errors.toLogFormat(error) ); @@ -136,7 +136,7 @@ export function setup( try { await unlink(fullPath); } catch (error) { - getLogger().error( + logger.error( `crashReports: failed to unlink crash report ${fullPath}`, Errors.toLogFormat(error) ); @@ -147,9 +147,7 @@ export function setup( ).filter(isNotNil); if (filteredDumps.length !== 0) { - getLogger().warn( - `crashReports: ${filteredDumps.length} pending dumps found` - ); + logger.warn(`crashReports: ${filteredDumps.length} pending dumps found`); } return filteredDumps.length; }); @@ -164,7 +162,6 @@ export function setup( return; } - const logger = getLogger(); logger.warn(`crashReports: logging ${pendingDumps.length} dumps`); await Promise.all( @@ -225,6 +222,6 @@ export function setup( const pendingDumps = await getPendingDumps(); - await eraseDumps(getLogger(), pendingDumps); + await eraseDumps(logger, pendingDumps); }); } diff --git a/app/dns-fallback.ts b/app/dns-fallback.ts index 18ce401c66..423a7105a2 100644 --- a/app/dns-fallback.ts +++ b/app/dns-fallback.ts @@ -6,6 +6,7 @@ import { readFile } from 'fs/promises'; import { DNSFallbackSchema } from '../ts/types/DNSFallback'; import type { DNSFallbackType } from '../ts/types/DNSFallback'; import { parseUnknown } from '../ts/util/schemas'; +import * as log from '../ts/logging/log'; let cached: DNSFallbackType | undefined; @@ -19,7 +20,7 @@ export async function getDNSFallback(): Promise { try { str = await readFile(configPath, 'utf8'); } catch (error) { - console.error( + log.error( 'Warning: build/dns-fallback.json not build, run `npm run build:dns-fallback`' ); cached = []; diff --git a/app/global_errors.ts b/app/global_errors.ts index 3a3fc092c6..3e6b81979a 100644 --- a/app/global_errors.ts +++ b/app/global_errors.ts @@ -6,6 +6,7 @@ import os from 'node:os'; import * as Errors from '../ts/types/errors'; import { redactAll } from '../ts/util/privacy'; +import * as log from '../ts/logging/log'; import { reallyJsonStringify } from '../ts/util/reallyJsonStringify'; import type { LocaleType } from './locale'; @@ -15,10 +16,8 @@ let copyErrorAndQuitText = 'Copy error and quit'; function handleError(prefix: string, error: Error): void { const formattedError = Errors.toLogFormat(error); - if (console._error) { - console._error(`${prefix}:`, formattedError); - } console.error(`${prefix}:`, formattedError); + log.error(`${prefix}:`, formattedError); if (app.isReady()) { // title field is not shown on macOS, so we don't use it diff --git a/app/main.ts b/app/main.ts index 9476b8950c..e23cb9b89a 100644 --- a/app/main.ts +++ b/app/main.ts @@ -42,11 +42,11 @@ import { createSupportUrl } from '../ts/util/createSupportUrl'; import { missingCaseError } from '../ts/util/missingCaseError'; import { strictAssert } from '../ts/util/assert'; import { drop } from '../ts/util/drop'; -import { createBufferedConsoleLogger } from '../ts/util/consoleLogger'; import type { ThemeSettingType } from '../ts/types/StorageUIKeys'; import { ThemeType } from '../ts/types/Util'; import * as Errors from '../ts/types/errors'; import { resolveCanonicalLocales } from '../ts/util/resolveCanonicalLocales'; +import * as log from '../ts/logging/log'; import * as debugLog from '../ts/logging/debuglogs'; import * as uploadDebugLog from '../ts/logging/uploadDebugLog'; import { explodePromise } from '../ts/util/explodePromise'; @@ -92,7 +92,7 @@ import { isContentProtectionEnabledByDefault, } from '../ts/types/Settings'; import * as ephemeralConfig from './ephemeral_config'; -import * as logging from '../ts/logging/main_process_logging'; +import * as mainProcessLogging from '../ts/logging/main_process_logging'; import { MainSQL } from '../ts/sql/main'; import * as sqlChannels from './sql_channel'; import * as windowState from './window_state'; @@ -113,7 +113,6 @@ import { getHeicConverter } from '../ts/workers/heicConverterMain'; import type { LocaleDirection, LocaleType } from './locale'; import { load as loadLocale } from './locale'; -import type { LoggerType } from '../ts/types/Logging'; import { HourCyclePreference } from '../ts/types/I18N'; import { ScreenShareStatus } from '../ts/types/Calling'; import type { ParsedSignalRoute } from '../ts/util/signalRoutes'; @@ -142,12 +141,7 @@ let mainWindow: BrowserWindow | undefined; let mainWindowCreated = false; let loadingWindow: BrowserWindow | undefined; -// Create a buffered logger to hold our log lines until we fully initialize -// the logger in `app.on('ready')` -const consoleLogger = createBufferedConsoleLogger(); - // These will be set after app fires the 'ready' event -let logger: LoggerType | undefined; let preferredSystemLocales: Array | undefined; let localeOverride: string | null | undefined; @@ -217,7 +211,7 @@ const DISABLE_SCREEN_SECURITY = process.argv.some( const CLI_LANG = cliOptions.lang as string | undefined; -setupCrashReports(getLogger, showDebugLogWindow, FORCE_ENABLE_CRASH_REPORTS); +setupCrashReports(log, showDebugLogWindow, FORCE_ENABLE_CRASH_REPORTS); let sendDummyKeystroke: undefined | (() => void); if (OS.isWindows()) { @@ -226,10 +220,7 @@ if (OS.isWindows()) { const windowsNotifications = require('./WindowsNotifications'); sendDummyKeystroke = windowsNotifications.sendDummyKeystroke; } catch (error) { - getLogger().error( - 'Failed to initialize Windows Notifications:', - error.stack - ); + log.error('Failed to initialize Windows Notifications:', error.stack); } } @@ -250,10 +241,10 @@ function showWindow() { } if (!process.mas) { - console.log('making app single instance'); + log.info('making app single instance'); const gotLock = app.requestSingleInstanceLock(); if (!gotLock) { - console.log('quitting; we are the second instance'); + log.info('quitting; we are the second instance'); app.exit(); } else { app.on('second-instance', (_e: Electron.Event, argv: Array) => { @@ -269,12 +260,6 @@ if (!process.mas) { showWindow(); } - if (!logger) { - console.log( - 'second-instance: logger not initialized; skipping further checks' - ); - return; - } const route = maybeGetIncomingSignalRoute(argv); if (route != null) { @@ -311,14 +296,14 @@ const heicConverter = getHeicConverter(); async function getSpellCheckSetting(): Promise { const value = ephemeralConfig.get('spell-check'); if (typeof value === 'boolean') { - getLogger().info('got fast spellcheck setting', value); + log.info('got fast spellcheck setting', value); return value; } // Default to `true` if setting doesn't exist yet ephemeralConfig.set('spell-check', true); - getLogger().info('initializing spellcheck setting', true); + log.info('initializing spellcheck setting', true); return true; } @@ -332,7 +317,7 @@ async function getThemeSetting({ }: GetThemeSettingOptionsType = {}): Promise { const value = ephemeralConfig.get('theme-setting'); if (value !== undefined) { - getLogger().info('got fast theme-setting value', value); + log.info('got fast theme-setting value', value); } else if (ephemeralOnly) { return 'system'; } @@ -345,7 +330,7 @@ async function getThemeSetting({ if (value !== validatedResult) { ephemeralConfig.set('theme-setting', validatedResult); - getLogger().info('saving theme-setting value', validatedResult); + log.info('saving theme-setting value', validatedResult); } return validatedResult; @@ -386,14 +371,14 @@ async function getLocaleOverrideSetting(): Promise { const value = ephemeralConfig.get('localeOverride'); // eslint-disable-next-line eqeqeq -- Checking for null explicitly if (typeof value === 'string' || value === null) { - getLogger().info('got fast localeOverride setting', value); + log.info('got fast localeOverride setting', value); return value; } // Default to `null` if setting doesn't exist yet ephemeralConfig.set('localeOverride', null); - getLogger().info('initializing localeOverride setting', null); + log.info('initializing localeOverride setting', null); return null; } @@ -449,15 +434,6 @@ if (windowFromUserConfig) { let menuOptions: CreateTemplateOptionsType | undefined; -function getLogger(): LoggerType { - if (!logger) { - console.warn('getLogger: Logger not yet initialized!'); - return consoleLogger; - } - - return logger; -} - function getPreferredSystemLocales(): Array { if (!preferredSystemLocales) { throw new Error('getPreferredSystemLocales: Locales not yet initialized!'); @@ -537,7 +513,7 @@ async function handleUrl(rawTarget: string) { try { await shell.openExternal(rawTarget); } catch (error) { - getLogger().error(`Failed to open url: ${Errors.toLogFormat(error)}`); + log.error(`Failed to open url: ${Errors.toLogFormat(error)}`); } } } @@ -555,7 +531,7 @@ async function handleCommonWindowEvents(window: BrowserWindow) { window.webContents.on( 'preload-error', (_event: Electron.Event, preloadPath: string, error: Error) => { - getLogger().error(`Preload error in ${preloadPath}: `, error.message); + log.error(`Preload error in ${preloadPath}: `, error.message); } ); @@ -668,7 +644,7 @@ async function safeLoadURL(window: BrowserWindow, url: string): Promise { (wasDestroyed || windowState.readyForShutdown()) && error?.code === 'ERR_FAILED' ) { - getLogger().warn( + log.warn( 'safeLoadURL: ignoring ERR_FAILED because we are shutting down', error ); @@ -758,14 +734,14 @@ async function createWindow() { isNumber(windowOptions.width) && isNumber(windowOptions.height); if (haveFullWindowsBounds) { - getLogger().info( + log.info( `visibleOnAnyScreen(window): x=${windowOptions.x}, y=${windowOptions.y}, ` + `width=${windowOptions.width}, height=${windowOptions.height}` ); const visibleOnAnyScreen = some(screen.getAllDisplays(), display => { const displayBounds = get(display, 'bounds'); - getLogger().info( + log.info( `visibleOnAnyScreen(display #${display.id}): ` + `x=${displayBounds.x}, y=${displayBounds.y}, ` + `width=${displayBounds.width}, height=${displayBounds.height}` @@ -774,16 +750,13 @@ async function createWindow() { return isVisible(windowOptions as BoundsType, displayBounds); }); if (!visibleOnAnyScreen) { - getLogger().info('visibleOnAnyScreen: Location reset needed'); + log.info('visibleOnAnyScreen: Location reset needed'); delete windowOptions.x; delete windowOptions.y; } } - getLogger().info( - 'Initializing BrowserWindow config:', - JSON.stringify(windowOptions) - ); + log.info('Initializing BrowserWindow config:', windowOptions); // Create the browser window. mainWindow = new BrowserWindow(windowOptions); @@ -797,7 +770,7 @@ async function createWindow() { getPreferredSystemLocales(), getLocaleOverride(), getResolvedMessagesLocale().i18n, - getLogger() + log ); if (!startInTray && windowConfig && windowConfig.maximized) { mainWindow.maximize(); @@ -814,10 +787,7 @@ async function createWindow() { return; } - getLogger().info( - 'Updating BrowserWindow config: %s', - JSON.stringify(windowConfig) - ); + log.info('Updating BrowserWindow config:', windowConfig); ephemeralConfig.set('window', windowConfig); } const debouncedSaveStats = debounce(saveWindowStats, 500); @@ -878,11 +848,11 @@ async function createWindow() { // Electron before the app quits. mainWindow.on('close', async e => { if (!mainWindow) { - getLogger().info('close event: no main window'); + log.info('close event: no main window'); return; } - getLogger().info('close event', { + log.info('close event', { readyForShutdown: windowState.readyForShutdown(), shouldQuit: windowState.shouldQuit(), }); @@ -906,7 +876,7 @@ async function createWindow() { try { shouldClose = await maybeRequestCloseConfirmation(); } catch (error) { - getLogger().warn( + log.warn( 'Error while requesting close confirmation.', Errors.toLogFormat(error) ); @@ -947,12 +917,12 @@ async function createWindow() { if (usingTrayIcon) { const shownTrayNotice = ephemeralConfig.get('shown-tray-notice'); if (shownTrayNotice) { - getLogger().info('close: not showing tray notice'); + log.info('close: not showing tray notice'); return; } ephemeralConfig.set('shown-tray-notice', true); - getLogger().info('close: showing tray notice'); + log.info('close: showing tray notice'); const n = new Notification({ title: getResolvedMessagesLocale().i18n( @@ -984,7 +954,7 @@ async function createWindow() { // Dereference the window object, usually you would store windows // in an array if your app supports multi windows, this is the time // when you should delete the corresponding element. - getLogger().info('main window closed event'); + log.info('main window closed event'); mainWindow = undefined; if (settingsChannel) { settingsChannel.setMainWindow(mainWindow); @@ -995,13 +965,13 @@ async function createWindow() { }); mainWindow.on('enter-full-screen', () => { - getLogger().info('mainWindow enter-full-screen event'); + log.info('mainWindow enter-full-screen event'); if (mainWindow) { mainWindow.webContents.send('full-screen-change', true); } }); mainWindow.on('leave-full-screen', () => { - getLogger().info('mainWindow leave-full-screen event'); + log.info('mainWindow leave-full-screen event'); if (mainWindow) { mainWindow.webContents.send('full-screen-change', false); } @@ -1031,19 +1001,19 @@ async function createWindow() { mainWindow.webContents.send('ci:event', 'db-initialized', {}); if (shouldShowWindow) { - getLogger().info('showing main window'); + log.info('showing main window'); mainWindow.show(); } }; if (OS.isLinux() && OS.isWaylandEnabled()) { mainWindow.webContents.once('did-finish-load', async () => { - getLogger().info('main window webContents did-finish-load'); + log.info('main window webContents did-finish-load'); drop(maybeShowMainWindow()); }); } else { mainWindow.once('ready-to-show', async () => { - getLogger().info('main window is ready-to-show'); + log.info('main window is ready-to-show'); drop(maybeShowMainWindow()); }); } @@ -1059,20 +1029,20 @@ async function createWindow() { // Renderer asks if we are done with the database ipc.handle('database-ready', async () => { if (!sqlInitPromise) { - getLogger().error('database-ready requested, but sqlInitPromise is falsey'); + log.error('database-ready requested, but sqlInitPromise is falsey'); return; } const { error } = await sqlInitPromise; if (error) { - getLogger().error( + log.error( 'database-ready requested, but got sql error', Errors.toLogFormat(error) ); return; } - getLogger().info('sending `database-ready`'); + log.info('sending `database-ready`'); }); ipc.handle( @@ -1143,10 +1113,10 @@ ipc.on('set-is-call-active', (_event, isCallActive) => { let backgroundThrottling: boolean; if (isCallActive) { - getLogger().info('Background throttling disabled because a call is active'); + log.info('Background throttling disabled because a call is active'); backgroundThrottling = false; } else { - getLogger().info('Background throttling enabled because no call is active'); + log.info('Background throttling enabled because no call is active'); backgroundThrottling = true; } @@ -1192,23 +1162,20 @@ async function readyForUpdates() { ); }, getMainWindow, - logger: getLogger(), + logger: log, sql, }); } catch (error) { - getLogger().error( - 'Error starting update checks:', - Errors.toLogFormat(error) - ); + log.error('Error starting update checks:', Errors.toLogFormat(error)); } } async function forceUpdate() { try { - getLogger().info('starting force update'); + log.info('starting force update'); await updater.force(); } catch (error) { - getLogger().error('Error during force update:', Errors.toLogFormat(error)); + log.error('Error during force update:', Errors.toLogFormat(error)); } } @@ -1605,7 +1572,7 @@ const runSQLCorruptionHandler = async () => { // `onDatabaseInitializationError`. const error = await sql.whenCorrupted(); - getLogger().error( + log.error( 'Detected sql corruption in main process. ' + `Restarting the application immediately. Error: ${error.message}` ); @@ -1620,15 +1587,13 @@ const runSQLReadonlyHandler = async () => { // `onDatabaseInitializationError`. const error = await sql.whenReadonly(); - getLogger().error( - `Detected readonly sql database in main process: ${error.message}` - ); + log.error(`Detected readonly sql database in main process: ${error.message}`); throw error; }; function generateSQLKey(): string { - getLogger().info( + log.info( 'key/initialize: Generating new encryption key, since we did not find it on disk' ); // https://www.zetetic.net/sqlcipher/sqlcipher-api/#key @@ -1673,31 +1638,29 @@ function getSQLKey(): string { throw new Error("Can't decrypt database key"); } - getLogger().info('getSQLKey: decrypting key'); + log.info('getSQLKey: decrypting key'); const encrypted = Buffer.from(modernKeyValue, 'hex'); key = safeStorage.decryptString(encrypted); if (legacyKeyValue != null) { - getLogger().info('getSQLKey: removing legacy key'); + log.info('getSQLKey: removing legacy key'); userConfig.set('key', undefined); } if (isLinux && previousBackend == null) { - getLogger().info( - `getSQLKey: saving safeStorageBackend: ${safeStorageBackend}` - ); + log.info(`getSQLKey: saving safeStorageBackend: ${safeStorageBackend}`); userConfig.set('safeStorageBackend', safeStorageBackend); } } else if (typeof legacyKeyValue === 'string') { key = legacyKeyValue; update = isEncryptionAvailable; if (update) { - getLogger().info('getSQLKey: migrating key'); + log.info('getSQLKey: migrating key'); } else { - getLogger().info('getSQLKey: using legacy key'); + log.info('getSQLKey: using legacy key'); } } else { - getLogger().warn("getSQLKey: got key from config, but it wasn't a string"); + log.warn("getSQLKey: got key from config, but it wasn't a string"); key = generateSQLKey(); update = true; } @@ -1707,19 +1670,17 @@ function getSQLKey(): string { } if (isEncryptionAvailable) { - getLogger().info('getSQLKey: updating encrypted key in the config'); + log.info('getSQLKey: updating encrypted key in the config'); const encrypted = safeStorage.encryptString(key).toString('hex'); userConfig.set('encryptedKey', encrypted); userConfig.set('key', undefined); if (isLinux && safeStorageBackend) { - getLogger().info( - `getSQLKey: saving safeStorageBackend: ${safeStorageBackend}` - ); + log.info(`getSQLKey: saving safeStorageBackend: ${safeStorageBackend}`); userConfig.set('safeStorageBackend', safeStorageBackend); } } else { - getLogger().info('getSQLKey: updating plaintext key in the config'); + log.info('getSQLKey: updating plaintext key in the config'); userConfig.set('key', key); } @@ -1741,7 +1702,7 @@ async function initializeSQL( appVersion: app.getVersion(), configDir: userDataPath, key: 'abcd', - logger: getLogger(), + logger: log, }); } catch { // Do nothing, we fail right below anyway. @@ -1765,7 +1726,7 @@ async function initializeSQL( appVersion: app.getVersion(), configDir: userDataPath, key, - logger: getLogger(), + logger: log, }); } catch (error: unknown) { if (error instanceof Error) { @@ -1792,7 +1753,7 @@ async function initializeSQL( } function onUnknownSqlError(error: Error) { - getLogger().error('Unknown SQL Error:', Errors.toLogFormat(error)); + log.error('Unknown SQL Error:', Errors.toLogFormat(error)); if (mainWindow) { mainWindow.webContents.send('sql-error'); } @@ -1901,10 +1862,10 @@ const onDatabaseInitializationError = async (error: Error) => { }); if (confirmationButtonIndex === confirmDeleteAllDataButtonIndex) { - getLogger().error('onDatabaseInitializationError: Deleting all data'); + log.error('onDatabaseInitializationError: Deleting all data'); await sql.removeDB(); userConfig.remove(); - getLogger().error( + log.error( 'onDatabaseInitializationError: Requesting immediate restart after quit' ); app.relaunch(); @@ -1917,7 +1878,7 @@ const onDatabaseInitializationError = async (error: Error) => { ); } - getLogger().error('onDatabaseInitializationError: Quitting application'); + log.error('onDatabaseInitializationError: Quitting application'); app.exit(1); }; @@ -2007,7 +1968,7 @@ app.on('ready', async () => { realpath(app.getAppPath()), ]); - updateDefaultSession(session.defaultSession, getLogger); + updateDefaultSession(session.defaultSession, log); if (getEnvironment() !== Environment.Test) { installFileHandler({ @@ -2025,10 +1986,7 @@ app.on('ready', async () => { session: session.defaultSession, }); - logger = await logging.initialize(getMainWindow); - - // Write buffered information into newly created logger. - consoleLogger.writeBufferInto(logger); + await mainProcessLogging.initialize(getMainWindow); const resourceService = OptionalResourceService.create( join(userDataPath, 'optionalResources') @@ -2043,19 +2001,15 @@ app.on('ready', async () => { localeOverride = await getLocaleOverrideSetting(); const hourCyclePreference = getHourCyclePreference(); - logger.info(`app.ready: hour cycle preference: ${hourCyclePreference}`); + log.info(`app.ready: hour cycle preference: ${hourCyclePreference}`); - logger.info( - `app.ready: preferred system locales: ${preferredSystemLocales.join( - ', ' - )}` - ); + log.info('app.ready: preferred system locales:', preferredSystemLocales); resolvedTranslationsLocale = loadLocale({ preferredSystemLocales, localeOverride, localeDirectionTestingOverride, hourCyclePreference, - logger: getLogger(), + logger: log, }); } @@ -2070,13 +2024,13 @@ app.on('ready', async () => { (await systemTraySettingCache.get()) === SystemTraySetting.Uninitialized ) { const newValue = getDefaultSystemTraySetting(OS, app.getVersion()); - getLogger().info(`app.ready: setting system-tray-setting to ${newValue}`); + log.info(`app.ready: setting system-tray-setting to ${newValue}`); systemTraySettingCache.set(newValue); ephemeralConfig.set('system-tray-setting', newValue); if (OS.isWindows()) { - getLogger().info('app.ready: enabling open at login'); + log.info('app.ready: enabling open at login'); app.setLoginItemSettings({ ...(await getDefaultLoginItemSettings()), openAtLogin: true, @@ -2103,7 +2057,7 @@ app.on('ready', async () => { } // Default login item settings might have changed, so update the object. - getLogger().info('refresh-auto-launch: new value', openAtLogin); + log.info('refresh-auto-launch: new value', openAtLogin); app.setLoginItemSettings({ ...(await getDefaultLoginItemSettings()), openAtLogin, @@ -2128,7 +2082,7 @@ app.on('ready', async () => { const messageTime = loadTime - preloadTime - connectTime; const messagesPerSec = (processedCount * 1000) / messageTime; - const innerLogger = getLogger(); + const innerLogger = log; innerLogger.info('App loaded - time:', loadTime); innerLogger.info('SQL init - time:', sqlInitTime); innerLogger.info('Preload Compile - time:', preloadCompileTime); @@ -2162,8 +2116,8 @@ app.on('ready', async () => { }); } - logger.info('app ready'); - logger.info(`starting version ${packageJson.version}`); + log.info('app ready'); + log.info(`starting version ${packageJson.version}`); // This logging helps us debug user reports about broken devices. { @@ -2175,7 +2129,7 @@ app.on('ready', async () => { } else { getMediaAccessStatus = noop; } - logger.info( + log.info( 'media access status', getMediaAccessStatus('microphone'), getMediaAccessStatus('camera'), @@ -2206,7 +2160,7 @@ app.on('ready', async () => { return; } - getLogger().info( + log.info( 'sql.initialize is taking more than three seconds; showing loading dialog' ); @@ -2248,16 +2202,13 @@ app.on('ready', async () => { try { await attachments.clearTempPath(userDataPath); } catch (err) { - logger.error( - 'main/ready: Error deleting temp dir:', - Errors.toLogFormat(err) - ); + log.error('main/ready: Error deleting temp dir:', Errors.toLogFormat(err)); } try { await attachments.deleteStaleDownloads(userDataPath); } catch (err) { - logger.error( + log.error( 'main/ready: Error deleting stale downloads:', Errors.toLogFormat(err) ); @@ -2286,7 +2237,7 @@ app.on('ready', async () => { const { error: sqlError } = await sqlInitPromise; if (sqlError) { - getLogger().error('sql.initialize was unsuccessful; returning early'); + log.error('sql.initialize was unsuccessful; returning early'); await onDatabaseInitializationError(sqlError); @@ -2301,7 +2252,7 @@ app.on('ready', async () => { await sql.sqlWrite('removeItemById', IDB_KEY); } } catch (err) { - getLogger().error( + log.error( '(ready event handler) error deleting IndexedDB:', Errors.toLogFormat(err) ); @@ -2356,7 +2307,7 @@ function setupMenu(options?: Partial) { showKeyboardShortcuts, showSettings: () => { if (!settingsChannel) { - getLogger().warn( + log.warn( 'showSettings: No settings channel; cannot open settings tab.' ); return; @@ -2393,7 +2344,7 @@ async function maybeRequestCloseConfirmation(): Promise { return true; } - getLogger().info( + log.info( 'maybeRequestCloseConfirmation: Checking to see if close confirmation is needed' ); const request = new Promise(resolveFn => { @@ -2405,14 +2356,14 @@ async function maybeRequestCloseConfirmation(): Promise { } ipc.once('received-close-confirmation', (_event, result) => { - getLogger().info('maybeRequestCloseConfirmation: Response received'); + log.info('maybeRequestCloseConfirmation: Response received'); clearTimeoutIfNecessary(timeout); resolveFn(result); }); ipc.once('requested-close-confirmation', () => { - getLogger().info( + log.info( 'maybeRequestCloseConfirmation: Confirmation dialog shown, waiting for user.' ); clearTimeoutIfNecessary(timeout); @@ -2423,7 +2374,7 @@ async function maybeRequestCloseConfirmation(): Promise { // Wait a short time then proceed. Normally the dialog should be // shown right away. timeout = setTimeout(() => { - getLogger().error( + log.error( 'maybeRequestCloseConfirmation: Response never received; continuing with close.' ); resolveFn(true); @@ -2433,7 +2384,7 @@ async function maybeRequestCloseConfirmation(): Promise { try { return await request; } catch (error) { - getLogger().error( + log.error( 'maybeRequestCloseConfirmation error:', Errors.toLogFormat(error) ); @@ -2446,7 +2397,7 @@ async function requestShutdown() { return; } - getLogger().info('requestShutdown: Requesting close of mainWindow...'); + log.info('requestShutdown: Requesting close of mainWindow...'); const request = new Promise(resolveFn => { let timeout: NodeJS.Timeout | undefined; @@ -2456,13 +2407,10 @@ async function requestShutdown() { } ipc.once('now-ready-for-shutdown', (_event, error) => { - getLogger().info('requestShutdown: Response received'); + log.info('requestShutdown: Response received'); if (error) { - getLogger().error( - 'requestShutdown: got error, still shutting down.', - error - ); + log.error('requestShutdown: got error, still shutting down.', error); } clearTimeoutIfNecessary(timeout); @@ -2477,7 +2425,7 @@ async function requestShutdown() { // Note: two minutes is also our timeout for SQL tasks in data.js in the browser. timeout = setTimeout( () => { - getLogger().error( + log.error( 'requestShutdown: Response never received; forcing shutdown.' ); resolveFn(); @@ -2489,7 +2437,7 @@ async function requestShutdown() { try { await request; } catch (error) { - getLogger().error('requestShutdown error:', Errors.toLogFormat(error)); + log.error('requestShutdown error:', Errors.toLogFormat(error)); } } @@ -2512,7 +2460,7 @@ function getWindowDebugInfo() { } app.on('before-quit', e => { - getLogger().info('before-quit event', { + log.info('before-quit event', { readyForShutdown: windowState.readyForShutdown(), shouldQuit: windowState.shouldQuit(), hasEventBeenPrevented: e.defaultPrevented, @@ -2524,14 +2472,14 @@ app.on('before-quit', e => { }); app.on('will-quit', e => { - getLogger().info('will-quit event', { + log.info('will-quit event', { hasEventBeenPrevented: e.defaultPrevented, ...getWindowDebugInfo(), }); }); app.on('quit', e => { - getLogger().info('quit event', { + log.info('quit event', { hasEventBeenPrevented: e.defaultPrevented, ...getWindowDebugInfo(), }); @@ -2539,7 +2487,7 @@ app.on('quit', e => { // Quit when all windows are closed. app.on('window-all-closed', () => { - getLogger().info('main process handling window-all-closed'); + log.info('main process handling window-all-closed'); // On OS X it is common for applications and their menu bar // to stay active until the user quits explicitly with Cmd + Q const shouldAutoClose = !OS.isMacOS() || isTestEnvironment(getEnvironment()); @@ -2618,7 +2566,7 @@ ipc.on('draw-attention', () => { }); ipc.on('restart', () => { - getLogger().info('Relaunching application'); + log.info('Relaunching application'); app.relaunch(); app.quit(); }); @@ -2710,10 +2658,7 @@ ipc.handle( try { await showPermissionsPopupWindow(forCalling, forCamera); } catch (error) { - getLogger().error( - 'show-permissions-popup error:', - Errors.toLogFormat(error) - ); + log.error('show-permissions-popup error:', Errors.toLogFormat(error)); } } ); @@ -2868,7 +2813,7 @@ ipc.handle('DebugLogs.upload', async (_event, content: string) => { return uploadDebugLog.upload({ content, appVersion: app.getVersion(), - logger: getLogger(), + logger: log, }); }); @@ -2912,8 +2857,6 @@ function maybeGetIncomingSignalRoute(argv: Array) { } function handleSignalRoute(route: ParsedSignalRoute) { - const log = getLogger(); - if (mainWindow == null || !mainWindow.webContents) { log.error('handleSignalRoute: mainWindow is null or missing webContents'); return; @@ -2983,7 +2926,7 @@ ipc.handle('ensure-file-permissions', () => ensureFilePermissions()); * @param {string[]} [onlyFiles] - Only ensure permissions on these given files */ async function ensureFilePermissions(onlyFiles?: Array) { - getLogger().info('Begin ensuring permissions'); + log.info('Begin ensuring permissions'); const start = Date.now(); const userDataPath = await realpath(app.getPath('userData')); @@ -2998,7 +2941,7 @@ async function ensureFilePermissions(onlyFiles?: Array) { ignore: ['**/Singleton*'], }); - getLogger().info(`Ensuring file permissions for ${files.length} files`); + log.info(`Ensuring file permissions for ${files.length} files`); // Touch each file in a queue const q = new PQueue({ concurrency: 5, timeout: 1000 * 60 * 2 }); @@ -3009,10 +2952,7 @@ async function ensureFilePermissions(onlyFiles?: Array) { try { await chmod(normalize(f), isDir ? 0o700 : 0o600); } catch (error) { - getLogger().error( - 'ensureFilePermissions: Error from chmod', - error.message - ); + log.error('ensureFilePermissions: Error from chmod', error.message); } }) ) @@ -3020,7 +2960,7 @@ async function ensureFilePermissions(onlyFiles?: Array) { await q.onEmpty(); - getLogger().info(`Finish ensuring permissions in ${Date.now() - start}ms`); + log.info(`Finish ensuring permissions in ${Date.now() - start}ms`); } ipc.handle('get-media-access-status', async (_event, value) => { @@ -3063,7 +3003,7 @@ ipc.handle('get-auto-launch', async () => { ipc.handle('set-auto-launch', async (_event, value) => { const openAtLogin = Boolean(value); - getLogger().info('set-auto-launch: new value', openAtLogin); + log.info('set-auto-launch: new value', openAtLogin); app.setLoginItemSettings({ ...(await getDefaultLoginItemSettings()), openAtLogin, @@ -3080,7 +3020,7 @@ ipc.on('show-item-in-folder', (_event, folder) => { ipc.handle('show-save-dialog', async (_event, { defaultPath }) => { if (!mainWindow) { - getLogger().warn('show-save-dialog: no main window'); + log.warn('show-save-dialog: no main window'); return { canceled: true }; } @@ -3128,7 +3068,7 @@ ipc.handle( if (useMainWindow) { if (!mainWindow) { - getLogger().warn('show-open-folder-dialog: no main window'); + log.warn('show-open-folder-dialog: no main window'); return { canceled: true }; } @@ -3155,9 +3095,7 @@ ipc.handle( } if (selectedDirPaths.length > 1) { - getLogger().warn( - 'show-open-folder-dialog: multiple directories selected' - ); + log.warn('show-open-folder-dialog: multiple directories selected'); return { canceled: true }; } diff --git a/app/permissions.ts b/app/permissions.ts index b6a446cfd0..05a8d45f80 100644 --- a/app/permissions.ts +++ b/app/permissions.ts @@ -7,6 +7,7 @@ import type { session as ElectronSession, Session } from 'electron'; import type { ConfigType } from './base_config'; +import * as log from '../ts/logging/log'; const PERMISSIONS: Record = { // Allowed @@ -67,12 +68,12 @@ function _createPermissionHandler( } if (PERMISSIONS[permission]) { - console.log(`Approving request for permission '${permission}'`); + log.info(`Approving request for permission '${permission}'`); callback(true); return; } - console.log(`Denying request for permission '${permission}'`); + log.info(`Denying request for permission '${permission}'`); callback(false); }; } diff --git a/app/protocol_filter.ts b/app/protocol_filter.ts index 68dceea2ac..9f16dc7af4 100644 --- a/app/protocol_filter.ts +++ b/app/protocol_filter.ts @@ -15,6 +15,7 @@ import { getTempPath, getUpdateCachePath, } from './attachments'; +import * as log from '../ts/logging/log'; type CallbackType = (response: string | ProtocolResponse) => void; @@ -91,9 +92,7 @@ function _createFileHandler({ const properCasing = isWindows ? realPath.toLowerCase() : realPath; if (!isAbsolute(realPath)) { - console.log( - `Warning: denying request to non-absolute path '${realPath}'` - ); + log.info(`Warning: denying request to non-absolute path '${realPath}'`); // This is an "Access Denied" error. See [Chromium's net error list][0]. // // [0]: https://source.chromium.org/chromium/chromium/src/+/master:net/base/net_error_list.h;l=57;drc=a836ee9868cf1b9673fce362a82c98aba3e195de @@ -108,7 +107,7 @@ function _createFileHandler({ } } - console.log( + log.info( `Warning: denying request to path '${realPath}' (allowedRoots: '${allowedRoots}')` ); callback({ error: -10 }); @@ -117,9 +116,7 @@ function _createFileHandler({ err && typeof err.message === 'string' ? err.message : 'no error message'; - console.log( - `Warning: denying request because of an error: ${errorMessage}` - ); + log.info(`Warning: denying request because of an error: ${errorMessage}`); callback({ error: -300 }); } diff --git a/app/spell_check.ts b/app/spell_check.ts index fce8c4c5f5..729be2af53 100644 --- a/app/spell_check.ts +++ b/app/spell_check.ts @@ -11,6 +11,7 @@ import type { MenuListType } from '../ts/types/menu'; import type { LocalizerType } from '../ts/types/Util'; import { strictAssert } from '../ts/util/assert'; import type { LoggerType } from '../ts/types/Logging'; +import * as log from '../ts/logging/log'; import { handleAttachmentRequest } from './attachment_channel'; export const FAKE_DEFAULT_LOCALE = 'und'; // 'und' is the BCP 47 subtag for "undetermined" @@ -84,12 +85,9 @@ export const setup = ( const availableLocales = session.availableSpellCheckerLanguages; const languages = getLanguages(combinedLocales, availableLocales, 'en'); - console.log('spellcheck: user locales:', combinedLocales); - console.log( - 'spellcheck: available spellchecker languages:', - availableLocales - ); - console.log('spellcheck: setting languages to:', languages); + log.info('spellcheck: user locales:', combinedLocales); + log.info('spellcheck: available spellchecker languages:', availableLocales); + log.info('spellcheck: setting languages to:', languages); session.setSpellCheckerLanguages(languages); browserWindow.webContents.on('context-menu', (_event, params) => { diff --git a/app/startup_config.ts b/app/startup_config.ts index ee8d0473ce..107daf07ea 100644 --- a/app/startup_config.ts +++ b/app/startup_config.ts @@ -4,6 +4,7 @@ import { app } from 'electron'; import packageJson from '../package.json'; +import * as log from '../ts/logging/log'; import * as GlobalErrors from './global_errors'; GlobalErrors.addHandler(); @@ -13,7 +14,7 @@ GlobalErrors.addHandler(); process.umask(0o077); export const AUMID = `org.whispersystems.${packageJson.name}`; -console.log('Set Windows Application User Model ID (AUMID)', { +log.info('Set Windows Application User Model ID (AUMID)', { AUMID, }); app.setAppUserModelId(AUMID); diff --git a/app/updateDefaultSession.ts b/app/updateDefaultSession.ts index 0ea87670ea..42f9a8caa9 100644 --- a/app/updateDefaultSession.ts +++ b/app/updateDefaultSession.ts @@ -14,7 +14,7 @@ const SPELL_CHECKER_DICTIONARY_DOWNLOAD_URL = `https://updates.signal.org/deskto export function updateDefaultSession( session: Session, - getLogger: () => LoggerType + logger: LoggerType ): void { session.setSpellCheckerDictionaryDownloadURL( SPELL_CHECKER_DICTIONARY_DOWNLOAD_URL @@ -74,7 +74,7 @@ export function updateDefaultSession( // Electron throws error here, but this is the only way to cancel the // request. } - getLogger().error('Failed to get desktopCapturer sources', error); + logger.error('Failed to get desktopCapturer sources', error); } }, { useSystemPicker: false } diff --git a/app/user_config.ts b/app/user_config.ts index 12da26a314..fe1ed95fe6 100644 --- a/app/user_config.ts +++ b/app/user_config.ts @@ -7,6 +7,7 @@ import { app } from 'electron'; import { start } from './base_config'; import config from './config'; +import * as log from '../ts/logging/log'; import * as Errors from '../ts/types/errors'; let userData: string | undefined; @@ -24,13 +25,13 @@ if (userData !== undefined) { try { mkdirSync(userData, { recursive: true }); } catch (error) { - console.error('Failed to create userData', Errors.toLogFormat(error)); + log.error('Failed to create userData', Errors.toLogFormat(error)); } app.setPath('userData', userData); } -console.log(`userData: ${app.getPath('userData')}`); +log.info(`userData: ${app.getPath('userData')}`); const userDataPath = app.getPath('userData'); const targetPath = join(userDataPath, 'config.json'); diff --git a/scripts/esbuild.js b/scripts/esbuild.js index 42f712dedf..20b2e65979 100644 --- a/scripts/esbuild.js +++ b/scripts/esbuild.js @@ -145,7 +145,7 @@ async function sandboxedEnv() { }, preloadConfig: { ...sandboxedPreloadDefaults, - mainFields: ['main'], + mainFields: ['browser', 'main'], entryPoints: [ path.join(ROOT_DIR, 'ts', 'windows', 'about', 'preload.ts'), path.join(ROOT_DIR, 'ts', 'windows', 'debuglog', 'preload.ts'), diff --git a/test/setup-test-node.js b/test/setup-test-node.js index c855a5eee0..be8d7d9d61 100644 --- a/test/setup-test-node.js +++ b/test/setup-test-node.js @@ -1,8 +1,6 @@ // Copyright 2021 Signal Messenger, LLC // SPDX-License-Identifier: AGPL-3.0-only -/* eslint-disable no-console */ - const chai = require('chai'); const chaiAsPromised = require('chai-as-promised'); @@ -22,11 +20,6 @@ global.window = { performance, SignalContext: { crypto: new Crypto(), - log: { - info: (...args) => console.log(...args), - warn: (...args) => console.warn(...args), - error: (...args) => console.error(...args), - }, getResolvedMessagesLocale: () => 'en', getResolvedMessagesLocaleDirection: () => 'ltr', getHourCyclePreference: () => HourCyclePreference.UnknownPreference, diff --git a/ts/backbone/reliable_trigger.ts b/ts/backbone/reliable_trigger.ts index 37a835e802..8473c8e9f1 100644 --- a/ts/backbone/reliable_trigger.ts +++ b/ts/backbone/reliable_trigger.ts @@ -2,6 +2,7 @@ // SPDX-License-Identifier: AGPL-3.0-only import type * as Backbone from 'backbone'; +import * as log from '../logging/log'; type InternalBackboneEvent = { callback: (...args: Array) => unknown; @@ -74,7 +75,7 @@ const triggerEvents = function ( a2 = args[1], a3 = args[2]; const logError = function (error: unknown) { - window.SignalContext.log.error( + log.error( 'Model caught error triggering', name, 'event:', diff --git a/ts/components/GroupCallRemoteParticipants.tsx b/ts/components/GroupCallRemoteParticipants.tsx index 9c8f20495f..48d1297e68 100644 --- a/ts/components/GroupCallRemoteParticipants.tsx +++ b/ts/components/GroupCallRemoteParticipants.tsx @@ -16,6 +16,7 @@ import type { import { CallViewMode } from '../types/Calling'; import { useGetCallingFrameBuffer } from '../calling/useGetCallingFrameBuffer'; import type { LocalizerType } from '../types/Util'; +import { toLogFormat } from '../types/errors'; import { usePageVisibility } from '../hooks/usePageVisibility'; import { useDevicePixelRatio } from '../hooks/useDevicePixelRatio'; import { nonRenderedRemoteParticipant } from '../util/ringrtc/nonRenderedRemoteParticipant'; @@ -449,7 +450,7 @@ export function GroupCallRemoteParticipants({ videoRequest = remoteParticipants.map(nonRenderedRemoteParticipant); break; default: - log.error(missingCaseError(videoRequestMode)); + log.error(toLogFormat(missingCaseError(videoRequestMode))); videoRequest = remoteParticipants.map(nonRenderedRemoteParticipant); break; } diff --git a/ts/components/PureComponentProfiler.tsx b/ts/components/PureComponentProfiler.tsx deleted file mode 100644 index 7d6eee0f4e..0000000000 --- a/ts/components/PureComponentProfiler.tsx +++ /dev/null @@ -1,55 +0,0 @@ -// Copyright 2022 Signal Messenger, LLC -// SPDX-License-Identifier: AGPL-3.0-only -/* eslint-disable no-console */ - -import React from 'react'; - -export abstract class PureComponentProfiler< - Props extends Record, - State extends Record, -> extends React.Component { - public override shouldComponentUpdate( - nextProps: Props, - nextState: State - ): boolean { - console.group(`PureComponentProfiler(${this.props.id})`); - - const propKeys = new Set([ - ...Object.keys(nextProps), - ...Object.keys(this.props), - ]); - - const stateKeys = new Set([ - ...Object.keys(nextState ?? {}), - ...Object.keys(this.state ?? {}), - ]); - - let result = false; - for (const key of propKeys) { - if (nextProps[key] !== this.props[key]) { - console.error( - `propUpdated(${key})`, - this.props[key], - '=>', - nextProps[key] - ); - result = true; - } - } - for (const key of stateKeys) { - if (nextState[key] !== this.state[key]) { - console.error( - `stateUpdated(${key}):`, - this.state[key], - '=>', - nextState[key] - ); - result = true; - } - } - - console.groupEnd(); - - return result; - } -} diff --git a/ts/components/conversation/CallingNotification.tsx b/ts/components/conversation/CallingNotification.tsx index c8cf7155f6..daacd68f24 100644 --- a/ts/components/conversation/CallingNotification.tsx +++ b/ts/components/conversation/CallingNotification.tsx @@ -17,6 +17,7 @@ import { DirectCallStatus, GroupCallStatus, } from '../../types/CallDisposition'; +import { toLogFormat } from '../../types/errors'; import type { CallingNotificationType } from '../../util/callingNotification'; import { getCallingIcon, @@ -241,7 +242,7 @@ function renderCallingNotificationButton( log.warn('CallingNotification for adhoc call, should never happen'); return null; default: - log.error(missingCaseError(props.callHistory.mode)); + log.error(toLogFormat(missingCaseError(props.callHistory.mode))); return null; } diff --git a/ts/components/conversation/Message.tsx b/ts/components/conversation/Message.tsx index 9973bb3f73..4b11bd0a96 100644 --- a/ts/components/conversation/Message.tsx +++ b/ts/components/conversation/Message.tsx @@ -47,6 +47,7 @@ import type { import { ReactionViewer } from './ReactionViewer'; import { LinkPreviewDate } from './LinkPreviewDate'; import type { LinkPreviewForUIType } from '../../types/message/LinkPreviews'; +import { toLogFormat } from '../../types/errors'; import { shouldUseFullSizeLinkPreviewImage } from '../../linkPreviews/shouldUseFullSizeLinkPreviewImage'; import type { WidthBreakpoint } from '../_util'; import { OutgoingGiftBadgeModal } from '../OutgoingGiftBadgeModal'; @@ -1107,7 +1108,7 @@ export class Message extends React.PureComponent { isInline = false; break; default: - log.error(missingCaseError(metadataPlacement)); + log.error(toLogFormat(missingCaseError(metadataPlacement))); isInline = false; break; } diff --git a/ts/components/conversation/media-gallery/groupMediaItemsByDate.ts b/ts/components/conversation/media-gallery/groupMediaItemsByDate.ts index ad4a811e40..861ee09ef0 100644 --- a/ts/components/conversation/media-gallery/groupMediaItemsByDate.ts +++ b/ts/components/conversation/media-gallery/groupMediaItemsByDate.ts @@ -8,6 +8,7 @@ import * as log from '../../../logging/log'; import type { MediaItemType } from '../../../types/MediaItem'; import { missingCaseError } from '../../../util/missingCaseError'; +import { toLogFormat } from '../../../types/errors'; type StaticSectionType = 'today' | 'yesterday' | 'thisWeek' | 'thisMonth'; type YearMonthSectionType = 'yearMonth'; @@ -83,7 +84,7 @@ const toSection = ( mediaItems, }; default: - log.error(missingCaseError(firstMediaItemWithSection)); + log.error(toLogFormat(missingCaseError(firstMediaItemWithSection))); return undefined; } }; diff --git a/ts/indexeddb.ts b/ts/indexeddb.ts index 6d0852c0da..86187c4c0e 100644 --- a/ts/indexeddb.ts +++ b/ts/indexeddb.ts @@ -1,19 +1,19 @@ // Copyright 2018 Signal Messenger, LLC // SPDX-License-Identifier: AGPL-3.0-only +import * as log from './logging/log'; + const LEGACY_DATABASE_ID = 'signal'; export async function doesDatabaseExist(): Promise { - window.SignalContext.log.info( - 'Checking for the existence of IndexedDB data...' - ); + log.info('Checking for the existence of IndexedDB data...'); return new Promise((resolve, reject) => { const req = window.indexedDB.open(LEGACY_DATABASE_ID); let existed = true; let timer: undefined | ReturnType = setTimeout(() => { - window.SignalContext.log.warn( + log.warn( 'doesDatabaseExist: Timed out attempting to check IndexedDB status' ); return resolve(false); @@ -46,20 +46,16 @@ export async function doesDatabaseExist(): Promise { export function removeDatabase(): Promise { return new Promise((resolve, reject) => { - window.SignalContext.log.info( + log.info( `removeDatabase: Deleting IndexedDB database '${LEGACY_DATABASE_ID}'` ); const request = window.indexedDB.deleteDatabase(LEGACY_DATABASE_ID); request.onerror = () => { - window.SignalContext.log.error( - 'removeDatabase: Error deleting database.' - ); + log.error('removeDatabase: Error deleting database.'); reject(new Error('Error deleting database')); }; request.onsuccess = () => { - window.SignalContext.log.info( - 'removeDatabase: Database deleted successfully' - ); + log.info('removeDatabase: Database deleted successfully'); resolve(); }; }); diff --git a/ts/jobs/JobLogger.ts b/ts/jobs/JobLogger.ts index 260caa00c7..87a71d58be 100644 --- a/ts/jobs/JobLogger.ts +++ b/ts/jobs/JobLogger.ts @@ -42,6 +42,10 @@ export class JobLogger implements LoggerType { this.logger.trace(this.#prefix(), ...args); } + child(): LoggerType { + throw new Error('Not supported'); + } + #prefix(): string { return `${this.#queueType} job queue, job ID ${this.#id}, attempt ${this.attempt}:`; } diff --git a/ts/logging/log.ts b/ts/logging/log.ts index 69feba5f43..f79d750bb8 100644 --- a/ts/logging/log.ts +++ b/ts/logging/log.ts @@ -1,39 +1,112 @@ // Copyright 2021 Signal Messenger, LLC // SPDX-License-Identifier: AGPL-3.0-only -import noop from 'lodash/noop'; -import type { LogFunction } from '../types/Logging'; -import { LogLevel } from '../types/Logging'; +import pino from 'pino'; -type LogAtLevelFnType = ( - level: LogLevel, - ...args: ReadonlyArray -) => void; +import type { LoggerType, LoggingFn } from '../types/Logging'; +import { Environment, getEnvironment } from '../environment'; +import { reallyJsonStringify } from '../util/reallyJsonStringify'; +import { getLogLevelString } from './shared'; -let logAtLevel: LogAtLevelFnType = noop; -let hasInitialized = false; +// This file is imported by some components so we can't import `ts/util/privacy` +let redactAll = (value: string) => value; -export const fatal: LogFunction = (...args) => - logAtLevel(LogLevel.Fatal, ...args); -export const error: LogFunction = (...args) => - logAtLevel(LogLevel.Error, ...args); -export const warn: LogFunction = (...args) => - logAtLevel(LogLevel.Warn, ...args); -export const info: LogFunction = (...args) => - logAtLevel(LogLevel.Info, ...args); -export const debug: LogFunction = (...args) => - logAtLevel(LogLevel.Debug, ...args); -export const trace: LogFunction = (...args) => - logAtLevel(LogLevel.Trace, ...args); +let destination: pino.DestinationStream | undefined; +let buffer = new Array(); + +const pinoInstance = pino( + { + formatters: { + // No point in saving pid or hostname + bindings: () => ({}), + }, + hooks: { + logMethod(args, method, level) { + if (getEnvironment() !== Environment.PackagedApp) { + const consoleMethod = getLogLevelString(level); + + const { msgPrefixSym } = pino.symbols as unknown as { + readonly msgPrefixSym: unique symbol; + }; + const msgPrefix = ( + this as unknown as Record + )[msgPrefixSym]; + + const [message, ...extra] = args; + + // `fatal` has no respective analog in `console` + // eslint-disable-next-line no-console + console[consoleMethod === 'fatal' ? 'error' : consoleMethod]( + `${msgPrefix ?? ''}${message}`, + ...extra + ); + } + + // Always call original method, but with stringified arguments for + // compatibility with existing logging. + // + // (Since pino >= 6 extra arguments that don't correspond to %d/%s/%j + // templates in the `message` are ignored) + const line = args + .map(item => + typeof item === 'string' ? item : reallyJsonStringify(item) + ) + .join(' '); + return method.call(this, line); + }, + }, + timestamp: pino.stdTimeFunctions.isoTime, + redact: { + paths: ['*'], + censor: item => redactAll(item), + }, + }, + { + write(msg) { + if (destination == null) { + buffer.push(msg); + } else { + destination.write(msg); + } + }, + } +); + +export const fatal: LoggingFn = pinoInstance.fatal.bind(pinoInstance); +export const error: LoggingFn = pinoInstance.error.bind(pinoInstance); +export const warn: LoggingFn = pinoInstance.error.bind(pinoInstance); +export const info: LoggingFn = pinoInstance.info.bind(pinoInstance); +export const debug: LoggingFn = pinoInstance.debug.bind(pinoInstance); +export const trace: LoggingFn = pinoInstance.trace.bind(pinoInstance); +export const child = createChild.bind(pinoInstance); + +function createChild(name: string): LoggerType { + const instance = pinoInstance.child({}, { msgPrefix: `[${name}] ` }); + + return { + fatal: instance.fatal.bind(instance), + error: instance.error.bind(instance), + warn: instance.warn.bind(instance), + info: instance.info.bind(instance), + debug: instance.debug.bind(instance), + trace: instance.trace.bind(instance), + child: createChild.bind(instance), + }; +} /** - * Sets the low-level logging interface. Should be called early in a process's life, and - * can only be called once. + * Sets the low-level logging interface. Should be called early in a process's + * life. */ -export function setLogAtLevel(log: LogAtLevelFnType): void { - if (hasInitialized) { - throw new Error('Logger has already been initialized'); +export function setPinoDestination( + newDestination: pino.DestinationStream, + newRedactAll: typeof redactAll +): void { + destination = newDestination; + redactAll = newRedactAll; + const queued = buffer; + buffer = []; + for (const msg of queued) { + destination.write(msg); } - logAtLevel = log; - hasInitialized = true; } diff --git a/ts/logging/main_process_logging.ts b/ts/logging/main_process_logging.ts index 9411f3a58f..a2d444b39f 100644 --- a/ts/logging/main_process_logging.ts +++ b/ts/logging/main_process_logging.ts @@ -9,7 +9,7 @@ import { CircularBuffer } from 'cirbuf'; import type { BrowserWindow } from 'electron'; import { app, ipcMain as ipc } from 'electron'; import readFirstLine from 'firstline'; -import { filter, flatten, map, noop, pick, sortBy } from 'lodash'; +import { filter, flatten, map, pick, sortBy } from 'lodash'; import { createReadStream, mkdirSync, @@ -19,45 +19,31 @@ import { } from 'node:fs'; import { rm } from 'node:fs/promises'; import { join } from 'path'; -import type { StreamEntry } from 'pino'; -import pino from 'pino'; import { read as readLastLines } from 'read-last-lines'; import split2 from 'split2'; import type { LoggerType } from '../types/Logging'; import * as Errors from '../types/errors'; import { createRotatingPinoDest } from '../util/rotatingPinoDest'; +import { redactAll } from '../util/privacy'; -import { Environment, getEnvironment } from '../environment'; import * as log from './log'; import type { FetchLogIpcData, LogEntryType } from './shared'; -import { LogLevel, cleanArgs, getLogLevelString, isLogEntry } from './shared'; - -declare global { - // We want to extend `Console`, so we need an interface. - // eslint-disable-next-line no-restricted-syntax - interface Console { - _log: typeof console.log; - _warn: typeof console.warn; - _error: typeof console.error; - } -} +import { LogLevel, isLogEntry } from './shared'; const MAX_LOG_LINES = 10_000_000; -let globalLogger: undefined | pino.Logger; +let isInitialized = false; let shouldRestart = false; -const isRunningFromConsole = - Boolean(process.stdout.isTTY) || getEnvironment() === Environment.Test; - export async function initialize( getMainWindow: () => undefined | BrowserWindow ): Promise { - if (globalLogger) { + if (isInitialized) { throw new Error('Already called initialize!'); } + isInitialized = true; const basePath = app.getPath('userData'); const logPath = join(basePath, 'logs'); @@ -86,7 +72,7 @@ export async function initialize( }); const onClose = () => { - globalLogger = undefined; + isInitialized = false; if (shouldRestart) { void initialize(getMainWindow); @@ -96,34 +82,13 @@ export async function initialize( rotatingStream.on('close', onClose); rotatingStream.on('error', onClose); - const streams = new Array(); - streams.push({ stream: rotatingStream }); - - if (isRunningFromConsole) { - process.stdout.on('error', noop); - - streams.push({ - level: 'debug' as const, - stream: process.stdout, - }); - } - - const logger = pino( - { - formatters: { - // No point in saving pid or hostname - bindings: () => ({}), - }, - timestamp: pino.stdTimeFunctions.isoTime, - }, - pino.multistream(streams) - ); + log.setPinoDestination(rotatingStream, redactAll); ipc.removeHandler('fetch-log'); ipc.handle('fetch-log', async () => { const mainWindow = getMainWindow(); if (!mainWindow) { - logger.info('Logs were requested, but the main window is missing'); + log.info('Logs were requested, but the main window is missing'); return; } @@ -138,7 +103,7 @@ export async function initialize( ...rest, }; } catch (error) { - logger.error(`Problem loading log data: ${Errors.toLogFormat(error)}`); + log.error(`Problem loading log data: ${Errors.toLogFormat(error)}`); return; } @@ -153,12 +118,10 @@ export async function initialize( try { await deleteAllLogs(logPath); } catch (error) { - logger.error(`Problem deleting all logs: ${Errors.toLogFormat(error)}`); + log.error(`Problem deleting all logs: ${Errors.toLogFormat(error)}`); } }); - globalLogger = logger; - return log; } @@ -326,24 +289,3 @@ export const fetchAdditionalLogData = ( resolve(data); }); }); - -function logAtLevel(level: LogLevel, ...args: ReadonlyArray) { - if (globalLogger) { - const levelString = getLogLevelString(level); - globalLogger[levelString](cleanArgs(args)); - } else if (isRunningFromConsole && !process.stdout.destroyed) { - console._log(...args); - } -} - -// This blows up using mocha --watch, so we ensure it is run just once -if (!console._log) { - log.setLogAtLevel(logAtLevel); - - console._log = console.log; - console.log = log.info; - console._error = console.error; - console.error = log.error; - console._warn = console.warn; - console.warn = log.warn; -} diff --git a/ts/logging/set_up_renderer_logging.ts b/ts/logging/set_up_renderer_logging.ts index 3cfe399d2a..24784c1e9f 100644 --- a/ts/logging/set_up_renderer_logging.ts +++ b/ts/logging/set_up_renderer_logging.ts @@ -3,44 +3,20 @@ /* eslint-env node */ -/* eslint-disable no-console */ - import { ipcRenderer as ipc } from 'electron'; import * as path from 'path'; -import pino from 'pino'; import { initLogger, LogLevel as SignalClientLogLevel, } from '@signalapp/libsignal-client'; -import { - LogLevel, - cleanArgs, - getLogLevelString, - levelMaxLength, -} from './shared'; import * as log from './log'; -import { Environment, getEnvironment } from '../environment'; import * as Errors from '../types/errors'; import { createRotatingPinoDest } from '../util/rotatingPinoDest'; +import { redactAll } from '../util/privacy'; -// Backwards-compatible logging, simple strings and no level (defaulted to INFO) -function now() { - const date = new Date(); - return date.toJSON(); -} - -function consoleLog(...args: ReadonlyArray) { - logAtLevel(LogLevel.Info, ...args); -} - -if (window.console) { - console._log = console.log; - console.log = consoleLog; -} - -let globalLogger: undefined | pino.Logger; +let isInitialized = false; let shouldRestart = false; export function beforeRestart(): void { @@ -48,16 +24,15 @@ export function beforeRestart(): void { } export function initialize(): void { - if (globalLogger) { - throw new Error('Already called initialize!'); + if (isInitialized) { + throw new Error('Already initialized'); } + isInitialized = true; const basePath = ipc.sendSync('get-user-data-path'); const logFile = path.join(basePath, 'logs', 'app.log'); const onClose = () => { - globalLogger = undefined; - if (shouldRestart) { initialize(); } @@ -70,50 +45,9 @@ export function initialize(): void { stream.on('close', onClose); stream.on('error', onClose); - globalLogger = pino( - { - formatters: { - // No point in saving pid or hostname - bindings: () => ({}), - }, - timestamp: pino.stdTimeFunctions.isoTime, - }, - stream - ); + log.setPinoDestination(stream, redactAll); } -// A modern logging interface for the browser - -function logAtLevel(level: LogLevel, ...args: ReadonlyArray): void { - if (getEnvironment() !== Environment.PackagedApp) { - const prefix = getLogLevelString(level) - .toUpperCase() - .padEnd(levelMaxLength, ' '); - console._log(prefix, now(), ...args); - } - - const levelString = getLogLevelString(level); - const msg = cleanArgs(args); - - if (!globalLogger) { - throw new Error('Logger has not been initialized yet'); - } - - globalLogger[levelString](msg); -} - -log.setLogAtLevel(logAtLevel); - -window.SignalContext = window.SignalContext || {}; -window.SignalContext.log = { - fatal: log.fatal, - error: log.error, - warn: log.warn, - info: log.info, - debug: log.debug, - trace: log.trace, -}; - function toLocation(source?: string, line?: number, column?: number) { if (source == null) { return '(@ unknown)'; diff --git a/ts/logging/shared.ts b/ts/logging/shared.ts index 00f4b7c263..07fb8227cc 100644 --- a/ts/logging/shared.ts +++ b/ts/logging/shared.ts @@ -3,9 +3,7 @@ import pino from 'pino'; import { isRecord } from '../util/isRecord'; -import { redactAll } from '../util/privacy'; import { missingCaseError } from '../util/missingCaseError'; -import { reallyJsonStringify } from '../util/reallyJsonStringify'; import { LogLevel } from '../types/Logging'; export { LogLevel }; @@ -89,16 +87,6 @@ export function getLogLevelString(value: LogLevel): pino.Level { } } -export function cleanArgs(args: ReadonlyArray): string { - return redactAll( - args - .map(item => - typeof item === 'string' ? item : reallyJsonStringify(item) - ) - .join(' ') - ); -} - // To make it easier to visually scan logs, we make all levels the same length const levelFromName = pino().levels.values; export const levelMaxLength: number = Object.keys(levelFromName).reduce( diff --git a/ts/mediaEditor/util/getTextStyleAttributes.ts b/ts/mediaEditor/util/getTextStyleAttributes.ts index 9083e3eb28..67a278d532 100644 --- a/ts/mediaEditor/util/getTextStyleAttributes.ts +++ b/ts/mediaEditor/util/getTextStyleAttributes.ts @@ -4,6 +4,7 @@ import * as log from '../../logging/log'; import { getHSL } from './color'; import { missingCaseError } from '../../util/missingCaseError'; +import { toLogFormat } from '../../types/errors'; export enum TextStyle { Regular = 'Regular', @@ -38,7 +39,7 @@ export function getTextStyleAttributes( textBackgroundColor: '', }; default: - log.error(missingCaseError(textStyle)); + log.error(toLogFormat(missingCaseError(textStyle))); return getTextStyleAttributes(TextStyle.Regular, hueSliderValue); } } diff --git a/ts/messages/migrateMessageData.ts b/ts/messages/migrateMessageData.ts index 59ff9d38f3..dbebab3419 100644 --- a/ts/messages/migrateMessageData.ts +++ b/ts/messages/migrateMessageData.ts @@ -13,6 +13,7 @@ import type { AciString } from '../types/ServiceId'; import * as Errors from '../types/errors'; import { DataReader, DataWriter } from '../sql/Client'; import { postSaveUpdates } from '../util/cleanup'; +import * as log from '../logging/log'; const MAX_CONCURRENCY = 5; @@ -83,7 +84,7 @@ export async function _migrateMessageData({ { maxVersion } ); } catch (error) { - window.SignalContext.log.error( + log.error( 'migrateMessageData.getMessagesNeedingUpgrade error:', Errors.toLogFormat(error) ); @@ -103,7 +104,7 @@ export async function _migrateMessageData({ try { return await upgradeMessageSchema(message, { maxVersion }); } catch (error) { - window.SignalContext.log.error( + log.error( 'migrateMessageData.upgradeMessageSchema error:', Errors.toLogFormat(error) ); @@ -176,8 +177,6 @@ export async function migrateBatchOfMessages({ } export async function migrateAllMessages(): Promise { - const { log } = window.SignalContext; - let batch: BatchResultType | undefined; let total = 0; while (!batch?.done) { diff --git a/ts/services/backups/import.ts b/ts/services/backups/import.ts index ab4a99785e..a4e7d5166a 100644 --- a/ts/services/backups/import.ts +++ b/ts/services/backups/import.ts @@ -987,8 +987,8 @@ export class BackupImportStream extends Writable { attrs.firstUnregisteredAt = timestamp || undefined; } else if (!contact.registered) { log.error( - contact.registered, - 'contact is neither registered nor unregistered; treating as registered' + 'contact is neither registered nor unregistered; treating as registered', + contact.registered ); this.#frameErrorCount += 1; } diff --git a/ts/services/calling.ts b/ts/services/calling.ts index 32ccc68856..fb872aff24 100644 --- a/ts/services/calling.ts +++ b/ts/services/calling.ts @@ -3932,7 +3932,7 @@ export class CallingClass { break; } default: { - log.error(missingCaseError(notificationSetting)); + log.error(Errors.toLogFormat(missingCaseError(notificationSetting))); notificationTitle = FALLBACK_NOTIFICATION_TITLE; break; } diff --git a/ts/services/expiringMessagesDeletion.ts b/ts/services/expiringMessagesDeletion.ts index ba5882b8cc..1693679fd5 100644 --- a/ts/services/expiringMessagesDeletion.ts +++ b/ts/services/expiringMessagesDeletion.ts @@ -24,11 +24,9 @@ class ExpiringMessagesDeletionService { async #destroyExpiredMessages() { try { - window.SignalContext.log.info( - 'destroyExpiredMessages: Loading messages...' - ); + log.info('destroyExpiredMessages: Loading messages...'); const messages = await DataReader.getExpiredMessages(); - window.SignalContext.log.info( + log.info( `destroyExpiredMessages: found ${messages.length} messages to expire` ); @@ -49,7 +47,7 @@ class ExpiringMessagesDeletionService { batch(() => { inMemoryMessages.forEach(message => { - window.SignalContext.log.info('Message expired', { + log.info('Message expired', { sentAt: message.get('sent_at'), }); @@ -58,32 +56,26 @@ class ExpiringMessagesDeletionService { }); }); } catch (error) { - window.SignalContext.log.error( + log.error( 'destroyExpiredMessages: Error deleting expired messages', Errors.toLogFormat(error) ); - window.SignalContext.log.info( + log.info( 'destroyExpiredMessages: Waiting 30 seconds before trying again' ); await sleep(30 * SECOND); } - window.SignalContext.log.info( - 'destroyExpiredMessages: done, scheduling another check' - ); + log.info('destroyExpiredMessages: done, scheduling another check'); void this.update(); } async #checkExpiringMessages() { - window.SignalContext.log.info( - 'checkExpiringMessages: checking for expiring messages' - ); + log.info('checkExpiringMessages: checking for expiring messages'); const soonestExpiry = await DataReader.getSoonestMessageExpiry(); if (!soonestExpiry) { - window.SignalContext.log.info( - 'checkExpiringMessages: found no messages to expire' - ); + log.info('checkExpiringMessages: found no messages to expire'); return; } @@ -99,7 +91,7 @@ class ExpiringMessagesDeletionService { wait = 2147483647; } - window.SignalContext.log.info( + log.info( `checkExpiringMessages: next message expires ${new Date( soonestExpiry ).toISOString()}; waiting ${wait} ms before clearing` diff --git a/ts/services/notifications.ts b/ts/services/notifications.ts index 436f727597..16efa5bbe4 100644 --- a/ts/services/notifications.ts +++ b/ts/services/notifications.ts @@ -12,6 +12,7 @@ import OS from '../util/os/osMain'; import * as log from '../logging/log'; import { makeEnumParser } from '../util/enum'; import { missingCaseError } from '../util/missingCaseError'; +import { toLogFormat } from '../types/errors'; import type { StorageInterface } from '../types/Storage.d'; import type { LocalizerType } from '../types/Util'; import { drop } from '../util/drop'; @@ -411,7 +412,7 @@ class NotificationService extends EventEmitter { notificationMessage = i18n('icu:newMessage'); break; default: - log.error(missingCaseError(userSetting)); + log.error(toLogFormat(missingCaseError(userSetting))); notificationTitle = FALLBACK_NOTIFICATION_TITLE; notificationMessage = i18n('icu:newMessage'); break; diff --git a/ts/services/tapToViewMessagesDeletionService.ts b/ts/services/tapToViewMessagesDeletionService.ts index bbec211cf4..9c5a6e415e 100644 --- a/ts/services/tapToViewMessagesDeletionService.ts +++ b/ts/services/tapToViewMessagesDeletionService.ts @@ -12,12 +12,11 @@ import { getMessageIdForLogging } from '../util/idForLogging'; import { eraseMessageContents } from '../util/cleanup'; import { drop } from '../util/drop'; import { MessageModel } from '../models/messages'; +import * as log from '../logging/log'; async function eraseTapToViewMessages() { try { - window.SignalContext.log.info( - 'eraseTapToViewMessages: Loading messages...' - ); + log.info('eraseTapToViewMessages: Loading messages...'); const maxTimestamp = Date.now() - getMessageQueueTime(); const messages = await DataReader.getTapToViewMessagesNeedingErase(maxTimestamp); @@ -32,7 +31,7 @@ async function eraseTapToViewMessages() { const message = window.MessageCache.register(new MessageModel(fromDB)); - window.SignalContext.log.info( + log.info( 'eraseTapToViewMessages: erasing message contents', getMessageIdForLogging(message.attributes) ); @@ -44,13 +43,13 @@ async function eraseTapToViewMessages() { }) ); } catch (error) { - window.SignalContext.log.error( + log.error( 'eraseTapToViewMessages: Error erasing messages', Errors.toLogFormat(error) ); } - window.SignalContext.log.info('eraseTapToViewMessages: complete'); + log.info('eraseTapToViewMessages: complete'); } class TapToViewMessagesDeletionService { @@ -64,11 +63,11 @@ class TapToViewMessagesDeletionService { pause(): void { if (this.#isPaused) { - window.SignalContext.log.warn('checkTapToViewMessages: already paused'); + log.warn('checkTapToViewMessages: already paused'); return; } - window.SignalContext.log.info('checkTapToViewMessages: pause'); + log.info('checkTapToViewMessages: pause'); this.#isPaused = true; clearTimeoutIfNecessary(this.#timeout); @@ -77,11 +76,11 @@ class TapToViewMessagesDeletionService { resume(): void { if (!this.#isPaused) { - window.SignalContext.log.warn('checkTapToViewMessages: not paused'); + log.warn('checkTapToViewMessages: not paused'); return; } - window.SignalContext.log.info('checkTapToViewMessages: resuming'); + log.info('checkTapToViewMessages: resuming'); this.#isPaused = false; this.#debouncedUpdate.cancel(); @@ -90,7 +89,7 @@ class TapToViewMessagesDeletionService { async #checkTapToViewMessages() { if (!this.#shouldRun()) { - window.SignalContext.log.info('checkTapToViewMessages: not running'); + log.info('checkTapToViewMessages: not running'); return; } @@ -102,7 +101,7 @@ class TapToViewMessagesDeletionService { const nextCheck = receivedAtMsForOldestTapToViewMessage + getMessageQueueTime(); - window.SignalContext.log.info( + log.info( 'checkTapToViewMessages: next check at', toBoundedDate(nextCheck).toISOString() ); @@ -122,7 +121,7 @@ class TapToViewMessagesDeletionService { clearTimeoutIfNecessary(this.#timeout); this.#timeout = setTimeout(async () => { if (!this.#shouldRun()) { - window.SignalContext.log.info('checkTapToViewMessages: not running'); + log.info('checkTapToViewMessages: not running'); return; } diff --git a/ts/sql/sqlLogger.ts b/ts/sql/sqlLogger.ts index 9021fead7a..73b56593ac 100644 --- a/ts/sql/sqlLogger.ts +++ b/ts/sql/sqlLogger.ts @@ -1,6 +1,8 @@ // Copyright 2025 Signal Messenger, LLC // SPDX-License-Identifier: AGPL-3.0-only -import { parentPort } from 'worker_threads'; +import { parentPort } from 'node:worker_threads'; +import { format } from 'node:util'; + import type { LoggerType } from '../types/Logging'; import type { WrappedWorkerLogEntry, WrappedWorkerResponse } from './main'; import { consoleLogger } from '../util/consoleLogger'; @@ -19,7 +21,7 @@ const log = ( parentPort.postMessage(wrappedResponse); } else { strictAssert(process.env.NODE_ENV === 'test', 'must be test environment'); - consoleLogger[level](...args); + consoleLogger[level](format(...args)); } }; @@ -42,4 +44,7 @@ export const sqlLogger: LoggerType = { trace(...args: Array) { log('trace', args); }, + child() { + return sqlLogger; + }, }; diff --git a/ts/state/createStore.ts b/ts/state/createStore.ts index c49ce76121..0bb0b04e2c 100644 --- a/ts/state/createStore.ts +++ b/ts/state/createStore.ts @@ -1,8 +1,6 @@ // Copyright 2019 Signal Messenger, LLC // SPDX-License-Identifier: AGPL-3.0-only -/* eslint-disable no-console */ - import type { Middleware, Store, UnknownAction } from 'redux'; import { applyMiddleware, createStore as reduxCreateStore } from 'redux'; @@ -18,28 +16,9 @@ import { isOlderThan } from '../util/timestamp'; import { SECOND } from '../util/durations'; import { getEnvironment } from '../environment'; -declare global { - // We want to extend `window`'s properties, so we need an interface. - // eslint-disable-next-line no-restricted-syntax - interface Console { - _log: Console['log']; - } -} - const env = getEnvironment(); -// So Redux logging doesn't go to disk, and so we can get colors/styles -const directConsole = { - log: console._log, - groupCollapsed: console.groupCollapsed, - group: console.group, - groupEnd: console.groupEnd, - warn: console.warn, - error: console.error, -}; - const logger = createLogger({ - logger: directConsole, predicate: (_getState, action) => { if (action.type === 'network/CHECK_NETWORK_STATUS') { return false; diff --git a/ts/state/smart/ConversationPanel.tsx b/ts/state/smart/ConversationPanel.tsx index 55f6ea8ae9..02448e9cf1 100644 --- a/ts/state/smart/ConversationPanel.tsx +++ b/ts/state/smart/ConversationPanel.tsx @@ -14,6 +14,7 @@ import { useSelector } from 'react-redux'; import type { PanelRenderType } from '../../types/Panels'; import * as log from '../../logging/log'; import { PanelType } from '../../types/Panels'; +import { toLogFormat } from '../../types/errors'; import { SmartAllMedia } from './AllMedia'; import { SmartChatColorPicker } from './ChatColorPicker'; import { SmartContactDetail } from './ContactDetail'; @@ -368,6 +369,6 @@ function PanelElement({ return ; } - log.warn(missingCaseError(panel)); + log.warn(toLogFormat(missingCaseError(panel))); return null; } diff --git a/ts/test-electron/backup/filePointer_test.ts b/ts/test-electron/backup/filePointer_test.ts index 9b666534d0..84b95925bc 100644 --- a/ts/test-electron/backup/filePointer_test.ts +++ b/ts/test-electron/backup/filePointer_test.ts @@ -20,7 +20,7 @@ import { strictAssert } from '../../util/assert'; import type { GetBackupCdnInfoType } from '../../services/backups/util/mediaId'; import { MASTER_KEY, MEDIA_ROOT_KEY } from './helpers'; import { generateKeys, safeUnlink } from '../../AttachmentCrypto'; -import { writeNewAttachmentData } from '../../windows/attachments'; +import { writeNewAttachmentData } from '../../windows/main/attachments'; describe('convertFilePointerToAttachment', () => { it('processes filepointer with attachmentLocator', () => { diff --git a/ts/test-electron/cleanupOrphanedAttachments_test.ts b/ts/test-electron/cleanupOrphanedAttachments_test.ts index a961290cd5..5775049310 100644 --- a/ts/test-electron/cleanupOrphanedAttachments_test.ts +++ b/ts/test-electron/cleanupOrphanedAttachments_test.ts @@ -13,7 +13,7 @@ import { getDownloadsPath, getDraftPath, getPath, -} from '../windows/attachments'; +} from '../windows/main/attachments'; import { generateAci } from '../types/ServiceId'; import { IMAGE_JPEG, LONG_MESSAGE } from '../types/MIME'; diff --git a/ts/test-electron/util/ensureAttachmentIsReencryptable_test.ts b/ts/test-electron/util/ensureAttachmentIsReencryptable_test.ts index 88ef7dfe4e..55dfdb8f4a 100644 --- a/ts/test-electron/util/ensureAttachmentIsReencryptable_test.ts +++ b/ts/test-electron/util/ensureAttachmentIsReencryptable_test.ts @@ -20,7 +20,7 @@ import { import { fromBase64, toBase64 } from '../../Bytes'; import { ensureAttachmentIsReencryptable } from '../../util/ensureAttachmentIsReencryptable'; import { strictAssert } from '../../util/assert'; -import { writeNewAttachmentData } from '../../windows/attachments'; +import { writeNewAttachmentData } from '../../windows/main/attachments'; describe('utils/ensureAttachmentIsReencryptable', async () => { const fixturesDir = join(__dirname, '..', '..', '..', 'fixtures'); diff --git a/ts/test-electron/windows/attachments_test.ts b/ts/test-electron/windows/attachments_test.ts index d67d403948..20c54d8d7b 100644 --- a/ts/test-electron/windows/attachments_test.ts +++ b/ts/test-electron/windows/attachments_test.ts @@ -6,7 +6,7 @@ import path from 'path'; import fs from 'fs'; import os from 'os'; import fse from 'fs-extra'; -import * as Attachments from '../../windows/attachments'; +import * as Attachments from '../../windows/main/attachments'; import * as Bytes from '../../Bytes'; import { createName, getRelativePath } from '../../util/attachmentPath'; diff --git a/ts/test-node/app/locale_test.ts b/ts/test-node/app/locale_test.ts index f4b17b112c..630eb20a22 100644 --- a/ts/test-node/app/locale_test.ts +++ b/ts/test-node/app/locale_test.ts @@ -18,6 +18,7 @@ describe('locale', async () => { info: stub(), debug: stub(), trace: stub(), + child: () => logger, }; async function testCase( diff --git a/ts/test-node/app/menu_test.ts b/ts/test-node/app/menu_test.ts index 12cc5c4732..09702c0861 100644 --- a/ts/test-node/app/menu_test.ts +++ b/ts/test-node/app/menu_test.ts @@ -4,11 +4,13 @@ import { assert } from 'chai'; import { stub } from 'sinon'; import type { MenuItemConstructorOptions } from 'electron'; +import type pino from 'pino'; import type { CreateTemplateOptionsType } from '../../../app/menu'; import { createTemplate } from '../../../app/menu'; import { load as loadLocale } from '../../../app/locale'; import type { MenuListType } from '../../types/menu'; +import type { LoggerType } from '../../types/Logging'; import { HourCyclePreference } from '../../types/I18N'; const forceUpdate = stub(); @@ -203,19 +205,22 @@ const PLATFORMS = [ ]; describe('createTemplate', () => { + const logger: LoggerType = { + fatal: stub().throwsArg(0), + error: stub().throwsArg(0), + warn: stub().throwsArg(0), + info: stub() as pino.LogFn, + debug: stub() as pino.LogFn, + trace: stub() as pino.LogFn, + child: () => logger, + }; + const { i18n } = loadLocale({ preferredSystemLocales: ['en'], localeOverride: null, localeDirectionTestingOverride: null, hourCyclePreference: HourCyclePreference.UnknownPreference, - logger: { - fatal: stub().throwsArg(0), - error: stub().throwsArg(0), - warn: stub().throwsArg(0), - info: stub(), - debug: stub(), - trace: stub(), - }, + logger, }); const actions = { diff --git a/ts/test-node/app/updateDefaultSession_test.ts b/ts/test-node/app/updateDefaultSession_test.ts index ba83596202..1853e02440 100644 --- a/ts/test-node/app/updateDefaultSession_test.ts +++ b/ts/test-node/app/updateDefaultSession_test.ts @@ -21,15 +21,29 @@ describe('updateDefaultSession', () => { it('sets the spellcheck URL', () => { const sesh = session.fromPartition(uuid()); const stub = sandbox.stub(sesh, 'setSpellCheckerDictionaryDownloadURL'); - const getLogger = sandbox.stub(); - updateDefaultSession(sesh, getLogger); + const logger = { + fatal: sandbox.stub(), + error: sandbox.stub(), + warn: sandbox.stub(), + info: sandbox.stub(), + debug: sandbox.stub(), + trace: sandbox.stub(), + child: sandbox.stub(), + }; + updateDefaultSession(sesh, logger); sinon.assert.calledOnce(stub); sinon.assert.calledWith( stub, `https://updates.signal.org/desktop/hunspell_dictionaries/${process.versions.electron}/` ); - sinon.assert.notCalled(getLogger); + sinon.assert.notCalled(logger.fatal); + sinon.assert.notCalled(logger.error); + sinon.assert.notCalled(logger.warn); + sinon.assert.notCalled(logger.info); + sinon.assert.notCalled(logger.debug); + sinon.assert.notCalled(logger.trace); + sinon.assert.notCalled(logger.child); }); }); diff --git a/ts/test-node/jobs/JobLogger_test.ts b/ts/test-node/jobs/JobLogger_test.ts index c723e8d608..b3762aea88 100644 --- a/ts/test-node/jobs/JobLogger_test.ts +++ b/ts/test-node/jobs/JobLogger_test.ts @@ -15,6 +15,8 @@ describe('JobLogger', () => { info: sinon.fake(), debug: sinon.fake(), trace: sinon.fake(), + + child: () => createFakeLogger(), }); LEVELS.forEach(level => { diff --git a/ts/test-node/jobs/JobQueue_test.ts b/ts/test-node/jobs/JobQueue_test.ts index 3b201e850d..3d8b5ce398 100644 --- a/ts/test-node/jobs/JobQueue_test.ts +++ b/ts/test-node/jobs/JobQueue_test.ts @@ -408,6 +408,7 @@ describe('JobQueue', () => { info: sinon.fake(), debug: sinon.fake(), trace: sinon.fake(), + child: () => fakeLogger, }; class TestQueue extends JobQueue { diff --git a/ts/test-node/types/Message2_test.ts b/ts/test-node/types/Message2_test.ts index d23457df58..cc13117604 100644 --- a/ts/test-node/types/Message2_test.ts +++ b/ts/test-node/types/Message2_test.ts @@ -34,6 +34,7 @@ describe('Message', () => { info: () => null, debug: () => null, trace: () => null, + child: () => logger, }; function getDefaultMessage( diff --git a/ts/textsecure/MessageReceiver.ts b/ts/textsecure/MessageReceiver.ts index f3a67917b0..1d9b3ae224 100644 --- a/ts/textsecure/MessageReceiver.ts +++ b/ts/textsecure/MessageReceiver.ts @@ -139,7 +139,7 @@ import { ViewOnceOpenSyncEvent, ViewSyncEvent, } from './messageReceiverEvents'; -import * as log from '../logging/log'; +import * as logger from '../logging/log'; import { diffArraysAsSets } from '../util/diffArraysAsSets'; import { generateBlurHash } from '../util/generateBlurHash'; import { TEXT_ATTACHMENT } from '../types/MIME'; @@ -159,6 +159,8 @@ import { CallLinkUpdateSyncType } from '../types/CallLink'; import { bytesToUuid } from '../util/uuidToBytes'; import { isBodyTooLong } from '../util/longAttachment'; +const log = logger.child('MessageReceiver'); + const GROUPV2_ID_LENGTH = 32; const RETRY_TIMEOUT = 2 * 60 * 1000; @@ -359,7 +361,7 @@ export default class MessageReceiver public handleRequest(request: IncomingWebSocketRequest): void { // We do the message decryption here, instead of in the ordered pending queue, // to avoid exposing the time it took us to process messages through the time-to-ack. - log.info('MessageReceiver: got request', request.requestType); + log.info('got request', request.requestType); if (request.requestType !== ServerRequestType.ApiMessage) { request.respond(200, 'OK'); @@ -473,14 +475,14 @@ export default class MessageReceiver } public startProcessingQueue(): void { - log.info('MessageReceiver.startProcessingQueue'); + log.info('startProcessingQueue'); this.#stoppingProcessing = false; drop(this.#addCachedMessagesToQueue()); } #addCachedMessagesToQueue(): Promise { - log.info('MessageReceiver.addCachedMessagesToQueue'); + log.info('addCachedMessagesToQueue'); return this.#incomingQueue.add( createTaskWithTimeout( async () => this.#queueAllCached(), @@ -493,7 +495,7 @@ export default class MessageReceiver } public stopProcessing(): void { - log.info('MessageReceiver.stopProcessing'); + log.info('stopProcessing'); this.#stoppingProcessing = true; } @@ -748,15 +750,12 @@ export default class MessageReceiver ]); if (this.#pniIdentityKeyCheckRequired) { - log.warn( - "MessageReceiver: got 'empty' event, " + - 'running scheduled pni identity key check' - ); + log.warn("got 'empty' event, running scheduled pni identity key check"); drop(checkOurPniIdentityKey()); } this.#pniIdentityKeyCheckRequired = false; - log.info("MessageReceiver: emitting 'empty' event"); + log.info("emitting 'empty' event"); this.dispatchEvent(new EmptyEvent()); this.#isEmptied = true; @@ -765,7 +764,7 @@ export default class MessageReceiver const waitForDecryptedQueue = async () => { log.info( - "MessageReceiver: finished processing messages after 'empty', now waiting for application" + "finished processing messages after 'empty', now waiting for application" ); // We don't await here because we don't want this to gate future message processing @@ -818,9 +817,7 @@ export default class MessageReceiver async #queueAllCached(): Promise { if (this.#stoppingProcessing) { - log.info( - 'MessageReceiver.queueAllCached: not running due to stopped processing' - ); + log.info('queueAllCached: not running due to stopped processing'); return; } @@ -831,11 +828,11 @@ export default class MessageReceiver await this.#queueCached(batch[i]); } } - log.info('MessageReceiver.queueAllCached - finished'); + log.info('queueAllCached - finished'); } async #queueCached(item: UnprocessedType): Promise { - log.info('MessageReceiver.queueCached', item.id); + log.info('queueCached', item.id); try { const ourAci = this.#storage.user.getCheckedAci(); @@ -975,7 +972,7 @@ export default class MessageReceiver } async #decryptAndCacheBatch(items: Array): Promise { - log.info('MessageReceiver.decryptAndCacheBatch', items.length); + log.info('decryptAndCacheBatch', items.length); const decrypted: Array< Readonly<{ @@ -1046,8 +1043,7 @@ export default class MessageReceiver } catch (error) { failed.push(data); log.error( - 'MessageReceiver.decryptAndCacheBatch error when ' + - 'processing the envelope', + 'decryptAndCacheBatch error when processing the envelope', Errors.toLogFormat(error) ); } @@ -1055,7 +1051,7 @@ export default class MessageReceiver ); log.info( - 'MessageReceiver.decryptAndCacheBatch storing ' + + 'decryptAndCacheBatch storing ' + `${decrypted.length} decrypted envelopes, keeping ` + `${failed.length} failed envelopes.` ); @@ -1086,7 +1082,7 @@ export default class MessageReceiver ); }); - log.info('MessageReceiver.decryptAndCacheBatch acknowledging receipt'); + log.info('decryptAndCacheBatch acknowledging receipt'); // Acknowledge all envelopes for (const { request } of items) { @@ -1138,7 +1134,7 @@ export default class MessageReceiver }) ); - log.info('MessageReceiver.decryptAndCacheBatch fully processed'); + log.info('decryptAndCacheBatch fully processed'); this.#maybeScheduleRetryTimeout(); } @@ -1263,16 +1259,11 @@ export default class MessageReceiver TaskType.Encrypted ); } catch (error) { - const args = [ - 'queueEncryptedEnvelope error handling envelope', - logId, - ':', - Errors.toLogFormat(error), - ]; + const args = [logId, ':', Errors.toLogFormat(error)]; if (error instanceof WarnOnlyError) { - log.warn(...args); + log.warn('queueEncryptedEnvelope error handling envelope', ...args); } else { - log.error(...args); + log.error('queueEncryptedEnvelope error handling envelope', ...args); } throw error; } @@ -1321,7 +1312,7 @@ export default class MessageReceiver const logId = getEnvelopeId(envelope); if (this.#stoppingProcessing) { - log.warn(`MessageReceiver.unsealEnvelope(${logId}): dropping`); + log.warn(`unsealEnvelope(${logId}): dropping`); throw new Error('Sealed envelope dropped due to stopping processing'); } @@ -1339,7 +1330,7 @@ export default class MessageReceiver } if (serviceIdKind === ServiceIdKind.PNI) { - log.warn(`MessageReceiver.unsealEnvelope(${logId}): dropping for PNI`); + log.warn(`unsealEnvelope(${logId}): dropping for PNI`); return undefined; } @@ -1354,7 +1345,7 @@ export default class MessageReceiver throw new Error('Received message with no content'); } - log.info(`MessageReceiver.unsealEnvelope(${logId}): unidentified message`); + log.info(`unsealEnvelope(${logId}): unidentified message`); const messageContent = await sealedSenderDecryptToUsmc( Buffer.from(ciphertext), stores.identityKeyStore @@ -1400,7 +1391,7 @@ export default class MessageReceiver envelope: UnsealedEnvelope, serviceIdKind: ServiceIdKind ): Promise { - const logId = `MessageReceiver.decryptEnvelope(${getEnvelopeId(envelope)})`; + const logId = `decryptEnvelope(${getEnvelopeId(envelope)})`; if (this.#stoppingProcessing) { log.warn(`${logId}: dropping unsealed`); @@ -1597,7 +1588,7 @@ export default class MessageReceiver } = envelope; const envelopeId = getEnvelopeId(envelope); - const logId = `MessageReceiver.validateUnsealedEnvelope(${envelopeId})`; + const logId = `validateUnsealedEnvelope(${envelopeId})`; strictAssert( messageContent !== undefined, @@ -1693,7 +1684,7 @@ export default class MessageReceiver messageContent.msgType() === unidentifiedSenderTypeEnum.PLAINTEXT_CONTENT ) { log.info( - `MessageReceiver.decryptSealedSender(${logId}): ` + + `decryptSealedSender(${logId}): ` + 'unidentified message/plaintext contents' ); const plaintextContent = PlaintextContent.deserialize( @@ -1710,7 +1701,7 @@ export default class MessageReceiver messageContent.msgType() === unidentifiedSenderTypeEnum.SENDERKEY_MESSAGE ) { log.info( - `MessageReceiver.decryptSealedSender(${logId}): ` + + `decryptSealedSender(${logId}): ` + 'unidentified message/sender key contents' ); const sealedSenderIdentifier = certificate.senderUuid(); @@ -1742,7 +1733,7 @@ export default class MessageReceiver } log.info( - `MessageReceiver.decryptSealedSender(${logId}): ` + + `decryptSealedSender(${logId}): ` + 'unidentified message/passing to sealedSenderDecryptMessage' ); @@ -1837,10 +1828,7 @@ export default class MessageReceiver serviceIdKind === ServiceIdKind.PNI && envelope.type !== envelopeTypeEnum.PREKEY_BUNDLE ) { - log.warn( - `MessageReceiver.innerDecrypt(${logId}): ` + - 'non-PreKey envelope on PNI' - ); + log.warn(`innerDecrypt(${logId}): non-PreKey envelope on PNI`); return undefined; } @@ -1992,9 +1980,7 @@ export default class MessageReceiver (envelope.sourceServiceId && this.#isServiceIdBlocked(envelope.sourceServiceId)) ) { - log.info( - 'MessageReceiver.decrypt: Error from blocked sender; no further processing' - ); + log.info('decrypt: Error from blocked sender; no further processing'); this.#removeFromCache(envelope); throw error; } @@ -2002,16 +1988,14 @@ export default class MessageReceiver if (uuid && deviceId) { const senderAci = uuid; if (!isAciString(senderAci)) { - log.info( - 'MessageReceiver.decrypt: Error from PNI; no further processing' - ); + log.info('decrypt: Error from PNI; no further processing'); this.#removeFromCache(envelope); throw error; } if (serviceIdKind === ServiceIdKind.PNI) { log.info( - 'MessageReceiver.decrypt: Error on PNI; no further processing; ' + + 'decrypt: Error on PNI; no further processing; ' + 'queueing pni identity check' ); this.#pniIdentityKeyCheckRequired = true; @@ -2047,9 +2031,7 @@ export default class MessageReceiver ); } else { this.#removeFromCache(envelope); - log.error( - `MessageReceiver.decrypt: Envelope ${envelopeId} missing uuid or deviceId` - ); + log.error(`decrypt: Envelope ${envelopeId} missing uuid or deviceId`); } throw error; @@ -2060,7 +2042,7 @@ export default class MessageReceiver envelope: ProcessedEnvelope, sentContainer: ProcessedSent ) { - const logId = `MessageReceiver.handleSentMessage/${getEnvelopeId(envelope)}`; + const logId = `handleSentMessage/${getEnvelopeId(envelope)}`; log.info(logId); logUnexpectedUrgentValue(envelope, 'sentSync'); @@ -2122,7 +2104,7 @@ export default class MessageReceiver sentMessage?: ProcessedSent ): Promise { const envelopeId = getEnvelopeId(envelope); - const logId = `MessageReceiver.handleStoryMessage(${envelopeId})`; + const logId = `handleStoryMessage(${envelopeId})`; logUnexpectedUrgentValue(envelope, 'story'); @@ -2137,7 +2119,7 @@ export default class MessageReceiver const { sourceServiceId: sourceAci } = envelope; strictAssert( isAciString(sourceAci), - 'MessageReceiver.handleStoryMessage: received message from PNI' + 'handleStoryMessage: received message from PNI' ); const attachments: Array = []; @@ -2331,9 +2313,7 @@ export default class MessageReceiver envelope: UnsealedEnvelope, msg: Proto.IEditMessage ): Promise { - const logId = `MessageReceiver.handleEditMessage(${getEnvelopeId( - envelope - )})`; + const logId = `handleEditMessage(${getEnvelopeId(envelope)})`; log.info(logId); if (!msg.targetSentTimestamp) { @@ -2395,7 +2375,7 @@ export default class MessageReceiver envelope: UnsealedEnvelope, msg: Proto.IDataMessage ): Promise { - const logId = `MessageReceiver.handleDataMessage/${getEnvelopeId(envelope)}`; + const logId = `handleDataMessage/${getEnvelopeId(envelope)}`; log.info(logId); if (getStoriesBlocked() && msg.storyContext) { @@ -2759,9 +2739,7 @@ export default class MessageReceiver this.#removeFromCache(envelope); - const logId = `MessageReceiver.handleCallingMessage(${getEnvelopeId( - envelope - )})`; + const logId = `handleCallingMessage(${getEnvelopeId(envelope)})`; if ( (envelope.source && this.#isBlocked(envelope.source)) || @@ -2887,7 +2865,7 @@ export default class MessageReceiver } #handleNullMessage(envelope: UnsealedEnvelope): void { - log.info('MessageReceiver.handleNullMessage', getEnvelopeId(envelope)); + log.info('handleNullMessage', getEnvelopeId(envelope)); logUnexpectedUrgentValue(envelope, 'nullMessage'); @@ -2973,7 +2951,7 @@ export default class MessageReceiver ) { if (getStoriesBlocked()) { log.info( - 'MessageReceiver.handleSyncMessage: dropping story recipients update', + 'handleSyncMessage: dropping story recipients update', getEnvelopeId(envelope) ); this.#removeFromCache(envelope); @@ -2981,7 +2959,7 @@ export default class MessageReceiver } log.info( - 'MessageReceiver.handleSyncMessage: handling story recipients update', + 'handleSyncMessage: handling story recipients update', getEnvelopeId(envelope) ); const ev = new StoryRecipientUpdateEvent( @@ -3116,9 +3094,7 @@ export default class MessageReceiver envelope: UnsealedEnvelope, sentMessage: ProcessedSent ): Promise { - const logId = `MessageReceiver.handleSentEditMessage(${getEnvelopeId( - envelope - )})`; + const logId = `handleSentEditMessage(${getEnvelopeId(envelope)})`; log.info(logId); const { editMessage } = sentMessage; @@ -3374,7 +3350,7 @@ export default class MessageReceiver read: Array ): Promise { const logId = getEnvelopeId(envelope); - log.info('MessageReceiver.handleRead', logId); + log.info('handleRead', logId); logUnexpectedUrgentValue(envelope, 'readSync'); @@ -3405,7 +3381,7 @@ export default class MessageReceiver viewed: ReadonlyArray ): Promise { const logId = getEnvelopeId(envelope); - log.info('MessageReceiver.handleViewed', logId); + log.info('handleViewed', logId); logUnexpectedUrgentValue(envelope, 'viewSync'); @@ -3434,7 +3410,7 @@ export default class MessageReceiver callEvent: Proto.SyncMessage.ICallEvent ): Promise { const logId = getEnvelopeId(envelope); - log.info('MessageReceiver.handleCallEvent', logId); + log.info('handleCallEvent', logId); logUnexpectedUrgentValue(envelope, 'callEventSync'); @@ -3463,7 +3439,7 @@ export default class MessageReceiver callLinkUpdate: Proto.SyncMessage.ICallLinkUpdate ): Promise { const logId = getEnvelopeId(envelope); - log.info('MessageReceiver.handleCallLinkUpdate', logId); + log.info('handleCallLinkUpdate', logId); logUnexpectedUrgentValue(envelope, 'callLinkUpdateSync'); @@ -3506,7 +3482,7 @@ export default class MessageReceiver callLogEvent: Proto.SyncMessage.ICallLogEvent ): Promise { const logId = getEnvelopeId(envelope); - log.info('MessageReceiver.handleCallLogEvent', logId); + log.info('handleCallLogEvent', logId); logUnexpectedUrgentValue(envelope, 'callLogEventSync'); @@ -3531,7 +3507,7 @@ export default class MessageReceiver deleteSync: Proto.SyncMessage.IDeleteForMe ): Promise { const logId = getEnvelopeId(envelope); - log.info('MessageReceiver.handleDeleteForMeSync', logId); + log.info('handleDeleteForMeSync', logId); logUnexpectedUrgentValue(envelope, 'deleteForMeSync'); @@ -3730,7 +3706,7 @@ export default class MessageReceiver response: Proto.SyncMessage.IAttachmentBackfillResponse ): Promise { const logId = getEnvelopeId(envelope); - log.info('MessageReceiver.handleAttachmentBackfillResponse', logId); + log.info('handleAttachmentBackfillResponse', logId); logUnexpectedUrgentValue(envelope, 'attachmentBackfillResponseSync'); @@ -3807,7 +3783,7 @@ export default class MessageReceiver envelope: ProcessedEnvelope, deviceNameChange: Proto.SyncMessage.IDeviceNameChange ): Promise { - const logId = `MessageReceiver.handleDeviceNameChangeSync: ${getEnvelopeId(envelope)}`; + const logId = `handleDeviceNameChangeSync: ${getEnvelopeId(envelope)}`; log.info(logId); logUnexpectedUrgentValue(envelope, 'deviceNameChangeSync'); diff --git a/ts/textsecure/UpdateKeysListener.ts b/ts/textsecure/UpdateKeysListener.ts index 66abac97a7..d79fd5bbdc 100644 --- a/ts/textsecure/UpdateKeysListener.ts +++ b/ts/textsecure/UpdateKeysListener.ts @@ -110,7 +110,7 @@ export class UpdateKeysListener { public static init(events: MinimalEventsType, newVersion: boolean): void { if (initComplete) { - window.SignalContext.log.info('UpdateKeysListener: Already initialized'); + log.info('UpdateKeysListener: Already initialized'); return; } initComplete = true; diff --git a/ts/types/Conversation.ts b/ts/types/Conversation.ts index 3b59930f0b..a7cb2e8f0d 100644 --- a/ts/types/Conversation.ts +++ b/ts/types/Conversation.ts @@ -5,6 +5,7 @@ import type { ConversationAttributesType } from '../model-types.d'; import type { ContactAvatarType } from './Avatar'; import type { LocalAttachmentV2Type } from './Attachment'; import { computeHash } from '../Crypto'; +import * as log from '../logging/log'; export type BuildAvatarUpdaterOptions = Readonly<{ data?: Uint8Array; @@ -60,7 +61,7 @@ function buildAvatarUpdater({ field }: { field: 'avatar' | 'profileAvatar' }) { const { hash, path } = oldAvatar; const exists = path && (await doesAttachmentExist(path)); if (!exists) { - window.SignalContext.log.warn( + log.warn( `Conversation.buildAvatarUpdater: attachment ${path} did not exist` ); } diff --git a/ts/types/Logging.ts b/ts/types/Logging.ts index fab8b5bb9b..28ce138aa4 100644 --- a/ts/types/Logging.ts +++ b/ts/types/Logging.ts @@ -1,15 +1,17 @@ // Copyright 2020 Signal Messenger, LLC // SPDX-License-Identifier: AGPL-3.0-only -export type LogFunction = (...args: Array) => void; +export type LoggingFn = (msg: string, ...args: Array) => void; export type LoggerType = { - fatal: LogFunction; - error: LogFunction; - warn: LogFunction; - info: LogFunction; - debug: LogFunction; - trace: LogFunction; + fatal: LoggingFn; + error: LoggingFn; + warn: LoggingFn; + info: LoggingFn; + debug: LoggingFn; + trace: LoggingFn; + + child: (name: string) => LoggerType; }; // These match [Pino's recommendations][0]. diff --git a/ts/util/callingMessageToProto.ts b/ts/util/callingMessageToProto.ts index 8f19e4f3af..931fcb1e8d 100644 --- a/ts/util/callingMessageToProto.ts +++ b/ts/util/callingMessageToProto.ts @@ -6,6 +6,7 @@ import { CallMessageUrgency } from '@signalapp/ringrtc'; import Long from 'long'; import { SignalService as Proto } from '../protobuf'; import * as log from '../logging/log'; +import { toLogFormat } from '../types/errors'; import { missingCaseError } from './missingCaseError'; export function callingMessageToProto( @@ -99,7 +100,7 @@ function urgencyToProto( case CallMessageUrgency.HandleImmediately: return Proto.CallMessage.Opaque.Urgency.HANDLE_IMMEDIATELY; default: - log.error(missingCaseError(urgency)); + log.error(toLogFormat(missingCaseError(urgency))); return Proto.CallMessage.Opaque.Urgency.DROPPABLE; } } diff --git a/ts/util/consoleLogger.ts b/ts/util/consoleLogger.ts index 02658931e1..0d4d4aa891 100644 --- a/ts/util/consoleLogger.ts +++ b/ts/util/consoleLogger.ts @@ -5,67 +5,27 @@ import type { LoggerType } from '../types/Logging'; /* eslint-disable no-console */ export const consoleLogger: LoggerType = { - fatal(...args: Array) { + fatal(...args) { console.error(...args); }, - error(...args: Array) { + error(...args) { console.error(...args); }, - warn(...args: Array) { + warn(...args) { console.warn(...args); }, - info(...args: Array) { + info(...args) { console.info(...args); }, - debug(...args: Array) { + debug(...args) { console.debug(...args); }, - trace(...args: Array) { + trace(...args) { console.log(...args); }, + child() { + throw new Error('Not supported'); + }, }; -export type BufferedLoggerType = LoggerType & { - writeBufferInto(logger: LoggerType): void; -}; - -export function createBufferedConsoleLogger(): BufferedLoggerType { - type BufferEntryType = Readonly<{ - level: keyof LoggerType; - args: Array; - }>; - const buffer = new Array(); - return { - fatal(...args: Array) { - buffer.push({ level: 'fatal', args }); - console.error(...args); - }, - error(...args: Array) { - buffer.push({ level: 'error', args }); - console.error(...args); - }, - warn(...args: Array) { - buffer.push({ level: 'warn', args }); - console.warn(...args); - }, - info(...args: Array) { - buffer.push({ level: 'info', args }); - console.info(...args); - }, - debug(...args: Array) { - buffer.push({ level: 'debug', args }); - console.debug(...args); - }, - trace(...args: Array) { - buffer.push({ level: 'trace', args }); - console.log(...args); - }, - - writeBufferInto(output) { - for (const { level, args } of buffer) { - output[level](...args); - } - }, - }; -} /* eslint-enable no-console */ diff --git a/ts/util/timelineUtil.ts b/ts/util/timelineUtil.ts index e0834bbefe..b60b968b14 100644 --- a/ts/util/timelineUtil.ts +++ b/ts/util/timelineUtil.ts @@ -6,6 +6,7 @@ import * as log from '../logging/log'; import type { PropsType as TimelinePropsType } from '../components/conversation/Timeline'; import type { TimelineItemType } from '../components/conversation/TimelineItem'; import { WidthBreakpoint } from '../components/_util'; +import { toLogFormat } from '../types/errors'; import { MINUTE } from './durations'; import { missingCaseError } from './missingCaseError'; import { isSameDay } from './timestamp'; @@ -98,7 +99,7 @@ export function shouldCurrentMessageHideMetadata( case 'viewed': return true; default: - log.error(missingCaseError(message.status)); + log.error(toLogFormat(missingCaseError(message.status))); return true; } } diff --git a/ts/windows/context.ts b/ts/windows/context.ts index 8e92d01e7d..8137bf49ee 100644 --- a/ts/windows/context.ts +++ b/ts/windows/context.ts @@ -5,7 +5,6 @@ import type { MenuItemConstructorOptions } from 'electron'; import { ipcRenderer } from 'electron'; import type { NativeThemeType } from '../context/createNativeThemeListener'; -import type { LoggerType } from '../types/Logging'; import type { MenuOptionsType } from '../types/menu'; import type { RendererConfigType } from '../types/RendererConfig'; import type { LocalizerType } from '../types/Util'; @@ -17,17 +16,11 @@ import { Timers } from '../context/Timers'; import type { LocaleDirection } from '../../app/locale'; import { i18n } from '../context/i18n'; -import { initialize as initializeLogging } from '../logging/set_up_renderer_logging'; import type { ActiveWindowServiceType } from '../services/ActiveWindowService'; import type { LocaleEmojiListType } from '../types/emoji'; import type { HourCyclePreference } from '../types/I18N'; -import { strictAssert } from '../util/assert'; import { MinimalSignalContext } from './minimalContext'; -strictAssert(Boolean(window.SignalContext), 'context must be defined'); - -initializeLogging(); - export type MainWindowStatsType = Readonly<{ isMaximized: boolean; isFullScreen: boolean; @@ -73,7 +66,6 @@ export type SignalContextType = { bytes: Bytes; crypto: Crypto; i18n: LocalizerType; - log: LoggerType; renderWindow?: () => void; setIsCallActive: (isCallActive: boolean) => unknown; timers: Timers; @@ -84,7 +76,6 @@ export const SignalContext: SignalContextType = { bytes: new Bytes(), crypto: new Crypto(), i18n, - log: window.SignalContext.log, setIsCallActive(isCallActive: boolean): void { ipcRenderer.send('set-is-call-active', isCallActive); }, diff --git a/ts/windows/init.ts b/ts/windows/init.ts index 3d61b0f49c..765238e3eb 100644 --- a/ts/windows/init.ts +++ b/ts/windows/init.ts @@ -5,6 +5,6 @@ document.body.classList.add(window.SignalContext.OS.getClassName()); if (window.SignalContext.renderWindow) { window.SignalContext.renderWindow(); -} else if (window.SignalContext.log) { - window.SignalContext.log.error('renderWindow is undefined!'); +} else { + throw new Error('renderWindow is undefined!'); } diff --git a/ts/windows/attachments.ts b/ts/windows/main/attachments.ts similarity index 92% rename from ts/windows/attachments.ts rename to ts/windows/main/attachments.ts index a9aa3a6652..86f84437ef 100644 --- a/ts/windows/attachments.ts +++ b/ts/windows/main/attachments.ts @@ -8,15 +8,16 @@ import { existsSync } from 'fs'; import fse from 'fs-extra'; import { v4 as getGuid } from 'uuid'; -import { isPathInside } from '../util/isPathInside'; -import { writeWindowsZoneIdentifier } from '../util/windowsZoneIdentifier'; -import OS from '../util/os/osMain'; -import { getRelativePath, createName } from '../util/attachmentPath'; -import { toHex } from '../Bytes'; -import { getRandomBytes } from '../Crypto'; +import { isPathInside } from '../../util/isPathInside'; +import { writeWindowsZoneIdentifier } from '../../util/windowsZoneIdentifier'; +import OS from '../../util/os/osMain'; +import { getRelativePath, createName } from '../../util/attachmentPath'; +import { toHex } from '../../Bytes'; +import { getRandomBytes } from '../../Crypto'; +import * as log from '../../logging/log'; -export * from '../util/ensureAttachmentIsReencryptable'; -export * from '../../app/attachments'; +export * from '../../util/ensureAttachmentIsReencryptable'; +export * from '../../../app/attachments'; type FSAttrType = { set: (path: string, attribute: string, value: string) => Promise; @@ -33,7 +34,7 @@ try { if (process.platform === 'darwin') { throw e; } - window.SignalContext.log?.info('x-attr dependency did not load successfully'); + log.info('x-attr dependency did not load successfully'); } export const createPlaintextReader = ( @@ -226,9 +227,7 @@ async function writeWithAttributes( try { await writeWindowsZoneIdentifier(target); } catch (err) { - window.SignalContext.log?.warn( - 'Failed to write Windows Zone.Identifier file; continuing' - ); + log.error('Failed to write Windows Zone.Identifier file; continuing'); } } } diff --git a/ts/windows/main/phase2-dependencies.ts b/ts/windows/main/phase2-dependencies.ts index 7afcb1a1c2..6406a37e89 100644 --- a/ts/windows/main/phase2-dependencies.ts +++ b/ts/windows/main/phase2-dependencies.ts @@ -10,12 +10,15 @@ import * as moment from 'moment'; import 'moment/min/locales.min'; import { textsecure } from '../../textsecure'; -import * as Attachments from '../attachments'; +import { initialize as initializeLogging } from '../../logging/set_up_renderer_logging'; import { setup } from '../../signal'; import { addSensitivePath } from '../../util/privacy'; import * as dns from '../../util/dns'; import * as log from '../../logging/log'; import { SignalContext } from '../context'; +import * as Attachments from './attachments'; + +initializeLogging(); window.nodeSetImmediate = setImmediate; window.Backbone = Backbone; diff --git a/ts/windows/main/preload.ts b/ts/windows/main/preload.ts index 2a3226a2bd..d79a1e9cdb 100644 --- a/ts/windows/main/preload.ts +++ b/ts/windows/main/preload.ts @@ -11,11 +11,13 @@ try { require('./start'); } catch (error) { /* eslint-disable no-console */ - if (console._log) { - console._log('preload error!', error.stack); - } console.log('preload error!', error.stack); /* eslint-enable no-console */ + try { + log.info('preload error!', error.stack); + } catch { + // Best effort + } throw error; }