From 755ae85359d646a7d0bc8e8c2ac9a93f0b99994a Mon Sep 17 00:00:00 2001 From: Piers Powlesland Date: Wed, 26 Jan 2022 11:22:49 +0000 Subject: [PATCH 1/5] Disable log output from e2e tests The logging from these tests slowed them down and cluttered the output of test runs. --- e2e_test/e2e_test.go | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/e2e_test/e2e_test.go b/e2e_test/e2e_test.go index defcea614e..5e0a42c3f2 100644 --- a/e2e_test/e2e_test.go +++ b/e2e_test/e2e_test.go @@ -8,6 +8,7 @@ import ( "time" "github.com/celo-org/celo-blockchain/core/types" + "github.com/celo-org/celo-blockchain/log" "github.com/celo-org/celo-blockchain/node" "github.com/celo-org/celo-blockchain/test" "github.com/stretchr/testify/assert" @@ -18,7 +19,10 @@ func init() { // This statement is commented out but left here since its very useful for // debugging problems and its non trivial to construct. // - // log.Root().SetHandler(log.LvlFilterHandler(log.LvlDebug, log.StreamHandler(os.Stdout, log.TerminalFormat(true)))) + // log.Root().SetHandler(log.LvlFilterHandler(log.LvlTrace, log.StreamHandler(os.Stdout, log.TerminalFormat(true)))) + + // This disables all logging which in general we want, because there is a lot + log.Root().SetHandler(log.DiscardHandler()) } // This test starts a network submits a transaction and waits for the whole From 507beda11ec7b68f9cf0b965162d62f4af907cf2 Mon Sep 17 00:00:00 2001 From: Piers Powlesland Date: Wed, 26 Jan 2022 11:24:05 +0000 Subject: [PATCH 2/5] Enable all rpc api modules on test node instances --- test/node.go | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/test/node.go b/test/node.go index 2b315b26e5..7563e52310 100644 --- a/test/node.go +++ b/test/node.go @@ -24,6 +24,7 @@ import ( "github.com/celo-org/celo-blockchain/crypto" "github.com/celo-org/celo-blockchain/eth" "github.com/celo-org/celo-blockchain/eth/downloader" + "github.com/celo-org/celo-blockchain/eth/tracers" "github.com/celo-org/celo-blockchain/ethclient" "github.com/celo-org/celo-blockchain/mycelo/env" "github.com/celo-org/celo-blockchain/mycelo/genesis" @@ -35,6 +36,7 @@ import ( ) var ( + allModules = []string{"admin", "debug", "web3", "eth", "txpool", "personal", "istanbul", "miner", "net"} baseNodeConfig *node.Config = &node.Config{ Name: "celo", Version: params.Version, @@ -52,6 +54,8 @@ var ( HTTPHost: "0.0.0.0", WSHost: "0.0.0.0", UsePlaintextKeystore: true, + WSModules: allModules, + HTTPModules: allModules, } baseEthConfig = ð.Config{ @@ -179,6 +183,9 @@ func (n *Node) Start() error { if err != nil { return err } + // This manual step is required to enable tracing, it's messy but this is the + // approach taken by geth in cmd/utils.RegisterEthService. + n.Node.RegisterAPIs(tracers.APIs(n.Eth.APIBackend)) err = n.Node.Start() if err != nil { From fe2c5e6253fd2192ecbd653f607666e334db1fdf Mon Sep 17 00:00:00 2001 From: Piers Powlesland Date: Wed, 26 Jan 2022 11:31:40 +0000 Subject: [PATCH 3/5] Add test to reproduce concurrent map access error issue: https://github.com/celo-org/celo-blockchain/issues/1799 --- e2e_test/e2e_test.go | 56 ++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 56 insertions(+) diff --git a/e2e_test/e2e_test.go b/e2e_test/e2e_test.go index 5e0a42c3f2..a22e92a65b 100644 --- a/e2e_test/e2e_test.go +++ b/e2e_test/e2e_test.go @@ -4,12 +4,15 @@ import ( "context" "errors" "fmt" + "sync" "testing" "time" + "github.com/celo-org/celo-blockchain/common/hexutil" "github.com/celo-org/celo-blockchain/core/types" "github.com/celo-org/celo-blockchain/log" "github.com/celo-org/celo-blockchain/node" + "github.com/celo-org/celo-blockchain/rpc" "github.com/celo-org/celo-blockchain/test" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" @@ -193,3 +196,56 @@ func TestStartStopValidators(t *testing.T) { require.NoError(t, err) } + +// This test was created to reproduce the concurrent map access error in +// https://github.com/celo-org/celo-blockchain/issues/1799 +// +// It does this by calling debug_traceBlockByNumber a number of times since the +// trace block code was the source of the concurrent map access. +func TestBlockTracingConcurrentMapAccess(t *testing.T) { + ac := test.AccountConfig(1, 2) + gc, ec, err := test.BuildConfig(ac) + require.NoError(t, err) + network, shutdown, err := test.NewNetwork(ac, gc, ec) + require.NoError(t, err) + defer shutdown() + ctx, cancel := context.WithTimeout(context.Background(), time.Second*60) + defer cancel() + + n := network[0] + + accounts := test.Accounts(ac.DeveloperAccounts(), gc.ChainConfig()) + + var txs []*types.Transaction + // Send one celo from external account 0 to 1 via node 0. + for i := 0; i < 10; i++ { + tx, err := accounts[0].SendCelo(ctx, accounts[1].Address, 1, n) + require.NoError(t, err) + txs = append(txs, tx) + } + + // Wait for the whole network to process the transactions. + err = network.AwaitTransactions(ctx, txs...) + require.NoError(t, err) + + lastTx := txs[len(txs)-1] + + b := n.Tracker.GetProcessedBlockForTx(lastTx.Hash()) + + var wg sync.WaitGroup + for i := 1; i < +int(b.NumberU64()); i++ { + wg.Add(1) + num := i + go func() { + defer wg.Done() + c, err := rpc.DialContext(ctx, n.WSEndpoint()) + require.NoError(t, err) + + var result []interface{} + err = c.CallContext(ctx, &result, "debug_traceBlockByNumber", hexutil.EncodeUint64(uint64(num))) + require.NoError(t, err) + }() + + } + wg.Wait() +} From b3079ba0e75470883ce7ec033b47582cf1dd6c1c Mon Sep 17 00:00:00 2001 From: Piers Powlesland Date: Wed, 26 Jan 2022 12:14:22 +0000 Subject: [PATCH 4/5] Fix concurrent map access error Ensure state.StateDB instances are not accessed concurrently. --- eth/tracers/api.go | 18 ++++++++++++------ 1 file changed, 12 insertions(+), 6 deletions(-) diff --git a/eth/tracers/api.go b/eth/tracers/api.go index 3c2acddb14..f8ed40875f 100644 --- a/eth/tracers/api.go +++ b/eth/tracers/api.go @@ -529,19 +529,20 @@ func (api *API) traceBlock(ctx context.Context, block *types.Block, config *Trac } blockCtx := core.NewEVMBlockContext(block.Header(), api.chainContext(ctx), nil) blockHash := block.Hash() - var sysCtx *core.SysContractCallCtx - if api.backend.ChainConfig().IsEspresso(block.Number()) { - sysVmRunner := api.backend.VmRunnerAtHeader(block.Header(), statedb) - sysCtx = core.NewSysContractCallCtx(sysVmRunner) - } for th := 0; th < threads; th++ { pend.Add(1) + innerStatedb := statedb.Copy() + var sysCtx *core.SysContractCallCtx + if api.backend.ChainConfig().IsEspresso(block.Number()) { + sysVmRunner := api.backend.VmRunnerAtHeader(block.Header(), innerStatedb) + sysCtx = core.NewSysContractCallCtx(sysVmRunner) + } go func() { defer pend.Done() // Fetch and execute the next transaction trace tasks for task := range jobs { msg, _ := txs[task.index].AsMessage(signer, nil) - vmRunner := api.backend.VmRunnerAtHeader(block.Header(), statedb) + vmRunner := api.backend.VmRunnerAtHeader(block.Header(), innerStatedb) txctx := &Context{ BlockHash: blockHash, TxIndex: task.index, @@ -556,6 +557,11 @@ func (api *API) traceBlock(ctx context.Context, block *types.Block, config *Trac } }() } + var sysCtx *core.SysContractCallCtx + if api.backend.ChainConfig().IsEspresso(block.Number()) { + sysVmRunner := api.backend.VmRunnerAtHeader(block.Header(), statedb) + sysCtx = core.NewSysContractCallCtx(sysVmRunner) + } // Feed the transactions into the tracers and return var failed error for i, tx := range txs { From ce331067578a0dc3b3ddaf6f43cca79f42fb2172 Mon Sep 17 00:00:00 2001 From: Piers Powlesland Date: Wed, 26 Jan 2022 12:17:43 +0000 Subject: [PATCH 5/5] Reduce proliferation of vmrunners and statedbs --- eth/tracers/api.go | 17 +++++++---------- 1 file changed, 7 insertions(+), 10 deletions(-) diff --git a/eth/tracers/api.go b/eth/tracers/api.go index f8ed40875f..0bc7f25c6a 100644 --- a/eth/tracers/api.go +++ b/eth/tracers/api.go @@ -531,18 +531,16 @@ func (api *API) traceBlock(ctx context.Context, block *types.Block, config *Trac blockHash := block.Hash() for th := 0; th < threads; th++ { pend.Add(1) - innerStatedb := statedb.Copy() - var sysCtx *core.SysContractCallCtx - if api.backend.ChainConfig().IsEspresso(block.Number()) { - sysVmRunner := api.backend.VmRunnerAtHeader(block.Header(), innerStatedb) - sysCtx = core.NewSysContractCallCtx(sysVmRunner) - } go func() { defer pend.Done() // Fetch and execute the next transaction trace tasks for task := range jobs { + var sysCtx *core.SysContractCallCtx + vmRunner := api.backend.VmRunnerAtHeader(block.Header(), task.statedb) + if api.backend.ChainConfig().IsEspresso(block.Number()) { + sysCtx = core.NewSysContractCallCtx(vmRunner) + } msg, _ := txs[task.index].AsMessage(signer, nil) - vmRunner := api.backend.VmRunnerAtHeader(block.Header(), innerStatedb) txctx := &Context{ BlockHash: blockHash, TxIndex: task.index, @@ -558,9 +556,9 @@ func (api *API) traceBlock(ctx context.Context, block *types.Block, config *Trac }() } var sysCtx *core.SysContractCallCtx + vmRunner := api.backend.VmRunnerAtHeader(block.Header(), statedb) if api.backend.ChainConfig().IsEspresso(block.Number()) { - sysVmRunner := api.backend.VmRunnerAtHeader(block.Header(), statedb) - sysCtx = core.NewSysContractCallCtx(sysVmRunner) + sysCtx = core.NewSysContractCallCtx(vmRunner) } // Feed the transactions into the tracers and return var failed error @@ -572,7 +570,6 @@ func (api *API) traceBlock(ctx context.Context, block *types.Block, config *Trac msg, _ := tx.AsMessage(signer, nil) statedb.Prepare(tx.Hash(), i) vmenv := vm.NewEVM(blockCtx, core.NewEVMTxContext(msg), statedb, api.backend.ChainConfig(), vm.Config{}) - vmRunner := api.backend.VmRunnerAtHeader(block.Header(), statedb) if _, err := core.ApplyMessage(vmenv, msg, new(core.GasPool).AddGas(msg.Gas()), vmRunner, sysCtx); err != nil { failed = err break