Add logs to help debug long virtual parent selection. (#1470)

Co-authored-by: Ori Newman <orinewman1@gmail.com>
This commit is contained in:
stasatdaglabs 2021-02-01 19:15:50 +02:00 committed by GitHub
parent aeb8e9d2cd
commit 97be133cee
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
3 changed files with 30 additions and 9 deletions

View File

@ -4,6 +4,7 @@ import (
"github.com/kaspanet/kaspad/domain/consensus/utils/consensushashing"
"github.com/kaspanet/kaspad/domain/consensus/utils/multiset"
"github.com/kaspanet/kaspad/domain/consensus/utils/utxo"
"github.com/kaspanet/kaspad/infrastructure/logger"
"github.com/pkg/errors"
"github.com/kaspanet/kaspad/domain/consensus/model"
@ -15,8 +16,10 @@ import (
func (csm *consensusStateManager) CalculatePastUTXOAndAcceptanceData(blockHash *externalapi.DomainHash) (
model.UTXODiff, externalapi.AcceptanceData, model.Multiset, error) {
onEnd := logger.LogAndMeasureExecutionTime(log, "CalculatePastUTXOAndAcceptanceData")
defer onEnd()
log.Debugf("CalculatePastUTXOAndAcceptanceData start for block %s", blockHash)
defer log.Debugf("CalculatePastUTXOAndAcceptanceData end for block %s", blockHash)
if blockHash.Equal(csm.genesisHash) {
log.Debugf("Block %s is the genesis. By definition, "+
@ -35,6 +38,9 @@ func (csm *consensusStateManager) CalculatePastUTXOAndAcceptanceData(blockHash *
if err != nil {
return nil, nil, nil, err
}
log.Debugf("Restored the past UTXO of block %s with selectedParent %s. "+
"Diff toAdd length: %d, toRemove length: %d", blockHash, blockGHOSTDAGData.SelectedParent(),
selectedParentPastUTXO.ToAdd().Len(), selectedParentPastUTXO.ToRemove().Len())
log.Debugf("Applying blue blocks to the selected parent past UTXO of block %s", blockHash)
acceptanceData, utxoDiff, err := csm.applyMergeSetBlocks(blockHash, selectedParentPastUTXO, blockGHOSTDAGData)
@ -53,8 +59,10 @@ func (csm *consensusStateManager) CalculatePastUTXOAndAcceptanceData(blockHash *
}
func (csm *consensusStateManager) restorePastUTXO(blockHash *externalapi.DomainHash) (model.MutableUTXODiff, error) {
onEnd := logger.LogAndMeasureExecutionTime(log, "restorePastUTXO")
defer onEnd()
log.Debugf("restorePastUTXO start for block %s", blockHash)
defer log.Debugf("restorePastUTXO end for block %s", blockHash)
var err error

View File

@ -1,6 +1,7 @@
package consensusstatemanager
import (
"github.com/kaspanet/kaspad/infrastructure/logger"
"github.com/pkg/errors"
"github.com/kaspanet/kaspad/domain/consensus/model"
@ -9,8 +10,10 @@ import (
)
func (csm *consensusStateManager) pickVirtualParents(tips []*externalapi.DomainHash) ([]*externalapi.DomainHash, error) {
onEnd := logger.LogAndMeasureExecutionTime(log, "pickVirtualParents")
defer onEnd()
log.Debugf("pickVirtualParents start for tips len: %d", len(tips))
defer log.Debugf("pickVirtualParents end for tips len: %d", len(tips))
log.Debugf("Pushing all tips into a DownHeap")
candidatesHeap := csm.dagTraversalManager.NewDownHeap()
@ -84,8 +87,8 @@ func (csm *consensusStateManager) pickVirtualParents(tips []*externalapi.DomainH
func (csm *consensusStateManager) selectVirtualSelectedParent(
candidatesHeap model.BlockHeap) (*externalapi.DomainHash, error) {
log.Tracef("selectVirtualSelectedParent start")
defer log.Tracef("selectVirtualSelectedParent end")
onEnd := logger.LogAndMeasureExecutionTime(log, "selectVirtualSelectedParent")
defer onEnd()
disqualifiedCandidates := hashset.New()
@ -153,8 +156,8 @@ func (csm *consensusStateManager) selectVirtualSelectedParent(
func (csm *consensusStateManager) mergeSetIncrease(
candidate *externalapi.DomainHash, selectedVirtualParents hashset.HashSet) (uint64, error) {
log.Tracef("mergeSetIncrease start")
defer log.Tracef("mergeSetIncrease end")
onEnd := logger.LogAndMeasureExecutionTime(log, "mergeSetIncrease")
defer onEnd()
visited := hashset.New()
queue := csm.dagTraversalManager.NewDownHeap()
@ -204,8 +207,10 @@ func (csm *consensusStateManager) mergeSetIncrease(
func (csm *consensusStateManager) boundedMergeBreakingParents(
parents []*externalapi.DomainHash) (hashset.HashSet, error) {
onEnd := logger.LogAndMeasureExecutionTime(log, "boundedMergeBreakingParents")
defer onEnd()
log.Tracef("boundedMergeBreakingParents start for parents: %s", parents)
defer log.Tracef("boundedMergeBreakingParents end for parents: %s", parents)
log.Debug("Temporarily setting virtual to all parents, so that we can run ghostdag on it")
err := csm.dagTopologyManager.SetParents(model.VirtualBlockHash, parents)

View File

@ -3,13 +3,16 @@ package consensusstatemanager
import (
"github.com/kaspanet/kaspad/domain/consensus/model"
"github.com/kaspanet/kaspad/domain/consensus/model/externalapi"
"github.com/kaspanet/kaspad/infrastructure/logger"
)
func (csm *consensusStateManager) updateVirtual(newBlockHash *externalapi.DomainHash,
tips []*externalapi.DomainHash) (*externalapi.SelectedChainPath, error) {
onEnd := logger.LogAndMeasureExecutionTime(log, "updateVirtual")
defer onEnd()
log.Debugf("updateVirtual start for block %s", newBlockHash)
defer log.Debugf("updateVirtual end for block %s", newBlockHash)
log.Debugf("Saving a reference to the GHOSTDAG data of the old virtual")
var oldVirtualSelectedParent *externalapi.DomainHash
@ -44,6 +47,9 @@ func (csm *consensusStateManager) updateVirtual(newBlockHash *externalapi.Domain
if err != nil {
return nil, err
}
log.Debugf("Calculated the past UTXO of the new virtual. "+
"Diff toAdd length: %d, toRemove length: %d",
virtualUTXODiff.ToAdd().Len(), virtualUTXODiff.ToRemove().Len())
log.Debugf("Staging new acceptance data for the virtual block")
csm.acceptanceDataStore.Stage(model.VirtualBlockHash, virtualAcceptanceData)
@ -73,6 +79,8 @@ func (csm *consensusStateManager) updateVirtual(newBlockHash *externalapi.Domain
if err != nil {
return nil, err
}
log.Debugf("Selected parent chain changes: %d blocks were removed and %d blocks were added",
len(selectedParentChainChanges.Removed), len(selectedParentChainChanges.Added))
}
return selectedParentChainChanges, nil