Merge pull request #6770 from multiversx/trie-refactor-logging

add logging for trie goroutines and batch

common/interface.go

@@ -42,7 +42,7 @@ type Trie interface {
 	Delete(key []byte)
 	RootHash() ([]byte, error)
 	Commit(collector TrieHashesCollector) error
-	Recreate(options RootHashHolder) (Trie, error)
+	Recreate(options RootHashHolder, identifier string) (Trie, error)
 	GetSerializedNodes([]byte, uint64) ([][]byte, uint64, error)
 	GetSerializedNode([]byte) ([]byte, error)
 	GetAllLeavesOnChannel(allLeavesChan *TrieIteratorChannels, ctx context.Context, rootHash []byte, keyBuilder KeyBuilder, trieLeafParser TrieLeafParser) error

genesis/process/memoryComponents.go

@@ -11,7 +11,10 @@ import (
 	"github.com/multiversx/mx-chain-go/trie"
 )
 
-const maxTrieLevelInMemory = uint(5)
+const (
+	maxTrieLevelInMemory = uint(5)
+	trieIdentifier       = "main trie in memory"
+)
 
 func createAccountAdapter(
 	marshaller marshal.Marshalizer,
@@ -29,6 +32,7 @@ func createAccountAdapter(
 			EnableEpochsHandler:  enableEpochsHandler,
 			MaxTrieLevelInMemory: maxTrieLevelInMemory,
 			Throttler:            trie.NewDisabledTrieGoRoutinesThrottler(),
+			Identifier:           trieIdentifier,
 		})
 	if err != nil {
 		return nil, err

integrationTests/benchmarks/loadFromTrie_test.go

@@ -70,7 +70,7 @@ func testTrieLoadTime(t *testing.T, numChildrenPerBranch int, numTries int, maxT
 func timeTrieRecreate(tries []*keyForTrie, depth int) {
 	startTime := time.Now()
 	for j := range tries {
-		_, _ = tries[j].tr.Recreate(holders.NewDefaultRootHashesHolder(tries[j].key))
+		_, _ = tries[j].tr.Recreate(holders.NewDefaultRootHashesHolder(tries[j].key), "")
 	}
 	duration := time.Since(startTime)
 	fmt.Printf("trie with depth %d, duration %d \n", depth, duration.Nanoseconds()/int64(len(tries)))
@@ -117,7 +117,7 @@ func generateTriesWithMaxDepth(
 		key := insertKeysIntoTrie(t, tr, numTrieLevels, numChildrenPerBranch)
 
 		rootHash, _ := tr.RootHash()
-		collapsedTrie, _ := tr.Recreate(holders.NewDefaultRootHashesHolder(rootHash))
+		collapsedTrie, _ := tr.Recreate(holders.NewDefaultRootHashesHolder(rootHash), "")
 
 		if numTrieLevels == 1 {
 			key = rootHash

integrationTests/state/stateTrie/stateTrie_test.go

@@ -283,7 +283,7 @@ func TestTrieDB_RecreateFromStorageShouldWork(t *testing.T) {
 	err := tr1.Commit(hashesCollector.NewDisabledHashesCollector())
 	require.Nil(t, err)
 
-	tr2, err := tr1.Recreate(holders.NewDefaultRootHashesHolder(h1))
+	tr2, err := tr1.Recreate(holders.NewDefaultRootHashesHolder(h1), "")
 	require.Nil(t, err)
 
 	valRecov, _, err := tr2.Get(key)
@@ -1290,7 +1290,7 @@ func TestTrieDbPruning_GetDataTrieTrackerAfterPruning(t *testing.T) {
 func collapseTrie(state state.UserAccountHandler, t *testing.T) {
 	stateRootHash := state.GetRootHash()
 	stateTrie := state.DataTrie().(common.Trie)
-	stateNewTrie, _ := stateTrie.Recreate(holders.NewDefaultRootHashesHolder(stateRootHash))
+	stateNewTrie, _ := stateTrie.Recreate(holders.NewDefaultRootHashesHolder(stateRootHash), "")
 	require.NotNil(t, stateNewTrie)
 
 	state.SetDataTrie(stateNewTrie)
@@ -1692,12 +1692,12 @@ func checkTrieCanBeRecreated(tb testing.TB, node *integrationTests.TestProcessor
 
 	stateTrie := node.TrieContainer.Get([]byte(dataRetriever.UserAccountsUnit.String()))
 	roothash := node.BlockChain.GetCurrentBlockRootHash()
-	tr, err := stateTrie.Recreate(holders.NewDefaultRootHashesHolder(roothash))
+	tr, err := stateTrie.Recreate(holders.NewDefaultRootHashesHolder(roothash), "")
 	require.Nil(tb, err)
 	require.NotNil(tb, tr)
 
 	_, _, finalRoothash := node.BlockChain.GetFinalBlockInfo()
-	tr, err = stateTrie.Recreate(holders.NewDefaultRootHashesHolder(finalRoothash))
+	tr, err = stateTrie.Recreate(holders.NewDefaultRootHashesHolder(finalRoothash), "")
 	require.Nil(tb, err)
 	require.NotNil(tb, tr)
 
@@ -1709,7 +1709,7 @@ func checkTrieCanBeRecreated(tb testing.TB, node *integrationTests.TestProcessor
 	err = integrationTests.TestMarshalizer.Unmarshal(hdr, hdrBytes)
 	require.Nil(tb, err)
 
-	tr, err = stateTrie.Recreate(holders.NewDefaultRootHashesHolder(hdr.GetRootHash()))
+	tr, err = stateTrie.Recreate(holders.NewDefaultRootHashesHolder(hdr.GetRootHash()), "")
 	require.Nil(tb, err)
 	require.NotNil(tb, tr)
 }
@@ -1860,15 +1860,15 @@ func testNodeStateSnapshotAndPruning(
 	stateTrie := node.TrieContainer.Get([]byte(dataRetriever.UserAccountsUnit.String()))
 	assert.Equal(t, 1, len(snapshotsRootHashes))
 	for i := range snapshotsRootHashes {
-		tr, err := stateTrie.Recreate(holders.NewDefaultRootHashesHolder(snapshotsRootHashes[i]))
+		tr, err := stateTrie.Recreate(holders.NewDefaultRootHashesHolder(snapshotsRootHashes[i]), "")
 		require.Nil(t, err)
 		require.NotNil(t, tr)
 	}
 
 	assert.Equal(t, 1, len(prunedRootHashes))
 	// if pruning is called for a root hash in a different epoch than the commit, then recreate trie should work
 	for i := 0; i < len(prunedRootHashes)-1; i++ {
-		tr, err := stateTrie.Recreate(holders.NewDefaultRootHashesHolder(prunedRootHashes[i]))
+		tr, err := stateTrie.Recreate(holders.NewDefaultRootHashesHolder(prunedRootHashes[i]), "")
 		require.Nil(t, tr)
 		require.NotNil(t, err)
 	}

integrationTests/state/stateTrieSync/stateTrieSync_test.go

@@ -141,7 +141,7 @@ func testNodeRequestInterceptTrieNodesWithMessenger(t *testing.T, version int) {
 	assert.Nil(t, err)
 	cancel()
 
-	requesterTrie, err = requesterTrie.Recreate(holders.NewDefaultRootHashesHolder(rootHash))
+	requesterTrie, err = requesterTrie.Recreate(holders.NewDefaultRootHashesHolder(rootHash), "")
 	require.Nil(t, err)
 
 	newRootHash, _ := requesterTrie.RootHash()
@@ -563,7 +563,7 @@ func copyPartialState(t *testing.T, sourceNode, destinationNode *integrationTest
 func getDataTriesHashes(t *testing.T, tr common.Trie, dataTriesRootHashes [][]byte) [][]byte {
 	hashes := make([][]byte, 0)
 	for _, rh := range dataTriesRootHashes {
-		dt, err := tr.Recreate(holders.NewDefaultRootHashesHolder(rh))
+		dt, err := tr.Recreate(holders.NewDefaultRootHashesHolder(rh), "")
 		assert.Nil(t, err)
 
 		dtHashes := GetAllHashes(t, dt, rh)

state/accountsDB.go

@@ -437,7 +437,7 @@ func (adb *AccountsDB) loadDataTrieConcurrentSafe(accountHandler baseAccountHand
 	}
 
 	rootHashHolder := holders.NewDefaultRootHashesHolder(accountHandler.GetRootHash())
-	dataTrie, err := mainTrie.Recreate(rootHashHolder)
+	dataTrie, err := mainTrie.Recreate(rootHashHolder, hex.EncodeToString(accountHandler.AddressBytes()))
 	if err != nil {
 		return fmt.Errorf("trie was not found for hash, rootHash = %s, err = %w", hex.EncodeToString(accountHandler.GetRootHash()), err)
 	}
@@ -878,7 +878,7 @@ func (adb *AccountsDB) recreateTrie(options common.RootHashHolder) error {
 
 	adb.dataTries.Reset()
 	adb.entries = make([]JournalEntry, 0)
-	newTrie, err := adb.mainTrie.Recreate(options)
+	newTrie, err := adb.mainTrie.Recreate(options, string(common.MainTrie))
 	if err != nil {
 		return err
 	}
@@ -925,7 +925,7 @@ func (adb *AccountsDB) RecreateAllTries(rootHash []byte) (map[string]common.Trie
 		userAccountRootHash := userAccount.GetRootHash()
 		if len(userAccountRootHash) > 0 {
 			rootHashHolder := holders.NewDefaultRootHashesHolder(userAccountRootHash)
-			dataTrie, errRecreate := mainTrie.Recreate(rootHashHolder)
+			dataTrie, errRecreate := mainTrie.Recreate(rootHashHolder, "")
 			if errRecreate != nil {
 				return nil, errRecreate
 			}
@@ -964,7 +964,7 @@ func getUserAccountFromBytes(accountFactory AccountFactory, marshaller marshal.M
 
 func (adb *AccountsDB) recreateMainTrie(rootHash []byte) (map[string]common.Trie, error) {
 	rootHashHolder := holders.NewDefaultRootHashesHolder(rootHash)
-	recreatedTrie, err := adb.getMainTrie().Recreate(rootHashHolder)
+	recreatedTrie, err := adb.getMainTrie().Recreate(rootHashHolder, string(common.MainTrie))
 	if err != nil {
 		return nil, err
 	}
@@ -978,7 +978,7 @@ func (adb *AccountsDB) recreateMainTrie(rootHash []byte) (map[string]common.Trie
 // GetTrie returns the trie that has the given rootHash
 func (adb *AccountsDB) GetTrie(rootHash []byte) (common.Trie, error) {
 	rootHashHolder := holders.NewDefaultRootHashesHolder(rootHash)
-	return adb.getMainTrie().Recreate(rootHashHolder)
+	return adb.getMainTrie().Recreate(rootHashHolder, "")
 }
 
 // Journalize adds a new object to entries list.

state/accountsDB_test.go

@@ -543,7 +543,7 @@ func TestAccountsDB_LoadAccountExistingShouldLoadDataTrie(t *testing.T) {
 			}
 			return nil, 0, nil
 		},
-		RecreateCalled: func(holder common.RootHashHolder) (d common.Trie, err error) {
+		RecreateCalled: func(holder common.RootHashHolder, _ string) (d common.Trie, err error) {
 			return dataTrie, nil
 		},
 		GetStorageManagerCalled: func() common.StorageManager {
@@ -621,7 +621,7 @@ func TestAccountsDB_GetExistingAccountFoundShouldRetAccount(t *testing.T) {
 			}
 			return nil, 0, nil
 		},
-		RecreateCalled: func(root common.RootHashHolder) (d common.Trie, err error) {
+		RecreateCalled: func(root common.RootHashHolder, _ string) (d common.Trie, err error) {
 			return dataTrie, nil
 		},
 		GetStorageManagerCalled: func() common.StorageManager {
@@ -844,7 +844,7 @@ func TestAccountsDB_LoadDataWithSomeValuesShouldWork(t *testing.T) {
 
 	account := generateAccount()
 	mockTrie := &trieMock.TrieStub{
-		RecreateCalled: func(root common.RootHashHolder) (trie common.Trie, e error) {
+		RecreateCalled: func(root common.RootHashHolder, _ string) (trie common.Trie, e error) {
 			if !bytes.Equal(root.GetRootHash(), rootHash) {
 				return nil, errors.New("bad root hash")
 			}
@@ -889,7 +889,7 @@ func TestAccountsDB_CommitShouldCallCommitFromTrie(t *testing.T) {
 		GetCalled: func(_ []byte) ([]byte, uint32, error) {
 			return serializedAccount, 0, nil
 		},
-		RecreateCalled: func(root common.RootHashHolder) (trie common.Trie, err error) {
+		RecreateCalled: func(root common.RootHashHolder, _ string) (trie common.Trie, err error) {
 			return &trieMock.TrieStub{
 				GetCalled: func(_ []byte) ([]byte, uint32, error) {
 					return []byte("doge"), 0, nil
@@ -937,7 +937,7 @@ func TestAccountsDB_RecreateTrieMalfunctionTrieShouldErr(t *testing.T) {
 			return &storageManager.StorageManagerStub{}
 		},
 	}
-	trieStub.RecreateCalled = func(_ common.RootHashHolder) (tree common.Trie, e error) {
+	trieStub.RecreateCalled = func(_ common.RootHashHolder, _ string) (tree common.Trie, e error) {
 		wasCalled = true
 		return nil, errExpected
 	}
@@ -959,7 +959,7 @@ func TestAccountsDB_RecreateTrieOutputsNilTrieShouldErr(t *testing.T) {
 			return &storageManager.StorageManagerStub{}
 		},
 	}
-	trieStub.RecreateCalled = func(_ common.RootHashHolder) (tree common.Trie, e error) {
+	trieStub.RecreateCalled = func(_ common.RootHashHolder, _ string) (tree common.Trie, e error) {
 		wasCalled = true
 		return nil, nil
 	}
@@ -981,7 +981,7 @@ func TestAccountsDB_RecreateTrieOkValsShouldWork(t *testing.T) {
 		GetStorageManagerCalled: func() common.StorageManager {
 			return &storageManager.StorageManagerStub{}
 		},
-		RecreateCalled: func(_ common.RootHashHolder) (common.Trie, error) {
+		RecreateCalled: func(_ common.RootHashHolder, _ string) (common.Trie, error) {
 			wasCalled = true
 			return &trieMock.TrieStub{}, nil
 		},
@@ -1890,7 +1890,7 @@ func TestAccountsDB_PruningAndPruningCancellingOnTrieRollback(t *testing.T) {
 	}
 
 	for i := 0; i < len(rootHashes); i++ {
-		_, err := tr.Recreate(holders.NewDefaultRootHashesHolder(rootHashes[i]))
+		_, err := tr.Recreate(holders.NewDefaultRootHashesHolder(rootHashes[i]), "")
 		assert.Nil(t, err)
 	}
 
@@ -1899,7 +1899,7 @@ func TestAccountsDB_PruningAndPruningCancellingOnTrieRollback(t *testing.T) {
 	finalizeTrieState(t, 2, tr, adb, rootHashes)
 	rollbackTrieState(t, 3, tr, adb, rootHashes)
 
-	_, err := tr.Recreate(holders.NewDefaultRootHashesHolder(rootHashes[2]))
+	_, err := tr.Recreate(holders.NewDefaultRootHashesHolder(rootHashes[2]), "")
 	assert.Nil(t, err)
 }
 
@@ -1908,7 +1908,7 @@ func finalizeTrieState(t *testing.T, index int, tr common.Trie, adb state.Accoun
 	adb.CancelPrune(rootHashes[index], state.NewRoot)
 	time.Sleep(trieDbOperationDelay)
 
-	_, err := tr.Recreate(holders.NewDefaultRootHashesHolder(rootHashes[index-1]))
+	_, err := tr.Recreate(holders.NewDefaultRootHashesHolder(rootHashes[index-1]), "")
 	assert.NotNil(t, err)
 }
 
@@ -1917,7 +1917,7 @@ func rollbackTrieState(t *testing.T, index int, tr common.Trie, adb state.Accoun
 	adb.CancelPrune(rootHashes[index-1], state.OldRoot)
 	time.Sleep(trieDbOperationDelay)
 
-	_, err := tr.Recreate(holders.NewDefaultRootHashesHolder(rootHashes[index]))
+	_, err := tr.Recreate(holders.NewDefaultRootHashesHolder(rootHashes[index]), "")
 	assert.NotNil(t, err)
 }
 
@@ -2063,7 +2063,7 @@ func TestAccountsDB_RecreateAllTries(t *testing.T) {
 
 				return nil
 			},
-			RecreateCalled: func(root common.RootHashHolder) (common.Trie, error) {
+			RecreateCalled: func(root common.RootHashHolder, _ string) (common.Trie, error) {
 				return &trieMock.TrieStub{}, nil
 			},
 			GetStorageManagerCalled: func() common.StorageManager {
@@ -2094,7 +2094,7 @@ func TestAccountsDB_RecreateAllTries(t *testing.T) {
 
 				return nil
 			},
-			RecreateCalled: func(root common.RootHashHolder) (common.Trie, error) {
+			RecreateCalled: func(root common.RootHashHolder, _ string) (common.Trie, error) {
 				return &trieMock.TrieStub{}, nil
 			},
 			GetStorageManagerCalled: func() common.StorageManager {
@@ -2266,7 +2266,7 @@ func TestAccountsDB_GetAccountFromBytes(t *testing.T) {
 			},
 		}
 		args.Trie = &trieMock.TrieStub{
-			RecreateCalled: func(root common.RootHashHolder) (common.Trie, error) {
+			RecreateCalled: func(root common.RootHashHolder, _ string) (common.Trie, error) {
 				assert.Equal(t, rootHash, root.GetRootHash())
 				return &trieMock.TrieStub{}, nil
 			},
@@ -2299,7 +2299,7 @@ func TestAccountsDB_GetAccountFromBytesShouldLoadDataTrie(t *testing.T) {
 			}
 			return nil, 0, nil
 		},
-		RecreateCalled: func(root common.RootHashHolder) (d common.Trie, err error) {
+		RecreateCalled: func(root common.RootHashHolder, _ string) (d common.Trie, err error) {
 			return dataTrie, nil
 		},
 		GetStorageManagerCalled: func() common.StorageManager {

state/peerAccountsDB_test.go

@@ -163,7 +163,7 @@ func TestNewPeerAccountsDB_RecreateAllTries(t *testing.T) {
 		GetStorageManagerCalled: func() common.StorageManager {
 			return &storageManager.StorageManagerStub{}
 		},
-		RecreateCalled: func(_ common.RootHashHolder) (common.Trie, error) {
+		RecreateCalled: func(_ common.RootHashHolder, _ string) (common.Trie, error) {
 			recreateCalled = true
 			return nil, nil
 		},

state/storagePruningManager/storagePruningManager_test.go

@@ -2,7 +2,7 @@ package storagePruningManager
 
 import (
 	"testing"
-	
+
 	"github.com/multiversx/mx-chain-core-go/core/throttler"
 	"github.com/multiversx/mx-chain-go/common"
 	"github.com/multiversx/mx-chain-go/common/holders"
@@ -234,7 +234,7 @@ func TestAccountsDB_PruneAfterCancelPruneShouldFail(t *testing.T) {
 	spm.CancelPrune(rootHash, state.OldRoot, trieStorage)
 	spm.PruneTrie(rootHash, state.OldRoot, trieStorage, state.NewPruningHandler(state.EnableDataRemoval))
 
-	newTr, err := tr.Recreate(holders.NewDefaultRootHashesHolder(rootHash))
+	newTr, err := tr.Recreate(holders.NewDefaultRootHashesHolder(rootHash), "")
 	assert.Nil(t, err)
 	assert.NotNil(t, newTr)
 }

state/syncer/baseAccountsSyncer.go

@@ -18,6 +18,8 @@ import (
 	"github.com/multiversx/mx-chain-go/trie"
 )
 
+const syncTrieIdentifier = "base sync main trie"
+
 type baseAccountsSyncer struct {
 	hasher                            hashing.Hasher
 	marshalizer                       marshal.Marshalizer
@@ -224,6 +226,7 @@ func (b *baseAccountsSyncer) GetSyncedTries() map[string]common.Trie {
 		EnableEpochsHandler:  b.enableEpochsHandler,
 		MaxTrieLevelInMemory: b.maxTrieLevelInMemory,
 		Throttler:            trie.NewDisabledTrieGoRoutinesThrottler(),
+		Identifier:           syncTrieIdentifier,
 	}
 	dataTrie, err := trie.NewTrie(trieArgs)
 	if err != nil {
@@ -235,7 +238,7 @@ func (b *baseAccountsSyncer) GetSyncedTries() map[string]common.Trie {
 	clonedMap := make(map[string]common.Trie, len(b.dataTries))
 	for key := range b.dataTries {
 		rootHashHolder := holders.NewDefaultRootHashesHolder([]byte(key))
-		recreatedTrie, err = dataTrie.Recreate(rootHashHolder)
+		recreatedTrie, err = dataTrie.Recreate(rootHashHolder, "base sync data trie")
 		if err != nil {
 			log.Warn("error recreating trie in baseAccountsSyncer.GetSyncedTries",
 				"roothash", []byte(key), "error", err)

state/trackableDataTrie/trackableDataTrie.go

@@ -1,6 +1,7 @@
 package trackableDataTrie
 
 import (
+	"encoding/hex"
 	"fmt"
 
 	"github.com/multiversx/mx-chain-core-go/core"
@@ -216,7 +217,7 @@ func (tdt *trackableDataTrie) SaveDirtyData(mainTrie common.Trie) ([]core.TrieDa
 
 	if check.IfNil(tdt.tr) {
 		emptyRootHash := holders.NewDefaultRootHashesHolder(make([]byte, 0))
-		newDataTrie, err := mainTrie.Recreate(emptyRootHash)
+		newDataTrie, err := mainTrie.Recreate(emptyRootHash, hex.EncodeToString(tdt.identifier))
 		if err != nil {
 			return nil, err
 		}

state/trackableDataTrie/trackableDataTrie_test.go

@@ -367,7 +367,7 @@ func TestTrackableDataTrie_SaveDirtyData(t *testing.T) {
 
 		recreateCalled := false
 		trie := &trieMock.TrieStub{
-			RecreateCalled: func(root common.RootHashHolder) (common.Trie, error) {
+			RecreateCalled: func(root common.RootHashHolder, _ string) (common.Trie, error) {
 				recreateCalled = true
 				return &trieMock.TrieStub{
 					GetCalled: func(_ []byte) ([]byte, uint32, error) {