From bf353b0971d6e5271428dfb3c8e3b025d40912bf Mon Sep 17 00:00:00 2001 From: Siddhant Date: Sat, 16 Sep 2023 17:38:49 -0500 Subject: [PATCH] improve(logs): roll `level` into the log line a instead of its own label This will help with storage & performance --- src/endpoints/logs.ts | 27 ++++++----------- tests/logs.test.ts | 70 ++++++++++++++++++------------------------- tests/tail.test.ts | 59 ++++++++++++++---------------------- 3 files changed, 60 insertions(+), 96 deletions(-) diff --git a/src/endpoints/logs.ts b/src/endpoints/logs.ts index f147437..b4d8098 100644 --- a/src/endpoints/logs.ts +++ b/src/endpoints/logs.ts @@ -48,24 +48,14 @@ export const endpoint: Endpoint = { // Serialize logs to the Loki log entry format // https://grafana.com/docs/loki/latest/reference/api/#push-log-entries-to-loki - const levelBuckets = params.data.logs.reduce( - (acc, l) => { - if (acc[l.level]) acc[l.level].push(l); - else acc[l.level] = [l]; - return acc; - }, - {} as Record, - ); - const body = JSON.stringify({ - streams: Object.entries(levelBuckets).map(([level, logs]) => { - return { + streams: [ + { stream: { environment: params.data.environment, service: params.data.service, - level, }, - values: logs.map((l) => { + values: params.data.logs.map((l) => { // Loki wants timestamps in nanoseconds if (l.timestamp.p === "ms") l.timestamp.v = `${l.timestamp.v}000000`; @@ -80,10 +70,11 @@ export const endpoint: Endpoint = { // Reference: https://grafana.com/docs/loki/latest/get-started/labels/structured-metadata/ // TODO: We should just use structured metadata once it lands as stable - const log = Object.entries({ + const line = Object.entries({ + level: l.level, ...params.data.kv, ...l.kv, - msg: l.message, + message: l.message, }) .filter(([_, v]) => v !== undefined) // Leave null values untouched .map(([k, v]) => { @@ -91,10 +82,10 @@ export const endpoint: Endpoint = { return `${k}=${v}`; }) .join(" "); - return [l.timestamp.v, log]; + return [l.timestamp.v, line]; }), - }; - }), + }, + ], }); return fetch(env.lokiUrl, { diff --git a/tests/logs.test.ts b/tests/logs.test.ts index d5bba71..ecb6b3a 100644 --- a/tests/logs.test.ts +++ b/tests/logs.test.ts @@ -29,9 +29,8 @@ test("with environment", async () => { stream: { environment: "staging", service: "blob-city", - level: "info", }, - values: [["001", 'msg="Incoming request"']], + values: [["001", 'level="info" message="Incoming request"']], }, ], }); @@ -64,9 +63,8 @@ test("with level", async () => { stream: { environment: "production", service: "blob-city", - level: "fatal", }, - values: [["001", 'msg="Incoming request"']], + values: [["001", 'level="fatal" message="Incoming request"']], }, ], }); @@ -99,9 +97,8 @@ test("with ms precision", async () => { stream: { environment: "production", service: "blob-city", - level: "info", }, - values: [["001000000", 'msg="Incoming request"']], + values: [["001000000", 'level="info" message="Incoming request"']], }, ], }); @@ -133,9 +130,8 @@ test("with ns precision", async () => { stream: { environment: "production", service: "blob-city", - level: "info", }, - values: [["001", 'msg="Incoming request"']], + values: [["001", 'level="info" message="Incoming request"']], }, ], }); @@ -168,9 +164,8 @@ test("without kv", async () => { stream: { environment: "production", service: "blob-city", - level: "info", }, - values: [["001", 'msg="Incoming request"']], + values: [["001", 'level="info" message="Incoming request"']], }, ], }); @@ -204,9 +199,10 @@ test("with line kv", async () => { stream: { environment: "production", service: "blob-city", - level: "info", }, - values: [["001", 'method="GET" msg="Incoming request"']], + values: [ + ["001", 'level="info" method="GET" message="Incoming request"'], + ], }, ], }); @@ -240,9 +236,10 @@ test("with common kv", async () => { stream: { environment: "production", service: "blob-city", - level: "info", }, - values: [["001", 'rayId="1234" msg="Incoming request"']], + values: [ + ["001", 'level="info" rayId="1234" message="Incoming request"'], + ], }, ], }); @@ -277,9 +274,13 @@ test("with both kv", async () => { stream: { environment: "production", service: "blob-city", - level: "info", }, - values: [["001", 'rayId="1234" method="GET" msg="Incoming request"']], + values: [ + [ + "001", + 'level="info" rayId="1234" method="GET" message="Incoming request"', + ], + ], }, ], }); @@ -314,9 +315,8 @@ test("with undefined kv values", async () => { stream: { environment: "production", service: "blob-city", - level: "info", }, - values: [["001", 'msg="Incoming request"']], + values: [["001", 'level="info" message="Incoming request"']], }, ], }); @@ -349,9 +349,8 @@ test("with no message", async () => { stream: { environment: "production", service: "blob-city", - level: "info", }, - values: [["001", ""]], + values: [["001", 'level="info"']], }, ], }); @@ -403,34 +402,23 @@ test("multiple logs", async () => { stream: { environment: "production", service: "blob-city", - level: "info", }, values: [ [ "001", - 'rayId="abcd" method="GET" path="/tunnel" msg="Incoming request"', + 'level="info" rayId="abcd" method="GET" path="/tunnel" message="Incoming request"', ], - ["004", 'rayId="abcd" status=200 msg="Response"'], - ], - }, - { - stream: { - environment: "production", - service: "blob-city", - level: "debug", - }, - values: [ - ["002", 'rayId="abcd" tunnelId="1234" msg="Forwarding to DO"'], + [ + "002", + 'level="debug" rayId="abcd" tunnelId="1234" message="Forwarding to DO"', + ], + [ + "003000000", + 'level="trace" rayId="abcd" message="Creating WebSocketPair"', + ], + ["004", 'level="info" rayId="abcd" status=200 message="Response"'], ], }, - { - stream: { - environment: "production", - service: "blob-city", - level: "trace", - }, - values: [["003000000", 'rayId="abcd" msg="Creating WebSocketPair"']], - }, ], }); }); diff --git a/tests/tail.test.ts b/tests/tail.test.ts index 11d99e3..0f0bc9d 100644 --- a/tests/tail.test.ts +++ b/tests/tail.test.ts @@ -46,13 +46,12 @@ test("shipping error logs", async () => { expect(streams[0].stream).toStrictEqual({ environment: "production", service: "ingest-worker", - level: "fatal", }); expect(streams[0].values).toHaveLength(1); expect(streams[0].values[0]).toHaveLength(2); expect(streams[0].values[0][0]).toBe("1000000"); expect(streams[0].values[0][1]).toMatch( - /name="Error" stack="Error: Missing scriptName(.|\n)*" msg="Missing scriptName"/, + /level="fatal" name="Error" stack="Error: Missing scriptName(.|\n)*" message="Missing scriptName"/, ); vi.useRealTimers(); @@ -86,9 +85,13 @@ test("extra log when outcome is not ok", async () => { stream: { environment: "production", service: "blob-city-api", - level: "fatal", }, - values: [["1000000", 'outcome="cpuExceeded" msg="Fatal outcome"']], + values: [ + [ + "1000000", + 'level="fatal" outcome="cpuExceeded" message="Fatal outcome"', + ], + ], }, ], }); @@ -139,25 +142,15 @@ test("script logs", async () => { stream: { environment: "production", service: "blob-city-api", - level: "info", - }, - values: [["1000000", 'msg="log1"']], - }, - { - stream: { - environment: "production", - service: "blob-city-api", - level: "warn", - }, - values: [["2000000", 'a="b" c=9 d=false msg="log2 extra params"']], - }, - { - stream: { - environment: "production", - service: "blob-city-api", - level: "fatal", }, - values: [["3000000", 'msg="log3 extra params"']], + values: [ + ["1000000", 'level="info" message="log1"'], + [ + "2000000", + 'level="warn" a="b" c=9 d=false message="log2 extra params"', + ], + ["3000000", 'level="fatal" message="log3 extra params"'], + ], }, ], }); @@ -203,11 +196,10 @@ test("script exceptions", async () => { stream: { environment: "production", service: "blob-city-api", - level: "error", }, values: [ - ["1000000", 'msg="exception1"'], - ["2000000", 'msg="exception2"'], + ["1000000", 'level="error" message="exception1"'], + ["2000000", 'level="error" message="exception2"'], ], }, ], @@ -275,17 +267,11 @@ test("event batch", async () => { stream: { environment: "production", service: "blob-city-api", - level: "info", - }, - values: [["1000000", 'msg="log1"']], - }, - { - stream: { - environment: "production", - service: "blob-city-api", - level: "warn", }, - values: [["2000000", 'msg="log2"']], + values: [ + ["1000000", 'level="info" message="log1"'], + ["2000000", 'level="warn" message="log2"'], + ], }, ], }); @@ -295,9 +281,8 @@ test("event batch", async () => { stream: { environment: "production", service: "blob-city-api", - level: "error", }, - values: [["3000000", 'msg="exception1"']], + values: [["3000000", 'level="error" message="exception1"']], }, ], });