diff --git a/app.ts b/app.ts index 70aba2df9..94ba5f3e3 100644 --- a/app.ts +++ b/app.ts @@ -4,7 +4,11 @@ import * as cookieParser from 'cookie-parser' import * as cors from 'cors' import * as https from 'https' import * as http from 'http' -import logger, { logging, sphinxLogger } from './src/utils/logger' +import logger, { + installConsoleTimestampPrefix, + logging, + sphinxLogger, +} from './src/utils/logger' import { checkInvitesHubInterval } from './src/hub' import { genUsersInterval } from './src/utils/proxy' import { @@ -29,6 +33,7 @@ import rateLimit from 'express-rate-limit' // force UTC time process.env.TZ = 'UTC' +installConsoleTimestampPrefix() const env = process.env.NODE_ENV || 'development' const config = loadConfig() diff --git a/src/tests/unit_tests/logger.test.ts b/src/tests/unit_tests/logger.test.ts new file mode 100644 index 000000000..35c22801c --- /dev/null +++ b/src/tests/unit_tests/logger.test.ts @@ -0,0 +1,37 @@ +jest.mock('../../utils/config', () => ({ + loadConfig: () => ({ + logging: '', + logging_level: 'info', + }), +})) + +import { timestampConsoleArgs } from '../../utils/logger' + +describe('tests for src/utils/logger.ts', () => { + const timestamp = new Date(2026, 5, 14, 12, 0, 0) + + test('prefixes string console messages with a timestamp', () => { + const args = timestampConsoleArgs(['hello', 'world'], timestamp) + + expect(args).toStrictEqual(['-> 2026-06-14 12:00:00: hello', 'world']) + }) + + test('adds a timestamp argument before non-string console messages', () => { + const data = { ok: true } + const args = timestampConsoleArgs([data], timestamp) + + expect(args).toStrictEqual(['-> 2026-06-14 12:00:00:', data]) + }) + + test('does not prefix existing express logger timestamps again', () => { + const args = ['-> 2026-06-14 12:00:00: POST /messages 200 71ms'] + + expect(timestampConsoleArgs(args, timestamp)).toBe(args) + }) + + test('does not prefix existing sphinx logger timestamps again', () => { + const args = ['26-06-14T12:00:00', '[MISC]', 'hello'] + + expect(timestampConsoleArgs(args, timestamp)).toBe(args) + }) +}) diff --git a/src/utils/logger.ts b/src/utils/logger.ts index 127a0b170..6cec96896 100644 --- a/src/utils/logger.ts +++ b/src/utils/logger.ts @@ -8,6 +8,40 @@ const config = loadConfig() const blgrLogger = new blgr(config.logging_level) const tsFormat = (ts) => moment(ts).format('YYYY-MM-DD HH:mm:ss').trim() +const consoleTimestampFlag = '__sphinxConsoleTimestampsInstalled' +const consoleMethods: Array<'debug' | 'error' | 'info' | 'log' | 'warn'> = [ + 'debug', + 'error', + 'info', + 'log', + 'warn', +] +const timestampedConsoleLineRegex = + /^(?:\x1b\[[0-9;]*m)*(?:-> \d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}:|\d{2}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2})/ + +function alreadyTimestamped(arg: any): boolean { + return typeof arg === 'string' && timestampedConsoleLineRegex.test(arg) +} + +function timestampConsoleArgs(args: any[], ts: Date = new Date()): any[] { + if (args.length > 0 && alreadyTimestamped(args[0])) return args + + const prefix = `-> ${tsFormat(ts)}:` + if (typeof args[0] === 'string') return [`${prefix} ${args[0]}`, ...args.slice(1)] + + return [prefix, ...args] +} + +function installConsoleTimestampPrefix() { + const consoleState = console as Console & { [key: string]: boolean | undefined } + if (consoleState[consoleTimestampFlag]) return + + consoleState[consoleTimestampFlag] = true + consoleMethods.forEach((method) => { + const original = console[method].bind(console) + console[method] = (...args: any[]) => original(...timestampConsoleArgs(args)) + }) +} const logger = expressWinston.logger({ transports: [new winston.transports.Console()], @@ -132,4 +166,4 @@ const sphinxLogger = { spam: sphinxLoggerSpam, } -export { logging, sphinxLogger } +export { installConsoleTimestampPrefix, logging, sphinxLogger, timestampConsoleArgs }