diff --git a/cmd/node/config/config.toml b/cmd/node/config/config.toml index e0aa2721f0f..d480b9fef05 100644 --- a/cmd/node/config/config.toml +++ b/cmd/node/config/config.toml @@ -815,6 +815,11 @@ [Debug.EpochStart] GoRoutineAnalyserEnabled = true ProcessDataTrieOnCommitEpoch = true + [Debug.Process] + Enabled = true + DebuggingLogLevel = "*:DEBUG,p2p:TRACE,debug:DEBUG,process:TRACE,intercept:TRACE" + GoRoutinesDump = true + PollingTimeInSeconds = 240 # 4 minutes [Health] IntervalVerifyMemoryInSeconds = 30 diff --git a/config/config.go b/config/config.go index 3cd5e991ced..a47c3d01f25 100644 --- a/config/config.go +++ b/config/config.go @@ -465,6 +465,7 @@ type DebugConfig struct { Antiflood AntifloodDebugConfig ShuffleOut ShuffleOutDebugConfig EpochStart EpochStartDebugConfig + Process ProcessDebugConfig } // HealthServiceConfig will hold health service (monitoring) configuration @@ -508,6 +509,14 @@ type EpochStartDebugConfig struct { ProcessDataTrieOnCommitEpoch bool } +// ProcessDebugConfig will hold the process debug configuration +type ProcessDebugConfig struct { + Enabled bool + GoRoutinesDump bool + DebuggingLogLevel string + PollingTimeInSeconds int +} + // ApiRoutesConfig holds the configuration related to Rest API routes type ApiRoutesConfig struct { Logging ApiLoggingConfig diff --git a/debug/factory/interface.go b/debug/factory/interface.go index f44e7380b2f..7a5f1b97f94 100644 --- a/debug/factory/interface.go +++ b/debug/factory/interface.go @@ -11,3 +11,10 @@ type InterceptorResolverDebugHandler interface { Close() error IsInterfaceNil() bool } + +// ProcessDebugger defines what a process debugger implementation should do +type ProcessDebugger interface { + SetLastCommittedBlockRound(round uint64) + Close() error + IsInterfaceNil() bool +} diff --git a/debug/factory/processDebuggerFactory.go b/debug/factory/processDebuggerFactory.go new file mode 100644 index 00000000000..a1a7f9bc05d --- /dev/null +++ b/debug/factory/processDebuggerFactory.go @@ -0,0 +1,15 @@ +package factory + +import ( + "github.com/ElrondNetwork/elrond-go/config" + "github.com/ElrondNetwork/elrond-go/debug/process" +) + +// CreateProcessDebugger creates a new instance of type ProcessDebugger +func CreateProcessDebugger(configs config.ProcessDebugConfig) (ProcessDebugger, error) { + if !configs.Enabled { + return process.NewDisabledDebugger(), nil + } + + return process.NewProcessDebugger(configs) +} diff --git a/debug/factory/processDebuggerFactory_test.go b/debug/factory/processDebuggerFactory_test.go new file mode 100644 index 00000000000..8f724c57ea3 --- /dev/null +++ b/debug/factory/processDebuggerFactory_test.go @@ -0,0 +1,50 @@ +package factory + +import ( + "fmt" + "testing" + + "github.com/ElrondNetwork/elrond-go-core/core/check" + "github.com/ElrondNetwork/elrond-go/config" + "github.com/stretchr/testify/assert" +) + +func TestCreateProcessDebugger(t *testing.T) { + t.Parallel() + + t.Run("create disabled process debugger", func(t *testing.T) { + t.Parallel() + + configs := config.ProcessDebugConfig{ + Enabled: false, + } + debugger, err := CreateProcessDebugger(configs) + assert.Nil(t, err) + assert.False(t, check.IfNil(debugger)) + assert.Equal(t, "*process.disabledDebugger", fmt.Sprintf("%T", debugger)) + }) + t.Run("create real process debugger", func(t *testing.T) { + t.Parallel() + + configs := config.ProcessDebugConfig{ + Enabled: true, + DebuggingLogLevel: "", + GoRoutinesDump: false, + PollingTimeInSeconds: 1, + } + debugger, err := CreateProcessDebugger(configs) + assert.Nil(t, err) + assert.False(t, check.IfNil(debugger)) + assert.Equal(t, "*process.processDebugger", fmt.Sprintf("%T", debugger)) + }) + t.Run("create real process debugger errors", func(t *testing.T) { + t.Parallel() + + configs := config.ProcessDebugConfig{ + Enabled: true, + } + debugger, err := CreateProcessDebugger(configs) + assert.NotNil(t, err) + assert.True(t, check.IfNil(debugger)) + }) +} diff --git a/debug/process/debugger.go b/debug/process/debugger.go new file mode 100644 index 00000000000..19d599e2d13 --- /dev/null +++ b/debug/process/debugger.go @@ -0,0 +1,170 @@ +package process + +import ( + "context" + "fmt" + "runtime" + "sync" + "time" + + logger "github.com/ElrondNetwork/elrond-go-logger" + "github.com/ElrondNetwork/elrond-go/config" +) + +const ( + minAcceptedValue = 1 + buffSize = 100 * 1024 * 1024 // 100MB +) + +var log = logger.GetOrCreate("debug/process") + +type processDebugger struct { + timer *time.Timer + mut sync.RWMutex + lastCheckedBlockRound int64 + lastCommittedBlockRound int64 + cancel func() + goRoutinesDumpHandler func() + logChangeHandler func() + pollingTime time.Duration + debuggingLogLevel string + dumpGoRoutines bool +} + +// NewProcessDebugger creates a new debugger instance used to monitor the block process flow +func NewProcessDebugger(config config.ProcessDebugConfig) (*processDebugger, error) { + err := checkConfigs(config) + if err != nil { + return nil, err + } + + pollingTime := time.Duration(config.PollingTimeInSeconds) * time.Second + d := &processDebugger{ + timer: time.NewTimer(pollingTime), + + pollingTime: pollingTime, + debuggingLogLevel: config.DebuggingLogLevel, + dumpGoRoutines: config.GoRoutinesDump, + } + + ctx, cancel := context.WithCancel(context.Background()) + d.cancel = cancel + d.goRoutinesDumpHandler = dumpGoRoutines + d.logChangeHandler = d.changeLog + + go d.processLoop(ctx) + + return d, nil +} + +func checkConfigs(config config.ProcessDebugConfig) error { + if config.PollingTimeInSeconds < minAcceptedValue { + return fmt.Errorf("%w for PollingTimeInSeconds, minimum %d, got %d", + errInvalidValue, minAcceptedValue, config.PollingTimeInSeconds) + } + + return nil +} + +func (debugger *processDebugger) processLoop(ctx context.Context) { + log.Debug("processor debugger processLoop is starting...") + + defer debugger.timer.Stop() + + for { + debugger.timer.Reset(debugger.pollingTime) + + select { + case <-ctx.Done(): + log.Debug("processor debugger processLoop is closing...") + return + case <-debugger.timer.C: + debugger.checkRounds() + } + } +} + +func (debugger *processDebugger) checkRounds() { + if debugger.shouldTriggerUpdatingLastCheckedRound() { + debugger.trigger() + } +} + +func (debugger *processDebugger) shouldTriggerUpdatingLastCheckedRound() bool { + debugger.mut.Lock() + defer debugger.mut.Unlock() + + isNodeStarting := debugger.lastCheckedBlockRound == 0 && debugger.lastCommittedBlockRound <= 0 + if isNodeStarting { + log.Debug("processor debugger: node is starting") + return false + } + + defer func() { + // update the last checked round + debugger.lastCheckedBlockRound = debugger.lastCommittedBlockRound + }() + + isFirstCommit := debugger.lastCheckedBlockRound == 0 && debugger.lastCommittedBlockRound > 0 + if isFirstCommit { + log.Debug("processor debugger: first committed block", "round", debugger.lastCommittedBlockRound) + return false + } + + isNodeRunning := debugger.lastCheckedBlockRound < debugger.lastCommittedBlockRound + if isNodeRunning { + log.Debug("processor debugger: node is running, nothing to do", "round", debugger.lastCommittedBlockRound) + return false + } + + return true +} + +func (debugger *processDebugger) trigger() { + debugger.mut.RLock() + lastCommittedBlockRound := debugger.lastCommittedBlockRound + debugger.mut.RUnlock() + + log.Warn("processor debugger: node is stuck", + "last committed round", lastCommittedBlockRound) + + debugger.logChangeHandler() + + if debugger.dumpGoRoutines { + debugger.goRoutinesDumpHandler() + } +} + +// SetLastCommittedBlockRound sets the last committed block's round +func (debugger *processDebugger) SetLastCommittedBlockRound(round uint64) { + debugger.mut.Lock() + defer debugger.mut.Unlock() + + log.Debug("processor debugger: updated last committed block round", "round", round) + debugger.lastCommittedBlockRound = int64(round) +} + +// Close stops any started go routines +func (debugger *processDebugger) Close() error { + debugger.cancel() + + return nil +} + +func dumpGoRoutines() { + buff := make([]byte, buffSize) + numBytes := runtime.Stack(buff, true) + log.Debug(string(buff[:numBytes])) +} + +func (debugger *processDebugger) changeLog() { + errSetLogLevel := logger.SetLogLevel(debugger.debuggingLogLevel) + if errSetLogLevel != nil { + log.Error("debugger.changeLog: cannot change log level", "error", errSetLogLevel) + } +} + +// IsInterfaceNil returns true if there is no value under the interface +func (debugger *processDebugger) IsInterfaceNil() bool { + return debugger == nil +} diff --git a/debug/process/debugger_test.go b/debug/process/debugger_test.go new file mode 100644 index 00000000000..97d09811598 --- /dev/null +++ b/debug/process/debugger_test.go @@ -0,0 +1,223 @@ +package process + +import ( + "context" + "errors" + "strings" + "sync/atomic" + "testing" + "time" + + "github.com/ElrondNetwork/elrond-go-core/core/check" + "github.com/ElrondNetwork/elrond-go/config" + "github.com/stretchr/testify/assert" +) + +func createMockProcessDebugConfig() config.ProcessDebugConfig { + return config.ProcessDebugConfig{ + Enabled: true, + GoRoutinesDump: true, + DebuggingLogLevel: "*:INFO", + PollingTimeInSeconds: minAcceptedValue, + } +} + +func TestNewProcessDebugger(t *testing.T) { + t.Parallel() + + t.Run("invalid PollingTimeInSeconds", func(t *testing.T) { + t.Parallel() + + configs := createMockProcessDebugConfig() + configs.PollingTimeInSeconds = minAcceptedValue - 1 + + debuggerInstance, err := NewProcessDebugger(configs) + + assert.True(t, check.IfNil(debuggerInstance)) + assert.True(t, errors.Is(err, errInvalidValue)) + assert.True(t, strings.Contains(err.Error(), "PollingTimeInSeconds")) + }) + t.Run("should work", func(t *testing.T) { + t.Parallel() + + configs := createMockProcessDebugConfig() + debuggerInstance, err := NewProcessDebugger(configs) + + assert.False(t, check.IfNil(debuggerInstance)) + assert.Nil(t, err) + + _ = debuggerInstance.Close() + }) +} + +func TestDebugger_ProcessLoopAndClose(t *testing.T) { + t.Parallel() + + t.Run("node is starting, go routines dump active, should not trigger", func(t *testing.T) { + t.Parallel() + + configs := createMockProcessDebugConfig() + + numGoRoutinesDumpHandlerCalls := int32(0) + numLogChangeHandlerCalls := int32(0) + + debuggerInstance, _ := NewProcessDebugger(configs) + debuggerInstance.goRoutinesDumpHandler = func() { + atomic.AddInt32(&numGoRoutinesDumpHandlerCalls, 1) + } + debuggerInstance.logChangeHandler = func() { + atomic.AddInt32(&numLogChangeHandlerCalls, 1) + } + + time.Sleep(time.Second*3 + time.Millisecond*500) + + assert.Zero(t, atomic.LoadInt32(&numLogChangeHandlerCalls)) + assert.Zero(t, atomic.LoadInt32(&numGoRoutinesDumpHandlerCalls)) + + time.Sleep(time.Second * 3) + + assert.Zero(t, atomic.LoadInt32(&numLogChangeHandlerCalls)) + assert.Zero(t, atomic.LoadInt32(&numGoRoutinesDumpHandlerCalls)) + + err := debuggerInstance.Close() + assert.Nil(t, err) + + time.Sleep(time.Second * 3) + + assert.Zero(t, atomic.LoadInt32(&numLogChangeHandlerCalls)) + assert.Zero(t, atomic.LoadInt32(&numGoRoutinesDumpHandlerCalls)) + }) + t.Run("node is syncing, go routines dump active, should not trigger", func(t *testing.T) { + t.Parallel() + + configs := createMockProcessDebugConfig() + + numGoRoutinesDumpHandlerCalls := int32(0) + numLogChangeHandlerCalls := int32(0) + + debuggerInstance, _ := NewProcessDebugger(configs) + debuggerInstance.goRoutinesDumpHandler = func() { + atomic.AddInt32(&numGoRoutinesDumpHandlerCalls, 1) + } + debuggerInstance.logChangeHandler = func() { + atomic.AddInt32(&numLogChangeHandlerCalls, 1) + } + debuggerInstance.SetLastCommittedBlockRound(223) + + time.Sleep(time.Second*1 + time.Millisecond*500) + + assert.Zero(t, atomic.LoadInt32(&numLogChangeHandlerCalls)) + assert.Zero(t, atomic.LoadInt32(&numGoRoutinesDumpHandlerCalls)) + + err := debuggerInstance.Close() + assert.Nil(t, err) + + time.Sleep(time.Second * 3) + + assert.Zero(t, atomic.LoadInt32(&numLogChangeHandlerCalls)) + assert.Zero(t, atomic.LoadInt32(&numGoRoutinesDumpHandlerCalls)) + }) + t.Run("node is running, go routines dump active, should not trigger", func(t *testing.T) { + t.Parallel() + + configs := createMockProcessDebugConfig() + + numGoRoutinesDumpHandlerCalls := int32(0) + numLogChangeHandlerCalls := int32(0) + + debuggerInstance, _ := NewProcessDebugger(configs) + debuggerInstance.goRoutinesDumpHandler = func() { + atomic.AddInt32(&numGoRoutinesDumpHandlerCalls, 1) + } + debuggerInstance.logChangeHandler = func() { + atomic.AddInt32(&numLogChangeHandlerCalls, 1) + } + ctx, cancel := context.WithCancel(context.Background()) + defer cancel() + + go func() { + for i := uint64(0); ; i++ { + select { + case <-ctx.Done(): + return + case <-time.After(time.Millisecond * 100): + debuggerInstance.SetLastCommittedBlockRound(i) + } + } + }() + + time.Sleep(time.Second*3 + time.Millisecond*500) + + assert.Equal(t, int32(0), atomic.LoadInt32(&numLogChangeHandlerCalls)) + assert.Equal(t, int32(0), atomic.LoadInt32(&numGoRoutinesDumpHandlerCalls)) + + err := debuggerInstance.Close() + assert.Nil(t, err) + + time.Sleep(time.Second * 3) + + assert.Equal(t, int32(0), atomic.LoadInt32(&numLogChangeHandlerCalls)) + assert.Equal(t, int32(0), atomic.LoadInt32(&numGoRoutinesDumpHandlerCalls)) + }) + t.Run("node is stuck, go routines dump active, should trigger", func(t *testing.T) { + t.Parallel() + + configs := createMockProcessDebugConfig() + + numGoRoutinesDumpHandlerCalls := int32(0) + numLogChangeHandlerCalls := int32(0) + + debuggerInstance, _ := NewProcessDebugger(configs) + debuggerInstance.goRoutinesDumpHandler = func() { + atomic.AddInt32(&numGoRoutinesDumpHandlerCalls, 1) + } + debuggerInstance.logChangeHandler = func() { + atomic.AddInt32(&numLogChangeHandlerCalls, 1) + } + debuggerInstance.SetLastCommittedBlockRound(223) + + time.Sleep(time.Second*3 + time.Millisecond*500) + + assert.Equal(t, int32(2), atomic.LoadInt32(&numLogChangeHandlerCalls)) + assert.Equal(t, int32(2), atomic.LoadInt32(&numGoRoutinesDumpHandlerCalls)) + + err := debuggerInstance.Close() + assert.Nil(t, err) + + time.Sleep(time.Second * 3) + + assert.Equal(t, int32(2), atomic.LoadInt32(&numLogChangeHandlerCalls)) + assert.Equal(t, int32(2), atomic.LoadInt32(&numGoRoutinesDumpHandlerCalls)) + }) + t.Run("node is stuck, go routines dump inactive, should trigger", func(t *testing.T) { + t.Parallel() + + configs := createMockProcessDebugConfig() + configs.GoRoutinesDump = false + + numGoRoutinesDumpHandlerCalls := int32(0) + numLogChangeHandlerCalls := int32(0) + + debuggerInstance, _ := NewProcessDebugger(configs) + debuggerInstance.goRoutinesDumpHandler = func() { + atomic.AddInt32(&numGoRoutinesDumpHandlerCalls, 1) + } + debuggerInstance.logChangeHandler = func() { + atomic.AddInt32(&numLogChangeHandlerCalls, 1) + } + debuggerInstance.SetLastCommittedBlockRound(223) + + time.Sleep(time.Second*3 + time.Millisecond*500) + + assert.Equal(t, int32(2), atomic.LoadInt32(&numLogChangeHandlerCalls)) + assert.Equal(t, int32(0), atomic.LoadInt32(&numGoRoutinesDumpHandlerCalls)) + + err := debuggerInstance.Close() + assert.Nil(t, err) + + time.Sleep(time.Second * 3) + + assert.Equal(t, int32(2), atomic.LoadInt32(&numLogChangeHandlerCalls)) + assert.Equal(t, int32(0), atomic.LoadInt32(&numGoRoutinesDumpHandlerCalls)) + }) +} diff --git a/debug/process/disabledDebugger.go b/debug/process/disabledDebugger.go new file mode 100644 index 00000000000..980bb87c6f0 --- /dev/null +++ b/debug/process/disabledDebugger.go @@ -0,0 +1,23 @@ +package process + +type disabledDebugger struct { +} + +// NewDisabledDebugger creates a disabled process debugger instance +func NewDisabledDebugger() *disabledDebugger { + return &disabledDebugger{} +} + +// SetLastCommittedBlockRound does nothing +func (debugger *disabledDebugger) SetLastCommittedBlockRound(_ uint64) { +} + +// Close does nothing and returns nil +func (debugger *disabledDebugger) Close() error { + return nil +} + +// IsInterfaceNil returns true if there is no value under the interface +func (debugger *disabledDebugger) IsInterfaceNil() bool { + return debugger == nil +} diff --git a/debug/process/disabledDebugger_test.go b/debug/process/disabledDebugger_test.go new file mode 100644 index 00000000000..de4118e5c72 --- /dev/null +++ b/debug/process/disabledDebugger_test.go @@ -0,0 +1,35 @@ +package process + +import ( + "fmt" + "testing" + + "github.com/ElrondNetwork/elrond-go-core/core/check" + "github.com/stretchr/testify/assert" +) + +func TestNewDisabledDebugger(t *testing.T) { + t.Parallel() + + debugger := NewDisabledDebugger() + assert.False(t, check.IfNil(debugger)) +} + +func TestDisabledDebugger_MethodsShouldNotPanic(t *testing.T) { + t.Parallel() + + defer func() { + r := recover() + if r != nil { + assert.Fail(t, fmt.Sprintf("should have not failed %v", r)) + } + }() + + debugger := NewDisabledDebugger() + debugger.SetLastCommittedBlockRound(0) + debugger.SetLastCommittedBlockRound(1) + err := debugger.Close() + assert.Nil(t, err) + + debugger.SetLastCommittedBlockRound(1) +} diff --git a/debug/process/errors.go b/debug/process/errors.go new file mode 100644 index 00000000000..158541c3308 --- /dev/null +++ b/debug/process/errors.go @@ -0,0 +1,5 @@ +package process + +import "errors" + +var errInvalidValue = errors.New("invalid value") diff --git a/factory/blockProcessorCreator.go b/factory/blockProcessorCreator.go index d9fcfd9b7ca..6910f3c08d6 100644 --- a/factory/blockProcessorCreator.go +++ b/factory/blockProcessorCreator.go @@ -9,6 +9,7 @@ import ( "github.com/ElrondNetwork/elrond-go/common" "github.com/ElrondNetwork/elrond-go/config" "github.com/ElrondNetwork/elrond-go/dataRetriever" + debugFactory "github.com/ElrondNetwork/elrond-go/debug/factory" "github.com/ElrondNetwork/elrond-go/epochStart" "github.com/ElrondNetwork/elrond-go/epochStart/bootstrap/disabled" metachainEpochStart "github.com/ElrondNetwork/elrond-go/epochStart/metachain" @@ -412,6 +413,11 @@ func (pcf *processComponentsFactory) newShardBlockProcessor( return nil, errors.New("could not create block statisticsProcessor: " + err.Error()) } + err = pcf.attachProcessDebugger(blockProcessor, pcf.config.Debug.Process) + if err != nil { + return nil, err + } + blockProcessorComponents := &blockProcessorAndVmFactories{ blockProcessor: blockProcessor, vmFactoryForTxSimulate: vmFactoryTxSimulator, @@ -854,6 +860,11 @@ func (pcf *processComponentsFactory) newMetaBlockProcessor( return nil, errors.New("could not create block processor: " + err.Error()) } + err = pcf.attachProcessDebugger(metaProcessor, pcf.config.Debug.Process) + if err != nil { + return nil, err + } + blockProcessorComponents := &blockProcessorAndVmFactories{ blockProcessor: metaProcessor, vmFactoryForTxSimulate: vmFactoryTxSimulator, @@ -863,6 +874,18 @@ func (pcf *processComponentsFactory) newMetaBlockProcessor( return blockProcessorComponents, nil } +func (pcf *processComponentsFactory) attachProcessDebugger( + processor processDebuggerSetter, + configs config.ProcessDebugConfig, +) error { + processDebugger, err := debugFactory.CreateProcessDebugger(configs) + if err != nil { + return err + } + + return processor.SetProcessDebugger(processDebugger) +} + func (pcf *processComponentsFactory) createShardTxSimulatorProcessor( txSimulatorProcessorArgs *txsimulator.ArgsTxSimulator, scProcArgs smartContract.ArgsNewSmartContractProcessor, diff --git a/factory/interface.go b/factory/interface.go index 33a217a81c3..f049a15063d 100644 --- a/factory/interface.go +++ b/factory/interface.go @@ -505,3 +505,7 @@ type ReceiptsRepository interface { LoadReceipts(header data.HeaderHandler, headerHash []byte) (common.ReceiptsHolder, error) IsInterfaceNil() bool } + +type processDebuggerSetter interface { + SetProcessDebugger(debugger process.Debugger) error +} diff --git a/process/block/baseProcess.go b/process/block/baseProcess.go index 86dbda2944b..eb45496e6d5 100644 --- a/process/block/baseProcess.go +++ b/process/block/baseProcess.go @@ -7,6 +7,7 @@ import ( "fmt" "math/big" "sort" + "sync" "time" "github.com/ElrondNetwork/elrond-go-core/core" @@ -23,9 +24,11 @@ import ( "github.com/ElrondNetwork/elrond-go/common" "github.com/ElrondNetwork/elrond-go/common/holders" "github.com/ElrondNetwork/elrond-go/common/logging" + "github.com/ElrondNetwork/elrond-go/config" "github.com/ElrondNetwork/elrond-go/consensus" "github.com/ElrondNetwork/elrond-go/dataRetriever" "github.com/ElrondNetwork/elrond-go/dblookupext" + debugFactory "github.com/ElrondNetwork/elrond-go/debug/factory" "github.com/ElrondNetwork/elrond-go/errors" "github.com/ElrondNetwork/elrond-go/outport" "github.com/ElrondNetwork/elrond-go/process" @@ -78,6 +81,8 @@ type baseProcessor struct { blockChain data.ChainHandler hdrsForCurrBlock *hdrForBlock genesisNonce uint64 + mutProcessDebugger sync.RWMutex + processDebugger process.Debugger versionedHeaderFactory nodeFactory.VersionedHeaderFactory headerIntegrityVerifier process.HeaderIntegrityVerifier @@ -1808,15 +1813,17 @@ func unmarshalUserAccount(address []byte, userAccountsBytes []byte, marshalizer // Close - closes all underlying components func (bp *baseProcessor) Close() error { - var err1, err2 error + var err1, err2, err3 error if !check.IfNil(bp.vmContainer) { err1 = bp.vmContainer.Close() } if !check.IfNil(bp.vmContainerFactory) { err2 = bp.vmContainerFactory.Close() } - if err1 != nil || err2 != nil { - return fmt.Errorf("vmContainer close error: %v, vmContainerFactory close error: %v", err1, err2) + err3 = bp.processDebugger.Close() + if err1 != nil || err2 != nil || err3 != nil { + return fmt.Errorf("vmContainer close error: %v, vmContainerFactory close error: %v, processDebugger close: %v", + err1, err2, err3) } return nil @@ -1996,3 +2003,30 @@ func displayCleanupErrorMessage(message string, shardID uint32, noncesToPrevFina "nonces to previous final", noncesToPrevFinal, "error", err.Error()) } + +// SetProcessDebugger sets the process debugger associated to this block processor +func (bp *baseProcessor) SetProcessDebugger(debugger process.Debugger) error { + if check.IfNil(debugger) { + return process.ErrNilProcessDebugger + } + + bp.mutProcessDebugger.Lock() + bp.processDebugger = debugger + bp.mutProcessDebugger.Unlock() + + return nil +} + +func (bp *baseProcessor) updateLastCommittedInDebugger(round uint64) { + bp.mutProcessDebugger.RLock() + bp.processDebugger.SetLastCommittedBlockRound(round) + bp.mutProcessDebugger.RUnlock() +} + +func createDisabledProcessDebugger() (process.Debugger, error) { + configs := config.ProcessDebugConfig{ + Enabled: false, + } + + return debugFactory.CreateProcessDebugger(configs) +} diff --git a/process/block/metablock.go b/process/block/metablock.go index 73141649284..e06e9c6242b 100644 --- a/process/block/metablock.go +++ b/process/block/metablock.go @@ -95,6 +95,11 @@ func NewMetaProcessor(arguments ArgMetaProcessor) (*metaProcessor, error) { pruningDelay = defaultPruningDelay } + processDebugger, err := createDisabledProcessDebugger() + if err != nil { + return nil, err + } + genesisHdr := arguments.DataComponents.Blockchain().GetGenesisHeader() base := &baseProcessor{ accountsDB: arguments.AccountsDB, @@ -136,6 +141,7 @@ func NewMetaProcessor(arguments ArgMetaProcessor) (*metaProcessor, error) { pruningDelay: pruningDelay, processedMiniBlocksTracker: arguments.ProcessedMiniBlocksTracker, receiptsRepository: arguments.ReceiptsRepository, + processDebugger: processDebugger, } mp := metaProcessor{ @@ -1270,6 +1276,8 @@ func (mp *metaProcessor) CommitBlock( "nonce", headerHandler.GetNonce(), "hash", headerHash) + mp.updateLastCommittedInDebugger(headerHandler.GetRound()) + notarizedHeadersHashes, errNotCritical := mp.updateCrossShardInfo(header) if errNotCritical != nil { log.Debug("updateCrossShardInfo", "error", errNotCritical.Error()) diff --git a/process/block/metablock_test.go b/process/block/metablock_test.go index 2b683516ed7..1f8d2fbf4bf 100644 --- a/process/block/metablock_test.go +++ b/process/block/metablock_test.go @@ -1007,6 +1007,20 @@ func TestMetaProcessor_CommitBlockOkValsShouldWork(t *testing.T) { mp, _ := blproc.NewMetaProcessor(arguments) + debuggerMethodWasCalled := false + debugger := &testscommon.ProcessDebuggerStub{ + SetLastCommittedBlockRoundCalled: func(round uint64) { + assert.Equal(t, hdr.Round, round) + debuggerMethodWasCalled = true + }, + } + + err := mp.SetProcessDebugger(nil) + assert.Equal(t, process.ErrNilProcessDebugger, err) + + err = mp.SetProcessDebugger(debugger) + assert.Nil(t, err) + mdp.HeadersCalled = func() dataRetriever.HeadersPool { cs := &mock.HeadersCacherStub{} cs.RegisterHandlerCalled = func(i func(header data.HeaderHandler, key []byte)) { @@ -1027,9 +1041,10 @@ func TestMetaProcessor_CommitBlockOkValsShouldWork(t *testing.T) { } mp.SetHdrForCurrentBlock([]byte("hdr_hash1"), &block.Header{}, true) - err := mp.CommitBlock(hdr, body) + err = mp.CommitBlock(hdr, body) assert.Nil(t, err) assert.True(t, forkDetectorAddCalled) + assert.True(t, debuggerMethodWasCalled) // this should sleep as there is an async call to display current header and block in CommitBlock time.Sleep(time.Second) } diff --git a/process/block/shardblock.go b/process/block/shardblock.go index 0fd2ff3b69c..7418afd0267 100644 --- a/process/block/shardblock.go +++ b/process/block/shardblock.go @@ -82,6 +82,11 @@ func NewShardProcessor(arguments ArgShardProcessor) (*shardProcessor, error) { pruningDelay = defaultPruningDelay } + processDebugger, err := createDisabledProcessDebugger() + if err != nil { + return nil, err + } + base := &baseProcessor{ accountsDB: arguments.AccountsDB, blockSizeThrottler: arguments.BlockSizeThrottler, @@ -122,6 +127,7 @@ func NewShardProcessor(arguments ArgShardProcessor) (*shardProcessor, error) { pruningDelay: pruningDelay, processedMiniBlocksTracker: arguments.ProcessedMiniBlocksTracker, receiptsRepository: arguments.ReceiptsRepository, + processDebugger: processDebugger, } sp := shardProcessor{ @@ -1032,6 +1038,8 @@ func (sp *shardProcessor) CommitBlock( "hash", headerHash, ) + sp.updateLastCommittedInDebugger(headerHandler.GetRound()) + errNotCritical := sp.updateCrossShardInfo(processedMetaHdrs) if errNotCritical != nil { log.Debug("updateCrossShardInfo", "error", errNotCritical.Error()) diff --git a/process/block/shardblock_test.go b/process/block/shardblock_test.go index fbf32f16e71..ff4b379aa94 100644 --- a/process/block/shardblock_test.go +++ b/process/block/shardblock_test.go @@ -2105,13 +2105,27 @@ func TestShardProcessor_CommitBlockOkValsShouldWork(t *testing.T) { arguments.BlockTracker = blockTrackerMock sp, _ := blproc.NewShardProcessor(arguments) + debuggerMethodWasCalled := false + debugger := &testscommon.ProcessDebuggerStub{ + SetLastCommittedBlockRoundCalled: func(round uint64) { + assert.Equal(t, hdr.Round, round) + debuggerMethodWasCalled = true + }, + } - err := sp.ProcessBlock(hdr, body, haveTime) + err := sp.SetProcessDebugger(nil) + assert.Equal(t, process.ErrNilProcessDebugger, err) + + err = sp.SetProcessDebugger(debugger) + assert.Nil(t, err) + + err = sp.ProcessBlock(hdr, body, haveTime) assert.Nil(t, err) err = sp.CommitBlock(hdr, body) assert.Nil(t, err) assert.True(t, forkDetectorAddCalled) assert.Equal(t, hdrHash, blkc.GetCurrentBlockHeaderHash()) + assert.True(t, debuggerMethodWasCalled) // this should sleep as there is an async call to display current hdr and block in CommitBlock time.Sleep(time.Second) } diff --git a/process/errors.go b/process/errors.go index 69842defd1e..704a98a9fa5 100644 --- a/process/errors.go +++ b/process/errors.go @@ -1145,3 +1145,6 @@ var ErrPropertyTooLong = errors.New("property too long") // ErrPropertyTooShort signals that a heartbeat property was too short var ErrPropertyTooShort = errors.New("property too short") + +// ErrNilProcessDebugger signals that a nil process debugger was provided +var ErrNilProcessDebugger = errors.New("nil process debugger") diff --git a/process/interface.go b/process/interface.go index 4ae73a5f779..36705a02dcb 100644 --- a/process/interface.go +++ b/process/interface.go @@ -1242,3 +1242,10 @@ type PeerAuthenticationPayloadValidator interface { ValidateTimestamp(payloadTimestamp int64) error IsInterfaceNil() bool } + +// Debugger defines what a process debugger implementation should do +type Debugger interface { + SetLastCommittedBlockRound(round uint64) + Close() error + IsInterfaceNil() bool +} diff --git a/testscommon/processDebuggerStub.go b/testscommon/processDebuggerStub.go new file mode 100644 index 00000000000..b8e0d56d88d --- /dev/null +++ b/testscommon/processDebuggerStub.go @@ -0,0 +1,28 @@ +package testscommon + +// ProcessDebuggerStub - +type ProcessDebuggerStub struct { + SetLastCommittedBlockRoundCalled func(round uint64) + CloseCalled func() error +} + +// SetLastCommittedBlockRound - +func (stub *ProcessDebuggerStub) SetLastCommittedBlockRound(round uint64) { + if stub.SetLastCommittedBlockRoundCalled != nil { + stub.SetLastCommittedBlockRoundCalled(round) + } +} + +// Close - +func (stub *ProcessDebuggerStub) Close() error { + if stub.CloseCalled != nil { + return stub.CloseCalled() + } + + return nil +} + +// IsInterfaceNil - +func (stub *ProcessDebuggerStub) IsInterfaceNil() bool { + return stub == nil +}