neoneo-go/pkg/consensus/consensus.go

688 lines
19 KiB
Go
Raw Normal View History

2019-11-08 15:40:21 +00:00
package consensus
2019-11-15 10:32:40 +00:00
import (
"errors"
"fmt"
2019-11-15 10:32:40 +00:00
"sort"
"time"
"github.com/nspcc-dev/dbft"
"github.com/nspcc-dev/dbft/block"
"github.com/nspcc-dev/dbft/crypto"
"github.com/nspcc-dev/dbft/payload"
"github.com/nspcc-dev/neo-go/pkg/config"
"github.com/nspcc-dev/neo-go/pkg/config/netmode"
coreb "github.com/nspcc-dev/neo-go/pkg/core/block"
"github.com/nspcc-dev/neo-go/pkg/core/blockchainer"
"github.com/nspcc-dev/neo-go/pkg/core/mempool"
"github.com/nspcc-dev/neo-go/pkg/core/native"
"github.com/nspcc-dev/neo-go/pkg/core/transaction"
"github.com/nspcc-dev/neo-go/pkg/crypto/hash"
"github.com/nspcc-dev/neo-go/pkg/crypto/keys"
"github.com/nspcc-dev/neo-go/pkg/encoding/address"
2020-04-21 13:45:48 +00:00
"github.com/nspcc-dev/neo-go/pkg/io"
npayload "github.com/nspcc-dev/neo-go/pkg/network/payload"
"github.com/nspcc-dev/neo-go/pkg/smartcontract"
"github.com/nspcc-dev/neo-go/pkg/util"
2020-04-21 13:45:48 +00:00
"github.com/nspcc-dev/neo-go/pkg/vm/emit"
"github.com/nspcc-dev/neo-go/pkg/wallet"
consensus: prevent synchronization stalls When CN is not up to date with the network is synchonizes blocks first and only then starts consensus process. But while synchronizing it receives consensus payloads and tries to process them even though messages reader routine is not started yet. This leads to lots of goroutines waiting to send their messages: Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 1639919 [chan send, 4 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc005bd7680) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc00507d170, 0xc005bdd560, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc00507d170) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 1639181 [chan send, 10 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc013bb6600) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc01361ee10, 0xc01342c780, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc01361ee10) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 39454 [chan send, 32 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc014fea680) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc0140b2ea0, 0xc014fe0ed0, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc0140b2ea0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Luckily it doesn't break synchronization completely as eventually connection timers fire, the node breaks all connections, create new ones and these new ones request blocks successfully until another consensus payload stalls them too. In the end the node reaches synchronization, message processing loop starts and releases all of these waiting goroutines, but it's better for us to avoid this happening at all. This also makes double-starting a no-op which is a nice property.
2020-06-26 08:19:01 +00:00
"go.uber.org/atomic"
2019-11-15 10:32:40 +00:00
"go.uber.org/zap"
)
2019-11-08 15:40:21 +00:00
// cacheMaxCapacity is the default cache capacity taken
// from C# implementation https://github.com/neo-project/neo/blob/master/neo/Ledger/Blockchain.cs#L64
const cacheMaxCapacity = 100
2019-11-15 10:32:40 +00:00
// defaultTimePerBlock is a period between blocks which is used in NEO.
const defaultTimePerBlock = 15 * time.Second
// Number of nanoseconds in millisecond.
const nsInMs = 1000000
// Category is message category for extensible payloads.
const Category = "dBFT"
2019-11-08 15:40:21 +00:00
// Service represents consensus instance.
type Service interface {
2019-11-15 10:32:40 +00:00
// Start initializes dBFT and starts event loop for consensus service.
// It must be called only when sufficient amount of peers are connected.
Start()
2020-09-01 16:58:51 +00:00
// Shutdown stops dBFT event loop.
Shutdown()
2019-11-15 10:32:40 +00:00
// OnPayload is a callback to notify Service about new received payload.
OnPayload(p *npayload.Extensible) error
2019-11-15 10:32:40 +00:00
// OnTransaction is a callback to notify Service about new received transaction.
OnTransaction(tx *transaction.Transaction)
2019-11-08 15:40:21 +00:00
}
type service struct {
2019-11-15 10:32:40 +00:00
Config
log *zap.Logger
2019-11-15 10:32:40 +00:00
// txx is a fifo cache which stores miner transactions.
txx *relayCache
dbft *dbft.DBFT
// messages and transactions are channels needed to process
// everything in single thread.
messages chan Payload
transactions chan *transaction.Transaction
// blockEvents is used to pass a new block event to the consensus
// process.
blockEvents chan *coreb.Block
lastProposal []util.Uint256
2020-01-15 14:05:47 +00:00
wallet *wallet.Wallet
consensus: prevent synchronization stalls When CN is not up to date with the network is synchonizes blocks first and only then starts consensus process. But while synchronizing it receives consensus payloads and tries to process them even though messages reader routine is not started yet. This leads to lots of goroutines waiting to send their messages: Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 1639919 [chan send, 4 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc005bd7680) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc00507d170, 0xc005bdd560, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc00507d170) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 1639181 [chan send, 10 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc013bb6600) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc01361ee10, 0xc01342c780, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc01361ee10) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 39454 [chan send, 32 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc014fea680) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc0140b2ea0, 0xc014fe0ed0, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc0140b2ea0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Luckily it doesn't break synchronization completely as eventually connection timers fire, the node breaks all connections, create new ones and these new ones request blocks successfully until another consensus payload stalls them too. In the end the node reaches synchronization, message processing loop starts and releases all of these waiting goroutines, but it's better for us to avoid this happening at all. This also makes double-starting a no-op which is a nice property.
2020-06-26 08:19:01 +00:00
// started is a flag set with Start method that runs an event handling
// goroutine.
consensus: wait goroutine to finish on Shutdown Fixes: panic: assignment to entry in nil map goroutine 227 [running]: github.com/nspcc-dev/neo-go/pkg/core/storage.(*MemoryStore).put(...) /home/rik/dev/neo-go/pkg/core/storage/memory_store.go:53 github.com/nspcc-dev/neo-go/pkg/core/storage.(*MemoryStore).PutBatch(0xc00035f580, 0x110a680, 0xc000336750, 0x0, 0x0) /home/rik/dev/neo-go/pkg/core/storage/memory_store.go:93 +0x286 github.com/nspcc-dev/neo-go/pkg/core.(*Blockchain).addHeaders(0xc0000a2340, 0xc0001be301, 0xc00036d428, 0x1, 0x1, 0x0, 0x0) /home/rik/dev/neo-go/pkg/core/blockchain.go:516 +0xd5a github.com/nspcc-dev/neo-go/pkg/core.(*Blockchain).AddBlock(0xc0000a2340, 0xc0000bc2c0, 0x0, 0x0) /home/rik/dev/neo-go/pkg/core/blockchain.go:407 +0x9ca github.com/nspcc-dev/neo-go/pkg/consensus.(*service).processBlock(0xc000152160, 0x1122320, 0xc0000bc2c0) /home/rik/dev/neo-go/pkg/consensus/consensus.go:440 +0xbf github.com/nspcc-dev/dbft.(*DBFT).checkCommit(0xc0000d3400) /home/rik/go/pkg/mod/github.com/nspcc-dev/dbft@v0.0.0-20200911152629-be965ee4d449/check.go:71 +0x918 github.com/nspcc-dev/dbft.(*DBFT).checkPrepare(0xc0000d3400) /home/rik/go/pkg/mod/github.com/nspcc-dev/dbft@v0.0.0-20200911152629-be965ee4d449/check.go:36 +0x465 github.com/nspcc-dev/dbft.(*DBFT).sendPrepareRequest(0xc0000d3400) /home/rik/go/pkg/mod/github.com/nspcc-dev/dbft@v0.0.0-20200911152629-be965ee4d449/send.go:42 +0x2f8 github.com/nspcc-dev/dbft.(*DBFT).start(0xc0000d3400) /home/rik/go/pkg/mod/github.com/nspcc-dev/dbft@v0.0.0-20200911152629-be965ee4d449/dbft.go:269 +0x26f github.com/nspcc-dev/dbft.(*DBFT).Start(0xc0000d3400) /home/rik/go/pkg/mod/github.com/nspcc-dev/dbft@v0.0.0-20200911152629-be965ee4d449/dbft.go:82 +0x59 github.com/nspcc-dev/neo-go/pkg/consensus.(*service).Start(0xc000152160) /home/rik/dev/neo-go/pkg/consensus/consensus.go:191 +0x56 github.com/nspcc-dev/neo-go/pkg/network.(*Server).tryStartConsensus(0xc000235040) /home/rik/dev/neo-go/pkg/network/server.go:311 +0xda github.com/nspcc-dev/neo-go/pkg/network.(*Server).Start(0xc000235040, 0xc0000faba0) /home/rik/dev/neo-go/pkg/network/server.go:173 +0x202 created by github.com/nspcc-dev/neo-go/cli.newTestChain /home/rik/dev/neo-go/cli/executor_test.go:77 +0x47d FAIL github.com/nspcc-dev/neo-go/cli 14.479s
2020-09-19 18:49:05 +00:00
started *atomic.Bool
quit chan struct{}
finished chan struct{}
// lastTimestamp contains timestamp for the last processed block.
// We can't rely on timestamp from dbft context because it is changed
// before block is accepted, so in case of change view it will contain
// updated value.
lastTimestamp uint64
2019-11-15 10:32:40 +00:00
}
// Config is a configuration for consensus services.
type Config struct {
2019-12-30 07:43:05 +00:00
// Logger is a logger instance.
Logger *zap.Logger
2019-11-15 10:32:40 +00:00
// Broadcast is a callback which is called to notify server
// about new consensus payload to sent.
Broadcast func(p *npayload.Extensible)
2019-11-15 10:32:40 +00:00
// Chain is a core.Blockchainer instance.
Chain blockchainer.Blockchainer
// ProtocolConfiguration contains protocol settings.
ProtocolConfiguration config.ProtocolConfiguration
2019-11-15 10:32:40 +00:00
// RequestTx is a callback to which will be called
// when a node lacks transactions present in a block.
RequestTx func(h ...util.Uint256)
// TimePerBlock minimal time that should pass before next block is accepted.
TimePerBlock time.Duration
// Wallet is a local-node wallet configuration.
Wallet *config.Wallet
2019-11-08 15:40:21 +00:00
}
// NewService returns new consensus.Service instance.
2019-11-15 10:32:40 +00:00
func NewService(cfg Config) (Service, error) {
if cfg.TimePerBlock <= 0 {
cfg.TimePerBlock = defaultTimePerBlock
}
2019-12-30 07:43:05 +00:00
if cfg.Logger == nil {
return nil, errors.New("empty logger")
}
2019-11-15 10:32:40 +00:00
srv := &service{
Config: cfg,
log: cfg.Logger,
2019-11-15 10:32:40 +00:00
txx: newFIFOCache(cacheMaxCapacity),
messages: make(chan Payload, 100),
transactions: make(chan *transaction.Transaction, 100),
blockEvents: make(chan *coreb.Block, 1),
started: atomic.NewBool(false),
quit: make(chan struct{}),
finished: make(chan struct{}),
2019-11-15 10:32:40 +00:00
}
2020-01-15 14:05:47 +00:00
var err error
if srv.wallet, err = wallet.NewWalletFromFile(cfg.Wallet.Path); err != nil {
return nil, err
}
// Check that wallet password is correct for at least one account.
var ok bool
for _, acc := range srv.wallet.Accounts {
err := acc.Decrypt(srv.Config.Wallet.Password, srv.wallet.Scrypt)
if err == nil {
ok = true
break
}
}
if !ok {
return nil, errors.New("no account with provided password was found")
}
2020-01-15 14:05:47 +00:00
defer srv.wallet.Close()
2019-11-15 10:32:40 +00:00
srv.dbft = dbft.New(
dbft.WithLogger(srv.log),
2019-11-15 10:32:40 +00:00
dbft.WithSecondsPerBlock(cfg.TimePerBlock),
dbft.WithGetKeyPair(srv.getKeyPair),
2019-11-15 10:32:40 +00:00
dbft.WithRequestTx(cfg.RequestTx),
dbft.WithGetTx(srv.getTx),
dbft.WithGetVerified(srv.getVerifiedTx),
dbft.WithBroadcast(srv.broadcast),
dbft.WithProcessBlock(srv.processBlock),
dbft.WithVerifyBlock(srv.verifyBlock),
dbft.WithGetBlock(srv.getBlock),
dbft.WithWatchOnly(func() bool { return false }),
dbft.WithNewBlockFromContext(srv.newBlockFromContext),
2019-11-15 10:32:40 +00:00
dbft.WithCurrentHeight(cfg.Chain.BlockHeight),
dbft.WithCurrentBlockHash(cfg.Chain.CurrentBlockHash),
dbft.WithGetValidators(srv.getValidators),
dbft.WithGetConsensusAddress(srv.getConsensusAddress),
dbft.WithNewConsensusPayload(srv.newPayload),
dbft.WithNewPrepareRequest(srv.newPrepareRequest),
2019-11-15 10:32:40 +00:00
dbft.WithNewPrepareResponse(func() payload.PrepareResponse { return new(prepareResponse) }),
dbft.WithNewChangeView(func() payload.ChangeView { return new(changeView) }),
dbft.WithNewCommit(func() payload.Commit { return new(commit) }),
dbft.WithNewRecoveryRequest(func() payload.RecoveryRequest { return new(recoveryRequest) }),
dbft.WithNewRecoveryMessage(func() payload.RecoveryMessage {
return &recoveryMessage{stateRootEnabled: srv.ProtocolConfiguration.StateRootInHeader}
}),
consensus: prevent synchronization stalls When CN is not up to date with the network is synchonizes blocks first and only then starts consensus process. But while synchronizing it receives consensus payloads and tries to process them even though messages reader routine is not started yet. This leads to lots of goroutines waiting to send their messages: Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 1639919 [chan send, 4 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc005bd7680) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc00507d170, 0xc005bdd560, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc00507d170) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 1639181 [chan send, 10 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc013bb6600) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc01361ee10, 0xc01342c780, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc01361ee10) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 39454 [chan send, 32 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc014fea680) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc0140b2ea0, 0xc014fe0ed0, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc0140b2ea0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Luckily it doesn't break synchronization completely as eventually connection timers fire, the node breaks all connections, create new ones and these new ones request blocks successfully until another consensus payload stalls them too. In the end the node reaches synchronization, message processing loop starts and releases all of these waiting goroutines, but it's better for us to avoid this happening at all. This also makes double-starting a no-op which is a nice property.
2020-06-26 08:19:01 +00:00
dbft.WithVerifyPrepareRequest(srv.verifyRequest),
dbft.WithVerifyPrepareResponse(func(_ payload.ConsensusPayload) error { return nil }),
2019-11-15 10:32:40 +00:00
)
if srv.dbft == nil {
return nil, errors.New("can't initialize dBFT")
}
return srv, nil
}
var (
_ block.Transaction = (*transaction.Transaction)(nil)
_ block.Block = (*neoBlock)(nil)
)
2020-08-18 14:41:22 +00:00
// NewPayload creates new consensus payload for the provided network.
func NewPayload(m netmode.Magic, stateRootEnabled bool) *Payload {
return &Payload{
Extensible: npayload.Extensible{
Category: Category,
},
message: message{
stateRootEnabled: stateRootEnabled,
},
network: m,
}
}
func (s *service) newPayload(c *dbft.Context, t payload.MessageType, msg interface{}) payload.ConsensusPayload {
cp := NewPayload(s.ProtocolConfiguration.Magic, s.ProtocolConfiguration.StateRootInHeader)
cp.SetHeight(c.BlockIndex)
cp.SetValidatorIndex(uint16(c.MyIndex))
cp.SetViewNumber(c.ViewNumber)
cp.SetType(t)
if pr, ok := msg.(*prepareRequest); ok {
pr.SetPrevHash(s.dbft.PrevHash)
pr.SetVersion(s.dbft.Version)
}
cp.SetPayload(msg)
cp.Extensible.ValidBlockStart = 0
cp.Extensible.ValidBlockEnd = c.BlockIndex
cp.Extensible.Sender = c.Validators[c.MyIndex].(*publicKey).GetScriptHash()
return cp
}
func (s *service) newPrepareRequest() payload.PrepareRequest {
r := new(prepareRequest)
if s.ProtocolConfiguration.StateRootInHeader {
r.stateRootEnabled = true
if sr, err := s.Chain.GetStateModule().GetStateRoot(s.dbft.BlockIndex - 1); err == nil {
r.stateRoot = sr.Root
} else {
panic(err)
}
}
return r
}
2019-11-15 10:32:40 +00:00
func (s *service) Start() {
consensus: prevent synchronization stalls When CN is not up to date with the network is synchonizes blocks first and only then starts consensus process. But while synchronizing it receives consensus payloads and tries to process them even though messages reader routine is not started yet. This leads to lots of goroutines waiting to send their messages: Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 1639919 [chan send, 4 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc005bd7680) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc00507d170, 0xc005bdd560, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc00507d170) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 1639181 [chan send, 10 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc013bb6600) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc01361ee10, 0xc01342c780, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc01361ee10) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 39454 [chan send, 32 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc014fea680) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc0140b2ea0, 0xc014fe0ed0, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc0140b2ea0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Luckily it doesn't break synchronization completely as eventually connection timers fire, the node breaks all connections, create new ones and these new ones request blocks successfully until another consensus payload stalls them too. In the end the node reaches synchronization, message processing loop starts and releases all of these waiting goroutines, but it's better for us to avoid this happening at all. This also makes double-starting a no-op which is a nice property.
2020-06-26 08:19:01 +00:00
if s.started.CAS(false, true) {
s.log.Info("starting consensus service")
consensus: prevent synchronization stalls When CN is not up to date with the network is synchonizes blocks first and only then starts consensus process. But while synchronizing it receives consensus payloads and tries to process them even though messages reader routine is not started yet. This leads to lots of goroutines waiting to send their messages: Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 1639919 [chan send, 4 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc005bd7680) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc00507d170, 0xc005bdd560, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc00507d170) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 1639181 [chan send, 10 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc013bb6600) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc01361ee10, 0xc01342c780, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc01361ee10) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 39454 [chan send, 32 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc014fea680) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc0140b2ea0, 0xc014fe0ed0, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc0140b2ea0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Luckily it doesn't break synchronization completely as eventually connection timers fire, the node breaks all connections, create new ones and these new ones request blocks successfully until another consensus payload stalls them too. In the end the node reaches synchronization, message processing loop starts and releases all of these waiting goroutines, but it's better for us to avoid this happening at all. This also makes double-starting a no-op which is a nice property.
2020-06-26 08:19:01 +00:00
s.dbft.Start()
s.Chain.SubscribeForBlocks(s.blockEvents)
go s.eventLoop()
}
2019-11-15 10:32:40 +00:00
}
2020-09-01 16:58:51 +00:00
// Shutdown implements Service interface.
func (s *service) Shutdown() {
if s.started.Load() {
close(s.quit)
<-s.finished
}
2020-09-01 16:58:51 +00:00
}
2019-11-15 10:32:40 +00:00
func (s *service) eventLoop() {
consensus: wait goroutine to finish on Shutdown Fixes: panic: assignment to entry in nil map goroutine 227 [running]: github.com/nspcc-dev/neo-go/pkg/core/storage.(*MemoryStore).put(...) /home/rik/dev/neo-go/pkg/core/storage/memory_store.go:53 github.com/nspcc-dev/neo-go/pkg/core/storage.(*MemoryStore).PutBatch(0xc00035f580, 0x110a680, 0xc000336750, 0x0, 0x0) /home/rik/dev/neo-go/pkg/core/storage/memory_store.go:93 +0x286 github.com/nspcc-dev/neo-go/pkg/core.(*Blockchain).addHeaders(0xc0000a2340, 0xc0001be301, 0xc00036d428, 0x1, 0x1, 0x0, 0x0) /home/rik/dev/neo-go/pkg/core/blockchain.go:516 +0xd5a github.com/nspcc-dev/neo-go/pkg/core.(*Blockchain).AddBlock(0xc0000a2340, 0xc0000bc2c0, 0x0, 0x0) /home/rik/dev/neo-go/pkg/core/blockchain.go:407 +0x9ca github.com/nspcc-dev/neo-go/pkg/consensus.(*service).processBlock(0xc000152160, 0x1122320, 0xc0000bc2c0) /home/rik/dev/neo-go/pkg/consensus/consensus.go:440 +0xbf github.com/nspcc-dev/dbft.(*DBFT).checkCommit(0xc0000d3400) /home/rik/go/pkg/mod/github.com/nspcc-dev/dbft@v0.0.0-20200911152629-be965ee4d449/check.go:71 +0x918 github.com/nspcc-dev/dbft.(*DBFT).checkPrepare(0xc0000d3400) /home/rik/go/pkg/mod/github.com/nspcc-dev/dbft@v0.0.0-20200911152629-be965ee4d449/check.go:36 +0x465 github.com/nspcc-dev/dbft.(*DBFT).sendPrepareRequest(0xc0000d3400) /home/rik/go/pkg/mod/github.com/nspcc-dev/dbft@v0.0.0-20200911152629-be965ee4d449/send.go:42 +0x2f8 github.com/nspcc-dev/dbft.(*DBFT).start(0xc0000d3400) /home/rik/go/pkg/mod/github.com/nspcc-dev/dbft@v0.0.0-20200911152629-be965ee4d449/dbft.go:269 +0x26f github.com/nspcc-dev/dbft.(*DBFT).Start(0xc0000d3400) /home/rik/go/pkg/mod/github.com/nspcc-dev/dbft@v0.0.0-20200911152629-be965ee4d449/dbft.go:82 +0x59 github.com/nspcc-dev/neo-go/pkg/consensus.(*service).Start(0xc000152160) /home/rik/dev/neo-go/pkg/consensus/consensus.go:191 +0x56 github.com/nspcc-dev/neo-go/pkg/network.(*Server).tryStartConsensus(0xc000235040) /home/rik/dev/neo-go/pkg/network/server.go:311 +0xda github.com/nspcc-dev/neo-go/pkg/network.(*Server).Start(0xc000235040, 0xc0000faba0) /home/rik/dev/neo-go/pkg/network/server.go:173 +0x202 created by github.com/nspcc-dev/neo-go/cli.newTestChain /home/rik/dev/neo-go/cli/executor_test.go:77 +0x47d FAIL github.com/nspcc-dev/neo-go/cli 14.479s
2020-09-19 18:49:05 +00:00
events:
2019-11-15 10:32:40 +00:00
for {
select {
2020-09-01 16:58:51 +00:00
case <-s.quit:
s.dbft.Timer.Stop()
consensus: wait goroutine to finish on Shutdown Fixes: panic: assignment to entry in nil map goroutine 227 [running]: github.com/nspcc-dev/neo-go/pkg/core/storage.(*MemoryStore).put(...) /home/rik/dev/neo-go/pkg/core/storage/memory_store.go:53 github.com/nspcc-dev/neo-go/pkg/core/storage.(*MemoryStore).PutBatch(0xc00035f580, 0x110a680, 0xc000336750, 0x0, 0x0) /home/rik/dev/neo-go/pkg/core/storage/memory_store.go:93 +0x286 github.com/nspcc-dev/neo-go/pkg/core.(*Blockchain).addHeaders(0xc0000a2340, 0xc0001be301, 0xc00036d428, 0x1, 0x1, 0x0, 0x0) /home/rik/dev/neo-go/pkg/core/blockchain.go:516 +0xd5a github.com/nspcc-dev/neo-go/pkg/core.(*Blockchain).AddBlock(0xc0000a2340, 0xc0000bc2c0, 0x0, 0x0) /home/rik/dev/neo-go/pkg/core/blockchain.go:407 +0x9ca github.com/nspcc-dev/neo-go/pkg/consensus.(*service).processBlock(0xc000152160, 0x1122320, 0xc0000bc2c0) /home/rik/dev/neo-go/pkg/consensus/consensus.go:440 +0xbf github.com/nspcc-dev/dbft.(*DBFT).checkCommit(0xc0000d3400) /home/rik/go/pkg/mod/github.com/nspcc-dev/dbft@v0.0.0-20200911152629-be965ee4d449/check.go:71 +0x918 github.com/nspcc-dev/dbft.(*DBFT).checkPrepare(0xc0000d3400) /home/rik/go/pkg/mod/github.com/nspcc-dev/dbft@v0.0.0-20200911152629-be965ee4d449/check.go:36 +0x465 github.com/nspcc-dev/dbft.(*DBFT).sendPrepareRequest(0xc0000d3400) /home/rik/go/pkg/mod/github.com/nspcc-dev/dbft@v0.0.0-20200911152629-be965ee4d449/send.go:42 +0x2f8 github.com/nspcc-dev/dbft.(*DBFT).start(0xc0000d3400) /home/rik/go/pkg/mod/github.com/nspcc-dev/dbft@v0.0.0-20200911152629-be965ee4d449/dbft.go:269 +0x26f github.com/nspcc-dev/dbft.(*DBFT).Start(0xc0000d3400) /home/rik/go/pkg/mod/github.com/nspcc-dev/dbft@v0.0.0-20200911152629-be965ee4d449/dbft.go:82 +0x59 github.com/nspcc-dev/neo-go/pkg/consensus.(*service).Start(0xc000152160) /home/rik/dev/neo-go/pkg/consensus/consensus.go:191 +0x56 github.com/nspcc-dev/neo-go/pkg/network.(*Server).tryStartConsensus(0xc000235040) /home/rik/dev/neo-go/pkg/network/server.go:311 +0xda github.com/nspcc-dev/neo-go/pkg/network.(*Server).Start(0xc000235040, 0xc0000faba0) /home/rik/dev/neo-go/pkg/network/server.go:173 +0x202 created by github.com/nspcc-dev/neo-go/cli.newTestChain /home/rik/dev/neo-go/cli/executor_test.go:77 +0x47d FAIL github.com/nspcc-dev/neo-go/cli 14.479s
2020-09-19 18:49:05 +00:00
break events
2020-09-10 13:34:33 +00:00
case <-s.dbft.Timer.C():
hv := s.dbft.Timer.HV()
s.log.Debug("timer fired",
zap.Uint32("height", hv.Height),
zap.Uint("view", uint(hv.View)))
s.dbft.OnTimeout(hv)
2019-11-15 10:32:40 +00:00
case msg := <-s.messages:
fields := []zap.Field{
zap.Uint8("from", msg.message.ValidatorIndex),
zap.Stringer("type", msg.Type()),
}
if msg.Type() == payload.RecoveryMessageType {
rec := msg.GetRecoveryMessage().(*recoveryMessage)
if rec.preparationHash == nil {
req := rec.GetPrepareRequest(&msg, s.dbft.Validators, uint16(s.dbft.PrimaryIndex))
if req != nil {
h := req.Hash()
rec.preparationHash = &h
}
}
fields = append(fields,
zap.Int("#preparation", len(rec.preparationPayloads)),
zap.Int("#commit", len(rec.commitPayloads)),
zap.Int("#changeview", len(rec.changeViewPayloads)),
zap.Bool("#request", rec.prepareRequest != nil),
zap.Bool("#hash", rec.preparationHash != nil))
}
s.log.Debug("received message", fields...)
2019-11-15 10:32:40 +00:00
s.dbft.OnReceive(&msg)
case tx := <-s.transactions:
s.dbft.OnTransaction(tx)
case b := <-s.blockEvents:
s.handleChainBlock(b)
}
// Always process block event if there is any, we can add one above.
select {
case b := <-s.blockEvents:
s.handleChainBlock(b)
default:
2019-11-15 10:32:40 +00:00
}
}
consensus: wait goroutine to finish on Shutdown Fixes: panic: assignment to entry in nil map goroutine 227 [running]: github.com/nspcc-dev/neo-go/pkg/core/storage.(*MemoryStore).put(...) /home/rik/dev/neo-go/pkg/core/storage/memory_store.go:53 github.com/nspcc-dev/neo-go/pkg/core/storage.(*MemoryStore).PutBatch(0xc00035f580, 0x110a680, 0xc000336750, 0x0, 0x0) /home/rik/dev/neo-go/pkg/core/storage/memory_store.go:93 +0x286 github.com/nspcc-dev/neo-go/pkg/core.(*Blockchain).addHeaders(0xc0000a2340, 0xc0001be301, 0xc00036d428, 0x1, 0x1, 0x0, 0x0) /home/rik/dev/neo-go/pkg/core/blockchain.go:516 +0xd5a github.com/nspcc-dev/neo-go/pkg/core.(*Blockchain).AddBlock(0xc0000a2340, 0xc0000bc2c0, 0x0, 0x0) /home/rik/dev/neo-go/pkg/core/blockchain.go:407 +0x9ca github.com/nspcc-dev/neo-go/pkg/consensus.(*service).processBlock(0xc000152160, 0x1122320, 0xc0000bc2c0) /home/rik/dev/neo-go/pkg/consensus/consensus.go:440 +0xbf github.com/nspcc-dev/dbft.(*DBFT).checkCommit(0xc0000d3400) /home/rik/go/pkg/mod/github.com/nspcc-dev/dbft@v0.0.0-20200911152629-be965ee4d449/check.go:71 +0x918 github.com/nspcc-dev/dbft.(*DBFT).checkPrepare(0xc0000d3400) /home/rik/go/pkg/mod/github.com/nspcc-dev/dbft@v0.0.0-20200911152629-be965ee4d449/check.go:36 +0x465 github.com/nspcc-dev/dbft.(*DBFT).sendPrepareRequest(0xc0000d3400) /home/rik/go/pkg/mod/github.com/nspcc-dev/dbft@v0.0.0-20200911152629-be965ee4d449/send.go:42 +0x2f8 github.com/nspcc-dev/dbft.(*DBFT).start(0xc0000d3400) /home/rik/go/pkg/mod/github.com/nspcc-dev/dbft@v0.0.0-20200911152629-be965ee4d449/dbft.go:269 +0x26f github.com/nspcc-dev/dbft.(*DBFT).Start(0xc0000d3400) /home/rik/go/pkg/mod/github.com/nspcc-dev/dbft@v0.0.0-20200911152629-be965ee4d449/dbft.go:82 +0x59 github.com/nspcc-dev/neo-go/pkg/consensus.(*service).Start(0xc000152160) /home/rik/dev/neo-go/pkg/consensus/consensus.go:191 +0x56 github.com/nspcc-dev/neo-go/pkg/network.(*Server).tryStartConsensus(0xc000235040) /home/rik/dev/neo-go/pkg/network/server.go:311 +0xda github.com/nspcc-dev/neo-go/pkg/network.(*Server).Start(0xc000235040, 0xc0000faba0) /home/rik/dev/neo-go/pkg/network/server.go:173 +0x202 created by github.com/nspcc-dev/neo-go/cli.newTestChain /home/rik/dev/neo-go/cli/executor_test.go:77 +0x47d FAIL github.com/nspcc-dev/neo-go/cli 14.479s
2020-09-19 18:49:05 +00:00
close(s.finished)
}
func (s *service) handleChainBlock(b *coreb.Block) {
// We can get our own block here, so check for index.
if b.Index >= s.dbft.BlockIndex {
s.log.Debug("new block in the chain",
zap.Uint32("dbft index", s.dbft.BlockIndex),
zap.Uint32("chain index", s.Chain.BlockHeight()))
s.postBlock(b)
s.dbft.InitializeConsensus(0)
2019-11-08 15:40:21 +00:00
}
}
2019-12-16 08:57:49 +00:00
func (s *service) validatePayload(p *Payload) bool {
validators := s.getValidators()
if int(p.message.ValidatorIndex) >= len(validators) {
2019-12-16 08:57:49 +00:00
return false
}
pub := validators[p.message.ValidatorIndex]
h := pub.(*publicKey).GetScriptHash()
return p.Sender == h
2019-12-16 08:57:49 +00:00
}
2020-01-15 14:05:47 +00:00
func (s *service) getKeyPair(pubs []crypto.PublicKey) (int, crypto.PrivateKey, crypto.PublicKey) {
for i := range pubs {
sh := pubs[i].(*publicKey).GetScriptHash()
acc := s.wallet.GetAccount(sh)
2020-01-15 14:05:47 +00:00
if acc == nil {
continue
}
key := acc.PrivateKey()
if acc.PrivateKey() == nil {
err := acc.Decrypt(s.Config.Wallet.Password, s.wallet.Scrypt)
if err != nil {
s.log.Fatal("can't unlock account", zap.String("address", address.Uint160ToString(sh)))
break
}
key = acc.PrivateKey()
2020-01-15 14:05:47 +00:00
}
return i, &privateKey{PrivateKey: key}, &publicKey{PublicKey: key.PublicKey()}
2019-11-15 10:32:40 +00:00
}
2020-01-15 14:05:47 +00:00
return -1, nil, nil
2019-11-15 10:32:40 +00:00
}
func (s *service) payloadFromExtensible(ep *npayload.Extensible) *Payload {
return &Payload{
Extensible: *ep,
message: message{
stateRootEnabled: s.ProtocolConfiguration.StateRootInHeader,
},
}
}
2019-11-08 15:40:21 +00:00
// OnPayload handles Payload receive.
func (s *service) OnPayload(cp *npayload.Extensible) error {
log := s.log.With(zap.Stringer("hash", cp.Hash()))
p := s.payloadFromExtensible(cp)
// decode payload data into message
if err := p.decodeData(); err != nil {
log.Info("can't decode payload data", zap.Error(err))
return nil
}
if !s.validatePayload(p) {
log.Info("can't validate payload")
return nil
2019-11-15 10:32:40 +00:00
}
consensus: prevent synchronization stalls When CN is not up to date with the network is synchonizes blocks first and only then starts consensus process. But while synchronizing it receives consensus payloads and tries to process them even though messages reader routine is not started yet. This leads to lots of goroutines waiting to send their messages: Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 1639919 [chan send, 4 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc005bd7680) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc00507d170, 0xc005bdd560, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc00507d170) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 1639181 [chan send, 10 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc013bb6600) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc01361ee10, 0xc01342c780, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc01361ee10) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 39454 [chan send, 32 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc014fea680) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc0140b2ea0, 0xc014fe0ed0, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc0140b2ea0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Luckily it doesn't break synchronization completely as eventually connection timers fire, the node breaks all connections, create new ones and these new ones request blocks successfully until another consensus payload stalls them too. In the end the node reaches synchronization, message processing loop starts and releases all of these waiting goroutines, but it's better for us to avoid this happening at all. This also makes double-starting a no-op which is a nice property.
2020-06-26 08:19:01 +00:00
if s.dbft == nil || !s.started.Load() {
log.Debug("dbft is inactive or not started yet")
return nil
2019-11-15 10:32:40 +00:00
}
s.messages <- *p
return nil
2019-11-15 10:32:40 +00:00
}
func (s *service) OnTransaction(tx *transaction.Transaction) {
if s.dbft != nil {
s.transactions <- tx
}
2019-11-08 15:40:21 +00:00
}
2019-11-15 10:32:40 +00:00
func (s *service) broadcast(p payload.ConsensusPayload) {
if err := p.(*Payload).Sign(s.dbft.Priv.(*privateKey)); err != nil {
s.log.Warn("can't sign consensus payload", zap.Error(err))
}
ep := &p.(*Payload).Extensible
s.Config.Broadcast(ep)
2019-11-15 10:32:40 +00:00
}
func (s *service) getTx(h util.Uint256) block.Transaction {
if tx := s.txx.Get(h); tx != nil {
return tx.(*transaction.Transaction)
}
tx, _, _ := s.Config.Chain.GetTransaction(h)
// this is needed because in case of absent tx dBFT expects to
// get nil interface, not a nil pointer to any concrete type
if tx != nil {
return tx
}
return nil
2019-11-15 10:32:40 +00:00
}
func (s *service) verifyBlock(b block.Block) bool {
coreb := &b.(*neoBlock).Block
if s.Chain.BlockHeight() >= coreb.Index {
s.log.Warn("proposed block has already outdated")
return false
}
if s.lastTimestamp >= coreb.Timestamp {
s.log.Warn("proposed block has small timestamp",
zap.Uint64("ts", coreb.Timestamp),
zap.Uint64("last", s.lastTimestamp))
return false
}
2021-03-15 10:00:04 +00:00
size := coreb.GetExpectedBlockSize()
if size > int(s.ProtocolConfiguration.MaxBlockSize) {
s.log.Warn("proposed block size exceeds config MaxBlockSize",
zap.Uint32("max size allowed", s.ProtocolConfiguration.MaxBlockSize),
zap.Int("block size", size))
return false
}
2021-03-15 10:51:07 +00:00
var fee int64
2021-01-15 12:40:15 +00:00
var pool = mempool.New(len(coreb.Transactions), 0, false)
var mainPool = s.Chain.GetMemPool()
2019-11-15 10:32:40 +00:00
for _, tx := range coreb.Transactions {
var err error
2021-03-15 10:51:07 +00:00
fee += tx.SystemFee
if mainPool.ContainsKey(tx.Hash()) {
err = pool.Add(tx, s.Chain)
if err == nil {
continue
}
} else {
err = s.Chain.PoolTx(tx, pool)
}
if err != nil {
s.log.Warn("invalid transaction in proposed block",
zap.Stringer("hash", tx.Hash()),
zap.Error(err))
2019-11-15 10:32:40 +00:00
return false
}
if s.Chain.BlockHeight() >= coreb.Index {
s.log.Warn("proposed block has already outdated")
return false
}
2019-11-15 10:32:40 +00:00
}
2021-03-15 10:51:07 +00:00
maxBlockSysFee := s.ProtocolConfiguration.MaxBlockSystemFee
if fee > maxBlockSysFee {
s.log.Warn("proposed block system fee exceeds config MaxBlockSystemFee",
zap.Int("max system fee allowed", int(maxBlockSysFee)),
zap.Int("block system fee", int(fee)))
return false
}
2019-11-15 10:32:40 +00:00
return true
}
var (
errInvalidPrevHash = errors.New("invalid PrevHash")
errInvalidVersion = errors.New("invalid Version")
errInvalidStateRoot = errors.New("state root mismatch")
errInvalidTransactionsCount = errors.New("invalid transactions count")
)
consensus: prevent synchronization stalls When CN is not up to date with the network is synchonizes blocks first and only then starts consensus process. But while synchronizing it receives consensus payloads and tries to process them even though messages reader routine is not started yet. This leads to lots of goroutines waiting to send their messages: Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 1639919 [chan send, 4 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc005bd7680) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc00507d170, 0xc005bdd560, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc00507d170) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 1639181 [chan send, 10 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc013bb6600) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc01361ee10, 0xc01342c780, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc01361ee10) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 39454 [chan send, 32 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc014fea680) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc0140b2ea0, 0xc014fe0ed0, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc0140b2ea0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Luckily it doesn't break synchronization completely as eventually connection timers fire, the node breaks all connections, create new ones and these new ones request blocks successfully until another consensus payload stalls them too. In the end the node reaches synchronization, message processing loop starts and releases all of these waiting goroutines, but it's better for us to avoid this happening at all. This also makes double-starting a no-op which is a nice property.
2020-06-26 08:19:01 +00:00
func (s *service) verifyRequest(p payload.ConsensusPayload) error {
req := p.GetPrepareRequest().(*prepareRequest)
if req.prevHash != s.dbft.PrevHash {
return errInvalidPrevHash
}
if req.version != s.dbft.Version {
return errInvalidVersion
}
if s.ProtocolConfiguration.StateRootInHeader {
sr, err := s.Chain.GetStateModule().GetStateRoot(s.dbft.BlockIndex - 1)
if err != nil {
return err
} else if sr.Root != req.stateRoot {
return fmt.Errorf("%w: %s != %s", errInvalidStateRoot, sr.Root, req.stateRoot)
}
}
if len(req.TransactionHashes()) > int(s.ProtocolConfiguration.MaxTransactionsPerBlock) {
return fmt.Errorf("%w: max = %d, got %d", errInvalidTransactionsCount, s.ProtocolConfiguration.MaxTransactionsPerBlock, len(req.TransactionHashes()))
}
consensus: prevent synchronization stalls When CN is not up to date with the network is synchonizes blocks first and only then starts consensus process. But while synchronizing it receives consensus payloads and tries to process them even though messages reader routine is not started yet. This leads to lots of goroutines waiting to send their messages: Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 1639919 [chan send, 4 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc005bd7680) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc00507d170, 0xc005bdd560, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc00507d170) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 1639181 [chan send, 10 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc013bb6600) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc01361ee10, 0xc01342c780, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc01361ee10) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Jun 25 23:55:53 nodoka neo-go[32733]: goroutine 39454 [chan send, 32 minutes]: Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).OnPayload(0xc0000ecb40, 0xc014fea680) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:329 +0x31b Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleConsensusCmd(...) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:687 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*Server).handleMessage(0xc0000ba160, 0x1053260, 0xc0140b2ea0, 0xc014fe0ed0, 0x0, 0x0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/server.go:806 +0xd58 Jun 25 23:55:53 nodoka neo-go[32733]: github.com/nspcc-dev/neo-go/pkg/network.(*TCPPeer).handleConn(0xc0140b2ea0) Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_peer.go:160 +0x294 Jun 25 23:55:53 nodoka neo-go[32733]: created by github.com/nspcc-dev/neo-go/pkg/network.(*TCPTransport).Dial Jun 25 23:55:53 nodoka neo-go[32733]: #011/go/src/github.com/nspcc-dev/neo-go/pkg/network/tcp_transport.go:38 +0x1ad Luckily it doesn't break synchronization completely as eventually connection timers fire, the node breaks all connections, create new ones and these new ones request blocks successfully until another consensus payload stalls them too. In the end the node reaches synchronization, message processing loop starts and releases all of these waiting goroutines, but it's better for us to avoid this happening at all. This also makes double-starting a no-op which is a nice property.
2020-06-26 08:19:01 +00:00
// Save lastProposal for getVerified().
s.lastProposal = req.transactionHashes
return nil
}
2019-11-15 10:32:40 +00:00
func (s *service) processBlock(b block.Block) {
bb := &b.(*neoBlock).Block
bb.Script = *(s.getBlockWitness(bb))
2019-11-15 10:32:40 +00:00
if err := s.Chain.AddBlock(bb); err != nil {
// The block might already be added via the regular network
// interaction.
if _, errget := s.Chain.GetBlock(bb.Hash()); errget != nil {
s.log.Warn("error on add block", zap.Error(err))
}
2019-11-15 10:32:40 +00:00
}
s.postBlock(bb)
}
func (s *service) postBlock(b *coreb.Block) {
if s.lastTimestamp < b.Timestamp {
s.lastTimestamp = b.Timestamp
}
s.lastProposal = nil
2019-11-15 10:32:40 +00:00
}
func (s *service) getBlockWitness(b *coreb.Block) *transaction.Witness {
2019-11-15 10:32:40 +00:00
dctx := s.dbft.Context
pubs := convertKeys(dctx.Validators)
sigs := make(map[*keys.PublicKey][]byte)
for i := range pubs {
if p := dctx.CommitPayloads[i]; p != nil && p.ViewNumber() == dctx.ViewNumber {
sigs[pubs[i]] = p.GetCommit().Signature()
}
}
m := s.dbft.Context.M()
verif, err := smartcontract.CreateMultiSigRedeemScript(m, pubs)
if err != nil {
s.log.Warn("can't create multisig redeem script", zap.Error(err))
2019-11-15 10:32:40 +00:00
return nil
}
sort.Sort(keys.PublicKeys(pubs))
2020-04-21 13:45:48 +00:00
buf := io.NewBufBinWriter()
2019-11-15 10:32:40 +00:00
for i, j := 0, 0; i < len(pubs) && j < m; i++ {
if sig, ok := sigs[pubs[i]]; ok {
2020-04-21 13:45:48 +00:00
emit.Bytes(buf.BinWriter, sig)
2019-11-15 10:32:40 +00:00
j++
}
}
return &transaction.Witness{
2020-04-21 13:45:48 +00:00
InvocationScript: buf.Bytes(),
2019-11-15 10:32:40 +00:00
VerificationScript: verif,
}
}
func (s *service) getBlock(h util.Uint256) block.Block {
b, err := s.Chain.GetBlock(h)
if err != nil {
return nil
}
return &neoBlock{network: s.ProtocolConfiguration.Magic, Block: *b}
2019-11-15 10:32:40 +00:00
}
func (s *service) getVerifiedTx() []block.Transaction {
2019-11-15 10:32:40 +00:00
pool := s.Config.Chain.GetMemPool()
var txx []*transaction.Transaction
if s.dbft.ViewNumber > 0 && len(s.lastProposal) > 0 {
txx = make([]*transaction.Transaction, 0, len(s.lastProposal))
for i := range s.lastProposal {
if tx, ok := pool.TryGetValue(s.lastProposal[i]); ok {
txx = append(txx, tx)
}
}
if len(txx) < len(s.lastProposal)/2 {
txx = pool.GetVerifiedTransactions()
}
} else {
txx = pool.GetVerifiedTransactions()
}
2019-11-15 10:32:40 +00:00
if len(txx) > 0 {
txx = s.Config.Chain.ApplyPolicyToTxSet(txx)
}
res := make([]block.Transaction, len(txx))
for i := range txx {
res[i] = txx[i]
}
2019-11-15 10:32:40 +00:00
return res
}
func (s *service) getValidators(txes ...block.Transaction) []crypto.PublicKey {
var (
pKeys []*keys.PublicKey
err error
)
if txes == nil {
pKeys, err = s.Chain.GetNextBlockValidators()
} else {
pKeys, err = s.Chain.GetValidators()
}
if err != nil {
s.log.Error("error while trying to get validators", zap.Error(err))
2019-11-15 10:32:40 +00:00
}
pubs := make([]crypto.PublicKey, len(pKeys))
for i := range pKeys {
pubs[i] = &publicKey{PublicKey: pKeys[i]}
}
return pubs
}
func (s *service) getConsensusAddress(validators ...crypto.PublicKey) util.Uint160 {
return util.Uint160{}
2019-11-15 10:32:40 +00:00
}
func convertKeys(validators []crypto.PublicKey) (pubs []*keys.PublicKey) {
pubs = make([]*keys.PublicKey, len(validators))
for i, k := range validators {
pubs[i] = k.(*publicKey).PublicKey
}
return
2019-11-08 15:40:21 +00:00
}
func (s *service) newBlockFromContext(ctx *dbft.Context) block.Block {
block := &neoBlock{network: s.ProtocolConfiguration.Magic}
block.Block.Timestamp = ctx.Timestamp / nsInMs
block.Block.Nonce = ctx.Nonce
block.Block.Index = ctx.BlockIndex
if s.ProtocolConfiguration.StateRootInHeader {
sr, err := s.Chain.GetStateModule().GetStateRoot(ctx.BlockIndex - 1)
if err != nil {
consensus: fix panic during verifyBlock Issue: panic during mixed 4-nodes consensus setup: ``` 2021-03-18T12:01:50.715Z INFO skip change view {"nc": 0, "nf": 3} 2021-03-18T12:01:52.786Z INFO received ChangeView {"validator": 0, "reason": "Timeout", "new view": 1} 2021-03-18T12:01:53.602Z INFO received ChangeView {"validator": 2, "reason": "Timeout", "new view": 1} 2021-03-18T12:01:56.736Z INFO received ChangeView {"validator": 1, "reason": "Timeout", "new view": 1} 2021-03-18T12:01:56.736Z INFO changing dbft view {"height": 3, "view": 1, "index": 3, "role": "Backup"} 2021-03-18T12:02:01.758Z INFO received PrepareRequest {"validator": 2, "tx": 0} panic: interface conversion: block.Block is nil, not *consensus.neoBlock goroutine 315 [running]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).verifyBlock(0xc000419540, 0x0, 0x0, 0x4) github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:427 +0x1306 github.com/nspcc-dev/dbft.(*DBFT).createAndCheckBlock(0xc0001f8840, 0x13f0002) github.com/nspcc-dev/dbft@v0.0.0-20210302103605-cc75991b7cfb/dbft.go:373 +0x27e github.com/nspcc-dev/dbft.(*DBFT).onPrepareRequest(0xc0001f8840, 0x13f4378, 0xc0003b8500) github.com/nspcc-dev/dbft@v0.0.0-20210302103605-cc75991b7cfb/dbft.go:329 +0xdf1 github.com/nspcc-dev/dbft.(*DBFT).OnReceive(0xc0001f8840, 0x13f4378, 0xc0003b8500) github.com/nspcc-dev/dbft@v0.0.0-20210302103605-cc75991b7cfb/dbft.go:247 +0xe25 github.com/nspcc-dev/neo-go/pkg/consensus.(*service).eventLoop(0xc000419540) github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:297 +0x79d created by github.com/nspcc-dev/neo-go/pkg/consensus.(*service).Start github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:249 +0xa5 ``` So (*service).verifyBlock is unable to work with nil block.
2021-03-18 15:05:24 +00:00
s.log.Fatal(fmt.Sprintf("failed to get state root: %s", err.Error()))
}
block.StateRootEnabled = true
block.PrevStateRoot = sr.Root
}
var validators keys.PublicKeys
var err error
if native.ShouldUpdateCommittee(ctx.BlockIndex, s.Chain) {
validators, err = s.Chain.GetValidators()
} else {
validators, err = s.Chain.GetNextBlockValidators()
}
if err != nil {
consensus: fix panic during verifyBlock Issue: panic during mixed 4-nodes consensus setup: ``` 2021-03-18T12:01:50.715Z INFO skip change view {"nc": 0, "nf": 3} 2021-03-18T12:01:52.786Z INFO received ChangeView {"validator": 0, "reason": "Timeout", "new view": 1} 2021-03-18T12:01:53.602Z INFO received ChangeView {"validator": 2, "reason": "Timeout", "new view": 1} 2021-03-18T12:01:56.736Z INFO received ChangeView {"validator": 1, "reason": "Timeout", "new view": 1} 2021-03-18T12:01:56.736Z INFO changing dbft view {"height": 3, "view": 1, "index": 3, "role": "Backup"} 2021-03-18T12:02:01.758Z INFO received PrepareRequest {"validator": 2, "tx": 0} panic: interface conversion: block.Block is nil, not *consensus.neoBlock goroutine 315 [running]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).verifyBlock(0xc000419540, 0x0, 0x0, 0x4) github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:427 +0x1306 github.com/nspcc-dev/dbft.(*DBFT).createAndCheckBlock(0xc0001f8840, 0x13f0002) github.com/nspcc-dev/dbft@v0.0.0-20210302103605-cc75991b7cfb/dbft.go:373 +0x27e github.com/nspcc-dev/dbft.(*DBFT).onPrepareRequest(0xc0001f8840, 0x13f4378, 0xc0003b8500) github.com/nspcc-dev/dbft@v0.0.0-20210302103605-cc75991b7cfb/dbft.go:329 +0xdf1 github.com/nspcc-dev/dbft.(*DBFT).OnReceive(0xc0001f8840, 0x13f4378, 0xc0003b8500) github.com/nspcc-dev/dbft@v0.0.0-20210302103605-cc75991b7cfb/dbft.go:247 +0xe25 github.com/nspcc-dev/neo-go/pkg/consensus.(*service).eventLoop(0xc000419540) github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:297 +0x79d created by github.com/nspcc-dev/neo-go/pkg/consensus.(*service).Start github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:249 +0xa5 ``` So (*service).verifyBlock is unable to work with nil block.
2021-03-18 15:05:24 +00:00
s.log.Fatal(fmt.Sprintf("failed to get validators: %s", err.Error()))
}
script, err := smartcontract.CreateMultiSigRedeemScript(s.dbft.Context.M(), validators)
if err != nil {
consensus: fix panic during verifyBlock Issue: panic during mixed 4-nodes consensus setup: ``` 2021-03-18T12:01:50.715Z INFO skip change view {"nc": 0, "nf": 3} 2021-03-18T12:01:52.786Z INFO received ChangeView {"validator": 0, "reason": "Timeout", "new view": 1} 2021-03-18T12:01:53.602Z INFO received ChangeView {"validator": 2, "reason": "Timeout", "new view": 1} 2021-03-18T12:01:56.736Z INFO received ChangeView {"validator": 1, "reason": "Timeout", "new view": 1} 2021-03-18T12:01:56.736Z INFO changing dbft view {"height": 3, "view": 1, "index": 3, "role": "Backup"} 2021-03-18T12:02:01.758Z INFO received PrepareRequest {"validator": 2, "tx": 0} panic: interface conversion: block.Block is nil, not *consensus.neoBlock goroutine 315 [running]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).verifyBlock(0xc000419540, 0x0, 0x0, 0x4) github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:427 +0x1306 github.com/nspcc-dev/dbft.(*DBFT).createAndCheckBlock(0xc0001f8840, 0x13f0002) github.com/nspcc-dev/dbft@v0.0.0-20210302103605-cc75991b7cfb/dbft.go:373 +0x27e github.com/nspcc-dev/dbft.(*DBFT).onPrepareRequest(0xc0001f8840, 0x13f4378, 0xc0003b8500) github.com/nspcc-dev/dbft@v0.0.0-20210302103605-cc75991b7cfb/dbft.go:329 +0xdf1 github.com/nspcc-dev/dbft.(*DBFT).OnReceive(0xc0001f8840, 0x13f4378, 0xc0003b8500) github.com/nspcc-dev/dbft@v0.0.0-20210302103605-cc75991b7cfb/dbft.go:247 +0xe25 github.com/nspcc-dev/neo-go/pkg/consensus.(*service).eventLoop(0xc000419540) github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:297 +0x79d created by github.com/nspcc-dev/neo-go/pkg/consensus.(*service).Start github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:249 +0xa5 ``` So (*service).verifyBlock is unable to work with nil block.
2021-03-18 15:05:24 +00:00
s.log.Fatal(fmt.Sprintf("failed to create multisignature script: %s", err.Error()))
}
block.Block.NextConsensus = crypto.Hash160(script)
block.Block.PrevHash = ctx.PrevHash
block.Block.Version = ctx.Version
2021-03-01 12:20:27 +00:00
primaryIndex := byte(ctx.PrimaryIndex)
block.Block.PrimaryIndex = primaryIndex
consensus: fix panic during verifyBlock Issue: panic during mixed 4-nodes consensus setup: ``` 2021-03-18T12:01:50.715Z INFO skip change view {"nc": 0, "nf": 3} 2021-03-18T12:01:52.786Z INFO received ChangeView {"validator": 0, "reason": "Timeout", "new view": 1} 2021-03-18T12:01:53.602Z INFO received ChangeView {"validator": 2, "reason": "Timeout", "new view": 1} 2021-03-18T12:01:56.736Z INFO received ChangeView {"validator": 1, "reason": "Timeout", "new view": 1} 2021-03-18T12:01:56.736Z INFO changing dbft view {"height": 3, "view": 1, "index": 3, "role": "Backup"} 2021-03-18T12:02:01.758Z INFO received PrepareRequest {"validator": 2, "tx": 0} panic: interface conversion: block.Block is nil, not *consensus.neoBlock goroutine 315 [running]: github.com/nspcc-dev/neo-go/pkg/consensus.(*service).verifyBlock(0xc000419540, 0x0, 0x0, 0x4) github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:427 +0x1306 github.com/nspcc-dev/dbft.(*DBFT).createAndCheckBlock(0xc0001f8840, 0x13f0002) github.com/nspcc-dev/dbft@v0.0.0-20210302103605-cc75991b7cfb/dbft.go:373 +0x27e github.com/nspcc-dev/dbft.(*DBFT).onPrepareRequest(0xc0001f8840, 0x13f4378, 0xc0003b8500) github.com/nspcc-dev/dbft@v0.0.0-20210302103605-cc75991b7cfb/dbft.go:329 +0xdf1 github.com/nspcc-dev/dbft.(*DBFT).OnReceive(0xc0001f8840, 0x13f4378, 0xc0003b8500) github.com/nspcc-dev/dbft@v0.0.0-20210302103605-cc75991b7cfb/dbft.go:247 +0xe25 github.com/nspcc-dev/neo-go/pkg/consensus.(*service).eventLoop(0xc000419540) github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:297 +0x79d created by github.com/nspcc-dev/neo-go/pkg/consensus.(*service).Start github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:249 +0xa5 ``` So (*service).verifyBlock is unable to work with nil block.
2021-03-18 15:05:24 +00:00
// it's OK to have ctx.TransactionsHashes == nil here
2021-03-01 12:20:27 +00:00
hashes := make([]util.Uint256, len(ctx.TransactionHashes))
copy(hashes, ctx.TransactionHashes)
block.Block.MerkleRoot = hash.CalcMerkleRoot(hashes)
return block
}