README fixes, new RoundedLocal time format, more local source options

* i wanted to make sure `undefined` was handled properly. seems like it is.
* tested with Bun, works. Deno runs faster though, by about 1.8µs/message construction!
* Removed skeletons from closet (bug fixes)
* Sources can now optionally specify their own time format and/or log timing
* Requests and Responses now can be converted and displayed (no bodies)
This commit is contained in:
2025-07-19 05:00:07 -04:00
parent b6f3ccb73c
commit 44784130f9
10 changed files with 706 additions and 117 deletions

1
.gitignore vendored Normal file
View File

@@ -0,0 +1 @@
node_modules/

49
BENCH.md Normal file
View File

@@ -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,<br>
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.

View File

@@ -66,7 +66,7 @@ Callback ran when a message is logged anywhere (this time components are split u
```ts ```ts
LoggingListeners.onmsg('type', (msg, type, source, time) => { LoggingListeners.onmsg('type', (msg, type, source, time) => {
// msg: string // msg: string
// type: MessageType - import { MessageType } from "@proxnet/undead-logging";) // type: MessageType - import { MessageType } from "@proxnet/undead-logging";
// source: string // source: string
// time: Date // time: Date
}); });
@@ -74,25 +74,26 @@ LoggingListeners.onmsg('type', (msg, type, source, time) => {
Remove callback: Remove callback:
```ts ```ts
const cb = msg => { /* do something with msg */ }; const cb = msg => { /* do something with msg: string */ };
LoggingListeners.onmsg('basic', cb); LoggingListeners.onmsg('basic', cb);
LoggingListeners.offmsg('basic', cb); LoggingListeners.offmsg('basic', cb);
``` ```
## Time display modes ## Time display modes
You can display three different formats for time: You can display four different formats for time:
* UTC * UTC
* Unix time (in milliseconds) * 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: Set the time format:
```ts ```ts
import { LoggingConfiguration, TimeFormat } from "@proxnet/undead-logging"; import { LoggingConfiguration, TimeFormat } from "@proxnet/undead-logging";
LoggingConfiguration.timeFormat = TimeFormat.Local LoggingConfiguration.timeFormat = TimeFormat.Local;
// or // or
LoggingConfiguration.timeFormat = TimeFormat.Utc LoggingConfiguration.timeFormat = TimeFormat.Utc;
``` ```
## (advanced) Logging timing ## (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` Logs are sent synchronously by default. You can optionally defer logs with `setImmediate` using `LogTiming.Deferred`
```ts ```ts
LoggingConfiguration.logTiming = LogTiming.Sync LoggingConfiguration.logTiming = LogTiming.Sync;
LoggingConfiguration.logTiming = LogTiming.Deferred // 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.

64
benchmark/bun.ts Normal file
View File

@@ -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('');
}

227
benchmark/deno-example.json Normal file
View File

@@ -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
}
}
]
}
]
}

109
benchmark/deno.ts Normal file
View File

@@ -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');
}
});

View File

