Inconsistent behavior when tracing messages within a failing validator (version 1.21.0.0)

[mmontin]

Summary

I have witnessed an inconsistent behavior when using trace functions within validation code. In some cases, the message actually appears in the final result, and in others, it does not.

Here is a vanilla example. Consider the following validator:

traceValidator :: Pl.TypedValidator MockContract
traceValidator =
  Pl.mkTypedValidator @MockContract
    $$(Pl.compile [||val||])
    $$(Pl.compile [||wrap||])
  where
    val :: () -> () -> Pl.ScriptContext -> Bool
    val _ _ _ = Pl.traceIfFalse "this is false" False
    wrap = Pl.mkUntypedValidator

When called, this validator produces the following validation error:

Evaluation error [ PT5 ]

Before, in version 1.0.0.0, we used to get:

EvaluationError ["Data decoded successfully","Redeemer decoded successfully","Script context decoded successfully","this is false","PT5"]

I have conducted some further testing with various variations of this validator.

1. Here are the variations that do produce a trace of the expected messages:

The validator with a boolean and a string as parameter. We get a trace of either the given string, or the statical one, depending on the value of the boolean:

val :: (Bool, Pl.BuiltinString) -> () -> () -> Pl.ScriptContext -> Bool
val (b, s) _ _ _ = Pl.traceIfFalse (if b then s else "this is false") False

The validator with a boolean as parameter:

val :: Bool -> () -> () -> Pl.ScriptContext -> Bool
val b _ _ _ = Pl.traceIfFalse (if b then "this is true" else "this is false") False

The validator with a String as parameter:

val :: Pl.BuiltinString -> () -> () -> Pl.ScriptContext -> Bool
val s _ _ _ = Pl.traceIfFalse s False

The validator with two conditions, both tracing a message:

val :: () -> () -> Pl.ScriptContext -> Bool
val _ _ _ =
  let a = Pl.traceIfFalse "this is true" False
      b = Pl.traceIfFalse "this is also true" False
  in a && b

2. Here are other examples where we do not get anything traced:

Encompass the string in a let binding:

val :: () -> () -> Pl.ScriptContext -> Bool
val _ _ _ = let s = "this is true" in Pl.traceIfFalse s False

Encompass the whole expression in a let binding:

val :: () -> () -> Pl.ScriptContext -> Bool
val _ _ _ = let a = Pl.traceIfFalse "this is true" False in a

I have no idea where these discrepancies come from. Everything used to be printed properly in v1.0.0.0.

Steps to reproduce the behavior

Create the following dummy validator:

traceValidator :: Pl.TypedValidator MockContract
traceValidator =
  Pl.mkTypedValidator @MockContract
    $$(Pl.compile [||val||])
    $$(Pl.compile [||wrap||])
  where
    val :: () -> () -> Pl.ScriptContext -> Bool
    val _ _ _ = Pl.traceIfFalse "this is false" False
    wrap = Pl.mkUntypedValidator

Run it by consuming one of its outputs.

Actual Result

Evaluation error [ PT5 ]

Expected Result

Evaluation error [ this is false, PT5 ]

Describe the approach you would take to fix this

No response

System info

Ubuntu.
Library version 1.21.0.0

[mmontin]

Thanks to @nhenin I managed to fix this. To my understanding, it turns out that this was not a bug but a feature where default optimizations would in fact remove some of the tracing. By using conservative-optimisation it works as it did before. Note that the option preserve-logging which is supposed to be implied by the former actually is not recognized by itself.

[Unisay]

Hi @mmontin,

I see that you've already discovered the conservative-optimisation flag which is not turned on by default. So by turning it on you disable certain optimisations that can remove traces. This is useful for development and debugging.

There is also another compiler option called remove-traces / no-remove-traces. This test spec uses both options to verify tracing preservation.

As for the preserve-logging option's behaviour - I'd need to investigate. Thanks for mentioning it!

[Unisay]

I wrote a few tests to verify that preserve-logging option behaves as expected. The tests didn't reveal any misbehaviour and the option got recognized.

@mmontin please check them out and let me know if you believe there is a way to reproduce the problem with preserve-logging you've mentioned.

Feel free to close the issue if you confirm that original problem is solved.