Debug.trace in test leads to cryptic and inconsistent error

[ceedubs]

Debug.trace in test leads to cryptic and inconsistent errors

If you have a Debug.trace call in a test, then a number of confusing things will happen:

• ucm will bug out with pure code can't perform I/O. Since tests are generally cached, this may be a reasonable thing to do, but people might not think of Debug.trace as IO, so it might be helpful to point out that it can be the cause of this error. It gets worse from here.

• It doesn't include the offending test in the test results, so you can't even tell that this test was run. A bug message prints to the screen but it has a stack trace that just has builtin.bug and a hash that doesn't actually correspond to the hash of the test term.

  Stack trace:
    builtin.bug
    #oit1slb1i3
  

• It's inconsistent because the IO sandbox doesn't apply to test> watch expressions in your scratch file.

• It's really easy to miss the introduction of the Debug.trace, because once it passes with the test> watch expression, the result is cached and you won't hit the sandbox error. Someone else will hit it when they pull your changes and run test without having a cached result for it.

Raw Transcript

Expand to copy raw transcript

```ucm:hide
.> builtins.merge
```

This passes, because the IO sandbox doesn't seem to apply to `test>` watch expressions.

```unison
test> foo.test =
  x = 192
  Debug.trace "x" x
  [Ok "Passed"]
```

```ucm
.> add
```

The `test` command succeeds, because the result of `foo.test` is already cached, which skips the IO sandbox.

```ucm
.> test
```

This test which is essentially the same will fail, because it is never run with a `test>` watch expression to get the result into the test cache.

```unison
bar.test : [Test.Result]
bar.test =
  x = 42
  Debug.trace "x" x
  [Ok "Passed"]
```

```ucm
.> add
.> test
```

Transcript output

This passes, because the IO sandbox doesn't seem to apply to test> watch expressions.

test> foo.test =
  x = 192
  Debug.trace "x" x
  [Ok "Passed"]

  Loading changes detected in scratch.u.

  I found and typechecked these definitions in scratch.u. If you
  do an `add` or `update`, here's how your codebase would
  change:
  
    ⍟ These new definitions are ok to `add`:
    
      foo.test : [Result]
  
  Now evaluating any watch expressions (lines starting with
  `>`)... Ctrl+C cancels.

    2 |   x = 192
    
    ✅ Passed Passed

.> add

  ⍟ I've added these definitions:
  
    foo.test : [Result]

The test command succeeds, because the result of foo.test is already cached, which skips the IO sandbox.

.> test

  Cached test results (`help testcache` to learn more)
  
  ◉ foo.test   Passed
  
  ✅ 1 test(s) passing
  
  Tip: Use view foo.test to view the source of a test.

This test which is essentially the same will fail, because it is never run with a test> watch expression to get the result into the test cache.

bar.test : [Test.Result]
bar.test =
  x = 42
  Debug.trace "x" x
  [Ok "Passed"]

  Loading changes detected in scratch.u.

  I found and typechecked these definitions in scratch.u. If you
  do an `add` or `update`, here's how your codebase would
  change:
  
    ⍟ These new definitions are ok to `add`:
    
      bar.test : [Result]

.> add

  ⍟ I've added these definitions:
  
    bar.test : [Result]

.> test

    
    Cached test results (`help testcache` to learn more)
    
    ◉ foo.test   Passed
    
    ✅ 1 test(s) passing
    
    ✅  

  

  💔💥
  
  I've encountered a call to builtin.bug with the following
  value:
  
    "pure code can't perform I/O"
  
  
  Stack trace:
    builtin.bug
    #oit1slb1i3

🛑

The transcript failed due to an error in the stanza above. The error is:

💔💥

I've encountered a call to builtin.bug with the following value:

"pure code can't perform I/O"

Stack trace: builtin.bug #oit1slb1i3

[aryairani]

I ran into this also.

Debug.trace "..."

fails

when false do Debug.trace "..."

fails

_ = do Debug.trace "..."

passes.

One repro with

clone @aryairani/hnsw-anns/@aryairani/pure-code-cant-perform-io
tests

[ceedubs]

This still happens and is super bewildering, because the test that it complains about doesn't show up anywhere in the output.