diff --git a/.gitignore b/.gitignore new file mode 100644 index 0000000..40b878d --- /dev/null +++ b/.gitignore @@ -0,0 +1 @@ +node_modules/ \ No newline at end of file diff --git a/BENCH.md b/BENCH.md new file mode 100644 index 0000000..30d1a4a --- /dev/null +++ b/BENCH.md @@ -0,0 +1,49 @@ +## Benchmarks +[<-- Back to README](./README.md) + +Deno 2.4.1 can't find my CPU for some reason. + +Ran with an AMD Ryzen 7 5800X @ 3.6GHz + +`benchmark/deno.ts`: +``` +| benchmark | time/iter (avg) | iter/s | (min … max) | p75 | p99 | p995 | +| ----------- | --------------- | ------------- | --------------------- | -------- | -------- | -------- | + +group timing-sync +| 1 Log | 1.6 µs | 643,000 | ( 1.5 µs … 1.9 µs) | 1.5 µs | 1.9 µs | 1.9 µs | +| 100 Logs | 153.4 µs | 6,520 | (147.1 µs … 279.5 µs) | 150.2 µs | 229.9 µs | 234.5 µs | +| 1k Logs | 1.5 ms | 650.2 | ( 1.5 ms … 1.7 ms) | 1.6 ms | 1.7 ms | 1.7 ms | +| 10k Logs | 15.4 ms | 65.0 | ( 15.2 ms … 16.1 ms) | 15.4 ms | 16.1 ms | 16.1 ms | +| 100k Logs | 153.5 ms | 6.5 | (152.9 ms … 154.8 ms) | 153.7 ms | 154.8 ms | 154.8 ms | + +summary + 1 Log + 98.62x faster than 100 Logs + 989.00x faster than 1k Logs + 9887x faster than 10k Logs + 98680x faster than 100k Logs + +group timing-deferred +| 1 Log | 1.6 µs | 644,200 | ( 1.5 µs … 1.6 µs) | 1.6 µs | 1.6 µs | 1.6 µs | +| 100 Logs | 153.2 µs | 6,525 | (147.5 µs … 269.1 µs) | 150.6 µs | 228.1 µs | 230.8 µs | +| 1k Logs | 1.5 ms | 653.9 | ( 1.5 ms … 1.7 ms) | 1.6 ms | 1.6 ms | 1.6 ms | +| 10k Logs | 15.3 ms | 65.3 | ( 15.2 ms … 15.7 ms) | 15.3 ms | 15.7 ms | 15.7 ms | +| 100k Logs | 153.7 ms | 6.5 | (152.9 ms … 155.9 ms) | 154.0 ms | 155.9 ms | 155.9 ms | + +summary + 1 Log + 98.72x faster than 100 Logs + 985.10x faster than 1k Logs + 9865x faster than 10k Logs + 99040x faster than 100k Logs +``` + +### TL;DR / What does this mean? + +You can, *in theory* and *on average*, construct 650,000 messages per second. + +I don't know how to benchmark a logger without logging messages to stdout,
+so I created a dedicated `bench` function on each source that just *constructs* them. + +Deferred is not really much faster, but can be helpful in some scenarios. I think. Maybe. \ No newline at end of file diff --git a/README.md b/README.md index bf7fab7..e20c53c 100644 --- a/README.md +++ b/README.md @@ -66,7 +66,7 @@ Callback ran when a message is logged anywhere (this time components are split u ```ts LoggingListeners.onmsg('type', (msg, type, source, time) => { // msg: string - // type: MessageType - import { MessageType } from "@proxnet/undead-logging";) + // type: MessageType - import { MessageType } from "@proxnet/undead-logging"; // source: string // time: Date }); @@ -74,25 +74,26 @@ LoggingListeners.onmsg('type', (msg, type, source, time) => { Remove callback: ```ts -const cb = msg => { /* do something with msg */ }; +const cb = msg => { /* do something with msg: string */ }; LoggingListeners.onmsg('basic', cb); LoggingListeners.offmsg('basic', cb); ``` ## Time display modes -You can display three different formats for time: +You can display four different formats for time: * UTC * Unix time (in milliseconds) -* Local [process] time (in seconds, from the `performance` API) +* Local [process] time (in milliseconds, from the `performance` API) +* RoundedLocal: Same as above, but rounded to the nearest whole ms Set the time format: ```ts import { LoggingConfiguration, TimeFormat } from "@proxnet/undead-logging"; -LoggingConfiguration.timeFormat = TimeFormat.Local +LoggingConfiguration.timeFormat = TimeFormat.Local; // or -LoggingConfiguration.timeFormat = TimeFormat.Utc +LoggingConfiguration.timeFormat = TimeFormat.Utc; ``` ## (advanced) Logging timing @@ -101,6 +102,14 @@ You can control when log functions are executed using `LoggingConfiguration.logT Logs are sent synchronously by default. You can optionally defer logs with `setImmediate` using `LogTiming.Deferred` ```ts -LoggingConfiguration.logTiming = LogTiming.Sync -LoggingConfiguration.logTiming = LogTiming.Deferred -``` \ No newline at end of file +LoggingConfiguration.logTiming = LogTiming.Sync; +// or +LoggingConfiguration.logTiming = LogTiming.Deferred; +``` + +## [Benchmarks](./BENCH.md) + +## Contributing +Are you crazy? This ol' thing is just.. "meh" at most. You're sure? + +... anyway, create an account on gitea.proxnet.dev, fork, then PR. \ No newline at end of file diff --git a/benchmark/bun.ts b/benchmark/bun.ts new file mode 100644 index 0000000..9f0e93b --- /dev/null +++ b/benchmark/bun.ts @@ -0,0 +1,64 @@ +import chalk from "chalk"; +import Logging, { MessageType } from "../mod.ts"; + +interface BenchStats { + avg: number, + med: number, + rng: number, + min: number, + max: number, +} + +function createBench(n: number) { + const log = new Logging("Bench"); + const data: number[] = []; + + for (let i = 0; i < 30; i++) { + const last = performance.now(); + for (let i = 0; i < n; i++) + log.bench(MessageType.Info, chalk.black, 'a'); + data.push(performance.now() - last); + } + + const sorted = [...data].sort((a, b) => a - b); + return { + n, + avg: data.reduce((sum, val) => sum + val, 0) / data.length, + med: sorted.length % 2 === 0 + ? (sorted[sorted.length / 2 - 1] + sorted[sorted.length / 2]) / 2 + : sorted[Math.floor(sorted.length / 2)], + rng: Math.max(...data) - Math.min(...data), + min: Math.min(...data), + max: Math.max(...data) + } as BenchStats; +} + +const benches = [ + createBench(1), + createBench(100), + createBench(1000), + createBench(10000), + createBench(100000), +]; + +function trimNumber(n: number) { + const split = n.toString().split('.'); + if (!split[1]) return n; + else if (split[1].length > 4) return `${split[0]}.${split[1].substring(0, 4)}`; + else if (split[1].length == 0) return n.toString(); + else return split.join('.'); +} + +for (const stats of benches) { + for (const value of Object.values(stats)) { + + const label = value < 1 ? 'µs' : 'ms'; + const val = value < 1 ? value * 1000 : value; + + const i = Object.values(stats).indexOf(value); + const key = Object.keys(stats).find((_val, index) => index == i); + + console.log(`${key}: ${trimNumber(val)}${key !== 'n' ? label : ''}`); + } + console.log(''); +} \ No newline at end of file diff --git a/benchmark/deno-example.json b/benchmark/deno-example.json new file mode 100644 index 0000000..ab79b42 --- /dev/null +++ b/benchmark/deno-example.json @@ -0,0 +1,227 @@ +{ + "version": 1, + "runtime": "Deno/2.4.1 x86_64-pc-windows-msvc", + "cpu": "unknown", + "benches": [ + { + "origin": "file:///C:/Users/Keagan/undead-logging/benchmark/deno.ts", + "group": "timing-sync", + "name": "1 Log", + "baseline": false, + "results": [ + { + "ok": { + "n": 42, + "min": 1547.66, + "max": 1867.93, + "avg": 1596.3097619047621, + "p75": 1602.51, + "p99": 1867.93, + "p995": 1867.93, + "p999": 1867.93, + "highPrecision": false, + "usedExplicitTimers": false + } + } + ] + }, + { + "origin": "file:///C:/Users/Keagan/undead-logging/benchmark/deno.ts", + "group": "timing-sync", + "name": "100 Logs", + "baseline": false, + "results": [ + { + "ok": { + "n": 3227, + "min": 149200.0, + "max": 277100.0, + "avg": 155426.0, + "p75": 151700.0, + "p99": 230500.0, + "p995": 233300.0, + "p999": 250500.0, + "highPrecision": true, + "usedExplicitTimers": false + } + } + ] + }, + { + "origin": "file:///C:/Users/Keagan/undead-logging/benchmark/deno.ts", + "group": "timing-sync", + "name": "1k Logs", + "baseline": false, + "results": [ + { + "ok": { + "n": 332, + "min": 1492200.0, + "max": 2041200.0, + "avg": 1553763.0, + "p75": 1581400.0, + "p99": 1678900.0, + "p995": 1847700.0, + "p999": 2041200.0, + "highPrecision": true, + "usedExplicitTimers": false + } + } + ] + }, + { + "origin": "file:///C:/Users/Keagan/undead-logging/benchmark/deno.ts", + "group": "timing-sync", + "name": "10k Logs", + "baseline": false, + "results": [ + { + "ok": { + "n": 43, + "min": 15433100.0, + "max": 15875500.0, + "avg": 15512717.0, + "p75": 15516000.0, + "p99": 15875500.0, + "p995": 15875500.0, + "p999": 15875500.0, + "highPrecision": true, + "usedExplicitTimers": false + } + } + ] + }, + { + "origin": "file:///C:/Users/Keagan/undead-logging/benchmark/deno.ts", + "group": "timing-sync", + "name": "100k Logs", + "baseline": false, + "results": [ + { + "ok": { + "n": 14, + "min": 154448800.0, + "max": 162192300.0, + "avg": 156260422.0, + "p75": 156585200.0, + "p99": 162192300.0, + "p995": 162192300.0, + "p999": 162192300.0, + "highPrecision": true, + "usedExplicitTimers": false + } + } + ] + }, + { + "origin": "file:///C:/Users/Keagan/undead-logging/benchmark/deno.ts", + "group": "timing-deferred", + "name": "1 Log", + "baseline": false, + "results": [ + { + "ok": { + "n": 42, + "min": 1553.59, + "max": 1623.61, + "avg": 1581.7592857142856, + "p75": 1594.76, + "p99": 1623.61, + "p995": 1623.61, + "p999": 1623.61, + "highPrecision": false, + "usedExplicitTimers": false + } + } + ] + }, + { + "origin": "file:///C:/Users/Keagan/undead-logging/benchmark/deno.ts", + "group": "timing-deferred", + "name": "100 Logs", + "baseline": false, + "results": [ + { + "ok": { + "n": 3205, + "min": 148800.0, + "max": 357900.0, + "avg": 156507.0, + "p75": 152200.0, + "p99": 233300.0, + "p995": 241400.0, + "p999": 273500.0, + "highPrecision": true, + "usedExplicitTimers": false + } + } + ] + }, + { + "origin": "file:///C:/Users/Keagan/undead-logging/benchmark/deno.ts", + "group": "timing-deferred", + "name": "1k Logs", + "baseline": false, + "results": [ + { + "ok": { + "n": 330, + "min": 1504500.0, + "max": 1744900.0, + "avg": 1564083.0, + "p75": 1595100.0, + "p99": 1668200.0, + "p995": 1732400.0, + "p999": 1744900.0, + "highPrecision": true, + "usedExplicitTimers": false + } + } + ] + }, + { + "origin": "file:///C:/Users/Keagan/undead-logging/benchmark/deno.ts", + "group": "timing-deferred", + "name": "10k Logs", + "baseline": false, + "results": [ + { + "ok": { + "n": 43, + "min": 15435800.0, + "max": 15980800.0, + "avg": 15641247.0, + "p75": 15771900.0, + "p99": 15980800.0, + "p995": 15980800.0, + "p999": 15980800.0, + "highPrecision": true, + "usedExplicitTimers": false + } + } + ] + }, + { + "origin": "file:///C:/Users/Keagan/undead-logging/benchmark/deno.ts", + "group": "timing-deferred", + "name": "100k Logs", + "baseline": false, + "results": [ + { + "ok": { + "n": 14, + "min": 154775900.0, + "max": 159622500.0, + "avg": 156075222.0, + "p75": 156708400.0, + "p99": 159622500.0, + "p995": 159622500.0, + "p999": 159622500.0, + "highPrecision": true, + "usedExplicitTimers": false + } + } + ] + } + ] +} \ No newline at end of file diff --git a/benchmark/deno.ts b/benchmark/deno.ts new file mode 100644 index 0000000..74127c2 --- /dev/null +++ b/benchmark/deno.ts @@ -0,0 +1,109 @@ +import Logging, { LogTiming, MessageType } from "@proxnet/undead-logging"; +import chalk from "chalk"; + +// SYNC + +Deno.bench({ + name: "1 Log", + group: "timing-sync", + fn: () => { + const log = new Logging("Bench"); + log.bench(MessageType.Info, chalk.black, 'a'); + } +}); + +Deno.bench({ + name: "100 Logs", + group: "timing-sync", + fn: () => { + const log = new Logging("Bench"); + for (let i = 0; i < 100; i++) + log.bench(MessageType.Info, chalk.black, 'a'); + } +}); + +Deno.bench({ + name: "1k Logs", + group: "timing-sync", + fn: () => { + const log = new Logging("Bench"); + for (let i = 0; i < 1_000; i++) + log.bench(MessageType.Info, chalk.black, 'a'); + } +}); + +Deno.bench({ + name: "10k Logs", + group: "timing-sync", + fn: () => { + const log = new Logging("Bench"); + for (let i = 0; i < 10_000; i++) + log.bench(MessageType.Info, chalk.black, 'a'); + } +}); + +Deno.bench({ + name: "100k Logs", + group: "timing-sync", + fn: () => { + const log = new Logging("Bench"); + log.logTiming = LogTiming.Deferred; + for (let i = 0; i < 100_000; i++) + log.bench(MessageType.Info, chalk.black, 'a'); + } +}); + +// DEFERRED + +Deno.bench({ + name: "1 Log", + group: "timing-deferred", + fn: () => { + const log = new Logging("Bench"); + log.logTiming = LogTiming.Deferred; + log.bench(MessageType.Info, chalk.black, 'a'); + } +}); + +Deno.bench({ + name: "100 Logs", + group: "timing-deferred", + fn: () => { + const log = new Logging("Bench"); + log.logTiming = LogTiming.Deferred; + for (let i = 0; i < 100; i++) + log.bench(MessageType.Info, chalk.black, 'a'); + } +}); + +Deno.bench({ + name: "1k Logs", + group: "timing-deferred", + fn: () => { + const log = new Logging("Bench"); + log.logTiming = LogTiming.Deferred; + for (let i = 0; i < 1_000; i++) + log.bench(MessageType.Info, chalk.black, 'a'); + } +}); + +Deno.bench({ + name: "10k Logs", + group: "timing-deferred", + fn: () => { + const log = new Logging("Bench"); + log.logTiming = LogTiming.Deferred; + for (let i = 0; i < 10_000; i++) + log.bench(MessageType.Info, chalk.black, 'a'); + } +}); + +Deno.bench({ + name: "100k Logs", + group: "timing-deferred", + fn: () => { + const log = new Logging("Bench"); + for (let i = 0; i < 100_000; i++) + log.bench(MessageType.Info, chalk.black, 'a'); + } +}); \ No newline at end of file diff --git a/deno.json b/deno.json index 6096327..e6f4fe4 100644 --- a/deno.json +++ b/deno.json @@ -1,14 +1,19 @@ { "tasks": { "debug": "deno run -A test.ts true", - "plain": "deno run -A test.ts" + "plain": "deno run -A test.ts", + "dev": "deno run plain", + "bench": "deno bench -A" }, "imports": { "@std/assert": "jsr:@std/assert@1", "chalk": "npm:chalk@^5.3.0" }, "exports": "./mod.ts", - "version": "1.3.0", + "version": "1.4.0", "name": "@proxnet/undead-logging", - "license": "MIT" + "license": "MIT", + "bench": { + "include": ["./benchmark/deno.ts"] + } } diff --git a/deno.lock b/deno.lock index d86c006..a4cb8a4 100644 --- a/deno.lock +++ b/deno.lock @@ -1,24 +1,34 @@ { - "version": "4", + "version": "5", "specifiers": { - "jsr:@std/assert@1": "1.0.8", - "jsr:@std/internal@^1.0.5": "1.0.5", - "npm:chalk@^5.3.0": "5.3.0" + "jsr:@std/assert@1": "1.0.13", + "jsr:@std/internal@^1.0.6": "1.0.9", + "npm:@types/node@*": "22.15.15", + "npm:chalk@^5.3.0": "5.4.1" }, "jsr": { - "@std/assert@1.0.8": { - "integrity": "ebe0bd7eb488ee39686f77003992f389a06c3da1bbd8022184804852b2fa641b", + "@std/assert@1.0.13": { + "integrity": "ae0d31e41919b12c656c742b22522c32fb26ed0cba32975cb0de2a273cb68b29", "dependencies": [ "jsr:@std/internal" ] }, - "@std/internal@1.0.5": { - "integrity": "54a546004f769c1ac9e025abd15a76b6671ddc9687e2313b67376125650dc7ba" + "@std/internal@1.0.9": { + "integrity": "bdfb97f83e4db7a13e8faab26fb1958d1b80cc64366501af78a0aee151696eb8" } }, "npm": { - "chalk@5.3.0": { - "integrity": "sha512-dLitG79d+GV1Nb/VYcCDFivJeK1hiukt9QjRNVOsUtTy1rR1YJsmpGGTZ3qJos+uw7WmWF4wUwBd9jxjocFC2w==" + "@types/node@22.15.15": { + "integrity": "sha512-R5muMcZob3/Jjchn5LcO8jdKwSCbzqmPB6ruBxMcf9kbxtniZHP327s6C37iOfuw8mbKK3cAQa7sEl7afLrQ8A==", + "dependencies": [ + "undici-types" + ] + }, + "chalk@5.4.1": { + "integrity": "sha512-zgVZuo2WcZgfUEmsn6eO3kINexW8RAE4maiQ8QNs8CtpPCSyMiYsULR3HQYkm3w8FIA3SberyMJMSldGsW+U3w==" + }, + "undici-types@6.21.0": { + "integrity": "sha512-iwDZqg0QAGrg9Rav5H4n0M64c3mkR59cJ6wQp+7C4nI0gsmExaedaYLNO44eT4AtBBwjbTiGPMlt2Md0T9H9JQ==" } }, "workspace": { diff --git a/mod.ts b/mod.ts index c134ad3..559488e 100644 --- a/mod.ts +++ b/mod.ts @@ -1,14 +1,25 @@ import chalk from "chalk"; import { setImmediate } from "node:timers"; +import process from "node:process"; -type ChalkFunction = (...msgs: unknown[]) => string; -type PrimitiveItems = unknown[]; +type Message = unknown; +type ChalkFunction = (...msgs: Message[]) => string; +type PrimitiveItems = Message[]; interface UnknownConversion { - condition: (arg: unknown) => boolean; + condition: (arg: Message) => boolean; converter: (arg: T) => string; } +interface WebLike { + url?: string, + headers?: Headers, + method?: string +} + +/** The first log message across all sources will not contain carriage return + newline control codes */ +let first = true; + /** * A source for pretty and cool and fun logging */ @@ -21,6 +32,11 @@ class Logging { /** Should I use bright colors over dull ones? */ bright: boolean = true; + /** Control when logs are handled for this source - similar (defaults to) `LoggingConfiguration.logTiming` */ + logTiming: LogTiming = LoggingConfiguration.logTiming; + /** Control how time is displayed for this source - similar (defaults to) `LoggingConfiguration.timeFormat` */ + timeFormat: TimeFormat = LoggingConfiguration.timeFormat; + /** * Create a logging source * ```ts @@ -29,8 +45,8 @@ class Logging { * log.i("Hello World!"); * ``` * @param source Module identifier. Used in every line to identify the module that sent the message. - * @param silent Set to false to log a message when the logger instantiates. Useful for debugging. - * @returns A source for logging messages to the console. Functions for info, warnings, errors, debug statements, and network events are provided and have shorthands. + * @param silent Set to false to log a message when the logger instantiates. May be useful when debugging. + * @returns A source for logging messages to the console (stdout). Functions for info, warnings, errors, debug statements, and network events are provided and have shorthands. */ constructor(source: string, silent?: boolean, bright?: boolean) { this.visible = true; @@ -40,81 +56,130 @@ class Logging { if (typeof silent == 'boolean' && !silent) this.info(`Instantiated logging for ${this.source}`); } + #conversions(...msgs: PrimitiveItems) { + const conversions = [ + { + condition: arg => arg instanceof Error, + converter: arg => arg.stack || arg.message + } as UnknownConversion, + { + condition: arg => arg == null, + converter: arg => JSON.stringify(arg) + } as UnknownConversion, + { + condition: arg => arg == undefined, + converter: _arg => 'undefined' + } as UnknownConversion, + { + condition: arg => arg instanceof Response, + converter: arg => { + try { + const url = arg.url.toString().length == 0 ? '(unknown origin) ' : new URL(arg.url); + const statusText = arg.statusText.length > 0 ? `${arg.statusText} ` : ''; + + const shouldNewline = Array.from(arg.headers.keys()).length > 0; + const entries = Array.from(arg.headers.entries()); + return ( + `${arg.status} ${statusText}${url}${shouldNewline ? '\n ' : ''}` + + entries.map(val => `${val[0]}: ${val[1]}`).join(`\n `) + ); + } catch { + return String(arg); + } + } + } as UnknownConversion, + { + condition: arg => arg instanceof Request, + converter: arg => { + try { + const url = new URL(arg.url); + const shouldNewline = Array.from(arg.headers.keys()).length > 0; + const entries = Array.from(arg.headers.entries()); + return `${arg.method} ${url}${shouldNewline ? '\n ' : ''}${entries.map(val => `${val[0]}: ${val[1]}`).join(`\n `)}`; + } catch { + return String(arg); + } + } + } as UnknownConversion, + { + condition: arg => typeof arg == 'object', + converter: arg => JSON.stringify(arg) + } as UnknownConversion, + ]; + function convertToString(arg: Message) { + for (const conversion of conversions) + if (conversion.condition(arg)) + return (conversion.converter as (arg: unknown) => string)(arg); + // gpt-4o idea cuz my brain has the `stupid` type + + return String(arg); // fallback + } + return msgs.map(val => convertToString(val)).join(' '); + } + #typeStr(type: MessageType) { + switch (type) { + case MessageType.Info: + return '[INFO]'; + case MessageType.Warn: + return '[WARN]'; + case MessageType.Error: + return '[ERROR]'; + case MessageType.Debug: + return '[DEBUG]'; + case MessageType.Network: + return '[NETWORK]'; + default: + return '[UNKNOWN]'; + } + } + #timeStr(time: Date) { + switch (this.timeFormat) { + case TimeFormat.Unix: + return time.getTime(); + case TimeFormat.Local: + return performance.now(); + case TimeFormat.RoundedLocal: + return Math.round(performance.now()); + default: + return time.toISOString(); + } + } + + /** + * Don't use this unless you're benchmarking. + * + * Constructs a message. Does not do anything with it, or even return it. + * + * Logging messages during [Deno] benchmarks causes problems. + */ + bench(type: MessageType, chalkColor: ChalkFunction, ...msgs: PrimitiveItems) { + `${chalk.gray(`${this.#timeStr(new Date())} `)} ${chalkColor(chalk.inverse(`${this.source} ${this.#typeStr(type)}`) + ` ${this.#conversions(...msgs)}`)}`; + } #log(type: MessageType, chalkColor: ChalkFunction, ...msgs: PrimitiveItems) { if (!this.visible) return; const func = () => { - - let typestr: string; - switch (type) { - case MessageType.Info: - typestr = '[INFO]'; - break; - case MessageType.Warn: - typestr = '[WARN]'; - break; - case MessageType.Error: - typestr = '[ERROR]'; - break; - case MessageType.Debug: - typestr = '[DEBUG]'; - break; - case MessageType.Network: - typestr = '[NETWORK]'; - break; - default: - typestr = '[UNKNOWN]'; - break; - } const time = new Date(); - let timeFormatted; - switch (LoggingConfiguration.timeFormat) { - case TimeFormat.Unix: - timeFormatted = time.getTime(); - break; - case TimeFormat.Local: - timeFormatted = performance.now(); - break; - default: - timeFormatted = time.toISOString(); - } - const conversions = [ - { - condition: arg => arg instanceof Error, - converter: arg => arg.stack || arg.message - } as UnknownConversion, - { - condition: arg => arg == null, - converter: arg => JSON.stringify(arg) - } as UnknownConversion, - { - condition: arg => typeof arg == 'object', - converter: arg => JSON.stringify(arg) - } as UnknownConversion, - ]; - function convertToString(arg: unknown) { - for (const conversion of conversions) - if (conversion.condition(arg)) - return (conversion.converter as (arg: unknown) => string)(arg); - // gpt-4o idea cuz my brain has the `stupid` type + const str = this.#conversions(...msgs); + const msg = `${chalk.gray(this.#timeStr(time))} ${chalkColor(chalk.inverse(`${this.source} ${this.#typeStr(type)}`) + ` ${str}`)}` - return String(arg); // fallback - } - - const str = msgs.map(val => convertToString(val)).join(' '); - const msg = chalk.gray(`${timeFormatted} `) + chalkColor(chalk.inverse(`${this.source} ${typestr}`) + ` ${str}`); - console.log(msg); + process.stdout.write(`${first ? '' : '\r\n'}${msg}`); + // I don't know if promise-ifying this helps or not. + // deno-lint-ignore require-await + (async () => { + first = false; + })(); try { LoggingListeners.emit('basic', msg); LoggingListeners.emit('type', str, type, this.source, time); } catch (err) { - console.error(`(FALLBACK ERROR) Callback failed! Stack: ${(err as Error).stack}`); + process.stderr.write(`\r\n(FALLBACK ERROR) Callback failed! Stack: ${(err as Error).stack}`); } } - if (LoggingConfiguration.logTiming == LogTiming.Sync) func(); + if (this.logTiming == LogTiming.Sync) func(); else setImmediate(func); } @@ -124,47 +189,62 @@ class Logging { * @param msgs Your message(s) */ log(type: MessageType, ...msgs: PrimitiveItems) { - if (type == MessageType.Info) this.i(...msgs); - if (type == MessageType.Warn) this.w(...msgs); - if (type == MessageType.Error) this.e(...msgs); - if (type == MessageType.Debug) this.d(...msgs); - if (type == MessageType.Network) this.n(...msgs); + switch (type) { + case MessageType.Info: + this.info(...msgs); + break; + case MessageType.Warn: + this.warn(...msgs); + break; + case MessageType.Error: + this.error(...msgs); + break; + case MessageType.Debug: + this.debug(...msgs); + break; + case MessageType.Network: + this.network(...msgs); + break; + default: + this.info(...msgs); + break; + } } /** Logging Function */ - i(...msgs: PrimitiveItems) {this.info(...msgs);} + i(...msgs: PrimitiveItems) { this.info(...msgs); } /** Logging Function */ info(...msgs: PrimitiveItems) { if (!MessageTypeVisibility.Info) return; this.#log(MessageType.Info, chalk.whiteBright, ...msgs); } - + /** Logging Function */ - w(...msgs: PrimitiveItems) {this.warn(...msgs);} + w(...msgs: PrimitiveItems) { this.warn(...msgs); } /** Logging Function */ warn(...msgs: PrimitiveItems) { if (!MessageTypeVisibility.Warn) return; this.#log(MessageType.Warn, chalk.yellowBright, ...msgs); } - + /** Logging Function */ - e(...msgs: PrimitiveItems) {this.error(...msgs);} + e(...msgs: PrimitiveItems) { this.error(...msgs); } /** Logging Function */ error(...msgs: PrimitiveItems) { if (!MessageTypeVisibility.Error) return; this.#log(MessageType.Error, chalk.redBright, ...msgs); } - + /** Logging Function */ - d(...msgs: PrimitiveItems) {this.debug(...msgs);} + d(...msgs: PrimitiveItems) { this.debug(...msgs); } /** Logging Function */ debug(...msgs: PrimitiveItems) { if (!MessageTypeVisibility.Debug) return; this.#log(MessageType.Debug, chalk.greenBright, ...msgs); } - + /** Logging Function */ - n(...msgs: PrimitiveItems) {this.network(...msgs);} + n(...msgs: PrimitiveItems) { this.network(...msgs); } /** Logging Function */ network(...msgs: PrimitiveItems) { if (!MessageTypeVisibility.Network) return; @@ -201,13 +281,15 @@ const basicListeners = new Set(); const typeListeners = new Set(); class ListenersBase { + /** Register listener callback */ onmsg(type: 'basic', cb: BasicListener): void onmsg(type: 'type', cb: TypeListener): void onmsg(type: ListenerType, cb: Listener) { if (type == 'basic') basicListeners.add(cb); else if (type == 'type') typeListeners.add(cb); } - + + /** Remove listener callback */ offmsg(type: 'basic', cb: BasicListener): void offmsg(type: 'type', cb: TypeListener): void offmsg(type: ListenerType, cb: Listener) { @@ -215,25 +297,36 @@ class ListenersBase { else if (type == 'type') typeListeners.delete(cb); } + /** Emit a log line. Usually not needed outside this module. */ emit(type: 'basic', msg: string, msgtype?: MessageType, source?: string, time?: Date): void emit(type: 'type', msg: string, msgtype: MessageType, source: string, time: Date): void emit(type: ListenerType, msg: string, msgtype: MessageType, source: string, time: Date) { - if (type == 'basic') + if (type == 'basic') for (const cb of basicListeners) (cb as BasicListener)(msg); - if (type == 'type') + if (type == 'type') for (const cb of typeListeners) (cb as TypeListener)(msg, msgtype, source, time); } } +/** + * Add/remove callbacks: run when something is logged anywhere + */ const LoggingListeners: ListenersBase = new ListenersBase(); +/** + * Specify when, in/around the event loop, logs are sent + */ enum LogTiming { Sync, Deferred } +/** + * Specify the format that loggers use to display time + */ enum TimeFormat { Utc, Unix, - Local + Local, + RoundedLocal } class LoggingConfigurationBase { @@ -249,6 +342,9 @@ class LoggingConfigurationBase { set logTiming(data: LogTiming) { this.#timing = data } } +/** + * Configure time display format and log timing here + */ const LoggingConfiguration: LoggingConfigurationBase = new LoggingConfigurationBase(); export { MessageType, TimeFormat, LogTiming, MessageTypeVisibility, LoggingListeners, LoggingConfiguration }; diff --git a/test.ts b/test.ts index b598e76..d7f4802 100644 --- a/test.ts +++ b/test.ts @@ -1,44 +1,63 @@ -import Logging, { LoggingListeners, LoggingConfiguration, MessageType, MessageTypeVisibility, TimeFormat, LogTiming } from "@proxnet/undead-logging"; +import Logging, { LoggingListeners, LoggingConfiguration, MessageType, MessageTypeVisibility, TimeFormat, LogTiming } from "./mod.ts"; import { setImmediate } from "node:timers/promises"; +import process from "node:process"; -const debug = Deno.args[0] == 'true'; +const debug = process.argv[process.argv.length - 1] == 'true'; +console.debug(`Debug mode: ${debug}`); +const changeTimeFormat = process.argv[process.argv.length - 2] == 'true'; +console.debug(`changeTimeFormat: ${changeTimeFormat}`); if (debug) { LoggingListeners.onmsg('basic', msg => { - console.debug(`[d] ${msg}`); + console.debug(`\r\n[d] ${msg}`); }); LoggingListeners.onmsg('type', (msg, type, source, time) => { console.debug(`[D] M:'${msg}' T:${type} S:'${source}' TM:${time.getTime()}`); }); } +LoggingConfiguration.timeFormat = TimeFormat.Utc; + const log = new Logging("Test1"); log.i("Hello World!"); log.visible = false; log.e('I should not be visible.'); log.visible = true; -log.e('Now I should be!'); +log.e('Now I should be visible! (above is all UTC time format)'); const logg = new Logging("Test2"); logg.w(`Uh oh..`); logg.d(`Here's some info that tells you about that warning:`, new Error('Uh oh..')); -LoggingConfiguration.timeFormat = TimeFormat.Unix; +if (changeTimeFormat) logg.timeFormat = TimeFormat.Unix; logg.i(`Unix time!`); -LoggingConfiguration.timeFormat = TimeFormat.Local; +if (changeTimeFormat) logg.timeFormat = TimeFormat.Local; logg.i(`Process time!`); -LoggingConfiguration.timeFormat = TimeFormat.Utc; -LoggingConfiguration.logTiming = LogTiming.Deferred; -logg.log(MessageType.Network, "Deferred mode!"); +if (changeTimeFormat) logg.timeFormat = TimeFormat.Utc; +logg.logTiming = LogTiming.Deferred; +logg.log(MessageType.Network, "Deferred mode and RoundedLocal time! (shouldn't be UTC)"); -LoggingConfiguration.timeFormat = TimeFormat.Local; +if (changeTimeFormat) logg.timeFormat = TimeFormat.RoundedLocal; setImmediate(() => { - // all should be local mode + // all should NOT be local mode MessageTypeVisibility.Error = false; logg.error("I can't be seen!"); log.error('Same!'); log.n("I *can* be seen!"); -}); \ No newline at end of file +}); + +// the big red error +const world = null; +if (changeTimeFormat) log.timeFormat = TimeFormat.Utc; +log.log(MessageType.Error, Object, "<-- nasty", 0, undefined, null, JSON.stringify({"hello": world})); + +LoggingConfiguration.logTiming = LogTiming.Sync; +LoggingConfiguration.timeFormat = TimeFormat.Unix; +const webLog = new Logging("Web"); +webLog.d(`Following is a Request`); +webLog.i(new Request('http://example.com?hello=world', { headers: { 'key1': 'value1', 'key2': 'value2' }})); +webLog.d(`Following is a Response`); +webLog.i(await fetch('https://example.com')); \ No newline at end of file