Added global time format and log timing controls using LoggingConfiguration

* Bench doc fixes
* README fixes
* Added test scripts in `tests/`
This commit is contained in:
2025-07-19 18:51:28 -04:00
parent 44784130f9
commit 5db910ca14
8 changed files with 102 additions and 74 deletions

View File

@@ -41,9 +41,9 @@ summary
### TL;DR / What does this mean? ### TL;DR / What does this mean?
You can, *in theory* and *on average*, construct 650,000 messages per second. You can, *in theory* and *on average*, construct 643,000 messages per second.
I don't know how to benchmark a logger without logging messages to stdout,<br> 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. 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. Deferred is not really much faster, but can be helpful in some scenarios.

View File

@@ -1,6 +1,11 @@
# Undead Logging # Undead Logging
Logging for stupid idiots like me Logging for stupid idiots like me
* Pluggable event listeners
* Per-source hushing, global log type hushing
* Log timing control
* Time display modes
```ts ```ts
import Logging from "@proxnet/undead-logging" import Logging from "@proxnet/undead-logging"
@@ -107,6 +112,44 @@ LoggingConfiguration.logTiming = LogTiming.Sync;
LoggingConfiguration.logTiming = LogTiming.Deferred; LoggingConfiguration.logTiming = LogTiming.Deferred;
``` ```
You might prefer to defer logs in asynchronous situations where order does not matter and<br>
you'd like to prevent slowing down I/O.<br>
You might also prefer to reset all sources to synchronous logging during app shutdown.<br>
This can help debug issues with how your app closes. (see example below)
## Global resets
Every source is tracked by this module in a `Set`.
You can reset every source's log timing or time format with `LoggingConfiguration.reset(something)`.<br>
The corresponding property will be updated on `LoggingConfiguration`:
```ts
import Logging, { LoggingConfiguration, LogTiming } from "@proxnet/undead-logging";
const log = new Logging("Logger");
log.logTiming = LogTiming.Sync; // the default
LoggingConfiguration.resetLogTiming = LogTiming.Deferred;
// both are LogTiming.Deferred
log.d(`My log timing: LogTiming.${LogTiming[log.logTiming]}`);
log.d(`Global: LogTiming.${LogTiming[LoggingConfiguration.logTiming]}`);
```
This is useful when you want to use synchronous logging during a shutdown:
```ts
// something is keeping the event loop alive (HTTP server, a database, some I/O?)
LoggingConfiguration.logTiming = LogTiming.Deferred;
const log = new Logging("Main");
Deno.addSignalListener('SIGINT', () => {
LoggingConfiguration.resetLogTiming = LogTiming.Sync;
});
```
See [`tests/shutdown.ts`.](./tests/shutdown.ts)
## [Benchmarks](./BENCH.md) ## [Benchmarks](./BENCH.md)
## Contributing ## Contributing

View File

