RPC server freezes on sendTx with wrong permissions

[containerman17]

As I understood from a conversation with @owenwahlgren, the RPC server stops responding if sendTx is called involving an action that is missing one of the required state keys. After some time, it eventually responds with the error "expired." This needs confirmation.

This commit fixed the issue for cfmm: https://github.com/ava-labs/hypersdk-starter/commit/5bb9b2274ea60f837c4dce9bba0e269bcc2ec128

[owenwahlgren]

+1 If state_manager.go doesn't have appropriate state keys the transaction will time out without an error. If an action is missing required state keys it will return the expected error invalid key or key permission.

The state manager should throw an error similar to how actions do when missing state keys.

[containerman17]

Confirmed. Reproduction steps for MorpheusVM:

1. Remove one of the required keys from examples/morpheusvm/actions/transfer.go:

   func (t *Transfer) StateKeys(actor codec.Address) state.Keys {
   return state.Keys{
       string(storage.BalanceKey(actor)): state.Read | state.Write,
       // string(storage.BalanceKey(t.To)):  state.All, // Remove this line 
   }
   }

2. Run e2e test: MODE=test ./scripts/run.sh
3. Observe the timeout:

/workspaces/Projects/ava-labs/hypersdk/examples/morpheusvm/tests/e2e/e2e_test.go:36
  Preparing configuration for new network with /home/vscode/.hypersdk/avalanchego-f03745d187d0c33b927121d4c8da977789b929ac/avalanchego
  Starting a single-node network with sybil protection disabled for quicker subnet creation
  Starting network /home/vscode/.tmpnet/networks/20241004-022825.453168-morpheusvm-e2e-tests (UUID: 6b4eaac9-84af-404f-ac04-a6d2ff9eaf75)
  [FAILED] in [SynchronizedBeforeSuite] - /go/pkg/mod/github.com/stretchr/testify@v1.8.4/assert/assertions.go:295 @ 10/04/24 02:28:35.7
[SynchronizedBeforeSuite] [FAILED] [10.507 seconds]
[SynchronizedBeforeSuite] 
/workspaces/Projects/ava-labs/hypersdk/examples/morpheusvm/tests/e2e/e2e_test.go:36

  [FAILED] 
        Error Trace:    /go/pkg/mod/github.com/ava-labs/avalanchego@v1.11.12-rc.2.0.20241001202925-f03745d187d0/tests/fixture/e2e/helpers.go:252
                                                /go/pkg/mod/github.com/ava-labs/avalanchego@v1.11.12-rc.2.0.20241001202925-f03745d187d0/tests/fixture/e2e/env.go:132
                                                /workspaces/Projects/ava-labs/hypersdk/tests/fixture/environment.go:40
                                                /workspaces/Projects/ava-labs/hypersdk/examples/morpheusvm/tests/e2e/e2e_test.go:57
                                                /usr/local/go/src/reflect/value.go:596
                                                /usr/local/go/src/reflect/value.go:380
                                                /go/pkg/mod/github.com/onsi/ginkgo/v2@v2.13.1/internal/node.go:486
                                                /go/pkg/mod/github.com/onsi/ginkgo/v2@v2.13.1/internal/suite.go:642
                                                /go/pkg/mod/github.com/onsi/ginkgo/v2@v2.13.1/internal/suite.go:889
                                                /usr/local/go/src/runtime/asm_arm64.s:1222
        Error:          failed to bootstrap network: %s
        Messages:       failed to start local node: failed to load process context for node "NodeID-7B5dkZw9SW3fWEt8iH31Q6xFZPmcy6o52" before timeout: context deadline exceeded

  In [SynchronizedBeforeSuite] at: /go/pkg/mod/github.com/stretchr/testify@v1.8.4/assert/assertions.go:295 @ 10/04/24 02:28:35.7
------------------------------

[RodrigoVillar]

@containerman17 on the main branch, i'm getting the following error instead:

[FAILED] 
        Error Trace:    /Users/rodrigo.villar/go/src/github.com/ava-labs/hypersdk/examples/morpheusvm/tests/workload/workload.go:235
                                                /Users/rodrigo.villar/go/src/github.com/ava-labs/hypersdk/examples/morpheusvm/tests/workload/workload.go:227
                                                /Users/rodrigo.villar/go/src/github.com/ava-labs/hypersdk/tests/workload/transactions.go:66
                                                /Users/rodrigo.villar/go/src/github.com/ava-labs/hypersdk/tests/e2e/e2e.go:102
                                                /Users/rodrigo.villar/.gvm/pkgsets/go1.21.12/global/pkg/mod/github.com/onsi/ginkgo/v2@v2.13.1/internal/suite.go:323
                                                /Users/rodrigo.villar/.gvm/pkgsets/go1.21.12/global/pkg/mod/github.com/onsi/ginkgo/v2@v2.13.1/core_dsl.go:591
                                                /Users/rodrigo.villar/go/src/github.com/ava-labs/hypersdk/tests/e2e/e2e.go:98
                                                /Users/rodrigo.villar/.gvm/pkgsets/go1.21.12/global/pkg/mod/github.com/onsi/ginkgo/v2@v2.13.1/internal/node.go:463
                                                /Users/rodrigo.villar/.gvm/pkgsets/go1.21.12/global/pkg/mod/github.com/onsi/ginkgo/v2@v2.13.1/internal/suite.go:889
                                                /Users/rodrigo.villar/.gvm/gos/go1.21.12/src/runtime/asm_arm64.s:1197
        Error:          Should be true

  In [It] at: /Users/rodrigo.villar/.gvm/pkgsets/go1.21.12/global/pkg/mod/github.com/stretchr/testify@v1.8.4/assert/assertions.go:773 @ 10/04/24 12:00:44.253

[RodrigoVillar]

@containerman17 after following the steps you outlined, it seems that the error you posted above isn't related to the missing state keys issue, but rather is because of port conflicts. If you look at the logs for NodeID-7B5dkZw9SW3fWEt8iH31Q6xFZPmcy6o52, you should see the following error message:

[10-04|14:18:26.241] INFO node/node.go:952 initializing NAT
[10-04|14:18:26.241] INFO node/node.go:970 initializing API server
[10-04|14:18:26.241] FATAL app/app.go:75 failed to initialize node {"error": "couldn't initialize API server: listen tcp :9650: bind: address already in use"}

To reproduce this error message, you can run the following:

./scripts/run.sh`
MODE=test ./scripts/run.sh

[RodrigoVillar]

@owenwahlgren can you give steps to reproduce the issue?

[containerman17]

@RodrigoVillar, you’re right. The issue still needs confirmation.