search

anoma / anoma-archive

Reference implementation of the Anoma protocols in Rust.
https://anoma.net
GNU General Public License v3.0
425 stars 176 forks source link

`e2e::ledger_tests::invalid_transactions` fails in `eth-bridge-integration` branch #1207

Closed james-chf closed 2 years ago

james-chf commented 2 years ago

This test fails even without v0.6.1 having been merged in. The test does pass on v0.6.1.

Logs below are from eth-bridge-integration + logging changes cherry picked from https://github.com/anoma/anoma/pull/1202/ , test run on Ubuntu. The test can hang if run on macOS.

Error: 
   0: Reached a timeout for expect type of command
      Command: /opt/workspace/heliax/repos/anoma/primary/target/debug/anoman --base-dir /tmp/.tmpbUyMUr/e2e-test.4047f319749ee708c4add/setup/validator-0/.anoma --mode validator ledger
      (logs at: /tmp/.tmpbUyMUr/e2e-test.4047f319749ee708c4add/setup/validator-0/.anoma/logs/1657097855974254-anoman-10609365879098251693.log)
       Needle: some VPs rejected transaction

Location:
   tests/src/e2e/setup.rs:488

  ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ BACKTRACE ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
                                ⋮ 5 frames hidden ⋮                               
   6: anoma_tests::e2e::setup::AnomaCmd::exp_string::{{closure}}::ha1d5bc66e7b68dd7
      at /opt/workspace/heliax/repos/anoma/primary/tests/src/e2e/setup.rs:488
   7: core::result::Result<T,E>::map_err::h9574f6e73f9ff272
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/core/src/result.rs:855
   8: anoma_tests::e2e::setup::AnomaCmd::exp_string::h6227e25e82f314d0
      at /opt/workspace/heliax/repos/anoma/primary/tests/src/e2e/setup.rs:487
   9: anoma_tests::e2e::ledger_tests::invalid_transactions::h2b7f3039d8e1d588
      at /opt/workspace/heliax/repos/anoma/primary/tests/src/e2e/ledger_tests.rs:489
  10: anoma_tests::e2e::ledger_tests::invalid_transactions::{{closure}}::hceaf712fe98d8e92
      at /opt/workspace/heliax/repos/anoma/primary/tests/src/e2e/ledger_tests.rs:424
  11: core::ops::function::FnOnce::call_once::h636be108b6fccdcb
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/core/src/ops/function.rs:227
  12: core::ops::function::FnOnce::call_once::h117306f28c6440b2
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/core/src/ops/function.rs:227
  13: test::__rust_begin_short_backtrace::hdf9f3f089dd9450d
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/test/src/lib.rs:574
  14: <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h1c7ec42f80b6bbf5
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/alloc/src/boxed.rs:1861
  15: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h3a32c43eeae577c5
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/core/src/panic/unwind_safe.rs:271
  16: std::panicking::try::do_call::h5c8445fa1695dfc0
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/std/src/panicking.rs:492
  17: std::panicking::try::h843e017f98c59921
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/std/src/panicking.rs:456
  18: std::panic::catch_unwind::heae97ad77b9c2afb
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/std/src/panic.rs:137
  19: test::run_test_in_process::h4f1c957830006b83
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/test/src/lib.rs:597
                                ⋮ 25 frames hidden ⋮                              

Run with COLORBT_SHOW_HIDDEN=1 environment variable to disable frame filtering.
Run with RUST_BACKTRACE=full to include source snippets.
The application panicked (crashed).
Message:  assertion failed: `(left == right)`
  left: `1`,
 right: `0`: the test returned a termination value with a non-zero status code (1) which indicates a failure
