src/hero.mjs: Include "timestamp" in the logged data objects

2 files changed, 51 insertions, 29 deletions

diff --git a/src/hero.mjs b/src/hero.mjs
index 34ac45c..e057781 100644
--- a/src/hero.mjs
+++ b/src/hero.mjs
@@ -19,21 +19,26 @@ export let loggerGlobals = {};
 
 export const configLogger = o => loggerGlobals = o;
 
-export const logit = (writerFn, level, o) =>
+export const logit = (writerFn, timestampFn, level, o) =>
 	writerFn(JSON.stringify({
 		...loggerDefaults,
 		...loggerGlobals,
 		level,
+		timestamp: timestampFn(),
 		...o,
 	}));
 
-export const makeLogger = (writerFn = console.error) => ({
+const now = () => (new Date()).toISOString();
+export const makeLogger = ({
+	writerFn = console.error,
+	timestampFn = now,
+} = {}) => ({
 	debug: (...args) => process.env.DEBUG ?
-		logit(writerFn, "DEBUG", ...args) :
+		logit(writerFn, timestampFn, "DEBUG", ...args) :
 		null,
-	info:  u.partial(logit, writerFn, "INFO"),
-	warn:  u.partial(logit, writerFn, "WARN"),
-	error: u.partial(logit, writerFn, "ERROR"),
+	info:  u.partial(logit, writerFn, timestampFn, "INFO"),
+	warn:  u.partial(logit, writerFn, timestampFn, "WARN"),
+	error: u.partial(logit, writerFn, timestampFn, "ERROR"),
 });
 
 export const log = makeLogger();
diff --git a/tests/js/hero.mjs b/tests/js/hero.mjs
index a5166c5..8f46e57 100644
--- a/tests/js/hero.mjs
+++ b/tests/js/hero.mjs
@@ -86,14 +86,17 @@ const test_logit = async t => {
 		configLogger({ app: "hero-based app" });
 		const contents = [];
 		const writerFn = x => contents.push(x);
+		let i = 0;
+		const timestampFn = () => `${i++}`;
 
-		logit(writerFn, "my level", { a: 1, type: "log-test" });
+		logit(writerFn, timestampFn, "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",
+			app:       "hero-based app",
+			level:     "my level",
+			timestamp: "0",
+			a:         1,
+			type:      "log-test",
 		}]);
 
 		/// reset the logger out of the values specific to this test
@@ -103,17 +106,19 @@ const test_logit = async t => {
 	await t.test("the object can change previous fallback values", () => {
 		const contents = [];
 		const writerFn = x => contents.push(x);
+		let i = 0;
+		const timestampFn = () => `${i++}`;
 
 		configLogger({
 			level: "unseen",
 			a:     "unseen",
 		});
-		logit(writerFn, "overwritten by level", { a: "overwritten by o" });
+		logit(writerFn, timestampFn, "overwritten by level", { a: "overwritten by o" });
 
 		configLogger({
 			pid: "overwritten by loggerGlobals",
 		});
-		logit(writerFn, "unseen", { level: "overwritten by o" });
+		logit(writerFn, timestampFn, "unseen", { level: "overwritten by o" });
 
 		/// reset the logger out of the values specific to this test
 		configLogger({});
@@ -121,14 +126,16 @@ const test_logit = async t => {
 		assert.deepEqual(contents.map(JSON.parse), [
 			{
 				...loggerDefaults,
-				pid:   process.pid,
-				level: "overwritten by level",
-				a:     "overwritten by o",
+				pid:       process.pid,
+				level:     "overwritten by level",
+				timestamp: "0",
+				a:         "overwritten by o",
 			},
 			{
 				...loggerDefaults,
-				pid:   "overwritten by loggerGlobals",
-				level: "overwritten by o",
+				pid:       "overwritten by loggerGlobals",
+				level:     "overwritten by o",
+				timestamp: "1",
 			},
 		]);
 
@@ -147,7 +154,9 @@ const test_makeLogger = async t => {
 	await t.test("various log levels", () => {
 		const contents = [];
 		const writerFn = x => contents.push(x);
-		const log = makeLogger(writerFn);
+		let i = 0;
+		const timestampFn = () => `${i++}`;
+		const log = makeLogger({ writerFn, timestampFn });
 
 		log.info ({ type: "expected"  });
 		log.warn ({ type: "worrysome" });
@@ -155,18 +164,23 @@ const test_makeLogger = async t => {
 		assert.deepEqual(contents.map(JSON.parse), [
 			{
 				...loggerDefaults,
-				level: "INFO",
-				type:  "expected",
+				level:     "INFO",
+				timestamp: "0",
+				type:      "expected",
 			},
 			{
 				...loggerDefaults,
-				level: "WARN",
-				type:  "worrysome",
+				level:     "WARN",
+				timestamp: "1",
+				type:      "expected",
+				type:      "worrysome",
 			},
 			{
 				...loggerDefaults,
-				level: "ERROR",
-				type:  "bad",
+				level:     "ERROR",
+				timestamp: "2",
+				type:      "expected",
+				type:      "bad",
 			},
 		]);
 	});
@@ -174,7 +188,9 @@ const test_makeLogger = async t => {
 	await t.test("debug only works when $DEBUG is set", () => {
 		const contents = [];
 		const writerFn = x => contents.push(x);
-		const log = makeLogger(writerFn);
+		let i = 0;
+		const timestampFn = () => `${i++}`;
+		const log = makeLogger({ writerFn, timestampFn });
 
 		const previous = process.env.DEBUG;
 		delete process.env.DEBUG;
@@ -188,8 +204,9 @@ const test_makeLogger = async t => {
 
 		assert.deepEqual(contents.map(JSON.parse), [{
 			...loggerDefaults,
-			level: "DEBUG",
-			x:     "seen",
+			level:     "DEBUG",
+			timestamp: "0",
+			x:         "seen",
 		}]);
 
 		process.env.DEBUG = previous;
@@ -209,7 +226,7 @@ const test_isValidMethod = async t => {
 const test_isValidUpgrade = async t => {
 	t.start("isValidUpgrade()");
 
-	await t.test("we ignoee the case", () => {
+	await t.test("we ignore the case", () => {
 		assert.ok(isValidUpgrade("Websocket"));
 		assert.ok(isValidUpgrade("WebSocket"));
 		assert.ok(isValidUpgrade("websocket"));