Confusing behavior / sometimes failing validators for semantically equivalent changes.

KtorZ commented 3 years ago

Area

[?] Plutus Foundation Related to the GHC plugin, Haskell-to-Plutus compiler, on-chain code [?] Plutus Application Framework Related to the Plutus application backend (PAB), emulator, Plutus libraries ~~[] Marlowe Related to Marlowe~~ ~~[] Other Any other topic (Playgrounds, etc.)~~

Summary

History

We had a working contract and test suite.
Then, we upgraded Plutus to the most recent commit hash 35b1e41b162a5bae87955a86e5eea33535130ff9 (at the time):
Our test suite was then failing (without any change) after the upgrade: input-output-hk/hydra-poc@6255012450728062dbbc13b3fbef49a48385fd49
We upgraded some other parts, and then gave a shot at fixing this test suite starting from: input-output-hk/hydra-poc@ce6e38c4d7cf70c0e6131ab75b23b238bb334d4a

Making what should be semantically equivalent changes (replacing a truthy expression with True, or changing from and [a,b] to a && b) do change the behavior of the validator in an unpredictable but deterministic way (see below for details).

Some changes made the test suite pass, some made it fail again but without clear reason. This is confusing :/

Steps to reproduce

Starting point

To the reproduce the initial failure, please follow these steps:

$ git clone https://github.com/input-output-hk/hydra-poc/tree/ce6e38c4d7cf70c0e6131ab75b23b238bb334d4a
$ cd hydra-poc 
$ nix-shell 
$ cabal test hydra-plutus --test-options '-p "Can CollectCom"

1. `and` -> `&&`

From there the fun begins... The following diff, makes the test suite pass. Notice that the only change is removing the use of and in favor of multiple inlined &&. Conditions are still the same and it is fully reproducible. Switching back to and makes the test fail again, and vice-versa.

input-output-hk/hydra-poc@ab45e9e62d2ba5d78720bc828a01a11361a873e8

See here the diff with the contract PIR https://github.com/input-output-hk/hydra-poc/commit/15b43ca975e6064c814b1350bfaef84982de09f1

2. Alternative (equivalent) implementation

That second diff, reverts the previous one but, changes the implementation of our mustForwardParty predicate to (what should be) an equivalent implementation. That is, we are inlining the internals of checkScriptContext with the corresponding code handling the MustSpendAtLeast and MustProduceAtLeast data-constructors.

Changing this makes the test pass.

input-output-hk/hydra-poc@847e72a0a17706543671e46f7848c926ed802eb3

See here the diff with the contract PIR https://github.com/input-output-hk/hydra-poc/commit/66ba442c1350cb43892ad1788a05673ff32fc216

3. Removing a (truthy) predicate

This one is our favorite.

On this diff, we removed one of the predicate on a conjunction. What led us here was the absence of trace ("PT not produced") in the failure from the Emulator. This changes... makes the passing test now fail... ?!?

input-output-hk/hydra-poc@da605c60307d5d75ca5b2e0a71cd8bf2ef3a8929

See here the diff with the contract PIR https://github.com/input-output-hk/hydra-poc/commit/149a8418391a5ba39bebb2b03990e76ac4caa8ff

4. Changing unrelated code

This is even better. Changing an unrelated case in the validator (according to diff (1)) makes the test pass again. Please do notice that the diff is about the Abort branch, which is not executed in the test (which fails on the CollectCom). Changing this was actually a mistake of ours as we intended to change the CollectCom branch, but the results were surprising, if not mind-blowing.

input-output-hk/hydra-poc@e0797accdda4d327a733574664445c7534d3d428

See here the diff with the contract PIR https://github.com/input-output-hk/hydra-poc/commit/43727bfa3052121b6f4dd38cce9c5fc7a427f4c3

Expected behavior

None of these changes should result in different validator behavior (observed from the tests). They are semantically equivalent.

System info (please complete the following information):