Location: /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/test/src/lib.rs:186

  ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ BACKTRACE ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
                                ⋮ 7 frames hidden ⋮                               
   8: core::panicking::assert_failed_inner::h92c01a43e8afd9c2
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/core/src/panicking.rs:<unknown line>
   9: core::panicking::assert_failed::h14bd06038f70f06f
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/core/src/panicking.rs:182
  10: test::assert_test_result::h4e423c47be5dbad2
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/test/src/lib.rs:186
  11: anoma_tests::e2e::ledger_tests::invalid_transactions::{{closure}}::hceaf712fe98d8e92
      at /opt/workspace/heliax/repos/anoma/primary/tests/src/e2e/ledger_tests.rs:424
  12: core::ops::function::FnOnce::call_once::h636be108b6fccdcb
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/core/src/ops/function.rs:227
  13: core::ops::function::FnOnce::call_once::h117306f28c6440b2
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/core/src/ops/function.rs:227
  14: test::__rust_begin_short_backtrace::hdf9f3f089dd9450d
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/test/src/lib.rs:574
  15: <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h1c7ec42f80b6bbf5
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/alloc/src/boxed.rs:1861
  16: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h3a32c43eeae577c5
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/core/src/panic/unwind_safe.rs:271
  17: std::panicking::try::do_call::h5c8445fa1695dfc0
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/std/src/panicking.rs:492
  18: std::panicking::try::h843e017f98c59921
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/std/src/panicking.rs:456
  19: std::panic::catch_unwind::heae97ad77b9c2afb
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/std/src/panic.rs:137
  20: test::run_test_in_process::h4f1c957830006b83
      at /rustc/fe5b13d681f25ee6474be29d748c65adcd91f69e/library/test/src/lib.rs:597
                                ⋮ 25 frames hidden ⋮                              

Run with COLORBT_SHOW_HIDDEN=1 environment variable to disable frame filtering.
Run with RUST_BACKTRACE=full to include source snippets.
FAILED

failures:

failures:
    e2e::ledger_tests::invalid_transactions
james-chf commented 2 years ago

I can get this Tendermint panic in the second anoman ledger run of the test, if I modify it slightly to check ledger.exp_string("some VPs rejected ")? only after client.exp_string("Transaction applied")?.

Error:
   0: EOF was reached; the read may successed later
      Command: /opt/workspace/heliax/repos/anoma/primary/target/debug/anomac --base-dir /var/folders/cy/fxxsxwd56yg67d68vxj6l52h0000gn/T/.tmpZLFAT9 --mode full transfer --source Daewon --signing-key Daewon --target Albert --token Bertha --amount 1_000_000.1 --fee-amount 0 --gas-limit 0 --fee-token XAN --force --ledger-address 127.0.0.1:27657
      (logs at: /var/folders/cy/fxxsxwd56yg67d68vxj6l52h0000gn/T/.tmpZLFAT9/logs/1657103646657931-anomac-16602012209445686937.log)
       Needle: Transaction applied
