improve: serialize messages first in log lines

sdnts · Jul 6, 2024 · 4987e0d · 4987e0d
1 parent 1c012f4
commit 4987e0d
Show file tree

Hide file tree

Showing 3 changed files with 27 additions and 27 deletions.
diff --git a/src/endpoints/logs.ts b/src/endpoints/logs.ts
@@ -78,10 +78,10 @@ export const endpoint: Endpoint<typeof schema> = {
             // TODO: We should just use structured metadata once it lands as stable
 
             const line = Object.entries({
-              level: l.level,
+              message: l.message,
               ...params.kv,
               ...l.kv,
-              message: l.message,
+              level: l.level,
             })
               .filter(([_, v]) => v !== undefined) // Leave null values untouched
               .map(([k, v]) => {

diff --git a/tests/logs.test.ts b/tests/logs.test.ts
@@ -27,7 +27,7 @@ test("with environment", async () => {
           environment: "staging",
           service: "blob-city",
         },
-        values: [["001", 'level="info" message="Incoming request"']],
+        values: [["001", 'message="Incoming request" level="info"']],
       },
     ],
   });
@@ -58,7 +58,7 @@ test("with level", async () => {
           environment: "production",
           service: "blob-city",
         },
-        values: [["001", 'level="fatal" message="Incoming request"']],
+        values: [["001", 'message="Incoming request" level="fatal"']],
       },
     ],
   });
@@ -89,7 +89,7 @@ test("with ms precision", async () => {
           environment: "production",
           service: "blob-city",
         },
-        values: [["001000000", 'level="info" message="Incoming request"']],
+        values: [["001000000", 'message="Incoming request" level="info"']],
       },
     ],
   });
@@ -119,7 +119,7 @@ test("with ns precision", async () => {
           environment: "production",
           service: "blob-city",
         },
-        values: [["001", 'level="info" message="Incoming request"']],
+        values: [["001", 'message="Incoming request" level="info"']],
       },
     ],
   });
@@ -150,7 +150,7 @@ test("without kv", async () => {
           environment: "production",
           service: "blob-city",
         },
-        values: [["001", 'level="info" message="Incoming request"']],
+        values: [["001", 'message="Incoming request" level="info"']],
       },
     ],
   });
@@ -183,7 +183,7 @@ test("with line kv", async () => {
           service: "blob-city",
         },
         values: [
-          ["001", 'level="info" method="GET" message="Incoming request"'],
+          ["001", 'message="Incoming request" method="GET" level="info"'],
         ],
       },
     ],
@@ -217,7 +217,7 @@ test("with common kv", async () => {
           service: "blob-city",
         },
         values: [
-          ["001", 'level="info" rayId="1234" message="Incoming request"'],
+          ["001", 'message="Incoming request" rayId="1234" level="info"'],
         ],
       },
     ],
@@ -254,7 +254,7 @@ test("with both kv", async () => {
         values: [
           [
             "001",
-            'level="info" rayId="1234" method="GET" message="Incoming request"',
+            'message="Incoming request" rayId="1234" method="GET" level="info"',
           ],
         ],
       },
@@ -289,7 +289,7 @@ test("with undefined kv values", async () => {
           environment: "production",
           service: "blob-city",
         },
-        values: [["001", 'level="info" message="Incoming request"']],
+        values: [["001", 'message="Incoming request" level="info"']],
       },
     ],
   });
@@ -373,17 +373,17 @@ test("multiple logs", async () => {
         values: [
           [
             "001",
-            'level="info" rayId="abcd" method="GET" path="/tunnel" message="Incoming request"',
+            'message="Incoming request" rayId="abcd" method="GET" path="/tunnel" level="info"',
           ],
           [
             "002",
-            'level="debug" rayId="abcd" tunnelId="1234" message="Forwarding to DO"',
+            'message="Forwarding to DO" rayId="abcd" tunnelId="1234" level="debug"',
           ],
           [
             "003000000",
-            'level="trace" rayId="abcd" message="Creating WebSocketPair"',
+            'message="Creating WebSocketPair" rayId="abcd" level="trace"',
           ],
-          ["004", 'level="info" rayId="abcd" status=200 message="Response"'],
+          ["004", 'message="Response" rayId="abcd" status=200 level="info"'],
         ],
       },
     ],

diff --git a/tests/tail.test.ts b/tests/tail.test.ts
@@ -40,9 +40,9 @@ test("ingest-worker logs", async () => {
         values: [
           [
             "1000000",
-            'level="debug" logCount=0 exceptionCount=0 scriptName="blob-city-api" eventTimestamp=1 outcome="ok" message="Processing event"',
+            'message="Processing event" logCount=0 exceptionCount=0 scriptName="blob-city-api" eventTimestamp=1 outcome="ok" level="debug"',
           ],
-          ["1000000", 'level="debug" lineCount=0 message="Lines ready"'],
+          ["1000000", 'message="Lines ready" lineCount=0 level="debug"'],
         ],
       },
     ],
@@ -103,7 +103,7 @@ test("shipping error logs", async () => {
   expect(streams[0].values[0]).toHaveLength(2);
   expect(streams[0].values[0][0]).toBe("1000000");
   expect(streams[0].values[0][1]).toMatch(
-    /level="fatal" name="Error" stack="Error: Missing scriptName(.|\n)*" message="Missing scriptName"/,
+    /message="Missing scriptName" name="Error" stack="Error: Missing scriptName(.|\n)*" level="fatal"/,
   );
 });
 
@@ -139,7 +139,7 @@ test("extra log when outcome is not ok", async () => {
         values: [
           [
             "1000000",
-            'level="fatal" outcome="cpuExceeded" message="Fatal outcome"',
+            'message="Fatal outcome" outcome="cpuExceeded" level="fatal"',
           ],
         ],
       },
@@ -194,12 +194,12 @@ test("script logs", async () => {
           environment: "production",
         },
         values: [
-          ["1000000", 'level="info" message="log1"'],
+          ["1000000", 'message="log1" level="info"'],
           [
             "2000000",
-            'level="warn" a="b" c=9 d=false message="log2 extra params"',
+            'message="log2 extra params" a="b" c=9 d=false level="warn"',
           ],
-          ["3000000", 'level="fatal" message="log3 extra params"'],
+          ["3000000", 'message="log3 extra params" level="fatal"'],
         ],
       },
     ],
@@ -248,8 +248,8 @@ test("script exceptions", async () => {
           environment: "production",
         },
         values: [
-          ["1000000", 'level="error" message="exception1"'],
-          ["2000000", 'level="error" message="exception2"'],
+          ["1000000", 'message="exception1" level="error"'],
+          ["2000000", 'message="exception2" level="error"'],
         ],
       },
     ],
@@ -319,8 +319,8 @@ test("event batch", async () => {
           environment: "production",
         },
         values: [
-          ["1000000", 'level="info" message="log1"'],
-          ["2000000", 'level="warn" message="log2"'],
+          ["1000000", 'message="log1" level="info"'],
+          ["2000000", 'message="log2" level="warn"'],
         ],
       },
     ],
@@ -332,7 +332,7 @@ test("event batch", async () => {
           service: "blob-city-api",
           environment: "production",
         },
-        values: [["3000000", 'level="error" message="exception1"']],
+        values: [["3000000", 'message="exception1" level="error"']],
       },
     ],
   });