OS: NixOS, Ubuntu, Manjaro (everywhere we could try it out).
Version: 21.5, 20-04
Plutus version: 35b1e41b162a5bae87955a86e5eea33535130ff9

Screenshots and attachments

image(13)

Additional context

Might be related to #3488 & #3601

(cc @ch1bo @abailly-iohk)

Thanks for the help :pray:

michaelpj commented 3 years ago

When you say the tests pass/fail, do the failures come from script failures, or otherwise? Maybe @j-mueller can help us track this down? Because the scripts don't look too bad right now.

michaelpj commented 3 years ago

It would be helpful to have the trace log for the script that we expect to pass/fail in each case...

michaelpj commented 3 years ago

Another useful thing: I have a vague hypothesis that this could be due to differing strictnesses of && and all. We could verify this by putting some trace statements around each of the conditions and seeing whether we get all of them in the log in both cases.

If one of the conditions actually throws an error, but one of && or all is lazy enough not to evaluate it, then that could explain the difference.

KtorZ commented 3 years ago

When you say the tests pass/fail, do the failures come from script failures, or otherwise?

According to the emulator, the failures comes from the validator which fails to validate the transaction produced by the offchain code.

I have a vague hypothesis that this could be due to differing strictnesses of && and all

How come though? For a conjunction, I'd expect a lazy evaluation to stop at the first falsy value. And, the validator would actually fail on every call no matter what (because one of the element is falsy). But here, we have sometimes passing validators, and sometimes failing ones; To have a validator being evaluated to True, then surely all branches of the conjunction must evaluate to True :thinking:

KtorZ commented 3 years ago

It would be helpful to have the trace log for the script that we expect to pass/fail in each case...

Here's an example of the (end of the) trace log for the base contract, which fails because of some evaluation error for one of the script output. It complains about pretty much all conditions present in the validator.

Contracts tests
  Hydra Scenarios
    Init > Commit > Commit > CollectCom: Can CollectCom when all parties have submitted: FAIL (0.25s)

[...]

[INFO] Slot 6: 00000000-0000-4000-8000-000000000000 {Contract instance for wallet 1}:
                 Receive endpoint call on 'collectCom' for Object (fromList [("contents",Array [Object (fromList [("getEndpointDescription",String "collectCom")]),Object (fromList [("unEndpointValue",Array [Object (fromList [("getPubKeyHash",String "35dedd2982a03cf39e7dce03c839994ffdec2ec6b04f1cf2d40e61a3")]),Array [Object (fromList [("txOutAddress",Object (fromList [("addressCredential",Object (fromList [("contents",Object (fromList [("getPubKeyHash",String "35dedd2982a03cf39e7dce03c839994ffdec2ec6b04f1cf2d40e61a3")])),("tag",String "PubKeyCredential")])),("addressStakingCredential",Null)])),("txOutDatumHash",Null),("txOutValue",Object (fromList [("getValue",Array [Array [Object (fromList [("unCurrencySymbol",String "")]),Array [Array [Object (fromList [("unTokenName",String "")]),Number 1000.0]]]])]))]),Object (fromList [("txOutAddress",Object (fromList [("addressCredential",Object (fromList [("contents",Object (fromList [("getPubKeyHash",String "977efb35ab621d39dbeb7274ec7795a34708ff4d25a01a1df04c1f27")])),("tag",String "PubKeyCredential")])),("addressStakingCredential",Null)])),("txOutDatumHash",Null),("txOutValue",Object (fromList [("getValue",Array [Array [Object (fromList [("unCurrencySymbol",String "")]),Array [Array [Object (fromList [("unTokenName",String "")]),Number 1000.0]]]])]))])]])])]),("tag",String "ExposeEndpointResp")])