read: "I[2022-07-06|11:34:06.257] ABCI Replay Blocks                           module=consensus appHeight=9 storeHeight=9 stateHeight=9\r\n"
read: "panic: "
read: "state.AppHash does not match AppHash after replay. Got\r\nDF1269987D95BC6FF0305CDFF45C0D3B7ACCF2D1EC2C41E0E657DCB453FD8CFA, expected .\r\n\r\nState: {{{11 0} 0.34.13} e2e-test.59c59f49cfeec377afa50 1 9 71B59C8C86045F7517D6E36FD0EF715223A0449070318E16B538"
read: "8F6457591FEA:4:14F429E30047 2022-07-06 10:34:01.748023 +0000 UTC ValidatorSet{\r\n  Proposer: Validator{859BE1BA8D08A4376013BB9CB7F0F3ABE5DB9698 PubKeyEd25519{02F6E0BFD78D0BB94E83371028B45B74D2F1F228CDA494D1404300F05D179E52} VP:200 A:0}\r\n  Validators"
read: ":\r\n    Validator{859BE1BA8D08A4376013BB9CB7F0F3ABE5DB9698 PubKeyEd25519{02F6E0BFD78D0BB94E83371028B45B74D2F1F228CDA494D1404300F05D179E52} VP:200 A:0}\r\n} ValidatorSet{\r\n  Proposer: Validator{859BE1BA8D08A4376013BB9CB7F0F3ABE5DB9698 PubKeyEd25519{02F"
read: "6E0BFD78D0BB94E83371028B45B74D2F1F228CDA494D1404300F05D179E52} VP:200 A:0}\r\n  Validators:\r\n    Validator{859BE1BA8D08A4376013BB9CB7F0F3ABE5DB9698 PubKeyEd25519{02F6E0BFD78D0BB94E83371028B45B74D2F1F228CDA494D1404300F05D179E52} VP:200 A:0}\r\n} Validat"
read: "orSet{\r\n  Proposer: Validator{859BE1BA8D08A4376013BB9CB7F0F3ABE5DB9698 PubKeyEd25519{02F6E0BFD78D0BB94E83371028B45B74D2F1F228CDA494D1404300F05D179E52} VP:200 A:0}\r\n  Validators:\r\n    Validator{859BE1BA8D08A4376013BB9CB7F0F3ABE5DB9698 PubKeyEd25519{"
read: "02F6E0BFD78D0BB94E83371028B45B74D2F1F228CDA494D1404300F05D179E52} VP:200 A:0}\r\n} 1 {{22020096 -1 1000} {8 2s 0} {[ed25519]} {0}} 10 [110 52 11 156 255 179 122 152 156 165 68 230 187 120 10 44 120 144 29 63 179 55 56 118 133 17 163 6 23 175 160 29] "
read: "[]}\r\n\r\nDid you reset Tendermint without resetting your application's data?\r\n\r\ngoroutine 1 [running]:\r\n"
read: "github.com/tendermint/tendermint/consensus.assertAppHashEqualsOneFromState({"
read: "0x1400003ad20, 0x20, 0x20}, {{{0xb, 0x0}, {0x1400056c530, 0x7}}, {0x14000540220, 0x1e}, 0x1, ...})\r\n\t/home/runner/work/tendermint/tendermint/consensus/replay.go:525 +0x16c\r\ngithub.com/tendermint/tendermint/consensus.(*Handshaker).ReplayBlocks(0x140"
read: "002b8b90, {{{0xb, 0x0}, {0x1400056c530, 0x7}}, {0x14000540220, 0x1e}, 0x1, 0x9, {{0x14000540240, ...}, ...}, ...}, ...)\r\n\t/home/runner/work/tendermint/tendermint/consensus/replay.go:397 +0x464\r\ngithub.com/tendermint/tendermint/consensus.(*Handshake"
read: "r).Handshake(0x140002b8b90, {0x103315040, 0x140004b2750})\r\n\t/home/runner/work/tendermint/tendermint/consensus/replay.go:268 +0x400\r\ngithub.com/tendermint/tendermint/node.doHandshake({0x103310988, 0x1400054aaf0}, {{{0xb, 0x0}, {0x1400056c530, 0x7}},"
read: " {0x14000540220, 0x1e}, 0x1, 0x9, ...}, ...)\r\n\t/home/runner/work/tendermint/tendermint/node/node.go:322 +0x114\r\ngithub.com/tendermint/tendermint/node.NewNode(0x140005e2f00, {0x1032f12b0, 0x1400016cc80}, 0x14000e002f0, {0x1032e1660, 0x140004a2810}, "
read: "0x14000e00460, 0x1032cfbe0, 0x14000e00470, {0x1032fec68, ...}, ...)\r\n\t/home/runner/work/tendermint/tendermint/node/node.go:730 +0x510\r\ngithub.com/tendermint/tendermint/node.DefaultNewNode(0x140005e2f00, {0x1032fec68, 0x14000595240})\r\n\t/home/runner/"
read: "work/tendermint/tendermint/node/node.go:98 +0x354\r\ngithub.com/tendermint/tendermint/cmd/tendermint/commands.NewRunNodeCmd.func1(0x140005e82c0, {0x1400054d180, 0x0, 0x4})\r\n\t/home/runner/work/tendermint/tendermint/cmd/tendermint/commands/run_node.go:"
read: "110 +0x7c\r\n"
read: "github.com/spf13/cobra.(*Command).execute(0x140005e82c0, "
read: "{0x1400054d140, 0x4, 0x4})\r\n\t/home/runner/go/pkg/mod/github.com/spf13/cobra@v1.1.1/command.go:850 +0x668\r\ngithub.com/spf13/cobra.(*Command).ExecuteC(0x1039d53e0)\r\n\t/home/runner/go/pkg/mod/github.com/spf13/cobra@v1.1.1/command.go:958 +0x404\r\ngithub."
read: "com/spf13/cobra.(*Command).Execute(...)\r\n\t/home/runner/go/pkg/mod/github.com/spf13/cobra@v1.1.1/command.go:895\r\n"
read: "github.com/tendermint/tendermint/libs/cli.Executor.Execute"
read: "({0x1039d53e0, 0x1032d18e8})\r\n\t/home/runner/work/tendermint/tendermint/libs/cli/setup.go:89 +0x38\r\nmain.main()\r\n\t/home/runner/work/tendermint/tendermint/cmd/tendermint/main.go:48 +0x238\r\n"
james-chf commented 2 years ago

Fixed by https://github.com/anoma/anoma/pull/1196