diff --git a/TODO b/TODO index 8b14d4b..c64e463 100644 --- a/TODO +++ b/TODO @@ -68,7 +68,7 @@ Content-Type: application/issue ID: 5 Type: bugfix Title: fix critical bugs across core modules -Status: in-progress +Status: done Priority: high Created: 2026-03-13 Relationships: diff --git a/src/config.ts b/src/config.ts index 594d01d..d33cfa4 100644 --- a/src/config.ts +++ b/src/config.ts @@ -121,8 +121,8 @@ export function basicConfig(options: BasicConfigOptions) { const filename = options.filename ?? null; const stream = options.stream ?? null; const filemode = options.filemode ?? 'a'; - const dateformat = options.filemode ?? null; - const style = options.filemode ?? '%'; + const dateformat = options.datefmt ?? null; + const style = options.style ?? '%'; const level = options.level ?? null; if (!Object.keys(STYLES).includes(style)) { @@ -139,64 +139,54 @@ export function basicConfig(options: BasicConfigOptions) { } } - if (handlers.length == 0) { - if (handlers === null && stream && filename) { + if (MANAGER.root.handlers.length > 0 && !force) { + return; + } + + if (handlers.length > 0) { + if (stream || filename) { + throw new ValueError( + "'stream' or 'filename' should not be specified together " + + "with 'handlers'" + ); + } + } + else { + if (stream && filename) { throw new ValueError( "'stream' and 'filename' should not be specified together" ); } - else if (stream || filename) { - throw new ValueError( - "'stream' or 'filename' should not be specified together" + - "with 'handlers'" - ); + if (filename) { + if (filemode.match('b')) { errors = undefined } + else { encoding = 'utf-8' } + + handlers = [new FileHandler({ + filename: filename, + filemode: filemode, + encoding: encoding, + errors: errors + })]; } - - if (handlers === null) { - var h: Handler; - - if (filename) { - if (filemode.match('b')) { errors = undefined } - else { encoding = 'utf-8' } - - h = new FileHandler({ - filename: filename, - filemode: filemode, - 'encoding': encoding, - errors: errors - }); - } - - else { h = new StreamHandler(stream) } - - handlers = [h]; - } - - for (var i = 0; i < handlers.length; i += 1) { - let h = handlers[i]; - - if (h.formatter === null) { - h.formatter = new Formatter({ - fmt: options.format ?? STYLES[style][1], - datefmt: dateformat, - style: style - }); - } - - MANAGER.root.addHandler(h); - } - - if (level !== null) { MANAGER.root.setLevel(level) } - - if (options) { - // runtime interface guard, please let me stay. 🥺 - // the interface does not allow for additional members, but the - // runtime environment has no concept of interfaces. We can stick to - // the original implementation - const keys = Object.keys(options).join(', '); - - throw new ValueError(`Unrecognised argument(s): ${keys}`); + else { + handlers = [new StreamHandler(stream)]; } } + + for (let i = 0; i < handlers.length; i += 1) { + const h = handlers[i]; + + if (h.formatter === null) { + h.formatter = new Formatter({ + fmt: options.format ?? STYLES[style][1], + datefmt: dateformat, + style: style + }); + } + + MANAGER.root.addHandler(h); + } + + if (level !== null) { MANAGER.root.setLevel(level) } } diff --git a/src/formatter.ts b/src/formatter.ts index 7e0197c..cf1d6e6 100644 --- a/src/formatter.ts +++ b/src/formatter.ts @@ -174,6 +174,20 @@ export class Formatter { * formatters, for example if you want all logging times to be shown in GMT, * set the 'converter' attribute in the Formatter class. */ + /** + * Format the specified record as text. + * + * The record's attribute dictionary is used as the operand to a string + * formatting operation which yields the returned string. Before the + * formatting operation, a couple of preparatory steps are carried out. + * The message attribute of the record is computed using LogRecord.getMessage(). + * If the formatting string uses the time, formatTime() is called to format + * the event time. + */ + format(record: LogRecord): string { + return this.style.format(record); + } + formatTime(record: LogRecord, datefmt?: any): string { //TODO: record.created diff --git a/src/handler.ts b/src/handler.ts index c75db06..24ff076 100644 --- a/src/handler.ts +++ b/src/handler.ts @@ -78,7 +78,7 @@ export class Handler extends Filterer { } get level(): number { return this._level } - set level(level: LogLevel|string) { this.level = checkLevel(level) } + set level(level: LogLevel|string) { this._level = checkLevel(level) } get scope(): string|null { return this._scope } set scope(scope: string) { this._scope = scope } @@ -90,11 +90,9 @@ export class Handler extends Filterer { * If a formatter is set, use it. Otherwise, use the default formatter for * the module. */ - format(record: LogRecord) { - var fmt: Formatter|null = null; - - if (this.formatter) { fmt = this.formatter } - else { fmt = DEFAULT_FORMATTER } + format(record: LogRecord): string { + const fmt = this.formatter ?? DEFAULT_FORMATTER; + return fmt.format(record); } /** @@ -159,6 +157,7 @@ export class Handler extends Filterer { ) } + get formatter(): Formatter|null { return this._formatter } set formatter(fmt: Formatter) { this._formatter = fmt } } diff --git a/src/logger.ts b/src/logger.ts index 8cdff06..572f3a3 100644 --- a/src/logger.ts +++ b/src/logger.ts @@ -108,10 +108,13 @@ export class Logger extends Filterer { public set level(level: LogLevel) { this._level = checkLevel(level) } + public get manager(): Manager|null { return this._manager } + public set manager(manager: Manager) { - if (this.manager) { + if (this._manager) { throw new ValueError('logger can only be assigned to manager once'); } + this._manager = manager; } public setLevel(level: LogLevel) { @@ -143,13 +146,17 @@ export class Logger extends Filterer { public isEnabledFor(level: LogLevel): boolean { if (this.disabled) { return false } - if (this.cache[level] === undefined && this.manager && this.manager.disable < level) { - return this.cache[level] = ( - level >= this.getEffectiveLevel() - ); + if (level in this.cache) { + return this.cache[level]; } - return this.cache[level] = false; + if (this._manager && this._manager.disable >= level) { + this.cache[level] = false; + return false; + } + + this.cache[level] = level >= this.getEffectiveLevel(); + return this.cache[level]; } /** @@ -191,9 +198,9 @@ export class Logger extends Filterer { var [k, v] = item; - if (['message', 'asctime'].includes(k as string) || - (rv as {[key: string]: any}).keys().includes(k as string)) { - throw new KeyError('attempt to overwrite ${k} in LogRecord') + if (['message', 'asctime'].includes(k) || + Object.keys(rv).includes(k)) { + throw new KeyError(`attempt to overwrite ${k} in LogRecord`) } (rv as any)[k] = options.extra![k as string] as any @@ -226,7 +233,8 @@ export class Logger extends Filterer { } } - var record = this.makeRecord(this.scope, level, msg, options) + const record = this.makeRecord(this.scope, level, msg, options); + this.handle(this.scope, record); } /** diff --git a/src/manager.ts b/src/manager.ts index c891849..1d6828d 100644 --- a/src/manager.ts +++ b/src/manager.ts @@ -22,7 +22,7 @@ var loggerClass = Logger; * Placeholder instance */ class Placeholder { - protected loggers: Logger[] = []; + public loggers: Logger[] = []; /** * initialize with the specified logger being a child of this placeholder. @@ -71,20 +71,73 @@ export class Manager { * up the parent/child references which pointed to the placeholder to now * point to the logger. */ - getLogger(scope: string) { - var rv: null|Logger = null; + getLogger(scope: string): Logger { + let rv: Logger; - if (typeof scope != 'string') { + if (scope in this.loggers) { + const existing = this.loggers[scope]; - rv = this.loggers[scope]; - - if (rv instanceof Placeholder) { - var ph = rv; - rv = new (this._loggerClass ?? loggerClass)(scope, NOTSET); - } - else { + if (existing instanceof Placeholder) { rv = new (this._loggerClass ?? loggerClass)(scope, NOTSET); this.loggers[scope] = rv; + this._fixupChildren(existing, rv); + } + else { + rv = existing; + } + } + else { + rv = new (this._loggerClass ?? loggerClass)(scope, NOTSET); + this.loggers[scope] = rv; + this._fixupParents(rv); + } + + return rv; + } + + /** + * Ensure that there are either loggers or placeholders all the way from + * the specified logger to the root of the logger hierarchy. + */ + protected _fixupParents(logger: Logger) { + const name = logger.scope; + let i = name.lastIndexOf('.'); + let rv: Logger | null = null; + + while (i > 0 && !rv) { + const substr = name.substring(0, i); + + if (!(substr in this.loggers)) { + this.loggers[substr] = new Placeholder(logger) as unknown as Logger; + } + else { + const obj = this.loggers[substr]; + + if (obj instanceof Placeholder) { + obj.push(logger); + } + else { + rv = obj; + } + } + + i = name.lastIndexOf('.', i - 1); + } + + (logger as unknown as { parent: Logger }).parent = rv ?? this.root; + } + + /** + * Ensure that children of the placeholder ph are connected to the + * specified logger. + */ + protected _fixupChildren(ph: Placeholder, logger: Logger) { + const name = logger.scope; + + for (const c of ph.loggers) { + if (c.parent!.scope.substring(0, name.length) !== name) { + (logger as unknown as { parent: Logger }).parent = c.parent!; + (c as unknown as { parent: Logger }).parent = logger; } } } diff --git a/tests/unit/config.test.ts b/tests/unit/config.test.ts new file mode 100644 index 0000000..e918ba5 --- /dev/null +++ b/tests/unit/config.test.ts @@ -0,0 +1,93 @@ +import {expect, jest, test} from '@jest/globals'; +import { basicConfig } from '../../src/config'; +import { MANAGER } from '../../src/manager'; +import { Handler } from '../../src/handler'; +import { LogRecord } from '../../src/log-record'; +import { Formatter } from '../../src/formatter'; +import { DEBUG, WARNING, ERROR } from '../../src/log-level'; +describe('basicConfig', () => { + beforeEach(() => { + MANAGER.root.handlers.splice(0, MANAGER.root.handlers.length); + }); + + test('adds a handler to the root logger', () => { + basicConfig({}); + expect(MANAGER.root.handlers.length).toBeGreaterThan(0); + }); + + test('sets root logger level', () => { + basicConfig({ level: DEBUG }); + expect(MANAGER.root.level).toBe(DEBUG); + }); + + test('does nothing when handlers already exist and force is false', () => { + basicConfig({ level: DEBUG }); + const handlerCount = MANAGER.root.handlers.length; + basicConfig({ level: ERROR }); + expect(MANAGER.root.handlers.length).toBe(handlerCount); + expect(MANAGER.root.level).toBe(DEBUG); + }); + + test('replaces handlers when force is true', () => { + basicConfig({ level: DEBUG }); + basicConfig({ level: ERROR, force: true }); + expect(MANAGER.root.level).toBe(ERROR); + }); + + test('throws on invalid style', () => { + expect(() => { + basicConfig({ style: 'X' }); + }).toThrow('style must be one of'); + }); + + test('throws when stream and filename both specified', () => { + expect(() => { + basicConfig({ + stream: process.stderr, + filename: 'test.log', + }); + }).toThrow('should not be specified together'); + }); + + test('throws when handlers and stream both specified', () => { + class TestHandler extends Handler { + emit(record: LogRecord) {} + } + expect(() => { + basicConfig({ + handlers: [new TestHandler()], + stream: process.stderr, + }); + }).toThrow('should not be specified together'); + }); + + test('uses provided handlers', () => { + class TestHandler extends Handler { + emit(record: LogRecord) {} + } + const handler = new TestHandler(); + basicConfig({ handlers: [handler] }); + expect(MANAGER.root.handlers).toContain(handler); + }); + + test('assigns formatter to handlers without one', () => { + class TestHandler extends Handler { + emit(record: LogRecord) {} + } + const handler = new TestHandler(); + expect(handler.formatter).toBeNull(); + basicConfig({ handlers: [handler] }); + expect(handler.formatter).not.toBeNull(); + }); + + test('preserves existing formatter on handlers', () => { + class TestHandler extends Handler { + emit(record: LogRecord) {} + } + const handler = new TestHandler(); + const fmt = new Formatter({ fmt: '%(message)s' }); + handler.formatter = fmt; + basicConfig({ handlers: [handler] }); + expect(handler.formatter).toBe(fmt); + }); +}); diff --git a/tests/unit/handler.test.ts b/tests/unit/handler.test.ts new file mode 100644 index 0000000..99a897a --- /dev/null +++ b/tests/unit/handler.test.ts @@ -0,0 +1,92 @@ +import {expect, jest, test} from '@jest/globals'; +import { Handler, StreamHandler, StderrHandler } from '../../src/handler'; +import { Formatter, DEFAULT_FORMATTER } from '../../src/formatter'; +import { LogRecord } from '../../src/log-record'; +import { DEBUG, WARNING, ERROR, NOTSET } from '../../src/log-level'; +function makeRecord(level: number, msg: string): LogRecord { + return new LogRecord('test', { level, msg }); +} + +describe('Handler', () => { + describe('constructor', () => { + test('defaults to NOTSET level', () => { + const h = new Handler(); + expect(h.level).toBe(NOTSET); + }); + + test('accepts a level argument', () => { + const h = new Handler(WARNING); + expect(h.level).toBe(WARNING); + }); + }); + + describe('level setter', () => { + test('sets the level without infinite recursion', () => { + const h = new Handler(); + h.level = ERROR; + expect(h.level).toBe(ERROR); + }); + }); + + describe('formatter', () => { + test('getter returns null when no formatter set', () => { + const h = new Handler(); + expect(h.formatter).toBeNull(); + }); + + test('getter returns assigned formatter', () => { + const h = new Handler(); + const fmt = new Formatter(); + h.formatter = fmt; + expect(h.formatter).toBe(fmt); + }); + }); + + describe('format', () => { + test('uses DEFAULT_FORMATTER when no formatter assigned', () => { + const h = new Handler(); + const record = makeRecord(DEBUG, 'hello'); + const result = h.format(record); + expect(typeof result).toBe('string'); + }); + + test('uses assigned formatter', () => { + const h = new Handler(); + const fmt = new Formatter({ fmt: '%(message)s' }); + h.formatter = fmt; + const record = makeRecord(DEBUG, 'hello'); + const result = h.format(record); + expect(typeof result).toBe('string'); + }); + + test('returns a string', () => { + const h = new Handler(); + const record = makeRecord(WARNING, 'test message'); + expect(typeof h.format(record)).toBe('string'); + }); + }); + + describe('emit', () => { + test('throws NotImplementedError on base class', () => { + const h = new Handler(); + const record = makeRecord(DEBUG, 'hello'); + expect(() => h.emit(record)).toThrow('emit must be implemented'); + }); + }); + + describe('close', () => { + test('sets closed to true', () => { + const h = new Handler(); + expect(h.closed).toBe(false); + h.close(); + expect(h.closed).toBe(true); + }); + }); +}); + +describe('StderrHandler', () => { + test('accepts a level', () => { + const h = new StderrHandler(ERROR); + expect(h.level).toBe(ERROR); + }); +}); diff --git a/tests/unit/logger.test.ts b/tests/unit/logger.test.ts new file mode 100644 index 0000000..c88e98a --- /dev/null +++ b/tests/unit/logger.test.ts @@ -0,0 +1,181 @@ +import {expect, jest, test} from '@jest/globals'; +import { Logger, RootLogger, ROOT } from '../../src/logger'; +import { Handler } from '../../src/handler'; +import { LogRecord } from '../../src/log-record'; +import { Formatter } from '../../src/formatter'; +import { Manager } from '../../src/manager'; +import { + DEBUG, + INFO, + WARNING, + ERROR, + CRITICAL, + NOTSET, +} from '../../src/log-level'; +import { MyError } from '../../src/helper/error'; + +describe('Logger', () => { + describe('constructor', () => { + test('sets scope and default level', () => { + const logger = new Logger('test'); + expect(logger.scope).toBe('test'); + expect(logger.level).toBe(NOTSET); + }); + + test('accepts explicit level', () => { + const logger = new Logger('test', WARNING); + expect(logger.level).toBe(WARNING); + }); + }); + + describe('setLevel', () => { + test('changes the level', () => { + const logger = new Logger('test'); + logger.setLevel(ERROR); + expect(logger.level).toBe(ERROR); + }); + }); + + describe('getEffectiveLevel', () => { + test('returns own level when set', () => { + const logger = new Logger('test', WARNING); + expect(logger.getEffectiveLevel()).toBe(WARNING); + }); + + test('returns NOTSET when no level set and no parent', () => { + const logger = new Logger('test'); + expect(logger.getEffectiveLevel()).toBe(NOTSET); + }); + }); + + describe('isEnabledFor', () => { + test('returns true when level meets effective level', () => { + const logger = new Logger('test', DEBUG); + expect(logger.isEnabledFor(WARNING)).toBe(true); + expect(logger.isEnabledFor(DEBUG)).toBe(true); + }); + + test('returns false when level is below effective level', () => { + const logger = new Logger('test', WARNING); + expect(logger.isEnabledFor(DEBUG)).toBe(false); + expect(logger.isEnabledFor(INFO)).toBe(false); + }); + + test('caches results for repeated calls', () => { + const logger = new Logger('test', WARNING); + const first = logger.isEnabledFor(DEBUG); + const second = logger.isEnabledFor(DEBUG); + expect(first).toBe(second); + }); + + test('respects manager disable level', () => { + const root = new RootLogger(WARNING); + const manager = new Manager(root); + const logger = manager.getLogger('test'); + logger.setLevel(DEBUG); + logger.manager = manager; + manager.disable = ERROR; + logger.clear(); + expect(logger.isEnabledFor(DEBUG)).toBe(false); + expect(logger.isEnabledFor(WARNING)).toBe(false); + expect(logger.isEnabledFor(CRITICAL)).toBe(true); + }); + }); + + describe('manager property', () => { + test('starts as null', () => { + const logger = new Logger('test'); + expect(logger.manager).toBeNull(); + }); + + test('can be assigned once', () => { + const logger = new Logger('test'); + const root = new RootLogger(WARNING); + const manager = new Manager(root); + logger.manager = manager; + expect(logger.manager).toBe(manager); + }); + + test('throws on second assignment', () => { + const logger = new Logger('test'); + const root = new RootLogger(WARNING); + const manager = new Manager(root); + logger.manager = manager; + expect(() => { logger.manager = manager }).toThrow('logger can only be assigned to manager once'); + }); + }); + + describe('addHandler / removeHandler', () => { + test('adds and removes handlers', () => { + const logger = new Logger('test'); + const handler = new Handler(DEBUG); + expect(logger.handlers.length).toBe(0); + logger.addHandler(handler); + expect(logger.handlers.length).toBe(1); + logger.removeHandler(handler); + }); + + test('does not add duplicate handlers', () => { + const logger = new Logger('test'); + const handler = new Handler(DEBUG); + logger.addHandler(handler); + logger.addHandler(handler); + expect(logger.handlers.length).toBe(1); + }); + }); + + describe('debug', () => { + test('invokes handler when level is DEBUG', () => { + const logger = new Logger('test', DEBUG); + const emitted: LogRecord[] = []; + + class TestHandler extends Handler { + emit(record: LogRecord) { emitted.push(record) } + } + + logger.addHandler(new TestHandler(DEBUG)); + logger.debug('test message'); + expect(emitted.length).toBe(1); + expect(emitted[0].scope).toBe('test'); + }); + + test('does not invoke handler when level is above DEBUG', () => { + const logger = new Logger('test', WARNING); + const emitted: LogRecord[] = []; + + class TestHandler extends Handler { + emit(record: LogRecord) { emitted.push(record) } + } + + logger.addHandler(new TestHandler(DEBUG)); + logger.debug('test message'); + expect(emitted.length).toBe(0); + }); + }); + + describe('makeRecord', () => { + test('throws KeyError when extra overwrites existing LogRecord key', () => { + const logger = new Logger('test', DEBUG); + expect(() => { + logger.debug('test', { + excInfo: null, + extra: { scope: 'override' }, + stackInfo: false, + stackLevel: 1, + }); + }).toThrow('attempt to overwrite scope in LogRecord'); + }); + }); +}); + +describe('RootLogger', () => { + test('has scope "root"', () => { + const root = new RootLogger(WARNING); + expect(root.scope).toBe('root'); + }); + + test('accepts a level', () => { + const root = new RootLogger(ERROR); + expect(root.level).toBe(ERROR); + }); +}); diff --git a/tests/unit/manager.test.ts b/tests/unit/manager.test.ts new file mode 100644 index 0000000..2df1fbb --- /dev/null +++ b/tests/unit/manager.test.ts @@ -0,0 +1,128 @@ +import {expect, jest, test} from '@jest/globals'; +import { Manager } from '../../src/manager'; +import { Logger, RootLogger } from '../../src/logger'; +import { WARNING, DEBUG, NOTSET } from '../../src/log-level'; + +function makeManager(): Manager { + return new Manager(new RootLogger(WARNING)); +} + +describe('Manager', () => { + describe('constructor', () => { + test('stores the root logger', () => { + const root = new RootLogger(WARNING); + const manager = new Manager(root); + expect(manager.root).toBe(root); + }); + }); + + describe('getLogger', () => { + test('returns a Logger instance', () => { + const manager = makeManager(); + const logger = manager.getLogger('app'); + expect(logger).toBeInstanceOf(Logger); + expect(logger.scope).toBe('app'); + }); + + test('returns the same logger for the same scope', () => { + const manager = makeManager(); + const a = manager.getLogger('app'); + const b = manager.getLogger('app'); + expect(a).toBe(b); + }); + + test('returns different loggers for different scopes', () => { + const manager = makeManager(); + const a = manager.getLogger('app'); + const b = manager.getLogger('lib'); + expect(a).not.toBe(b); + }); + + test('sets parent to root for top-level loggers', () => { + const manager = makeManager(); + const logger = manager.getLogger('app'); + expect(logger.parent).toBe(manager.root); + }); + + test('sets parent to existing parent logger', () => { + const manager = makeManager(); + const parent = manager.getLogger('app'); + const child = manager.getLogger('app.module'); + expect(child.parent).toBe(parent); + }); + + test('establishes hierarchy for deeply nested loggers', () => { + const manager = makeManager(); + const top = manager.getLogger('a'); + const mid = manager.getLogger('a.b'); + const leaf = manager.getLogger('a.b.c'); + expect(leaf.parent).toBe(mid); + expect(mid.parent).toBe(top); + expect(top.parent).toBe(manager.root); + }); + + test('creates placeholders for intermediate loggers', () => { + const manager = makeManager(); + const leaf = manager.getLogger('a.b.c'); + expect(leaf.parent).toBe(manager.root); + + const mid = manager.getLogger('a.b'); + expect(leaf.parent).toBe(mid); + expect(mid.parent).toBe(manager.root); + }); + + test('fixes up children when intermediate logger is created', () => { + const manager = makeManager(); + const leaf = manager.getLogger('a.b.c'); + const top = manager.getLogger('a'); + + expect(top.parent).toBe(manager.root); + + const mid = manager.getLogger('a.b'); + expect(leaf.parent).toBe(mid); + }); + }); + + describe('disable', () => { + test('defaults to 0', () => { + const manager = makeManager(); + expect(manager.disable).toBe(0); + }); + + test('can be set to a level', () => { + const manager = makeManager(); + manager.disable = WARNING; + expect(manager.disable).toBe(WARNING); + }); + }); + + describe('loggerClass', () => { + test('accepts Logger subclass', () => { + const manager = makeManager(); + class CustomLogger extends Logger {} + expect(() => { manager.loggerClass = CustomLogger as any }).not.toThrow(); + }); + + test('rejects non-Logger class', () => { + const manager = makeManager(); + class NotALogger {} + expect(() => { + manager.loggerClass = NotALogger as any; + }).toThrow(TypeError); + }); + + test('accepts Logger itself', () => { + const manager = makeManager(); + expect(() => { manager.loggerClass = Logger as any }).not.toThrow(); + }); + }); + + describe('clear', () => { + test('clears logger caches', () => { + const manager = makeManager(); + const logger = manager.getLogger('test'); + logger.isEnabledFor(DEBUG); + manager.clear(); + }); + }); +});