[INFO] Slot 6: W1: Balancing an unbalanced transaction:
                     Tx:
                       Tx 1765d66cf878d1740a43e7fb1f750714e7691a2c07c93deb85c36881fed0034a:
                         {inputs:
                            - 22d479018f5cfeb6255e5f74769958691c6de75fabf00dc84b34f90ad3b4b907!1
                              <>
                            - e6556d453e86605eda29c0a221259cd831a91c1ad18c60f13a12142cb9964074!1
                              <>
                            - ebb0589a32f986407a2b2934a78b02fd03cfba5d289fde7c44a00222621f58cb!1
                              <>
                         collateral inputs:
                         outputs:
                           - Value (Map [(,Map [("",2000)]),(7823198bf3fa55a923f349eda13874c12deb28fa799b604b77430a82,Map [(0x35dedd2982a03cf39e7dce03c839994ffdec2ec6b04f1cf2d40e61a3,1),(0x977efb35ab621d39dbeb7274ec7795a34708ff4d25a01a1df04c1f27,1)])]) addressed to
                             addressed to ScriptCredential: 0d13999069c55537f3bb43f96040182c761c2d93d4b4fb031b9e6cff (no staking credential)
                         mint: Value (Map [])
                         fee: Value (Map [])
                         mps:
                         signatures:
                         validity range: Interval {ivFrom = LowerBound NegInf True, ivTo = UpperBound PosInf True}
                         data:
                           <>
                           <[<<<"\151~\251\&5\171b\GS9\219\235rt\236w\149\163G\b\255M%\160\SUB\GS\240L\US'">,
                           <>>,
                           [<"", [<"", 1000>]>],
                           <>>,
                           <<<"5\222\221)\130\160<\243\158}\206\ETX\200\&9\153O\253\236.\198\176O\FS\242\212\SOa\163">,
                           <>>,
                           [<"", [<"", 1000>]>],
                           <>>]>
                           <<<"\151~\251\&5\171b\GS9\219\235rt\236w\149\163G\b\255M%\160\SUB\GS\240L\US'">,
                           <>>,
                           [<"", [<"", 1000>]>],
                           <>>
                           <<<"5\222\221)\130\160<\243\158}\206\ETX\200\&9\153O\253\236.\198\176O\FS\242\212\SOa\163">,
                           <>>,
                           [<"", [<"", 1000>]>],
                           <>>}
                     Requires signatures:
                       35dedd2982a03cf39e7dce03c839994ffdec2ec6b04f1cf2d40e61a3
                     Utxo index:
                       ( 22d479018f5cfeb6255e5f74769958691c6de75fabf00dc84b34f90ad3b4b907!1
                       , - Value (Map [(,Map [("",1000)]),(7823198bf3fa55a923f349eda13874c12deb28fa799b604b77430a82,Map [(0x35dedd2982a03cf39e7dce03c839994ffdec2ec6b04f1cf2d40e61a3,1)])]) addressed to
                           addressed to ScriptCredential: be5719fcd50b32b8c5b37224c9165f84b881aeb99704ffb183358d1b (no staking credential) )
                       ( e6556d453e86605eda29c0a221259cd831a91c1ad18c60f13a12142cb9964074!1
                       , - Value (Map []) addressed to
                           addressed to ScriptCredential: 0d13999069c55537f3bb43f96040182c761c2d93d4b4fb031b9e6cff (no staking credential) )
                       ( ebb0589a32f986407a2b2934a78b02fd03cfba5d289fde7c44a00222621f58cb!1
                       , - Value (Map [(,Map [("",1000)]),(7823198bf3fa55a923f349eda13874c12deb28fa799b604b77430a82,Map [(0x977efb35ab621d39dbeb7274ec7795a34708ff4d25a01a1df04c1f27,1)])]) addressed to
                           addressed to ScriptCredential: be5719fcd50b32b8c5b37224c9165f84b881aeb99704ffb183358d1b (no staking credential) )
