src/hero.mjs: Promote log() to fancy logger object

4 files changed, 242 insertions, 16 deletions

diff --git a/src/hero.mjs b/src/hero.mjs
index 899e3fb..268136f 100644
--- a/src/hero.mjs
+++ b/src/hero.mjs
@@ -145,7 +145,32 @@ export const makeRequestListener = table => async (req, res) => {
 	res.end(response.body);
 };
 
-export const log = o => console.error(JSON.stringify(o));
+export const loggerDefaults = {
+	pid:  process.pid,
+	ppid: process.ppid,
+};
+
+export let loggerGlobals = {};
+
+export const configLogger = o => loggerGlobals = o;
+
+export const logit = (writerFn, level, o) =>
+	writerFn(JSON.stringify({
+		...loggerDefaults,
+		...loggerGlobals,
+		level,
+		...o,
+	}));
+
+export const makeLogger = (writerFn = console.error) => ({
+	debug: (...args) => process.env.DEBUG ?
+		logit(writerFn, "DEBUG", ...args) :
+		null,
+	info:  u.partial(logit, writerFn, "INFO"),
+	warn:  u.partial(logit, writerFn, "WARN"),
+	error: u.partial(logit, writerFn, "ERROR"),
+});
+export const log = makeLogger();
 
 export const interceptorsFn = ({
 	uuidFn,
@@ -157,7 +182,7 @@ export const interceptorsFn = ({
 	requestId: (req, next) => next({ ...req, id: uuidFn() }),
 	logged: async (req, next) => {
 		const { id, url, method } = req;
-		logger({
+		logger.info({
 			id,
 			url,
 			method,
@@ -165,7 +190,7 @@ export const interceptorsFn = ({
 		});
 		const response = await next(req);
 		const { status } = response;
-		logger({
+		logger.info({
 			id,
 			status,
 			type: "in-response",
@@ -193,7 +218,7 @@ export const interceptorsFn = ({
 			assert.ok("status" in response, `Missing "status"`);
 			return response;
 		} catch (error) {
-			logger({
+			logger.error({
 				id: req.id,
 				type: "server-error-interceptor",
 				message: error.message,
diff --git a/src/utils.mjs b/src/utils.mjs
index f2e09e4..c671f0f 100644
--- a/src/utils.mjs
+++ b/src/utils.mjs
@@ -76,3 +76,7 @@ export const first = (arr, fn) => {
 export const promisify = fn => (...args) =>
 	new Promise((resolve, reject) =>
 		fn(...args, (err, data) => err ? reject(err) : resolve(data)));
+
+export const partial = (fn, ...startArgs) =>
+	(...endArgs) =>
+		fn(...startArgs, ...endArgs);
diff --git a/tests/js/hero.mjs b/tests/js/hero.mjs
index 5507375..1e1668d 100644
--- a/tests/js/hero.mjs
+++ b/tests/js/hero.mjs
@@ -1,5 +1,6 @@
-import assert from "node:assert/strict";
-import http   from "node:http";
+import assert  from "node:assert/strict";
+import http    from "node:http";
+import procees from "node:process";
 
 import * as runner from "../runner.mjs";
 import * as u      from "../../src/utils.mjs";
@@ -15,7 +16,11 @@ import {
 	extractQueryParams,
 	handleRequest,
 	makeRequestListener,
-	log,
+	loggerDefaults,
+	loggerGlobals,
+	configLogger,
+	logit,
+	makeLogger,
 	interceptorsFn,
 	interceptors,
 	defaultInterceptors,
@@ -632,17 +637,137 @@ const test_makeRequestListener = t => {
 	});
 };
 
-const test_log = t => {
-	t.start("log()");
+const test_configLogger = t => {
+	t.start("configLogger()");
+
+	t.test("globals starts empty", () => {
+		assert.deepEqual(loggerGlobals, {});
+	});
+
+	t.test("is gets becomes we assign it", () => {
+		const globals = {
+			app: "my-app",
+			color: "green",
+			version: "deadbeef",
+		};
+		configLogger(globals);
+		assert.deepEqual(loggerGlobals, globals);
+	});
+
+	t.test("we can reset it", () => {
+		configLogger({});
+		assert.deepEqual(loggerGlobals, {});
+	});
+};
+
+const test_logit = t => {
+	t.start("logit()");
 
         t.test("we can log data", () => {
-		log({ a: 1, type: "log-test" });
+		configLogger({ app: "hero-based app" });
+		const contents = [];
+		const writerFn = x => contents.push(x);
+
+		logit(writerFn, "my level", { a: 1, type: "log-test" });
+		assert.deepEqual(contents.map(JSON.parse), [{
+			...loggerDefaults,
+			app:   "hero-based app",
+			level: "my level",
+			a:     1,
+			type:  "log-test",
+		}]);
+
+		// reset the logger out of the values specific to this test
+		configLogger({});
+	});
+
+	t.test("the object can change previous fallback values", () => {
+		const contents = [];
+		const writerFn = x => contents.push(x);
+
+		configLogger({
+			level: "unseen",
+			a:     "unseen",
+		});
+		logit(writerFn, "overwritten by level", { a: "overwritten by o" })
+
+		configLogger({
+			pid: "overwritten by loggerGlobals",
+		});
+		logit(writerFn, "unseen", { level: "overwritten by o" });
+
+		// reset the logger out of the values specific to this test
+		configLogger({});
+
+		assert.deepEqual(contents.map(JSON.parse), [
+			{
+				...loggerDefaults,
+				pid:   process.pid,
+				level: "overwritten by level",
+				a:     "overwritten by o",
+			},
+			{
+				...loggerDefaults,
+				pid:   "overwritten by loggerGlobals",
+				level: "overwritten by o",
+			},
+		]);
+
 	});
 
 	t.test("we can't log unserializable things", () => {
 		const obj = { self: null };
 		obj.self = obj;
-		assert.throws(() => log(obj), TypeError);
+		assert.throws(() => logit(obj), TypeError);
+	});
+};
+
+const test_makeLogger = t => {
+	t.start("makeLogger()");
+
+	t.test("various log levels", () => {
+		const contents = [];
+		const writerFn = x => contents.push(x);
+		const log = makeLogger(writerFn);
+
+		log.info ({ type: "expected"  });
+		log.warn ({ type: "worrysome" });
+		log.error({ type: "bad"       });
+		assert.deepEqual(contents.map(JSON.parse), [
+			{
+				...loggerDefaults,
+				level: "INFO",
+				type:  "expected",
+			},
+			{
+				...loggerDefaults,
+				level: "WARN",
+				type:  "worrysome",
+			},
+			{
+				...loggerDefaults,
+				level: "ERROR",
+				type:  "bad",
+			},
+		]);
+	});
+
+	t.test("debug only works when $DEBUG is set", () => {
+		const contents = [];
+		const writerFn = x => contents.push(x);
+		const log = makeLogger(writerFn);
+		
+		log.debug({ x: "ignored" });
+		process.env.DEBUG = 1;
+		log.debug({ x: "seen" });
+		delete process.env.DEBUG;
+		log.debug({ x: "ignored" });
+
+		assert.deepEqual(contents.map(JSON.parse), [{
+			...loggerDefaults,
+			level: "DEBUG",
+			x:     "seen",
+		}]);
 	});
 };
 
@@ -686,7 +811,7 @@ const test_interceptorsFn = t => {
 
 		t.test("we log before and after next()", async () => {
 			const contents = [];
-			const logger = x => contents.push(x);
+			const logger = { info: x => contents.push(x) };
 			const status = 201;
 			const req = {
 				id: "an ID",
@@ -810,7 +935,7 @@ const test_interceptorsFn = t => {
 
 		t.test(`an error is thrown if "status" is missing`, async () => {
 			const contents = [];
-			const logger = x => contents.push(x);
+			const logger = { error: x => contents.push(x) };
 			assert.deepEqual(
 				await interceptorsFn({ logger }).serverError({ id: 123 }, next),
 				{
@@ -830,7 +955,7 @@ const test_interceptorsFn = t => {
 
 		t.test("we turn a handler error into a 500 response", async () => {
 			const contents = [];
-			const logger = x => contents.push(x);
+			const logger = { error: x => contents.push(x) };
 			assert.deepEqual(
 				await interceptorsFn({ logger }).serverError(
 					{ id: "some ID" },
@@ -929,7 +1054,7 @@ const test_wrapHandler = t => {
 		const uuidFn = () => `${i++}`;
 
 		const contents = [];
-		const logger = x => contents.push(x);
+		const logger = { info: x => contents.push(x) };
 
 		const interceptors = interceptorsFn({uuidFn, logger});
 
@@ -1203,7 +1328,9 @@ await runner.runTests([
 	test_extractQueryParams,
 	test_handleRequest,
 	test_makeRequestListener,
-	test_log,
+	test_configLogger,
+	test_logit,
+	test_makeLogger,
 	test_interceptorsFn,
 	test_chainInterceptors,
 	test_wrapHandler,
diff --git a/tests/js/utils.mjs b/tests/js/utils.mjs
index 5a1507c..004af95 100644
--- a/tests/js/utils.mjs
+++ b/tests/js/utils.mjs
@@ -9,6 +9,7 @@ import {
 	getIn,
 	first,
 	promisify,
+	partial,
 } from "../../src/utils.mjs";
 
 const test_eq = t => {
@@ -275,6 +276,74 @@ const test_promisify = t => {
 	});
 };
 
+const test_partial = t => {
+	t.start("partial()");
+
+	t.test("empty values", () => {
+		const adder = (a, b, c) => a + b + c;
+
+		const adder1 = partial(adder);
+		assert.equal(adder1(1, 2, 3), 6);
+
+		const adder2 = partial(adder, 4, 5, 6);
+		assert.equal(adder2(), 15);
+
+		const noargs = () => "static";
+		assert.equal(partial(noargs)(), noargs());
+	});
+
+	t.test("too few arguments", () => {
+		const threeArgs = (a, b, c) => {
+			assert.notEqual(c, undefined);
+			return a + b + c
+		};
+
+		const add1 = partial(threeArgs, 1);
+		assert.throws(
+			() => add1(2),
+			assert.AssertionError,
+		);
+
+		const add1And2 = partial(threeArgs, 1, 2);
+		assert.throws(
+			() => add1And2(),
+			assert.AssertionError,
+		);
+
+		const addNothing = partial(threeArgs);
+		assert.throws(
+			() => addNothing(),
+			assert.AssertionError,
+		);
+	});
+
+	t.test("too many arguments", () => {
+		const twoArgs = (a, b) => a + b;
+
+		assert.equal(partial(twoArgs, 1)(2, 3), 3);
+		assert.equal(partial(twoArgs, 1, 2)(3), 3);
+	});
+
+	t.test("daily usage", () => {
+		const twoArg = (a, b) => a + b;
+
+		const numbers = [ 1, 2, 3, 4, 5 ];
+		assert.deepEqual(
+			numbers.map(partial(twoArg, 2)),
+			[ 3, 4, 5, 6, 7 ],
+		);
+	});
+
+	t.test("nested partials", () => {
+		const threeArgs = (a, b, c) => a + b + c;
+
+		const add1     = partial(threeArgs, 1);
+		const add1And2 = partial(add1,      2);
+
+		assert.equal(add1And2(3), 6);
+	});
+};
+
 
 await runner.runTests([
 	test_eq,
@@ -284,4 +353,5 @@ await runner.runTests([
 	test_getIn,
 	test_first,
 	test_promisify,
+	test_partial,
 ]);