fix: otel resiliency (#26857)

Improving the breadth of collected data, and ensuring that the collected
data is more likely to be successfully reported.

- Use `log` crate in more places
- Hook up `log` crate to otel
- Switch to process-wide otel processors
- Handle places that use `process::exit`

Also adds a more robust testing framework, with a deterministic tracing
setting.

Refs: https://github.com/denoland/deno/issues/26852

11 files changed, 215 insertions, 64 deletions

diff --git a/tests/specs/cli/otel_basic/__test__.jsonc b/tests/specs/cli/otel_basic/__test__.jsonc
index a9d4fff04..5a27e9262 100644
--- a/tests/specs/cli/otel_basic/__test__.jsonc
+++ b/tests/specs/cli/otel_basic/__test__.jsonc
@@ -1,4 +1,32 @@
 {
-  "args": "run -A main.ts",
-  "output": "processed\n"
+  "steps": [
+    {
+      "args": "run -A main.ts basic.ts",
+      "envs": {
+        "DENO_UNSTABLE_OTEL_DETERMINISTIC": "1"
+      },
+      "output": "basic.out"
+    },
+    {
+      "args": "run -A main.ts natural_exit.ts",
+      "envs": {
+        "DENO_UNSTABLE_OTEL_DETERMINISTIC": "1"
+      },
+      "output": "natural_exit.out"
+    },
+    {
+      "args": "run -A main.ts deno_dot_exit.ts",
+      "envs": {
+        "DENO_UNSTABLE_OTEL_DETERMINISTIC": "1"
+      },
+      "output": "deno_dot_exit.out"
+    },
+    {
+      "args": "run -A main.ts uncaught.ts",
+      "envs": {
+        "DENO_UNSTABLE_OTEL_DETERMINISTIC": "1"
+      },
+      "output": "uncaught.out"
+    }
+  ]
 }
diff --git a/tests/specs/cli/otel_basic/basic.out b/tests/specs/cli/otel_basic/basic.out
new file mode 100644
index 000000000..3f0554f96
--- /dev/null
+++ b/tests/specs/cli/otel_basic/basic.out
@@ -0,0 +1,76 @@
+{
+  "spans": [
+    {
+      "traceId": "00000000000000000000000000000002",
+      "spanId": "0000000000000003",
+      "traceState": "",
+      "parentSpanId": "0000000000000001",
+      "flags": 1,
+      "name": "inner span",
+      "kind": 1,
+      "startTimeUnixNano": "[WILDCARD]",
+      "endTimeUnixNano": "[WILDCARD]",
+      "attributes": [],
+      "droppedAttributesCount": 0,
+      "events": [],
+      "droppedEventsCount": 0,
+      "links": [],
+      "droppedLinksCount": 0,
+      "status": {
+        "message": "",
+        "code": 0
+      }
+    },
+    {
+      "traceId": "00000000000000000000000000000002",
+      "spanId": "0000000000000001",
+      "traceState": "",
+      "parentSpanId": "",
+      "flags": 1,
+      "name": "outer span",
+      "kind": 1,
+      "startTimeUnixNano": "[WILDCARD]",
+      "endTimeUnixNano": "[WILDCARD]",
+      "attributes": [],
+      "droppedAttributesCount": 0,
+      "events": [],
+      "droppedEventsCount": 0,
+      "links": [],
+      "droppedLinksCount": 0,
+      "status": {
+        "message": "",
+        "code": 0
+      }
+    }
+  ],
+  "logs": [
+    {
+      "timeUnixNano": "0",
+      "observedTimeUnixNano": "[WILDCARD]",
+      "severityNumber": 9,
+      "severityText": "INFO",
+      "body": {
+        "stringValue": "log 1\n"
+      },
+      "attributes": [],
+      "droppedAttributesCount": 0,
+      "flags": 1,
+      "traceId": "00000000000000000000000000000002",
+      "spanId": "0000000000000003"
+    },
+    {
+      "timeUnixNano": "0",
+      "observedTimeUnixNano": "[WILDCARD]",
+      "severityNumber": 9,
+      "severityText": "INFO",
+      "body": {
+        "stringValue": "log 2\n"
+      },
+      "attributes": [],
+      "droppedAttributesCount": 0,
+      "flags": 1,
+      "traceId": "00000000000000000000000000000002",
+      "spanId": "0000000000000003"
+    }
+  ]
+}
diff --git a/tests/specs/cli/otel_basic/child.ts b/tests/specs/cli/otel_basic/basic.ts
index 72cffd9f0..5a178794a 100644
--- a/tests/specs/cli/otel_basic/child.ts
+++ b/tests/specs/cli/otel_basic/basic.ts
@@ -7,10 +7,14 @@ async function inner() {
   console.log("log 2");
 }
 
-Deno.serve({
+const server = Deno.serve({
   port: 0,
-  onListen({ port }) {
-    console.log(port.toString());
+  async onListen({ port }) {
+    try {
+      await fetch(`http://localhost:${port}`);
+    } finally {
+      server.shutdown();
+    }
   },
   handler: async (_req) => {
     using _span = new Deno.tracing.Span("outer span");
diff --git a/tests/specs/cli/otel_basic/deno_dot_exit.out b/tests/specs/cli/otel_basic/deno_dot_exit.out
new file mode 100644
index 000000000..98a41cf60
--- /dev/null
+++ b/tests/specs/cli/otel_basic/deno_dot_exit.out
@@ -0,0 +1,19 @@
+{
+  "spans": [],
+  "logs": [
+    {
+      "timeUnixNano": "0",
+      "observedTimeUnixNano": "[WILDCARD]",
+      "severityNumber": 9,
+      "severityText": "INFO",
+      "body": {
+        "stringValue": "log 1\n"
+      },
+      "attributes": [],
+      "droppedAttributesCount": 0,
+      "flags": 0,
+      "traceId": "",
+      "spanId": ""
+    }
+  ]
+}
diff --git a/tests/specs/cli/otel_basic/deno_dot_exit.ts b/tests/specs/cli/otel_basic/deno_dot_exit.ts
new file mode 100644
index 000000000..73540fd9e
--- /dev/null
+++ b/tests/specs/cli/otel_basic/deno_dot_exit.ts
@@ -0,0 +1,2 @@
+console.log("log 1");
+Deno.exit(0);
diff --git a/tests/specs/cli/otel_basic/main.ts b/tests/specs/cli/otel_basic/main.ts
index 66ef5c79c..6c49462a0 100644
--- a/tests/specs/cli/otel_basic/main.ts
+++ b/tests/specs/cli/otel_basic/main.ts
@@ -1,76 +1,38 @@
 // Copyright 2018-2024 the Deno authors. All rights reserved. MIT license.
 
-import { assert, assertEquals } from "@std/assert";
-import { TextLineStream } from "@std/streams/text-line-stream";
+const data = {
+  spans: [],
+  logs: [],
+};
 
-const logs = [];
-const spans = [];
-let child: Deno.ChildProcess;
-
-Deno.serve(
+const server = Deno.serve(
   {
     port: 0,
-    async onListen({ port }) {
+    onListen({ port }) {
       const command = new Deno.Command(Deno.execPath(), {
-        args: ["run", "-A", "--unstable-otel", "child.ts"],
+        args: ["run", "-A", "--unstable-otel", Deno.args[0]],
         env: {
           OTEL_EXPORTER_OTLP_PROTOCOL: "http/json",
           OTEL_EXPORTER_OTLP_ENDPOINT: `http://localhost:${port}`,
-          OTEL_BSP_SCHEDULE_DELAY: "10",
-          OTEL_BLRP_SCHEDULE_DELAY: "10",
         },
-        stdin: "piped",
-        stdout: "piped",
-        stderr: "inherit",
+        stdout: "null",
+      });
+      const child = command.spawn();
+      child.output().then(() => {
+        server.shutdown();
+
+        console.log(JSON.stringify(data, null, 2));
       });
-      child = command.spawn();
-      const lines = child.stdout
-        .pipeThrough(new TextDecoderStream())
-        .pipeThrough(new TextLineStream())
-        .getReader();
-      const line = await lines.read();
-      await fetch(`http://localhost:${line.value}/`);
     },
     async handler(req) {
-      try {
-        const body = await req.json();
-        if (body.resourceLogs) {
-          logs.push(...body.resourceLogs[0].scopeLogs[0].logRecords);
-        }
-        if (body.resourceSpans) {
-          spans.push(...body.resourceSpans[0].scopeSpans[0].spans);
-        }
-
-        if (logs.length > 2 && spans.length > 1) {
-          child.kill();
-
-          const inner = spans.find((s) => s.name === "inner span");
-          const outer = spans.find((s) => s.name === "outer span");
-
-          assertEquals(inner.traceId, outer.traceId);
-          assertEquals(inner.parentSpanId, outer.spanId);
-
-          assertEquals(logs[1].body.stringValue, "log 1\n");
-          assertEquals(logs[1].traceId, inner.traceId);
-          assertEquals(logs[1].spanId, inner.spanId);
-
-          assertEquals(logs[2].body.stringValue, "log 2\n");
-          assertEquals(logs[2].traceId, inner.traceId);
-          assertEquals(logs[2].spanId, inner.spanId);
-
-          console.log("processed");
-          Deno.exit(0);
-        }
-
-        return Response.json({ partialSuccess: {} }, { status: 200 });
-      } catch (e) {
-        console.error(e);
-        Deno.exit(1);
+      const body = await req.json();
+      if (body.resourceLogs) {
+        data.logs.push(...body.resourceLogs[0].scopeLogs[0].logRecords);
+      }
+      if (body.resourceSpans) {
+        data.spans.push(...body.resourceSpans[0].scopeSpans[0].spans);
       }
+      return Response.json({ partialSuccess: {} }, { status: 200 });
     },
   },
 );
-
-setTimeout(() => {
-  assert(false, "test did not finish in time");
-}, 10e3);
diff --git a/tests/specs/cli/otel_basic/natural_exit.out b/tests/specs/cli/otel_basic/natural_exit.out
new file mode 100644
index 000000000..98a41cf60
--- /dev/null
+++ b/tests/specs/cli/otel_basic/natural_exit.out
@@ -0,0 +1,19 @@
+{
+  "spans": [],
+  "logs": [
+    {
+      "timeUnixNano": "0",
+      "observedTimeUnixNano": "[WILDCARD]",
+      "severityNumber": 9,
+      "severityText": "INFO",
+      "body": {
+        "stringValue": "log 1\n"
+      },
+      "attributes": [],
+      "droppedAttributesCount": 0,
+      "flags": 0,
+      "traceId": "",
+      "spanId": ""
+    }
+  ]
+}
diff --git a/tests/specs/cli/otel_basic/natural_exit.ts b/tests/specs/cli/otel_basic/natural_exit.ts
new file mode 100644
index 000000000..d40478252
--- /dev/null
+++ b/tests/specs/cli/otel_basic/natural_exit.ts
@@ -0,0 +1 @@
+console.log("log 1");
diff --git a/tests/specs/cli/otel_basic/uncaught.out b/tests/specs/cli/otel_basic/uncaught.out
new file mode 100644
index 000000000..a5a886bfe
--- /dev/null
+++ b/tests/specs/cli/otel_basic/uncaught.out
@@ -0,0 +1,37 @@
+error: Uncaught (in promise) Error: uncaught
+throw new Error("uncaught");
+      ^
+    at file:///[WILDCARD]/tests/specs/cli/otel_basic/uncaught.ts:2:7
+{
+  "spans": [],
+  "logs": [
+    {
+      "timeUnixNano": "0",
+      "observedTimeUnixNano": "[WILDCARD]",
+      "severityNumber": 9,
+      "severityText": "INFO",
+      "body": {
+        "stringValue": "log 1\n"
+      },
+      "attributes": [],
+      "droppedAttributesCount": 0,
+      "flags": 0,
+      "traceId": "",
+      "spanId": ""
+    },
+    {
+      "timeUnixNano": "0",
+      "observedTimeUnixNano": "[WILDCARD]",
+      "severityNumber": 17,
+      "severityText": "ERROR",
+      "body": {
+        "stringValue": "error: Uncaught (in promise) Error: uncaught\nthrow new Error(\"uncaught\");\n      ^\n    at file:///[WILDCARD]/tests/specs/cli/otel_basic/uncaught.ts:2:7"
+      },
+      "attributes": [],
+      "droppedAttributesCount": 0,
+      "flags": 0,
+      "traceId": "",
+      "spanId": ""
+    }
+  ]
+}
diff --git a/tests/specs/cli/otel_basic/uncaught.ts b/tests/specs/cli/otel_basic/uncaught.ts
new file mode 100644
index 000000000..eca7c05cb
--- /dev/null
+++ b/tests/specs/cli/otel_basic/uncaught.ts
@@ -0,0 +1,2 @@
+console.log("log 1");
+throw new Error("uncaught");
diff --git a/tests/util/server/src/macros.rs b/tests/util/server/src/macros.rs
index fdbb977e9..e076583f1 100644
--- a/tests/util/server/src/macros.rs
+++ b/tests/util/server/src/macros.rs
@@ -33,6 +33,7 @@ macro_rules! timeout {
           use std::io::Write;
           eprintln!("Test {function} timed out after {timeout} seconds, aborting");
           _ = std::io::stderr().flush();
+          #[allow(clippy::disallowed_methods)]
           ::std::process::exit(1);
         }
       });