deno test --trace-ops provides no additional detail when sanitizers are disabled for some related steps

[jsejcksn]

When running a test with an op/resource sanitization failure, a message is printed in the output:

To get more details where ops were leaked, run again with --trace-ops flag.

However, when sanitizers are disabled for some, but not all related test steps, using the suggested CLI argument offers no additional detail. Depending on the test runner implementation, this might be reasonable, but it's not intuitive why it seems ineffective and appears to be a bug without more documentation/context.

---

Here's a minimal, reproducible example (contrived, but based on another test I was debugging that's far too verbose to include here — the mechanics are similar):

example.test.ts:

import { delay } from "https://deno.land/[email protected]/async/delay.ts";

Deno.test(async function example(ctx) {
  let timerPromise: Promise<void>;

  await ctx.step({
    name: "starts and cancels timer",
    fn: async () => {
      const controller = new AbortController();
      await Promise.race([
        delay(10),
        timerPromise = delay(1000, { signal: controller.signal })
          .catch(() => {/* Ignore */}),
      ]);
      controller.abort();
    },
    sanitizeOps: false,
    sanitizeResources: false,
  });

  await ctx.step({
    name: "awaits timer",
    fn: () => timerPromise,
  });
});

Terminal outputs:

% deno --version
deno 1.34.3 (release, aarch64-apple-darwin)
v8 11.5.150.2
typescript 5.0.4

Without --trace-ops:

% deno test example.test.ts
running 1 test from ./example.test.ts
example ...
  starts and cancels timer ... ok (14ms)
  awaits timer ... FAILED (7ms)
example ... FAILED (due to 1 failed step) (26ms)

 ERRORS

example ... awaits timer => ./example.test.ts:21:13
error: Leaking async ops:
  - 1 async operation to sleep for a duration was started before this test, but was completed during the test. Async operations should not complete in a test if they were not started in that test.
            This is often caused by not cancelling a `setTimeout` or `setInterval` call.
To get more details where ops were leaked, run again with --trace-ops flag.

 FAILURES

example ... awaits timer => ./example.test.ts:21:13

FAILED | 0 passed (1 step) | 1 failed (1 step) (36ms)

error: Test failed

With --trace-ops:

% deno test --trace-ops example.test.ts
running 1 test from ./example.test.ts
example ...
  starts and cancels timer ... ok (13ms)
  awaits timer ... FAILED (6ms)
example ... FAILED (due to 1 failed step) (25ms)

 ERRORS

example ... awaits timer => ./example.test.ts:21:13
error: Leaking async ops:
  - 1 async operation to sleep for a duration was started before this test, but was completed during the test. Async operations should not complete in a test if they were not started in that test.
            This is often caused by not cancelling a `setTimeout` or `setInterval` call.

 FAILURES

example ... awaits timer => ./example.test.ts:21:13

FAILED | 0 passed (1 step) | 1 failed (1 step) (35ms)

error: Test failed

And here's a diff of those two outputs to make the comparison more obvious:

-% deno test example.test.ts
+% deno test --trace-ops example.test.ts
 running 1 test from ./example.test.ts
 example ...
-  starts and cancels timer ... ok (14ms)
-  awaits timer ... FAILED (7ms)
-example ... FAILED (due to 1 failed step) (26ms)
+  starts and cancels timer ... ok (13ms)
+  awaits timer ... FAILED (6ms)
+example ... FAILED (due to 1 failed step) (25ms)
 
  ERRORS
 
 example ... awaits timer => ./example.test.ts:21:13
 error: Leaking async ops:
   - 1 async operation to sleep for a duration was started before this test, but was completed during the test. Async operations should not complete in a test if they were not started in that test.
             This is often caused by not cancelling a `setTimeout` or `setInterval` call.
-To get more details where ops were leaked, run again with --trace-ops flag.
 
  FAILURES
 
 example ... awaits timer => ./example.test.ts:21:13
 
-FAILED | 0 passed (1 step) | 1 failed (1 step) (36ms)
+FAILED | 0 passed (1 step) | 1 failed (1 step) (35ms)
 
 error: Test failed

[bartlomieju]

@jsejcksn is this still a problem in latest Deno (v2.1.x)?

[jsejcksn]

@bartlomieju I'm not sure. The argument --trace-ops was removed in #25344 … and replaced by --trace-leaks, right? Aside from that change, running the same test file above in Deno 2.1.3 now passes all steps, so I guess something else changed in the way that Deno handles timer/async resources. That isn't what this issue was about, so the unrelated changes nullify the usefulness of the example test for behavior comparison across runtime versions.

[dandv]

--trace-leaks outputs nothing extra in a complex test that would me take a while to reduce to a minimal repro. Any chance --trace-leaks is known to not work in certain situations?

All I see from deno test... regarding leaks is

error: Leaks detected:

• A TCP connection was opened/accepted during the test, but not closed during the test. Close the TCP connection by calling tcpConn.close().

whether I add --trace-leaks or not.

#27948