@@ -1,14 +1,19 @@
{ {
"tasks": { "tasks": {
"debug": "deno run -A test.ts true", "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": { "imports": {
"@std/assert": "jsr:@std/assert@1", "@std/assert": "jsr:@std/assert@1",
"chalk": "npm:chalk@^5.3.0" "chalk": "npm:chalk@^5.3.0"
}, },
"exports": "./mod.ts", "exports": "./mod.ts",
"version": "1.3.0", "version": "1.4.0",
"name": "@proxnet/undead-logging", "name": "@proxnet/undead-logging",
"license": "MIT" "license": "MIT",
"bench": {
"include": ["./benchmark/deno.ts"]
}
} }

30
deno.lock generated
View File

@@ -1,24 +1,34 @@
{ {
"version": "4", "version": "5",
"specifiers": { "specifiers": {
"jsr:@std/assert@1": "1.0.8", "jsr:@std/assert@1": "1.0.13",
"jsr:@std/internal@^1.0.5": "1.0.5", "jsr:@std/internal@^1.0.6": "1.0.9",
"npm:chalk@^5.3.0": "5.3.0" "npm:@types/node@*": "22.15.15",
"npm:chalk@^5.3.0": "5.4.1"
}, },
"jsr": { "jsr": {
"@std/assert@1.0.8": { "@std/assert@1.0.13": {
"integrity": "ebe0bd7eb488ee39686f77003992f389a06c3da1bbd8022184804852b2fa641b", "integrity": "ae0d31e41919b12c656c742b22522c32fb26ed0cba32975cb0de2a273cb68b29",
"dependencies": [ "dependencies": [
"jsr:@std/internal" "jsr:@std/internal"
] ]
}, },
"@std/internal@1.0.5": { "@std/internal@1.0.9": {
"integrity": "54a546004f769c1ac9e025abd15a76b6671ddc9687e2313b67376125650dc7ba" "integrity": "bdfb97f83e4db7a13e8faab26fb1958d1b80cc64366501af78a0aee151696eb8"
} }
}, },
"npm": { "npm": {
"chalk@5.3.0": { "@types/node@22.15.15": {
"integrity": "sha512-dLitG79d+GV1Nb/VYcCDFivJeK1hiukt9QjRNVOsUtTy1rR1YJsmpGGTZ3qJos+uw7WmWF4wUwBd9jxjocFC2w==" "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": { "workspace": {

208
mod.ts
View File

@@ -1,14 +1,25 @@
import chalk from "chalk"; import chalk from "chalk";
import { setImmediate } from "node:timers"; import { setImmediate } from "node:timers";
import process from "node:process";
type ChalkFunction = (...msgs: unknown[]) => string; type Message = unknown;
type PrimitiveItems = unknown[]; type ChalkFunction = (...msgs: Message[]) => string;
type PrimitiveItems = Message[];
interface UnknownConversion<T> { interface UnknownConversion<T> {
condition: (arg: unknown) => boolean; condition: (arg: Message) => boolean;
converter: (arg: T) => string; 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 * A source for pretty and cool and fun logging
*/ */
@@ -21,6 +32,11 @@ class Logging {
/** Should I use bright colors over dull ones? */ /** Should I use bright colors over dull ones? */
bright: boolean = true; 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 * Create a logging source
* ```ts * ```ts
@@ -29,8 +45,8 @@ class Logging {
* log.i("Hello World!"); * log.i("Hello World!");
* ``` * ```
* @param source Module identifier. Used in every line to identify the module that sent the message. * @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. * @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. Functions for info, warnings, errors, debug statements, and network events are provided and have shorthands. * @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) { constructor(source: string, silent?: boolean, bright?: boolean) {
this.visible = true; this.visible = true;
@@ -40,45 +56,7 @@ class Logging {
if (typeof silent == 'boolean' && !silent) this.info(`Instantiated logging for ${this.source}`); if (typeof silent == 'boolean' && !silent) this.info(`Instantiated logging for ${this.source}`);
} }
#log(type: MessageType, chalkColor: ChalkFunction, ...msgs: PrimitiveItems) { #conversions(...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 = [ const conversions = [
{ {
condition: arg => arg instanceof Error, condition: arg => arg instanceof Error,
@@ -88,12 +66,47 @@ class Logging {
condition: arg => arg == null, condition: arg => arg == null,
converter: arg => JSON.stringify(arg) converter: arg => JSON.stringify(arg)
} as UnknownConversion<null>, } as UnknownConversion<null>,
{
condition: arg => arg == undefined,
converter: _arg => 'undefined'
} as UnknownConversion<undefined>,
{
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<Response>,
{
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<Request>,
{ {
condition: arg => typeof arg == 'object', condition: arg => typeof arg == 'object',
converter: arg => JSON.stringify(arg) converter: arg => JSON.stringify(arg)
} as UnknownConversion<object>, } as UnknownConversion<object>,
]; ];
function convertToString(arg: unknown) { function convertToString(arg: Message) {
for (const conversion of conversions) for (const conversion of conversions)
if (conversion.condition(arg)) if (conversion.condition(arg))
return (conversion.converter as (arg: unknown) => string)(arg); return (conversion.converter as (arg: unknown) => string)(arg);
@@ -101,20 +114,72 @@ class Logging {
return String(arg); // fallback 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();
}
}
const str = msgs.map(val => convertToString(val)).join(' '); /**
const msg = chalk.gray(`${timeFormatted} `) + chalkColor(chalk.inverse(`${this.source} ${typestr}`) + ` ${str}`); * Don't use this unless you're benchmarking.
console.log(msg); *
* 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 = () => {
const time = new Date();
const str = this.#conversions(...msgs);
const msg = `${chalk.gray(this.#timeStr(time))} ${chalkColor(chalk.inverse(`${this.source} ${this.#typeStr(type)}`) + ` ${str}`)}`
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 { try {
LoggingListeners.emit('basic', msg); LoggingListeners.emit('basic', msg);
LoggingListeners.emit('type', str, type, this.source, time); LoggingListeners.emit('type', str, type, this.source, time);
} catch (err) { } 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); else setImmediate(func);
} }
@@ -124,11 +189,26 @@ class Logging {
* @param msgs Your message(s) * @param msgs Your message(s)
*/ */
log(type: MessageType, ...msgs: PrimitiveItems) { log(type: MessageType, ...msgs: PrimitiveItems) {
if (type == MessageType.Info) this.i(...msgs); switch (type) {
if (type == MessageType.Warn) this.w(...msgs); case MessageType.Info:
if (type == MessageType.Error) this.e(...msgs); this.info(...msgs);
if (type == MessageType.Debug) this.d(...msgs); break;
if (type == MessageType.Network) this.n(...msgs); 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 */ /** Logging Function */
@@ -201,6 +281,7 @@ const basicListeners = new Set<Listener>();
const typeListeners = new Set<Listener>(); const typeListeners = new Set<Listener>();
class ListenersBase { class ListenersBase {
/** Register listener callback */
onmsg(type: 'basic', cb: BasicListener): void onmsg(type: 'basic', cb: BasicListener): void
onmsg(type: 'type', cb: TypeListener): void onmsg(type: 'type', cb: TypeListener): void
onmsg(type: ListenerType, cb: Listener) { onmsg(type: ListenerType, cb: Listener) {
@@ -208,6 +289,7 @@ class ListenersBase {
else if (type == 'type') typeListeners.add(cb); else if (type == 'type') typeListeners.add(cb);
} }
/** Remove listener callback */
offmsg(type: 'basic', cb: BasicListener): void offmsg(type: 'basic', cb: BasicListener): void
offmsg(type: 'type', cb: TypeListener): void offmsg(type: 'type', cb: TypeListener): void
offmsg(type: ListenerType, cb: Listener) { offmsg(type: ListenerType, cb: Listener) {
@@ -215,6 +297,7 @@ class ListenersBase {
else if (type == 'type') typeListeners.delete(cb); 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: 'basic', msg: string, msgtype?: MessageType, source?: string, time?: Date): void
emit(type: 'type', 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) { emit(type: ListenerType, msg: string, msgtype: MessageType, source: string, time: Date) {
@@ -224,16 +307,26 @@ class ListenersBase {
for (const cb of typeListeners) (cb as TypeListener)(msg, msgtype, source, time); 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(); const LoggingListeners: ListenersBase = new ListenersBase();
/**
* Specify when, in/around the event loop, logs are sent
*/
enum LogTiming { enum LogTiming {
Sync, Sync,
Deferred Deferred
} }
/**
* Specify the format that loggers use to display time
*/
enum TimeFormat { enum TimeFormat {
Utc, Utc,
Unix, Unix,
Local Local,
RoundedLocal
} }
class LoggingConfigurationBase { class LoggingConfigurationBase {
@@ -249,6 +342,9 @@ class LoggingConfigurationBase {
set logTiming(data: LogTiming) { this.#timing = data } set logTiming(data: LogTiming) { this.#timing = data }
} }
/**
* Configure time display format and log timing here
*/
const LoggingConfiguration: LoggingConfigurationBase = new LoggingConfigurationBase(); const LoggingConfiguration: LoggingConfigurationBase = new LoggingConfigurationBase();
export { MessageType, TimeFormat, LogTiming, MessageTypeVisibility, LoggingListeners, LoggingConfiguration }; export { MessageType, TimeFormat, LogTiming, MessageTypeVisibility, LoggingListeners, LoggingConfiguration };

41
test.ts
View File

@@ -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 { 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) { if (debug) {
LoggingListeners.onmsg('basic', msg => { LoggingListeners.onmsg('basic', msg => {
console.debug(`[d] ${msg}`); console.debug(`\r\n[d] ${msg}`);
}); });
LoggingListeners.onmsg('type', (msg, type, source, time) => { LoggingListeners.onmsg('type', (msg, type, source, time) => {
console.debug(`[D] M:'${msg}' T:${type} S:'${source}' TM:${time.getTime()}`); console.debug(`[D] M:'${msg}' T:${type} S:'${source}' TM:${time.getTime()}`);
}); });
} }
LoggingConfiguration.timeFormat = TimeFormat.Utc;
const log = new Logging("Test1"); const log = new Logging("Test1");
log.i("Hello World!"); log.i("Hello World!");
log.visible = false; log.visible = false;
log.e('I should not be visible.'); log.e('I should not be visible.');
log.visible = true; 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"); const logg = new Logging("Test2");
logg.w(`Uh oh..`); logg.w(`Uh oh..`);
logg.d(`Here's some info that tells you about that warning:`, new Error('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!`); logg.i(`Unix time!`);
LoggingConfiguration.timeFormat = TimeFormat.Local; if (changeTimeFormat) logg.timeFormat = TimeFormat.Local;
logg.i(`Process time!`); logg.i(`Process time!`);
LoggingConfiguration.timeFormat = TimeFormat.Utc; if (changeTimeFormat) logg.timeFormat = TimeFormat.Utc;
LoggingConfiguration.logTiming = LogTiming.Deferred; logg.logTiming = LogTiming.Deferred;
logg.log(MessageType.Network, "Deferred mode!"); logg.log(MessageType.Network, "Deferred mode and RoundedLocal time! (shouldn't be UTC)");
LoggingConfiguration.timeFormat = TimeFormat.Local; if (changeTimeFormat) logg.timeFormat = TimeFormat.RoundedLocal;
setImmediate(() => { setImmediate(() => {
// all should be local mode // all should NOT be local mode
MessageTypeVisibility.Error = false; MessageTypeVisibility.Error = false;
logg.error("I can't be seen!"); logg.error("I can't be seen!");
log.error('Same!'); log.error('Same!');
log.n("I *can* be seen!"); log.n("I *can* be seen!");
}); });
// 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'));