From 28ec9396072d32c89d6575dd90fedb093dc496c3 Mon Sep 17 00:00:00 2001 From: clover caruso Date: Sun, 26 Oct 2025 14:20:58 -0700 Subject: [PATCH] feat(lib/log): emit `Message` objects instead of text the logging interface now returns a Message object instead of working purely on ASCII text. messages contain the timestamp, ansi text, level, scope, stack, and any extra metadata[^1]. this change considers four consumers: - generally customizing the format of the terminal log - in browsers, the module must call the correct 'console' API - communicating rich log data across progress.ts' IPC - exporting logs to external tools for display/search/filtering in addition, `scope.tee` is introduced, which allows duplicating log output to another source, such as a file or to an external service. [^1]: custom metadata cannot be set with this change --- framework/hot.ts | 4 +- lib/log.ts | 565 ++++++++++++++++++++++++++++++++++++++---- lib/log/headless.ts | 345 -------------------------- lib/log/stack.ts | 9 +- lib/node.ts | 6 + lib/readme.changes.md | 13 + run.js | 4 +- 7 files changed, 547 insertions(+), 399 deletions(-) delete mode 100644 lib/log/headless.ts diff --git a/framework/hot.ts b/framework/hot.ts index 3695084aa3edbff84c537ad35fa75e8265e48355..3ba4d39ef6637261d0957424d78b3572613d9cd4 100644 --- a/framework/hot.ts +++ b/framework/hot.ts @@ -151,9 +151,9 @@ export function loadEsbuildCode( jsx: "automatic", jsxImportSource: "#jsx", jsxDev: true, - sourcefile: filepath, sourcemap: "inline", - sourceRoot: "/", + sourcefile: path.basename(filepath), + sourceRoot: path.dirname(filepath), }).code; return module._compile(src, filepath, "commonjs"); } diff --git a/lib/log.ts b/lib/log.ts index 2ac4ef49726dd87fd748e42c8e7d5558adbccaa5..7fc7751aaf9914286c8a3548ff39f42175255d48 100644 --- a/lib/log.ts +++ b/lib/log.ts @@ -1,28 +1,47 @@ /** - * By using `lib/log.ts`, your application gets easy scoped logging as well as + * by using `lib/log.ts`, your application gets easy scoped logging as well as * integration with terminal widgets such as `lib/progress.ts`. * - * The pattern for using this module is to shadow the global `console` with a - * local scope: + * the pattern for using this module is to shadow the global `console` with a + * per-file logging scope: * - * import * as log from "@clo/lib/log"; - * const console = log.scoped("http"); - * console("hi!"); // debug + * ```ts + * import * as log from "@clo/lib/log"; + * const console = log.scoped("http"); + * console.info("Hello world!"); // info message + * console.log("hi!"); // debug message only + * ``` * - * Or to use the global socpe, import the namespace as `console`. + * or to use the global scope, import the module's namespace as `console`. * - * import * as console from "@clo/lib/log"; + * ```ts + * import * as console from "@clo/lib/log"; + * ``` * - * Now, the code reads familiarly and output is organized. + * now, the code reads familiarly (`console.log` is universally understood), + * but the output is organized into relevant scopes. * - * This module offers a Node.js integration to have logs go to the standard - * output. Custom writers can be used with `lib/log/headless.ts`. + * in addition to static log messages, a system for interactive I/O + * {@linkcode Widget} is provided by calling {@linkcode startWidget}. these + * allow showing temporary or interactive information, such as program status + * or input prompts. a powerful example of this system in action is + * `lib/progress.ts`, which uses a log widget by default to show status. + * (TODO: widgets cannot recieve "input" data yet) + * + * this module offers two environment integrations: + * - in node.js, log messages are colored depending on the level and show + * widgets directly under the long using ANSI cursor controls. + * - otherwise, logs are surfaced using the global `console` API + * + * custom log integrations can be built on top of this module by calling + * `log.tee()` to duplicate all messages elsewhere. for example, a project may set up * * @module */ /** - * Logging scopes implement part of the `Console` API + * logging scopes implement part of the `Console` API. the `log` module itself + * satisfies this interface. */ export interface Scope { /** emit an informational message */ @@ -44,15 +63,33 @@ export interface Scope { /** create a nested sub-scope */ scoped(name: string): Scope; + /** redirect the logging output of this scope somewhere else */ + tee(writer: (message: Message) => void): ts.Dispose; } -/** custom scopes are colored based on the name */ -export function scoped(name: string): Scope { - return globalLog.scoped(name); +export const originalLogArgs = Symbol("originalLogArgs"); +export interface Message { + level: "error" | "warn" | "info" | "debug"; + /** ANSI-styled unicode text */ + text: string; + /** datetime in milliseconds since UNIX epoch */ + time: number; + /** scope name */ + scope?: string | null; + /** captured stack. */ + stack?: stack.Frame[]; + /** arbitrary data from the logging source. */ + custom?: Partial>; + /** + * original logging arguments, if present. this field is indexed by a symbol + * so that it is lost during JSON serialization, as callers are allowed to log + * non-serializable data. + */ + [originalLogArgs]?: unknown[]; } -// these functions implement `Scope`. If a function takes in `Scope`, the -// namespace import of this file can be passed to it. +// these functions implement `Scope` for the module's namespace. that means if +// a function takes in `Scope`, this file's namespace satisfies that. /** emit an informational message on the global log scope */ export function info(...args: unknown[]) { @@ -79,10 +116,34 @@ export function debug(...args: unknown[]) { globalLog.debug(...args); } +export function scoped(name: string): Scope { + return globalLog.scoped(name); +} + +/** + * a widget is an interactive display that persists at the end + * of the log. this can be used to implement status bars, progress + * indicators, and other human I/O. only 'format' is required. + * + * ```ts + * using _ = log.startWidget({ + * format: (now) => `It is ${new Date().toString()} right now\n` + * + `A random number: ${Math.random()}`, + * // no trailing '\n' is needed. + * }); + * await async.delay(10000); + * + * import * as log from "@clo/lib/log.ts"; + * import * as async from "@clo/lib/async.ts"; + * ``` + */ +export function startWidget(widget: Widget): ts.Dispose { + return globalWidgetHost.startWidget(widget); +} + /** * no built-in prefix or formatting. ensures the text does not interweave. data - * will be flushed in the next frame or when drawing is - * {@link getDrawLock|unlocked}. + * will be flushed in the next frame or when drawing is {@link getDrawLock|unlocked}. */ export function writeLine(text: string) { globalWidgetHost.writeLine(text); @@ -96,48 +157,403 @@ export function getDrawLock(): ts.Dispose { return globalWidgetHost.getDrawLock(); } -/** - * a widget is an interactive display that persists at the end - * of the log. this can be used to implement status bars, progress - * indicators, and other human i/o. only 'format' is required. - */ -export function startWidget(widget: Widget): ts.Dispose { - return globalWidgetHost.startWidget(widget); +export function headlessScope(dispatch: DispatchFunction): Scope { + return new Scope(dispatch); } +/** See {@linkcode startWidget} */ export interface Widget { /** * return the widget's text. return null to detach the widget. * may get called more often than the specified `fps`. * supports color codes but not ansi cursor movements. - */ - format(now: ReturnType): string | null; - /** 'null' to never update (use 'onChange'). defaults to 12 fps */ - fps?: number | null; - /** Subscribe to manual widget updates. Call `rerender` when needed. */ + */ format( + now: ReturnType, + ): + | string + | null; /** 'null' to never update (use 'onChange'). defaults to 12 fps */ + fps?: + | number + | null; /** Subscribe to manual widget updates. Call `rerender` when needed. */ onChange?(rerender: () => void): () => void; - // /** - // * listen for keyboard events. - // */ - // onKey?(key: string): void; + /** listen for keyboard events. */ + onKey?(key: string): void; } -const globalWidgetHost = /* @__PURE__ */ ((): headless.WidgetHost => { +/** {@linkcode widgetHost}'s input takes terminal i/o as well as timing APIs */ +export interface HeadlessWidgetEnv { + /** Recieves ANSI escape sequences for interactive data. */ + writeInteractive(text: string): void; + /** Recieves log content (from `writeLine`). */ + writeOutput(text: string): void; + /** Monotonic. */ + now(): ReturnType; + /** 0ms indicates "one frame". */ + wait(ms: number, cb: () => void): () => void; + /** Called often. */ + getSize(): { columns: number; rows: number }; + /** Called to enable input events */ + onInput?(write: (bytes: Uint8Array | string) => void): () => void; +} + +/** an implementation of an ANSI-based widget host */ +export interface HeadlessWidgetHost { + /** see the top-level {@linkcode writeLine} function */ + writeLine(text: string): void; + /** see the top-level {@linkcode getDrawLock} function */ + getDrawLock(): ts.Dispose; + /** see the top-level {@linkcode startWidget} function */ + startWidget(widget: Widget): ts.Dispose; + /** stop all widgets and remove all timers. */ + cancel(): void; +} + +interface WidgetState { + frameTime: number; + next: number; + unsub: (() => void) | null; +} + +/** + * terminal widget rendering is done by specifying all system APIs up front in + * an interface, creating an instance of the "widget host". + * + * some notes on widget rendering: + * - Never flush immediately (exception for + * {@linkcode WidgetHost["getDrawLock"]|getDrawLock}), always do it next tick. + * - Maximum of one `wait` call at once. When the expected time suddenly + * shrinks, the timer is rescheduled. + * - When redrawing widget lines, three tricks are done to reduce flickering: + * 1. Tell the terminal not to flicker (ansi.syncStart/syncEnd) + * 2. A simple prefix-based diffing algorithm for skipping unchanged text + * 3. Avoid clearing a line before redrawing it. + * Points 2 and 3 are used for terminals that are slow or do not support sync. + */ +export function headlessWidgetHost(env: HeadlessWidgetEnv): HeadlessWidgetHost { + const { writeOutput, writeInteractive, now, wait, getSize } = env; + type Cancel = ReturnType; + + let timer: Cancel | null = null; + + let locks = 0; + let redrawTime = 0; + let lastFlush = 0; + let buffer = ""; + const widgets: Widget[] = []; + const internals: WidgetState[] = []; + let lines: string[] = []; + + function redrawCallback() { + timer = null; + redrawTime = (lastFlush = now()) - 0.00001; // windows time precision workaround + + if (!lines.length && !widgets.length) { + buffer && writeOutput(buffer); + buffer = ""; + return; + } + + const { columns, rows } = getSize(); + let newWidgetLines: string[] = []; + let next = Infinity; + if (widgets[0]) { + for (let w = 0, { length } = widgets; w < length; w += 1) { + const outText = UNWRAP(widgets[w]).format(lastFlush); + if (!outText) { + widgets.splice(w, 1); + UNWRAP(internals.splice(w, 1)[0]).unsub?.(); + w -= 1; + length -= 1; + continue; + } + const rowsLeft = Math.max(1, rows - newWidgetLines.length - 1); + if (rowsLeft === 1) break; + const lines = outText.split("\n").slice(0, rowsLeft); + newWidgetLines.push( + ...lines.map((line) => ansi.trimToWidth(line, columns - 1)), + ); + + next = Math.min(next, UNWRAP(internals[w]).frameTime); + } + + newWidgetLines = newWidgetLines.slice(0, rows - 1); + } + + if (next < Infinity) redrawSoon(next); + + if (!newWidgetLines[0]) { + if (lines.length) { + let clearLinesTop = Math.min( + lines.length, + string.countNewlines(buffer), + ); + writeInteractive( + ansi.startOfLine + + // skip up the shared widget space + ansi.cursorUp(lines.length) + + // clear the lines to contain `buffer` + (ansi.clearFullLine + ansi.startOfNextLine) + .repeat(clearLinesTop) + + ansi.cursorUp(clearLinesTop), + ); + lines = []; + } + buffer && writeOutput(buffer); + buffer = ""; + return; + } + + if (buffer) { + // do not perform diffing since the entire screen is moving down + // TODO: should i handle wrapping? + let clearLinesTop = Math.min( + lines.length, + string.countNewlines(buffer), + ); + const oldLines = lines.slice(clearLinesTop); + writeInteractive( + ansi.syncStart + ansi.startOfLine + + // skip up the shared widget space + ansi.cursorUp(lines.length - clearLinesTop + 1) + + // clear the lines to contain `buffer` + ansi.clearFullLine + + (ansi.cursorUp(1) + ansi.clearFullLine) + .repeat(clearLinesTop - 1), + ); + // then write output lines on standard out + writeOutput(buffer); + writeInteractive( + // the widget text + newWidgetLines.map((newLine, i) => + (newLine.includes("\x1b") && !newLine.endsWith(ansi.reset) + ? newLine + ansi.reset + : newLine) + + // clear rest of line if needed + (oldLines[i] && + ansi.widthInTerminal(oldLines[i]) > + ansi.widthInTerminal(newLine) + ? ansi.clearToEndOfLine + : "") + + "\n" + ).join("") + ansi.syncEnd, + ); + } else { + const clearLinesBottom = Math.min( + lines.length, + Math.max(0, lines.length - (newWidgetLines?.length ?? 0)), + ); + writeInteractive( + ansi.syncStart + ansi.startOfLine + + // clear the bottom lines + (clearLinesBottom + ? (ansi.cursorUp(1) + ansi.clearToEndOfLine) + .repeat(clearLinesBottom) + : "") + + // skip up the widget space + ansi.cursorUp(lines.length - clearLinesBottom) + + // the widget text + newWidgetLines.map((newLine, i) => + (newLine.includes("\x1b") && !newLine.endsWith(ansi.reset) + ? newLine + ansi.reset + : newLine) + + // clear rest of line if needed + (lines[i] && + ansi.widthInTerminal(lines[i]) > + ansi.widthInTerminal(newLine) + ? ansi.clearToEndOfLine + : "") + + "\n" + ).join("") + + ansi.syncEnd, + ); + } + lines = newWidgetLines; + + buffer = ""; + } + + function redrawSoon(ms: number) { + if (locks > 0 || (ms === 0 && timer)) return; + const newRedrawTime = now() + ms; + if (timer) { + if (redrawTime < newRedrawTime) return; + timer(); // cancel previous + timer = null; + } + redrawTime = newRedrawTime + 1; + timer = wait(ms, redrawCallback); + } + + function flushAndClear() { + timer?.(); + timer = null; + if (lines.length > 0) { + // clear widgets + } + if (buffer.length > 0) writeOutput(buffer), buffer = ""; + } + + return { + writeLine(chunk) { + buffer += chunk + "\n"; + redrawSoon(0); + }, + getDrawLock() { + if (locks === 0) flushAndClear(); + locks += 1; + return ts.defer(() => { + locks -= 1; + if (locks === 0) { + if (buffer.length > 0) writeOutput(buffer), buffer = ""; + // TODO: reinit widget + } + }); + }, + startWidget(w) { + if (!widgets.includes(w)) { + const state: WidgetState = { + next: 0, + unsub: null, + frameTime: 1000 / (w.fps ?? 0), + }; + widgets.push(w); + internals.push(state); + state.unsub = w.onChange?.(() => { + state.next = 0; + redrawSoon(0); + }) ?? null; + redrawSoon(0); + } + return ts.defer(() => { + const i = widgets.indexOf(w); + widgets.splice(i, 1); + UNWRAP(internals.splice(i, 1)[0]).unsub?.(); + redrawSoon(0); + }); + }, + cancel() { + flushAndClear(); + }, + }; +} + +const logColors = node.process?.stderr.isTTY ?? false; + +let formatLine = /* @__PURE__ */ (() => { + const fwo = node.builtin("util")?.formatWithOptions; + if (fwo) return (...args: unknown[]) => fwo({ colors: logColors }, ...args); + return (...args: unknown[]) => + args.map((arg) => { + if (typeof arg === "string") return arg; + try { + return JSON.stringify(arg); + } catch { + return "[incompatible json " + typeof arg + "]"; + } + }).join(" "); +})(); + +let withinDispatch = false; +let withinStackCapture = false; + +const Scope = class Scope implements Scope { + name: string | undefined; + // TODO: this abstraction implementation has low performance. making every + // scope define it's own dispatch is needed to correctly implement `tee`. + // since it is possible to implement this in simple and non-recursive way, i + // feel okay adding the `tee` API. + #dispatches: DispatchFunction[] = []; + #dispatch: DispatchFunction = (m) => this.#dispatches.forEach((cb) => cb(m)); + + constructor( + dispatch: (m: Message) => void, + name: string | undefined = undefined, + ) { + this.name = name; + this.#dispatches = [dispatch]; + } + + #log(level: Message["level"], args: unknown[]) { + let frames; + if (!withinStackCapture) { + withinStackCapture = true; + frames = stack.capture().slice(2); + withinStackCapture = false; + } + const m = { + level, + scope: this.name, + get text() { + const value = formatLine(...args); + Object.defineProperty(this, "text", { value }); + return value; + }, + time: Date.now(), + stack: frames, + [originalLogArgs]: args, + }; + if (withinDispatch) return void globalOutputFunction(m); + withinDispatch = true; + this.#dispatch(m); + withinDispatch = false; + } + + info: (...args: unknown[]) => void = (...args: unknown[]) => { + this.#log("info", args); + }; + warn: (...args: unknown[]) => void = (...args: unknown[]) => { + this.#log("warn", args); + }; + error: (...args: unknown[]) => void = (...args: unknown[]) => { + this.#log("error", args); + }; + log: (...args: unknown[]) => void = (...args: unknown[]) => { + this.#log("debug", args); + }; + debug: (...args: unknown[]) => void = (...args: unknown[]) => { + this.#log("debug", args); + }; + + scoped(name: string): Scope { + const current = this.name; + return new Scope( + this.#dispatch, + name ? current ? `${current}/${name}` : name : current, + ); + } + + tee(destination: DispatchFunction) { + this.#dispatches.push(destination); + return ts.defer(() => + this.#dispatches.splice(this.#dispatches.indexOf(destination), 1) + ); + } +}; + +const globalWidgetHost = /* @__PURE__ */ (() => { + // TODO; write this in a tree-shakable manner const { process } = node; if (!process || !process.stderr.isTTY) { + // return a no-op + let warned = false; return { - // TODO: allow passing a level here - writeLine: (line) => console["log"](line), + writeLine: (line: string) => console.log(line), getDrawLock: () => ts.defer(() => {}), - startWidget: (w) => { + startWidget: (w: Widget) => { + if (!warned) { + console.warn( + '"@clo/lib/log.ts"\'s startWidget was called in an environment ' + + "that does not support the Node.js 'process' API. Widgets" + + "will not be visible.", + ); + } const close = w.onChange?.(() => {}); return ts.defer(close ?? (() => {})); }, cancel: () => {}, }; } - const widget = headless.widgetHost({ - // TODO:allow passing a level here to put debug, warn and errors on stderr + const widget = headlessWidgetHost({ writeOutput: (string) => process.stdout.write(string), writeInteractive: (string) => process.stderr.write(string), now: () => performance.now(), @@ -149,13 +565,70 @@ const globalWidgetHost = /* @__PURE__ */ ((): headless.WidgetHost => { }); process.addListener("beforeExit", () => widget.cancel()); process.addListener("exit", () => widget.cancel()); + + // Make sure the default `console` will not interweave with widgets + try { + const console = globalThis.console as unknown as Record; + for (const key of Object.keys(console)) { + const fn = console[key]; + if (typeof fn === "function") { + console[key] = function (...args: unknown[]) { + using _ = getDrawLock(); + fn.apply(this, args); + }; + } + } + } catch {} + return widget; })(); -const globalLog = /* @__PURE__ */ headless.logger({ - log: globalWidgetHost, - colors: node.process?.stderr.isTTY ?? false, -}); +const levelToAnsi: Record = { + info: `${ansi.fgBlue}info`, + warn: `${ansi.fgYellow}warn`, + error: `${ansi.fgRed}error`, + debug: `${ansi.dim}dbg`, +}; + +let globalOutputFunction!: DispatchFunction; +const globalLog = /* @__PURE__ */ (() => { + const colors = node.process?.stderr.isTTY ?? false; + globalOutputFunction = node.process + // In Node.js, coordinate with the widget host + ? ({ level, scope, text }) => { + if (!text) return globalWidgetHost.writeLine(""); + const prefix = colors + // colorful + ? `${levelToAnsi[level]}${ + scope ? `(${scope})` : "" + }${ansi.fgReset}${ansi.dim}:${ansi.reset} ` + // colorless + : scope + ? `${level}(${scope}): ` + : `${level}: `; + globalWidgetHost.writeLine(prefix + text); + } + // Otherwise, forward to `console` + : (m) => { + let { level, [originalLogArgs]: args = [m.text], scope } = m; + if (scope) { + const arg0 = args[0]; + const prefix = `[${scope}]`; + if (typeof arg0 === "string") args[0] = `${prefix} ${arg0}`; + else args.unshift(prefix); + } + console[level](...args); + }; + return new Scope(globalOutputFunction); +})(); + +export interface DispatchFunction { + (message: Message): void; +} + +import * as ansi from "lib/string/ansi.ts"; import * as node from "lib/node.ts"; -import * as headless from "lib/log/headless.ts"; +import * as stack from "lib/log/stack.ts"; +import * as string from "lib/string.ts"; import * as ts from "lib/ts.ts"; +import { UNWRAP } from "lib/assert.ts"; diff --git a/lib/log/headless.ts b/lib/log/headless.ts deleted file mode 100644 index 0d16bcc89523a5e34e0072b955904bdcfde733f2..0000000000000000000000000000000000000000 --- a/lib/log/headless.ts +++ /dev/null @@ -1,345 +0,0 @@ -/** - * terminal widget rendering and logging is done by specifying all system APIs up front in an - * interface, creating an instance of the widget host. `lib/log.ts` fufills - * this interface with `node:process` and `globalThis`. - * - * this file is under heavy construction. - * - I am happy with the overall API, likely no changes. - * - There are certainly a lot of bugs. - * - * some notes on widget rendering: - * - Never flush immediately (exception for - * {@linkcode WidgetHost["getDrawLock"]|getDrawLock}), always do it next tick. - * - Maximum of one `wait` call at once. When the expected time suddenly - * shrinks, the timer is rescheduled. - * - When redrawing widget lines, three tricks are done to reduce flickering: - * 1. Tell the terminal not to flicker (ansi.syncStart/syncEnd) - * 2. A simple prefix-based diffing algorithm for skipping unchanged text - * 3. Avoid clearing a line before redrawing it. - * Points 2 and 3 are used for terminals that are slow or do not support sync. - * - * @module - */ - -/** {@linkcode widgetHost}'s input takes terminal i/o as well as timing APIs */ -export interface WidgetHostEnv { - /** Recieves ANSI escape sequences for interactive data. */ - writeInteractive(text: string): void; - /** Recieves log content (from `writeLine`). */ - writeOutput(text: string): void; - /** Monotonic. */ - now(): ReturnType; - /** 0ms indicates "one frame". */ - wait(ms: number, cb: () => void): () => void; - /** Called often. */ - getSize(): { columns: number; rows: number }; - // onInput?(write: (bytes: Uint8Array | string) => void): () => void; -} - -/** Returned by {@linkcode widgetHost} */ -export interface WidgetHost { - /** - * no built-in prefix or formatting. ensures the text does not interweave - * with widgets. data will be flushed in the next frame or when drawing is - * unlocked. - */ - writeLine(text: string): void; - /** - * while locked, no widgets will draw. prefer `writeLine`. - * this lock is not exclusive. - */ - getDrawLock(): ts.Dispose; - /** - * a widget is an interactive display that persists at the end - * of the log. this can be used to implement status bars, progress - * indicators, and other human i/o. only `format` is required. - */ - startWidget(widget: log.Widget): ts.Dispose; - /** stop all widgets and remove all timers. */ - cancel(): void; -} - -interface WidgetState { - frameTime: number; - next: number; - unsub: (() => void) | null; -} - -/** Implement a widget host by providing an environment implementation. */ -export function widgetHost(env: WidgetHostEnv): WidgetHost { - const { writeOutput, writeInteractive, now, wait, getSize } = env; - type Cancel = ReturnType; - - let timer: Cancel | null = null; - - let locks = 0; - let redrawTime = 0; - let lastFlush = 0; - let buffer = ""; - const widgets: log.Widget[] = []; - const internals: WidgetState[] = []; - let lines: string[] = []; - - function redrawCallback() { - timer = null; - redrawTime = (lastFlush = now()) - 0.00001; // windows time precision workaround - - if (!lines.length && !widgets.length) { - buffer && writeOutput(buffer); - buffer = ""; - return; - } - - const { columns, rows } = getSize(); - let newWidgetLines: string[] = []; - let next = Infinity; - if (widgets[0]) { - for (let w = 0, { length } = widgets; w < length; w += 1) { - const outText = UNWRAP(widgets[w]).format(lastFlush); - if (!outText) { - widgets.splice(w, 1); - UNWRAP(internals.splice(w, 1)[0]).unsub?.(); - w -= 1; - length -= 1; - continue; - } - const rowsLeft = Math.max(1, rows - newWidgetLines.length - 1); - if (rowsLeft === 1) break; - const lines = outText.split("\n").slice(0, rowsLeft); - newWidgetLines.push( - ...lines.map((line) => ansi.trimToWidth(line, columns - 1)), - ); - - next = Math.min(next, UNWRAP(internals[w]).frameTime); - } - - newWidgetLines = newWidgetLines.slice(0, rows - 1); - } - - if (next < Infinity) redrawSoon(next); - - if (!newWidgetLines[0]) { - if (lines.length) { - let clearLinesTop = Math.min( - lines.length, - string.countNewlines(buffer), - ); - writeInteractive( - ansi.startOfLine + - // skip up the shared widget space - ansi.cursorUp(lines.length) + - // clear the lines to contain `buffer` - (ansi.clearFullLine + ansi.startOfNextLine) - .repeat(clearLinesTop) + - ansi.cursorUp(clearLinesTop), - ); - lines = []; - } - buffer && writeOutput(buffer); - buffer = ""; - return; - } - - if (buffer) { - // do not perform diffing since the entire screen is moving down - // TODO: should i handle wrapping? - let clearLinesTop = Math.min( - lines.length, - string.countNewlines(buffer), - ); - const oldLines = lines.slice(clearLinesTop); - writeInteractive( - ansi.syncStart + ansi.startOfLine + - // skip up the shared widget space - ansi.cursorUp(lines.length - clearLinesTop + 1) + - // clear the lines to contain `buffer` - ansi.clearFullLine + - (ansi.cursorUp(1) + ansi.clearFullLine) - .repeat(clearLinesTop - 1), - ); - // then write output lines on standard out - writeOutput(buffer); - writeInteractive( - // the widget text - newWidgetLines.map((newLine, i) => - (newLine.includes("\x1b") && !newLine.endsWith(ansi.reset) - ? newLine + ansi.reset - : newLine) + - // clear rest of line if needed - (oldLines[i] && - ansi.widthInTerminal(oldLines[i]) > - ansi.widthInTerminal(newLine) - ? ansi.clearToEndOfLine - : "") + - "\n" - ).join("") + ansi.syncEnd, - ); - } else { - const clearLinesBottom = Math.min( - lines.length, - Math.max(0, lines.length - (newWidgetLines?.length ?? 0)), - ); - writeInteractive( - ansi.syncStart + ansi.startOfLine + - // clear the bottom lines - (clearLinesBottom - ? (ansi.cursorUp(1) + ansi.clearToEndOfLine) - .repeat(clearLinesBottom) - : "") + - // skip up the widget space - ansi.cursorUp(lines.length - clearLinesBottom) + - // the widget text - newWidgetLines.map((newLine, i) => - (newLine.includes("\x1b") && !newLine.endsWith(ansi.reset) - ? newLine + ansi.reset - : newLine) + - // clear rest of line if needed - (lines[i] && - ansi.widthInTerminal(lines[i]) > - ansi.widthInTerminal(newLine) - ? ansi.clearToEndOfLine - : "") + - "\n" - ).join("") + - ansi.syncEnd, - ); - } - lines = newWidgetLines; - - buffer = ""; - } - - function redrawSoon(ms: number) { - if (locks > 0 || (ms === 0 && timer)) return; - const newRedrawTime = now() + ms; - if (timer) { - if (redrawTime < newRedrawTime) return; - timer(); // cancel previous - timer = null; - } - redrawTime = newRedrawTime + 1; - timer = wait(ms, redrawCallback); - } - - function flushAndClear() { - timer?.(); - timer = null; - if (lines.length > 0) { - // clear widgets - } - if (buffer.length > 0) writeOutput(buffer), buffer = ""; - } - - return { - writeLine(chunk) { - buffer += chunk + "\n"; - redrawSoon(0); - }, - getDrawLock() { - if (locks === 0) flushAndClear(); - locks += 1; - return ts.defer(() => { - locks -= 1; - if (locks === 0) { - if (buffer.length > 0) writeOutput(buffer), buffer = ""; - // TODO: reinit widget - } - }); - }, - startWidget(w) { - if (!widgets.includes(w)) { - const state: WidgetState = { - next: 0, - unsub: null, - frameTime: 1000 / (w.fps ?? 0), - }; - widgets.push(w); - internals.push(state); - state.unsub = w.onChange?.(() => { - state.next = 0; - redrawSoon(0); - }) ?? null; - redrawSoon(0); - } - return ts.defer(() => { - const i = widgets.indexOf(w); - widgets.splice(i, 1); - UNWRAP(internals.splice(i, 1)[0]).unsub?.(); - redrawSoon(0); - }); - }, - cancel() { - flushAndClear(); - }, - }; -} - -/** Input interface for {@linkcode logger} */ -export interface LoggerOptions { - /** Provide either a line writer or a log writer. */ - log: { - writeLine: WidgetHost["writeLine"]; - } | { - writeLog: (prefix: string, level: Level, ...args: unknown[]) => void; - }; - colors: boolean; -} - -/** Implement a logging scope by providing an environment interface. */ -export function logger(env: LoggerOptions): log.Scope { - const { colors, log } = env; - const levels = colors - ? [ - ansi.style(ansi.fgBlue, "info"), - ansi.style(ansi.fgYellow, "warn"), - ansi.style(ansi.fgRed, "error"), - ] as const - : ["info", "warn", "error"] as const; - const colon = colors ? ansi.style(ansi.fgBrightBlack, ":") + " " : ": "; - const logFn = "writeLog" in log - ? log.writeLog - : ((prefix: string, level: Level, ...args: unknown[]) => { - if (args.length === 0) return log.writeLine(""); - const start = prefix - ? prefix + (level > 0 ? levels[level] + colon : "") - : (levels[level] + colon); - // TODO: make a more general "inspect" function - if (args[0] instanceof Error) { - log.writeLine(start + stack.format(args[0], colors)); - } else { - log.writeLine(start + util.format(...args)); - } - }); - - function scoped(name: string): log.Scope { - const formatted = name ? name + colon : name; - const fn = logFn.bind(null, formatted, 0) as Partial; - // TODO: repair - fn.info = fn as log.Scope["info"]; - fn.debug = fn as log.Scope["info"]; - fn.log = fn as log.Scope["info"]; - fn.warn = logFn.bind(null, formatted, 1); - fn.error = logFn.bind(null, formatted, 2); - fn.scoped = createSubScope; - Object.defineProperty(fn, "name", { value: name }); - return fn as log.Scope; - } - - function createSubScope(this: log.Scope, name: string) { - // @ts-ignore - const { name: parent } = this; - return scoped(parent ? parent + "/" + name : name); - } - - return scoped(""); -} - -type Level = 0 | 1 | 2; - -import * as ansi from "lib/string/ansi.ts"; -import * as string from "lib/string.ts"; -import * as ts from "lib/ts.ts"; -import * as stack from "lib/log/stack.ts"; -import * as util from "node:util"; -import { UNWRAP } from "lib/assert.ts"; -import type * as log from "lib/log.ts"; diff --git a/lib/log/stack.ts b/lib/log/stack.ts index 72c5f5da183f19eef47a6a21908d72500a373f0a..9fe72879dd165668a41b3dc805a70930c1f1b2be 100644 --- a/lib/log/stack.ts +++ b/lib/log/stack.ts @@ -25,7 +25,7 @@ * @module */ -/** Retrieved from `parse` */ +/** retrieved from `parse` */ export interface Frame { /** `null` if top-level code or unnamed function. */ fn: string | null; @@ -45,10 +45,11 @@ export interface Frame { * derived from stacktracejs. this file is more refined than those two: * https://github.com/oven-sh/bun/blob/b5f31a6ee2f52ea67eabeb61f6e6e71215d55b26/src/bake/client/stack-trace.ts * https://github.com/stacktracejs/error-stack-parser/blob/9f33c224b5d7b607755eb277f9d51fcdb7287e24/error-stack-parser.js - */ -/** + * * supports parsing v8, JavaScriptCore, SpiderMonkey, and IE error stack - * frames, effectively working in every JavaScript environment. + * frames, effectively working in every JavaScript environment. leaves + * filesystem urls and paths intact (won't convert 'file:///' to or from a file + * path) */ export function parse(error: Error | string): Frame[] | null { const stack = (error as Error)?.stack ?? error; diff --git a/lib/node.ts b/lib/node.ts index 87d34f0de6e7f776f6366a42ecebdaed287a5541..0ab1922b59eb0132dbfca554435135ea874a9f29 100644 --- a/lib/node.ts +++ b/lib/node.ts @@ -47,6 +47,12 @@ interface Builtins { join(...parts: string[]): string; sep: string; }; + "util": { + formatWithOptions( + options: { colors?: boolean }, + ...args: unknown[] + ): string; + }; } /** * Subset of Node.js binding types diff --git a/lib/readme.changes.md b/lib/readme.changes.md index b55c93839a1dee23bc165b8a58e02aec7d2a2730..3594cb7cb7df1ee64b7e5ea5611b529419662230 100644 --- a/lib/readme.changes.md +++ b/lib/readme.changes.md @@ -5,6 +5,19 @@ ### breaking - promote `log/progress.ts` to top level `progress.ts` +- rework Log dispatching + - delete `log/headless.ts` by moving it into `log` + - headless scopes now emit `log.Message` objects instead of ANSI text, + templating is done in the consumer of the headless logging scope. + +### features + +- add `log.tee` (and `log.Scope.tee`) +- `log` in Node.js will inject into `console.*` to prevent interweaving logs + with widget output text. this injection is enabled regardless of if widgets + are actually running, but do not otherwise change their behavior. +- `log` scopes render differently in the terminal now +- `log` in the browser will call the correct ## v2 diff --git a/run.js b/run.js index f93c2ad28d2af0e0768c2d7b8f6616ad667f072e..89465a89fde98a3898e3750ff566ae90d1a2d028 100644 --- a/run.js +++ b/run.js @@ -45,8 +45,8 @@ const log = hot.load("./lib/log.ts"); console.info = log.info; console.warn = log.warn; console.error = log.error; -console.debug = log.scoped("debug"); -console["log"] = console.debug; +console.debug = log.debug; +console["log"] = log.log; process.on("uncaughtException", (error) => { console.error(error); -- 2.54.0