[WARNING] Slot 6: W1: Validation error: Phase2 1765d66cf878d1740a43e7fb1f750714e7691a2c07c93deb85c36881fed0034a: ScriptFailure (EvaluationError ["Missing signature","checkScriptContext failed","Missing datum","checkScriptContext failed","Check has failed"])
[WARNING] Slot 6: 00000000-0000-4000-8000-000000000000 {Contract instance for wallet 1}:
                    Contract instance stopped with error: WalletError (ValidationError (ScriptFailure (EvaluationError ["Missing signature","checkScriptContext failed","Missing datum","checkScriptContext failed","Check has failed"])))
  src/Plutus/Contract/Test.hs:243:
  Init > Commit > Commit > CollectCom: Can CollectCom when all parties have submitted

Changing from and to multiple inlined && makes the test pass:

Contracts tests
  Hydra Scenarios
    Init > Commit > Commit > CollectCom: Can CollectCom when all parties have submitted: OK (0.34s)

Changing it back to and but, inlining of the checkScriptContext in the validator branch makes it fail again with a similar error:

Contracts tests
  Hydra Scenarios
    Init > Commit > Commit > CollectCom: Can CollectCom when all parties have submitted: FAIL (0.24s)

[...]

      [WARNING] Slot 6: W1: Validation error: Phase2 df90f713608a4db280c74edba6be533305cbf72e7ea60b3d05bbdfe4bd12b610: ScriptFailure (EvaluationError ["Missing signature","checkScriptContext failed","Missing datum","checkScriptContext failed","Check has failed"])
      [WARNING] Slot 6: 00000000-0000-4000-8000-000000000000 {Contract instance for wallet 1}:
                          Contract instance stopped with error: WalletError (ValidationError (ScriptFailure (EvaluationError ["Missing signature","checkScriptContext failed","Missing datum","checkScriptContext failed","Check has failed"])))
        src/Plutus/Contract/Test.hs:243:
        Init > Commit > Commit > CollectCom: Can CollectCom when all parties have submitted

ch1bo commented 3 years ago

After updating plutus to f174d2700e3a4ae9378870b1968521a88f0f2801 (master from yesterday) I do get now a bit more info about errors on our test failures:

      [WARNING] Slot 6: W1: Validation error: Phase2 69e0b9baf815d4316ec26ad97131847d8eb1d8550b2aa46df5a7915c53f40409: ScriptFailure (EvaluationError ["L4","Ld","L2","Ld","Pd"] "CekEvaluationFailure")
      [WARNING] Slot 6: 00000000-0000-4000-8000-000000000000 {Contract instance for wallet 1}:
                          Contract instance stopped with error: WalletError (ValidationError (ScriptFailure (EvaluationError ["L4","Ld","L2","Ld","Pd"] "CekEvaluationFailure")))
        src/Plutus/Contract/Test.hs:241:
        Init > Commit > Commit > CollectCom: Can CollectCom when all parties have submitted

1 out of 1 tests failed (0.19s)
Test suite hydra-plutus-test: FAIL

But what was passing before is not anymore and what was not passing before does work now. For example before rebase, this diff https://github.com/input-output-hk/hydra-poc/commit/4bad81ab3199707c65c9fb62b19f869120970acd was making it pass, but now (rebased) this commit https://github.com/input-output-hk/hydra-poc/commit/a268d573d74b64fed3571f3b343cfa8c141b5a55 does make it fail, i.e. on the previous version True was failing and 1 == 1 was passing, but now it's the other way around.

Working hypothesis of the plutus team: could be ordering issues.

effectfully commented 1 year ago

i.e. on the previous version True was failing and 1 == 1 was passing, but now it's the other way around.

WAT?

@KtorZ @ch1bo Did you guys figure out what was going on in the end?

abailly-iohk commented 1 year ago

This is really old and given we have had our contracts written and running for a year and half, and we ditched use of trace emulator, PAB, Contract monad, etc. I would suggest to close this issue but @KtorZ might know better.

KtorZ commented 1 year ago

I've completely lost context of this by now. I believe it was an issue with the emulator and not with the on-chain code.

ch1bo commented 1 year ago

No clue either. If there is a problem with the plutus core or plutus-tx, we would have ran into this again. Which did not happen.. so I suggest we just close this.

effectfully commented 1 year ago

Thanks everyone!

IntersectMBO / plutus