Add more logs, In TestPickVirtualParents, only print relevant logs.

domain/consensus/processes/consensusstatemanager/calculate_past_utxo.go

@@ -118,8 +118,10 @@ func (csm *consensusStateManager) applyMergeSetBlocks(blockHash *externalapi.Dom
 	selectedParentPastUTXODiff model.MutableUTXODiff, ghostdagData *model.BlockGHOSTDAGData) (
 	externalapi.AcceptanceData, model.MutableUTXODiff, error) {
 
+	onEnd := logger.LogAndMeasureExecutionTime(log, "applyMergeSetBlocks")
+	defer onEnd()
+
 	log.Debugf("applyMergeSetBlocks start for block %s", blockHash)
-	defer log.Tracef("applyMergeSetBlocks end for block %s", blockHash)
 
 	mergeSetHashes := ghostdagData.MergeSet()
 	log.Debugf("Merge set for block %s is %v", blockHash, mergeSetHashes)

domain/consensus/processes/consensusstatemanager/pick_virtual_parents_test.go

@@ -15,8 +15,6 @@ func TestPickVirtualParents(t *testing.T) {
 	params := dagconfig.DevnetParams
 	params.SkipProofOfWork = true
 
-	logger.SetLogLevels("debug")
-
 	factory := consensus.NewFactory()
 	testConsensus, teardown, err := factory.NewTestConsensus(&params, false, "TestPickVirtualParents")
 	if err != nil {
@@ -24,6 +22,8 @@ func TestPickVirtualParents(t *testing.T) {
 	}
 	defer teardown(false)
 
+	found := false
+
 	// Build three chains over the genesis
 	for chainIndex := 0; chainIndex < 3; chainIndex++ {
 		const chainSize = 1000
@@ -31,22 +31,35 @@ func TestPickVirtualParents(t *testing.T) {
 
 		tipHash := params.GenesisHash
 		for blockIndex := 0; blockIndex < chainSize; blockIndex++ {
-			fmt.Printf("\n\n\nBUILD BLOCK WITH PARENTS\n\n\n")
+			if found {
+				fmt.Printf("\n\n\nBUILD BLOCK WITH PARENTS\n\n\n")
+			}
 			block, _, err := testConsensus.BuildBlockWithParents([]*externalapi.DomainHash{tipHash}, nil, nil)
 			if err != nil {
 				t.Fatalf("Could not build block: %s", err)
 			}
 			blockHash := consensushashing.BlockHash(block)
 			start := time.Now()
-			fmt.Printf("\n\n\nVALIDATE AND INSERT BLOCK\n\n\n")
+			if found {
+				fmt.Printf("\n\n\nVALIDATE AND INSERT BLOCK\n\n\n")
+			}
 			_, err = testConsensus.ValidateAndInsertBlock(block)
 			if err != nil {
 				t.Fatalf("Failed to validate block %s: %s", blockHash, err)
 			}
 			validationTime := time.Since(start)
+
 			accumulatedValidationTime += validationTime
 			fmt.Printf("Validated block #%d in chain #%d, took %s\n", blockIndex, chainIndex, validationTime)
 			tipHash = blockHash
+
+			if found {
+				t.Fatalf("DONE")
+			}
+			if validationTime > 100*time.Millisecond {
+				found = true
+				logger.SetLogLevels("debug")
+			}
 		}
 
 		averageValidationTime := accumulatedValidationTime / 1000

domain/consensus/processes/ghostdagmanager/ghostdag.go

@@ -3,6 +3,7 @@ package ghostdagmanager
 import (
 	"github.com/kaspanet/kaspad/domain/consensus/model"
 	"github.com/kaspanet/kaspad/domain/consensus/model/externalapi"
+	"github.com/kaspanet/kaspad/infrastructure/logger"
 	"github.com/kaspanet/kaspad/util/difficulty"
 	"github.com/pkg/errors"
 	"math/big"
@@ -40,6 +41,9 @@ func (bg *blockGHOSTDAGData) toModel() *model.BlockGHOSTDAGData {
 //
 // For further details see the article https://eprint.iacr.org/2018/104.pdf
 func (gm *ghostdagManager) GHOSTDAG(blockHash *externalapi.DomainHash) error {
+	onEnd := logger.LogAndMeasureExecutionTime(log, "GHOSTDAG")
+	defer onEnd()
+
 	newBlockData := &blockGHOSTDAGData{
 		blueWork:           new(big.Int),
 		mergeSetBlues:      make([]*externalapi.DomainHash, 0),

domain/consensus/processes/ghostdagmanager/log.go

@@ -0,0 +1,7 @@
+package ghostdagmanager
+
+import (
+	"github.com/kaspanet/kaspad/infrastructure/logger"
+)
+
+var log, _ = logger.Get(logger.SubsystemTags.BDAG)