@@ -1,8 +1,8 @@
{ {
"tasks": { "tasks": {
"debug": "deno run -A test.ts true", "test-conversion": "deno run -A tests/convert.ts",
"plain": "deno run -A test.ts", "test-global": "deno run -A tests/global.ts",
"dev": "deno run plain", "test-shutdown": "deno run -A tests/shutdown.ts",
"bench": "deno bench -A" "bench": "deno bench -A"
}, },
"imports": { "imports": {
@@ -10,7 +10,7 @@
"chalk": "npm:chalk@^5.3.0" "chalk": "npm:chalk@^5.3.0"
}, },
"exports": "./mod.ts", "exports": "./mod.ts",
"version": "1.4.0", "version": "1.4.1",
"name": "@proxnet/undead-logging", "name": "@proxnet/undead-logging",
"license": "MIT", "license": "MIT",
"bench": { "bench": {

12
mod.ts
View File

@@ -11,11 +11,8 @@ interface UnknownConversion<T> {
converter: (arg: T) => string; converter: (arg: T) => string;
} }
interface WebLike { /** Control all log sources from this module */
url?: string, const sources: Set<Logging> = new Set();
headers?: Headers,
method?: string
}
/** The first log message across all sources will not contain carriage return + newline control codes */ /** The first log message across all sources will not contain carriage return + newline control codes */
let first = true; let first = true;
@@ -54,6 +51,8 @@ class Logging {
if (typeof bright == 'boolean') this.bright = bright; if (typeof bright == 'boolean') this.bright = bright;
if (typeof silent == 'boolean' && !silent) this.info(`Instantiated logging for ${this.source}`); if (typeof silent == 'boolean' && !silent) this.info(`Instantiated logging for ${this.source}`);
sources.add(this);
} }
#conversions(...msgs: PrimitiveItems) { #conversions(...msgs: PrimitiveItems) {
@@ -341,6 +340,9 @@ class LoggingConfigurationBase {
get logTiming(): LogTiming { return this.#timing; } get logTiming(): LogTiming { return this.#timing; }
set logTiming(data: LogTiming) { this.#timing = data } set logTiming(data: LogTiming) { this.#timing = data }
set resetTimeFormat(data: TimeFormat) { for (const source of sources.values()) source.timeFormat = data; this.#timeType = data; }
set resetLogTiming(data: LogTiming) { for (const source of sources.values()) source.logTiming = data; this.#timing = data; }
} }
/** /**
* Configure time display format and log timing here * Configure time display format and log timing here

63
test.ts
View File

@@ -1,63 +0,0 @@
import Logging, { LoggingListeners, LoggingConfiguration, MessageType, MessageTypeVisibility, TimeFormat, LogTiming } from "./mod.ts";
import { setImmediate } from "node:timers/promises";
import process from "node:process";
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(`\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 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..'));
if (changeTimeFormat) logg.timeFormat = TimeFormat.Unix;
logg.i(`Unix time!`);
if (changeTimeFormat) logg.timeFormat = TimeFormat.Local;
logg.i(`Process time!`);
if (changeTimeFormat) logg.timeFormat = TimeFormat.Utc;
logg.logTiming = LogTiming.Deferred;
logg.log(MessageType.Network, "Deferred mode and RoundedLocal time! (shouldn't be UTC)");
if (changeTimeFormat) logg.timeFormat = TimeFormat.RoundedLocal;
setImmediate(() => {
// 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!");
});
// 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'));

21
tests/convert.ts Normal file
View File

@@ -0,0 +1,21 @@
import Logging, { LoggingListeners } from "../mod.ts";
import process from "node:process";
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(`\r\n[d] ${msg}`);
});
LoggingListeners.onmsg('type', (msg, type, source, time) => {
console.debug(`[D] M:'${msg}' T:${type} S:'${source}' TM:${time.getTime()}`);
});
}
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'));

9
tests/global.ts Normal file
View File

@@ -0,0 +1,9 @@
import Logging, { LoggingConfiguration, LogTiming } from "@proxnet/undead-logging";
const log = new Logging("Logger");
log.logTiming = LogTiming.Sync;
LoggingConfiguration.resetLogTiming = LogTiming.Deferred;
log.d(`My log timing: LogTiming.${LogTiming[log.logTiming]} (not sync!)`);
log.d(`Global: LogTiming.${LogTiming[LoggingConfiguration.logTiming]} (not sync!)`);

16
tests/shutdown.ts Normal file
View File

@@ -0,0 +1,16 @@
import Logging, { LoggingConfiguration, LogTiming } from "@proxnet/undead-logging";
//LoggingConfiguration.logTiming = LogTiming.Deferred;
const log = new Logging("Main");
log.i(`Deferred! - LogTiming.${LogTiming[log.logTiming]}`);
const timeout = setTimeout(() => { log.d(`Interval!`) }, 2000);
Deno.addSignalListener('SIGINT', () => {
clearTimeout(timeout);
LoggingConfiguration.resetLogTiming = LogTiming.Sync;
log.i(`Sync! - LogTiming.${LogTiming[LoggingConfiguration.logTiming]}`);
});