diff --git a/accounts/abi/bind/util.go b/accounts/abi/bind/util.go index 37bbabd81..d7cbb945a 100644 --- a/accounts/abi/bind/util.go +++ b/accounts/abi/bind/util.go @@ -32,17 +32,16 @@ import ( func WaitMined(ctx context.Context, b DeployBackend, tx *types.Transaction) (*types.Receipt, error) { queryTicker := time.NewTicker(time.Second) defer queryTicker.Stop() - - logger := utils.GetLogInstance().New("hash", tx.Hash()) + utils.Logger().Info().Str("hash", tx.Hash().Hex()) for { receipt, err := b.TransactionReceipt(ctx, tx.Hash()) if receipt != nil { return receipt, nil } if err != nil { - logger.Trace("Receipt retrieval failed", "err", err) + utils.Logger().Debug().Err(err).Msg("Receipt retrieval failed") } else { - logger.Trace("Transaction not yet mined") + utils.Logger().Debug().Msg("Transaction not yet mined") } // Wait for the next round. select { diff --git a/accounts/keystore/account_cache.go b/accounts/keystore/account_cache.go index d3e8c9f59..019433f09 100644 --- a/accounts/keystore/account_cache.go +++ b/accounts/keystore/account_cache.go @@ -236,7 +236,7 @@ func (ac *accountCache) scanAccounts() error { // Scan the entire folder metadata for file changes creates, deletes, updates, err := ac.fileC.scan(ac.keydir) if err != nil { - utils.GetLogger().Debug("Failed to reload keystore contents", "err", err) + utils.Logger().Debug().Err(err).Msg("Failed to reload keystore contents") return err } if creates.Cardinality() == 0 && deletes.Cardinality() == 0 && updates.Cardinality() == 0 { @@ -252,7 +252,10 @@ func (ac *accountCache) scanAccounts() error { readAccount := func(path string) *accounts.Account { fd, err := os.Open(path) if err != nil { - utils.GetLogger().Trace("Failed to open keystore file", "path", path, "err", err) + utils.Logger().Debug(). + Str("path", path). + Err(err). + Msg("Failed to open keystore file") return nil } defer fd.Close() @@ -263,9 +266,15 @@ func (ac *accountCache) scanAccounts() error { addr := common2.ParseAddr(key.Address) switch { case err != nil: - utils.GetLogger().Debug("Failed to decode keystore key", "path", path, "err", err) + utils.Logger().Debug(). + Str("path", path). + Err(err). + Msg("Failed to decode keystore key") case (addr == common.Address{}): - utils.GetLogger().Debug("Failed to decode keystore key", "path", path, "err", "missing or zero address") + utils.Logger().Debug(). + Str("path", path). + Err(err). + Msg("Failed to decode keystore key, missing or zero address") default: return &accounts.Account{ Address: addr, @@ -298,6 +307,6 @@ func (ac *accountCache) scanAccounts() error { case ac.notify <- struct{}{}: default: } - utils.GetLogger().Trace("Handled keystore changes", "time", end.Sub(start)) + utils.Logger().Debug().Uint64("time", uint64(end.Sub(start))).Msg("Handled keystore changes") return nil } diff --git a/accounts/keystore/file_cache.go b/accounts/keystore/file_cache.go index f0d47f02e..bd22a9f51 100644 --- a/accounts/keystore/file_cache.go +++ b/accounts/keystore/file_cache.go @@ -60,7 +60,7 @@ func (fc *fileCache) scan(keyDir string) (mapset.Set, mapset.Set, mapset.Set, er path := filepath.Join(keyDir, fi.Name()) // Skip any non-key files from the folder if nonKeyFile(fi) { - utils.GetLogger().Trace("Ignoring file on account scan", "path", path) + utils.Logger().Debug().Str("path", path).Msg("Ignoring file on account scan") continue } // Gather the set of all and fresly modified files @@ -85,7 +85,11 @@ func (fc *fileCache) scan(keyDir string) (mapset.Set, mapset.Set, mapset.Set, er t3 := time.Now() // Report on the scanning stats and return - utils.GetLogger().Debug("FS scan times", "list", t1.Sub(t0), "set", t2.Sub(t1), "diff", t3.Sub(t2)) + utils.Logger().Debug(). + Uint64("list", uint64(t1.Sub(t0))). + Uint64("set", uint64(t2.Sub(t1))). + Uint64("diff", uint64(t3.Sub(t2))). + Msg("FS scan times") return creates, deletes, updates, nil } diff --git a/api/service/explorer/service.go b/api/service/explorer/service.go index 80960aede..dce59d85b 100644 --- a/api/service/explorer/service.go +++ b/api/service/explorer/service.go @@ -25,7 +25,6 @@ import ( bls2 "github.com/harmony-one/harmony/crypto/bls" "github.com/harmony-one/harmony/internal/bech32" common2 "github.com/harmony-one/harmony/internal/common" - "github.com/harmony-one/harmony/internal/ctxerror" "github.com/harmony-one/harmony/internal/utils" "github.com/harmony-one/harmony/p2p" "github.com/harmony-one/harmony/shard" @@ -669,7 +668,7 @@ func (s *Service) GetExplorerAddress(w http.ResponseWriter, r *http.Request) { parsedAddr := common2.ParseAddr(id) oneAddr, err := common2.AddressToBech32(parsedAddr) if err != nil { - utils.Logger().Warn().Msg("unrecognized address format") + utils.Logger().Warn().Err(err).Msg("unrecognized address format") w.WriteHeader(http.StatusBadRequest) return } @@ -688,8 +687,7 @@ func (s *Service) GetExplorerAddress(w http.ResponseWriter, r *http.Request) { data := &Data{} defer func() { if err := json.NewEncoder(w).Encode(data.Address); err != nil { - ctxerror.Warn(utils.WithCallerSkip(utils.GetLogInstance(), 1), err, - "cannot JSON-encode Address") + utils.Logger().Warn().Err(err).Msg("cannot JSON-encode Address") } }() if id == "" { diff --git a/api/service/explorer/storage.go b/api/service/explorer/storage.go index 85b669719..79e12316d 100644 --- a/api/service/explorer/storage.go +++ b/api/service/explorer/storage.go @@ -10,7 +10,6 @@ import ( "github.com/ethereum/go-ethereum/rlp" "github.com/harmony-one/harmony/core/types" - "github.com/harmony-one/harmony/internal/ctxerror" "github.com/harmony-one/harmony/internal/utils" "github.com/harmony-one/harmony/shard" ) @@ -117,7 +116,7 @@ func (storage *Storage) Dump(block *types.Block, height uint64) { storage.UpdateAddress(batch, explorerTransaction, tx) } if err := batch.Write(); err != nil { - ctxerror.Warn(utils.GetLogger(), err, "cannot write batch") + utils.Logger().Warn().Err(err).Msg("cannot write batch") } } diff --git a/cmd/client/txgen/main.go b/cmd/client/txgen/main.go index 5363d193d..43a5641a4 100644 --- a/cmd/client/txgen/main.go +++ b/cmd/client/txgen/main.go @@ -13,7 +13,6 @@ import ( "github.com/harmony-one/harmony/consensus" "github.com/harmony-one/harmony/consensus/quorum" "github.com/harmony-one/harmony/core" - "github.com/harmony-one/harmony/internal/ctxerror" "github.com/harmony-one/harmony/internal/shardchain" "github.com/ethereum/go-ethereum/crypto" @@ -222,8 +221,7 @@ syncLoop: } stateMutex.Lock() if err := txGen.Worker.UpdateCurrent(block.Coinbase()); err != nil { - ctxerror.Warn(utils.GetLogger(), err, - "(*Worker).UpdateCurrent failed") + utils.Logger().Warn().Err(err).Msg("(*Worker).UpdateCurrent failed") } stateMutex.Unlock() readySignal <- shardID diff --git a/cmd/harmony/main.go b/cmd/harmony/main.go index 70c417b73..1427ed616 100644 --- a/cmd/harmony/main.go +++ b/cmd/harmony/main.go @@ -25,7 +25,6 @@ import ( "github.com/harmony-one/harmony/internal/common" nodeconfig "github.com/harmony-one/harmony/internal/configs/node" shardingconfig "github.com/harmony-one/harmony/internal/configs/sharding" - "github.com/harmony-one/harmony/internal/ctxerror" "github.com/harmony-one/harmony/internal/genesis" hmykey "github.com/harmony-one/harmony/internal/keystore" "github.com/harmony-one/harmony/internal/memprofiling" @@ -280,7 +279,7 @@ func createGlobalConfig() *nodeconfig.ConfigType { myHost, err = p2pimpl.NewHost(&selfPeer, nodeConfig.P2pPriKey) if *logConn && nodeConfig.GetNetworkType() != nodeconfig.Mainnet { - myHost.GetP2PHost().Network().Notify(utils.NewConnLogger(utils.GetLogInstance())) + myHost.GetP2PHost().Network().Notify(utils.NewConnLogger(utils.GetLogger())) } if err != nil { panic("unable to new host in harmony") @@ -382,8 +381,10 @@ func setupConsensusAndNode(nodeConfig *nodeconfig.ConfigType) *node.Node { // This needs to be executed after consensus and drand are setup if err := currentNode.CalculateInitShardState(); err != nil { - ctxerror.Crit(utils.GetLogger(), err, "CalculateInitShardState failed", - "shardID", *shardID) + utils.Logger().Warn(). + Int("shardID", *shardID). + Err(err). + Msg("CalculateInitShardState failed") } // Set the consensus ID to be the current block number @@ -477,7 +478,7 @@ func main() { currentNode.SetBeaconSyncFreq(*beaconSyncFreq) if nodeConfig.ShardID != 0 && currentNode.NodeConfig.Role() != nodeconfig.ExplorerNode { - utils.GetLogInstance().Info("SupportBeaconSyncing", "shardID", currentNode.Blockchain().ShardID(), "shardID", nodeConfig.ShardID) + utils.Logger().Info().Uint32("shardID", currentNode.Blockchain().ShardID()).Uint32("shardID", nodeConfig.ShardID).Msg("SupportBeaconSyncing") go currentNode.SupportBeaconSyncing() } @@ -505,7 +506,9 @@ func main() { currentNode.RunServices() // RPC for SDK not supported for mainnet. if err := currentNode.StartRPC(*port); err != nil { - ctxerror.Warn(utils.GetLogger(), err, "StartRPC failed") + utils.Logger().Warn(). + Err(err). + Msg("StartRPC failed") } // Run additional node collectors diff --git a/consensus/consensus_v2.go b/consensus/consensus_v2.go index 58c314b3b..10ddcbc0f 100644 --- a/consensus/consensus_v2.go +++ b/consensus/consensus_v2.go @@ -832,9 +832,6 @@ func (consensus *Consensus) finalizeCommits() { Str("blockHash", block.Hash().String()). Int("index", consensus.Decider.IndexOf(consensus.PubKey)). Msg("HOORAY!!!!!!! CONSENSUS REACHED!!!!!!!") - // Print to normal log too - utils.GetLogInstance().Info("HOORAY!!!!!!! CONSENSUS REACHED!!!!!!!", "BlockNum", block.NumberU64()) - // Send signal to Node so the new block can be added and new round of consensus can be triggered consensus.ReadySignal <- struct{}{} } @@ -965,6 +962,9 @@ func (consensus *Consensus) LastCommitSig() ([]byte, []byte, error) { if err != nil || len(lastCommits) < 96 { msgs := consensus.FBFTLog.GetMessagesByTypeSeq(msg_pb.MessageType_COMMITTED, consensus.blockNum-1) if len(msgs) != 1 { + utils.Logger().Error(). + Int("numCommittedMsg", len(msgs)). + Msg("GetLastCommitSig failed with wrong number of committed message") return nil, nil, ctxerror.New("GetLastCommitSig failed with wrong number of committed message", "numCommittedMsg", len(msgs)) } lastCommits = msgs[0].Payload diff --git a/contracts/contract_caller.go b/contracts/contract_caller.go index 577a5cd12..975080387 100644 --- a/contracts/contract_caller.go +++ b/contracts/contract_caller.go @@ -35,7 +35,7 @@ func (cc *ContractCaller) CallContract(tx *types.Transaction) ([]byte, error) { currBlock := cc.blockchain.CurrentBlock() msg, err := tx.AsMessage(types.MakeSigner(cc.config, currBlock.Header().Epoch())) if err != nil { - utils.GetLogInstance().Error("[ABI] Failed to convert transaction to message", "error", err) + utils.Logger().Error().Err(err).Msg("[ABI] Failed to convert transaction to message") return []byte{}, err } evmContext := core.NewEVMContext(msg, currBlock.Header(), cc.blockchain, nil) @@ -43,7 +43,7 @@ func (cc *ContractCaller) CallContract(tx *types.Transaction) ([]byte, error) { // about the transaction and calling mechanisms. stateDB, err := cc.blockchain.State() if err != nil { - utils.GetLogInstance().Error("[ABI] Failed to retrieve state db", "error", err) + utils.Logger().Error().Err(err).Msg("[ABI] Failed to retrieve state db") return []byte{}, err } vmenv := vm.NewEVM(evmContext, stateDB, cc.config, vm.Config{}) @@ -51,7 +51,7 @@ func (cc *ContractCaller) CallContract(tx *types.Transaction) ([]byte, error) { returnValue, _, failed, err := core.NewStateTransition(vmenv, msg, gaspool).TransitionDb() if err != nil || failed { - utils.GetLogInstance().Error("[ABI] Failed executing the transaction", "error", err) + utils.Logger().Error().Err(err).Msg("[ABI] Failed executing the transaction") return []byte{}, err } return returnValue, nil diff --git a/node/Find Results b/node/Find Results new file mode 100644 index 000000000..31fc312e7 --- /dev/null +++ b/node/Find Results @@ -0,0 +1,448 @@ +Searching 2456 files for "utils.GetLogInstance(" + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/accounts/abi/bind/util.go: + 34 defer queryTicker.Stop() + 35 + 36: logger := utils.GetLogInstance().New("hash", tx.Hash()) + 37 for { + 38 receipt, err := b.TransactionReceipt(ctx, tx.Hash()) + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/api/service/explorer/service.go: + 689 defer func() { + 690 if err := json.NewEncoder(w).Encode(data.Address); err != nil { + 691: ctxerror.Warn(utils.WithCallerSkip(utils.GetLogInstance(), 1), err, + 692 "cannot JSON-encode Address") + 693 } + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/cmd/bootnode/main.go: + 68 + 69 if *logConn { + 70: host.GetP2PHost().Network().Notify(utils.NewConnLogger(utils.GetLogInstance())) + 71 } + 72 + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/cmd/harmony/main.go: + 155 + 156 if *onlyLogTps { + 157: matchFilterHandler := log.MatchFilterHandler("msg", "TPS Report", utils.GetLogInstance().GetHandler()) + 158: utils.GetLogInstance().SetHandler(matchFilterHandler) + 159 } + 160 + ... + 281 myHost, err = p2pimpl.NewHost(&selfPeer, nodeConfig.P2pPriKey) + 282 if *logConn && nodeConfig.GetNetworkType() != nodeconfig.Mainnet { + 283: myHost.GetP2PHost().Network().Notify(utils.NewConnLogger(utils.GetLogInstance())) + 284 } + 285 if err != nil { + ... + 479 if nodeConfig.ShardID != 0 && currentNode.NodeConfig.Role() != nodeconfig.ExplorerNode { + 480 utils.Logger().Info().Uint32("shardID", currentNode.Blockchain().ShardID()).Uint32("shardID", nodeConfig.ShardID).Msg("SupportBeaconSyncing") + 481: //utils.GetLogInstance().Info("SupportBeaconSyncing", "shardID", currentNode.Blockchain().ShardID(), "shardID", nodeConfig.ShardID) + 482 go currentNode.SupportBeaconSyncing() + 483 } + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/consensus/consensus_v2.go: + 834 Msg("HOORAY!!!!!!! CONSENSUS REACHED!!!!!!!") + 835 // Print to normal log too + 836: utils.GetLogInstance().Info("HOORAY!!!!!!! CONSENSUS REACHED!!!!!!!", "BlockNum", block.NumberU64()) + 837 + 838 // Send signal to Node so the new block can be added and new round of consensus can be triggered + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/contracts/contract_caller.go: + 36 msg, err := tx.AsMessage(types.MakeSigner(cc.config, currBlock.Header().Epoch())) + 37 if err != nil { + 38: utils.GetLogInstance().Error("[ABI] Failed to convert transaction to message", "error", err) + 39 return []byte{}, err + 40 } + .. + 44 stateDB, err := cc.blockchain.State() + 45 if err != nil { + 46: utils.GetLogInstance().Error("[ABI] Failed to retrieve state db", "error", err) + 47 return []byte{}, err + 48 } + .. + 52 returnValue, _, failed, err := core.NewStateTransition(vmenv, msg, gaspool).TransitionDb() + 53 if err != nil || failed { + 54: utils.GetLogInstance().Error("[ABI] Failed executing the transaction", "error", err) + 55 return []byte{}, err + 56 } + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/internal/utils/testing.go: + 18 // + 19 // func TestMyFunc(t *testing.T) { + 20: // l := utils.GetLogInstance() + 21 // lrd := NewTestLogRedirector(l, t) + 22 // defer lrd.Close() + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/node/node_handler.go: + 337 Msg("BINGO !!! Reached Consensus") + 338 // Print to normal log too + 339: utils.GetLogInstance().Info("BINGO !!! Reached Consensus", "BlockNum", newBlock.NumberU64()) + 340 + 341 // 15% of the validator also need to do broadcasting + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/node/node_syncing.go: + 431 } else if len(node.peerRegistrationRecord) >= maxBroadcastNodes { + 432 response.Type = downloader_pb.DownloaderResponse_FAIL + 433: utils.GetLogInstance().Debug("[SYNC] maximum registration limit exceeds", "ip", ip, "port", port) + 434 return response, nil + 435 } else { + +14 matches across 9 files + + +Searching 2433 files for "GetLogger" + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/accounts/keystore/account_cache.go: + 237 creates, deletes, updates, err := ac.fileC.scan(ac.keydir) + 238 if err != nil { + 239: utils.GetLogger().Debug("Failed to reload keystore contents", "err", err) + 240 return err + 241 } + ... + 253 fd, err := os.Open(path) + 254 if err != nil { + 255: utils.GetLogger().Trace("Failed to open keystore file", "path", path, "err", err) + 256 return nil + 257 } + ... + 264 switch { + 265 case err != nil: + 266: utils.GetLogger().Debug("Failed to decode keystore key", "path", path, "err", err) + 267 case (addr == common.Address{}): + 268: utils.GetLogger().Debug("Failed to decode keystore key", "path", path, "err", "missing or zero address") + 269 default: + 270 return &accounts.Account{ + ... + 299 default: + 300 } + 301: utils.GetLogger().Trace("Handled keystore changes", "time", end.Sub(start)) + 302 return nil + 303 } + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/accounts/keystore/file_cache.go: + 61 // Skip any non-key files from the folder + 62 if nonKeyFile(fi) { + 63: utils.GetLogger().Trace("Ignoring file on account scan", "path", path) + 64 continue + 65 } + .. + 86 + 87 // Report on the scanning stats and return + 88: utils.GetLogger().Debug("FS scan times", "list", t1.Sub(t0), "set", t2.Sub(t1), "diff", t3.Sub(t2)) + 89 return creates, deletes, updates, nil + 90 } + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/api/service/explorer/service.go: + 689 if err := json.NewEncoder(w).Encode(data.Address); err != nil { + 690 utils.Logger().Warn().Err(err).Msg("cannot JSON-encode Address") + 691: //ctxerror.Warn(utils.WithCallerSkip(utils.GetLogger(), 1), err, "cannot JSON-encode Address") + 692 } + 693 }() + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/api/service/explorer/storage.go: + 118 } + 119 if err := batch.Write(); err != nil { + 120: ctxerror.Warn(utils.GetLogger(), err, "cannot write batch") + 121 } + 122 } + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/bin/0: + + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/bin/bootnode: + + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/bin/harmony: + + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/bin/staking-standalone: + + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/bin/txgen: + + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/bin/wallet: + + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/bin/wallet_stress_test: + + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/cmd/client/txgen/main.go: + 223 stateMutex.Lock() + 224 if err := txGen.Worker.UpdateCurrent(block.Coinbase()); err != nil { + 225: ctxerror.Warn(utils.GetLogger(), err, + 226 "(*Worker).UpdateCurrent failed") + 227 } + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/cmd/harmony/main.go: + 281 myHost, err = p2pimpl.NewHost(&selfPeer, nodeConfig.P2pPriKey) + 282 if *logConn && nodeConfig.GetNetworkType() != nodeconfig.Mainnet { + 283: myHost.GetP2PHost().Network().Notify(utils.NewConnLogger(utils.GetLogger())) + 284 } + 285 if err != nil { + ... + 383 // This needs to be executed after consensus and drand are setup + 384 if err := currentNode.CalculateInitShardState(); err != nil { + 385: ctxerror.Crit(utils.GetLogger(), err, "CalculateInitShardState failed", + 386 "shardID", *shardID) + 387 } + ... + 507 // RPC for SDK not supported for mainnet. + 508 if err := currentNode.StartRPC(*port); err != nil { + 509: ctxerror.Warn(utils.GetLogger(), err, "StartRPC failed") + 510 } + 511 + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/consensus/consensus_service.go: + 67 // sender address + 68 request.SenderPubkey = consensus.PubKey.Serialize() + 69: consensus.getLogger().Debug(). + 70 Str("senderKey", consensus.PubKey.SerializeToHexStr()). + 71 Msg("[populateMessageFields]") + .. + 205 // ResetState resets the state of the consensus + 206 func (consensus *Consensus) ResetState() { + 207: consensus.getLogger().Debug(). + 208 Str("Phase", consensus.phase.String()). + 209 Msg("[ResetState] Resetting consensus state") + ... + 382 numOfTxs := len(block.Transactions()) + 383 tps := float64(numOfTxs) / timeElapsed.Seconds() + 384: consensus.getLogger().Info(). + 385 Int("numOfTXs", numOfTxs). + 386 Time("startTime", startTime). + ... + 413 } + 414 + 415: // getLogger returns logger for consensus contexts added + 416: func (consensus *Consensus) getLogger() *zerolog.Logger { + 417 logger := utils.Logger().With(). + 418 Uint64("myEpoch", consensus.epoch). + ... + 478 consensus.numPrevPubKeys = len(curPubKeys) + 479 + 480: consensus.getLogger().Info().Msg("[UpdateConsensusInformation] Updating.....") + 481 + 482 if core.IsEpochLastBlockByHeader(header) { + 483 // increase epoch by one if it's the last block + 484 consensus.SetEpochNum(epoch.Uint64() + 1) + 485: consensus.getLogger().Info().Uint64("headerNum", header.Number().Uint64()). + 486 Msg("[UpdateConsensusInformation] Epoch updated for next epoch") + 487 nextEpoch := new(big.Int).Add(epoch, common.Big1) + ... + 493 + 494 if len(pubKeys) == 0 { + 495: consensus.getLogger().Warn(). + 496 Msg("[UpdateConsensusInformation] PublicKeys is Nil") + 497 hasError = true + ... + 499 + 500 // update public keys committee + 501: consensus.getLogger().Info(). + 502 Int("numPubKeys", len(pubKeys)). + 503 Msg("[UpdateConsensusInformation] Successfully updated public keys") + ... + 508 leaderPubKey, err := consensus.getLeaderPubKeyFromCoinbase(header) + 509 if err != nil || leaderPubKey == nil { + 510: consensus.getLogger().Debug().Err(err). + 511 Msg("[SYNC] Unable to get leaderPubKey from coinbase") + 512 consensus.ignoreViewIDCheck = true + 513 hasError = true + 514 } else { + 515: consensus.getLogger().Debug(). + 516 Str("leaderPubKey", leaderPubKey.SerializeToHexStr()). + 517 Msg("[SYNC] Most Recent LeaderPubKey Updated Based on BlockChain") + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/consensus/consensus_v2.go: + 34 err := protobuf.Unmarshal(payload, msg) + 35 if err != nil { + 36: consensus.getLogger().Error().Err(err).Msg("Failed to unmarshal message payload.") + 37 return + 38 } + .. + 1138 vrfBlockNumbers, err := consensus.ChainReader.ReadEpochVrfBlockNums(newBlock.Header().Epoch()) + 1139 if err != nil { + 1140: consensus.getLogger().Info(). + 1141 Uint64("MsgBlockNum", newBlock.NumberU64()). + 1142 Uint64("Epoch", newBlock.Header().Epoch().Uint64()). + .... + 1148 for _, v := range vrfBlockNumbers { + 1149 if v == newBlock.NumberU64() { + 1150: consensus.getLogger().Info(). + 1151 Uint64("MsgBlockNum", newBlock.NumberU64()). + 1152 Uint64("Epoch", newBlock.Header().Epoch().Uint64()). + .... + 1182 vdfObject := vdf_go.New(core.ShardingSchedule.VdfDifficulty(), seed) + 1183 if !vdfObject.Verify(vdfOutput) { + 1184: consensus.getLogger().Warn(). + 1185 Uint64("MsgBlockNum", newBlock.NumberU64()). + 1186 Uint64("Epoch", newBlock.Header().Epoch().Uint64()). + .... + 1190 _, err := consensus.ChainReader.ReadEpochVdfBlockNum(newBlock.Header().Epoch()) + 1191 if err == nil { + 1192: consensus.getLogger().Info(). + 1193 Uint64("MsgBlockNum", newBlock.NumberU64()). + 1194 Uint64("Epoch", newBlock.Header().Epoch().Uint64()). + 1195 Msg("[ConsensusMainLoop] VDF has already been generated previously") + 1196 } else { + 1197: consensus.getLogger().Info(). + 1198 Uint64("MsgBlockNum", newBlock.NumberU64()). + 1199 Uint64("Epoch", newBlock.Header().Epoch().Uint64()). + .... + 1204 } + 1205 } else { + 1206: //consensus.getLogger().Error().Err(err). Msg("[ConsensusMainLoop] Failed to get randomness") + 1207 } + 1208 } + .... + 1248 newBlock.AddVrf(append(vrf[:], proof...)) + 1249 + 1250: consensus.getLogger().Info(). + 1251 Uint64("MsgBlockNum", newBlock.NumberU64()). + 1252 Uint64("Epoch", newBlock.Header().Epoch().Uint64()). + .... + 1271 + 1272 if err != nil { + 1273: consensus.getLogger().Warn(). + 1274 Err(err). + 1275 Str("MsgBlockNum", headerObj.Number().String()). + .... + 1279 + 1280 if !bytes.Equal(hash[:], headerObj.Vrf()[:32]) { + 1281: consensus.getLogger().Warn(). + 1282 Str("MsgBlockNum", headerObj.Number().String()). + 1283 Msg("[OnAnnounce] VRF proof is not valid") + .... + 1288 headerObj.Epoch(), + 1289 ) + 1290: consensus.getLogger().Info(). + 1291 Str("MsgBlockNum", headerObj.Number().String()). + 1292 Int("Number of VRF", len(vrfBlockNumbers)). + .... + 1307 } + 1308 + 1309: consensus.getLogger().Info(). + 1310 Uint64("MsgBlockNum", newBlock.NumberU64()). + 1311 Uint64("Epoch", newBlock.Header().Epoch().Uint64()). + .... + 1320 vdf.Execute() + 1321 duration := time.Now().Sub(start) + 1322: consensus.getLogger().Info(). + 1323 Dur("duration", duration). + 1324 Msg("[ConsensusMainLoop] VDF computation finished") + .... + 1337 vrfBlockNumbers, err := consensus.ChainReader.ReadEpochVrfBlockNums(headerObj.Epoch()) + 1338 if err != nil { + 1339: consensus.getLogger().Error().Err(err). + 1340 Str("MsgBlockNum", headerObj.Number().String()). + 1341 Msg("[OnAnnounce] failed to read VRF block numbers for VDF computation") + .... + 1360 copy(vdfOutput[:], headerObj.Vdf()) + 1361 if vdfObject.Verify(vdfOutput) { + 1362: consensus.getLogger().Info(). + 1363 Str("MsgBlockNum", headerObj.Number().String()). + 1364 Int("Num of VRF", consensus.VdfSeedSize()). + .... + 1366 + 1367 } else { + 1368: consensus.getLogger().Warn(). + 1369 Str("MsgBlockNum", headerObj.Number().String()). + 1370 Uint64("Epoch", headerObj.Epoch().Uint64()). + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/internal/utils/logging.go: + 37 } + 38 + 39: // GetLogger is a shorthand for WithCaller(GetLogInstance()). + 40: func GetLogger() log.Logger { + 41 return WithCallerSkip(GetLogInstance(), 1) + 42 } + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/internal/utils/logging_test.go: + 70 } + 71 + 72: func TestGetLogger(t *testing.T) { + 73 oldHandler := GetLogInstance().GetHandler() + 74 defer GetLogInstance().SetHandler(oldHandler) + .. + 80 "port", "", // added by the singleton instance + 81 "ip", "", // added by the singleton instance + 82: "funcName", thisPkg + ".TestGetLogger", + 83 "funcFile", thisFile, + 84 "funcLine", 88, // keep this in sync with Debug() call below + .. + 86 }) + 87 GetLogInstance().SetHandler(handler) + 88: GetLogger().Debug("omg") + 89 } + 90 + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/node/node.go: + 246 err = ctxerror.New("cannot get shard chain", "shardID", shardID). + 247 WithCause(err) + 248: ctxerror.Log15(utils.GetLogger().Crit, err) + 249 } + 250 return bc + ... + 256 if err != nil { + 257 err = ctxerror.New("cannot get beaconchain").WithCause(err) + 258: ctxerror.Log15(utils.GetLogger().Crit, err) + 259 } + 260 return bc + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/node/node_handler.go: + 162 case proto_node.ShardState: + 163 if err := node.epochShardStateMessageHandler(msgPayload); err != nil { + 164: ctxerror.Log15(utils.GetLogger().Warn, err) + 165 } + 166 } + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/node/node_newblock.go: + 85 + 86 if err := node.Worker.CommitTransactions(selectedTxs, selectedStakingTxs, coinbase); err != nil { + 87: ctxerror.Log15(utils.GetLogger().Error, + 88 ctxerror.New("cannot commit transactions"). + 89 WithCause(err)) + .. + 95 if len(receiptsList) != 0 { + 96 if err := node.Worker.CommitReceipts(receiptsList); err != nil { + 97: ctxerror.Log15(utils.GetLogger().Error, + 98 ctxerror.New("cannot commit receipts"). + 99 WithCause(err)) + ... + 116 sig, mask, err := node.Consensus.LastCommitSig() + 117 if err != nil { + 118: ctxerror.Log15(utils.GetLogger().Error, + 119 ctxerror.New("Cannot get commit signatures from last block"). + 120 WithCause(err)) + +/Users/vladlazarus/go/src/github.com/harmony-one/harmony/node/node_resharding.go: + 72 // Don't treat this as a blocker until we fix the nondeterminism. + 73 //return err + 74: ctxerror.Log15(utils.GetLogger().Warn, err) + 75 } + 76 } else { + .. + 194 + 195 if myShardID == math.MaxUint32 { + 196: getLogger().Info("Somehow I got kicked out. Exiting") + 197 os.Exit(8) // 8 represents it's a loop and the program restart itself + 198 } + ... + 206 err := key.Deserialize(nodeID.BlsPublicKey[:]) + 207 if err != nil { + 208: getLogger().Error("Failed to deserialize BLS public key in shard state", + 209 "idx", idx, + 210 "error", err) + ... + 216 + 217 if node.Blockchain().ShardID() == myShardID { + 218: getLogger().Info("staying in the same shard") + 219 } else { + 220: getLogger().Info("moving to another shard") + 221 if err := node.shardChains.Close(); err != nil { + 222: getLogger().Error("cannot close shard chains", "error", err) + 223 } + 224 restartProcess(getRestartArguments(myShardID)) + +165 matches across 21 files diff --git a/node/node.go b/node/node.go index 782089b8e..262b1a5fe 100644 --- a/node/node.go +++ b/node/node.go @@ -243,9 +243,10 @@ func (node *Node) Blockchain() *core.BlockChain { shardID := node.NodeConfig.ShardID bc, err := node.shardChains.ShardChain(shardID) if err != nil { - err = ctxerror.New("cannot get shard chain", "shardID", shardID). - WithCause(err) - ctxerror.Log15(utils.GetLogger().Crit, err) + utils.Logger().Error(). + Uint32("shardID", shardID). + Err(err). + Msg("cannot get shard chain") } return bc } @@ -254,8 +255,7 @@ func (node *Node) Blockchain() *core.BlockChain { func (node *Node) Beaconchain() *core.BlockChain { bc, err := node.shardChains.ShardChain(0) if err != nil { - err = ctxerror.New("cannot get beaconchain").WithCause(err) - ctxerror.Log15(utils.GetLogger().Crit, err) + utils.Logger().Error().Err(err).Msg("cannot get beaconchain") } return bc } @@ -556,6 +556,7 @@ func New(host p2p.Host, consensusObj *consensus.Consensus, chainDBFactory shardc // CalculateInitShardState initialize shard state from latest epoch and update committee pub keys for consensus and drand func (node *Node) CalculateInitShardState() (err error) { if node.Consensus == nil { + utils.Logger().Error().Msg("[CalculateInitShardState] consenus is nil; Cannot figure out shardID") return ctxerror.New("[CalculateInitShardState] consenus is nil; Cannot figure out shardID") } shardID := node.Consensus.ShardID @@ -571,6 +572,10 @@ func (node *Node) CalculateInitShardState() (err error) { Msg("[CalculateInitShardState] Try To Get PublicKeys from database") pubKeys := core.CalculatePublicKeys(epoch, shardID) if len(pubKeys) == 0 { + utils.Logger().Error(). + Uint32("shardID", shardID). + Uint64("blockNum", blockNum). + Msg("[CalculateInitShardState] PublicKeys is Empty, Cannot update public keys") return ctxerror.New( "[CalculateInitShardState] PublicKeys is Empty, Cannot update public keys", "shardID", shardID, diff --git a/node/node_handler.go b/node/node_handler.go index c67f533f0..8eed706cb 100644 --- a/node/node_handler.go +++ b/node/node_handler.go @@ -161,7 +161,7 @@ func (node *Node) HandleMessage(content []byte, sender libp2p_peer.ID) { node.pingMessageHandler(msgPayload, sender) case proto_node.ShardState: if err := node.epochShardStateMessageHandler(msgPayload); err != nil { - ctxerror.Log15(utils.GetLogger().Warn, err) + utils.Logger().Warn().Err(err) } } default: @@ -257,15 +257,28 @@ func (node *Node) VerifyNewBlock(newBlock *types.Block) error { err := node.Blockchain().Validator().ValidateHeader(newBlock, true) if err != nil { + utils.Logger().Error(). + Str("blockHash", newBlock.Hash().Hex()). + Err(err). + Msg("cannot ValidateHeader for the new block") return ctxerror.New("cannot ValidateHeader for the new block", "blockHash", newBlock.Hash()).WithCause(err) } if newBlock.ShardID() != node.Blockchain().ShardID() { + utils.Logger().Error(). + Uint32("my shard ID", node.Blockchain().ShardID()). + Uint32("new block's shard ID", newBlock.ShardID()). + Msg("wrong shard ID") return ctxerror.New("wrong shard ID", "my shard ID", node.Blockchain().ShardID(), "new block's shard ID", newBlock.ShardID()) } err = node.Blockchain().ValidateNewBlock(newBlock) if err != nil { + utils.Logger().Error(). + Str("blockHash", newBlock.Hash().Hex()). + Int("numTx", len(newBlock.Transactions())). + Err(err). + Msg("cannot ValidateNewBlock") return ctxerror.New("cannot ValidateNewBlock", "blockHash", newBlock.Hash(), "numTx", len(newBlock.Transactions()), @@ -285,6 +298,11 @@ func (node *Node) VerifyNewBlock(newBlock *types.Block) error { // TODO: move into ValidateNewBlock err = node.verifyIncomingReceipts(newBlock) if err != nil { + utils.Logger().Error(). + Str("blockHash", newBlock.Hash().Hex()). + Int("numIncomingReceipts", len(newBlock.IncomingReceipts())). + Err(err). + Msg("[VerifyNewBlock] Cannot ValidateNewBlock") return ctxerror.New("[VerifyNewBlock] Cannot ValidateNewBlock", "blockHash", newBlock.Hash(), "numIncomingReceipts", len(newBlock.IncomingReceipts())).WithCause(err) } @@ -335,9 +353,6 @@ func (node *Node) PostConsensusProcessing(newBlock *types.Block, commitSigAndBit utils.Logger().Info(). Uint64("BlockNum", newBlock.NumberU64()). Msg("BINGO !!! Reached Consensus") - // Print to normal log too - utils.GetLogInstance().Info("BINGO !!! Reached Consensus", "BlockNum", newBlock.NumberU64()) - // 15% of the validator also need to do broadcasting rand.Seed(time.Now().UTC().UnixNano()) rnd := rand.Intn(100) diff --git a/node/node_newblock.go b/node/node_newblock.go index 711cb7225..dceae14e3 100644 --- a/node/node_newblock.go +++ b/node/node_newblock.go @@ -8,7 +8,6 @@ import ( "github.com/ethereum/go-ethereum/common" "github.com/harmony-one/harmony/core" "github.com/harmony-one/harmony/core/types" - "github.com/harmony-one/harmony/internal/ctxerror" "github.com/harmony-one/harmony/internal/utils" "github.com/harmony-one/harmony/shard" ) @@ -84,9 +83,7 @@ func (node *Node) proposeNewBlock() (*types.Block, error) { selectedTxs, selectedStakingTxs := node.getTransactionsForNewBlock(coinbase) if err := node.Worker.CommitTransactions(selectedTxs, selectedStakingTxs, coinbase); err != nil { - ctxerror.Log15(utils.GetLogger().Error, - ctxerror.New("cannot commit transactions"). - WithCause(err)) + utils.Logger().Error().Err(err).Msg("cannot commit transactions") return nil, err } @@ -94,9 +91,7 @@ func (node *Node) proposeNewBlock() (*types.Block, error) { receiptsList := node.proposeReceiptsProof() if len(receiptsList) != 0 { if err := node.Worker.CommitReceipts(receiptsList); err != nil { - ctxerror.Log15(utils.GetLogger().Error, - ctxerror.New("cannot commit receipts"). - WithCause(err)) + utils.Logger().Error().Err(err).Msg("cannot commit receipts") } } @@ -115,9 +110,7 @@ func (node *Node) proposeNewBlock() (*types.Block, error) { // Prepare last commit signatures sig, mask, err := node.Consensus.LastCommitSig() if err != nil { - ctxerror.Log15(utils.GetLogger().Error, - ctxerror.New("Cannot get commit signatures from last block"). - WithCause(err)) + utils.Logger().Error().Err(err).Msg("Cannot get commit signatures from last block") return nil, err } diff --git a/node/node_resharding.go b/node/node_resharding.go index fa9bc1e63..d5de36bed 100644 --- a/node/node_resharding.go +++ b/node/node_resharding.go @@ -60,6 +60,7 @@ func (node *Node) validateNewShardState(block *types.Block) error { // DRand may or or may not get in the way. Test this out. expected, err := core.CalculateNewShardState(node.Blockchain(), nextEpoch) if err != nil { + utils.Logger().Error().Err(err).Msg("cannot calculate expected shard state") return ctxerror.New("cannot calculate expected shard state"). WithCause(err) } @@ -70,8 +71,7 @@ func (node *Node) validateNewShardState(block *types.Block) error { // TODO ek/chao – calculated shard state is different even with the // same input, i.e. it is nondeterministic. // Don't treat this as a blocker until we fix the nondeterminism. - //return err - ctxerror.Log15(utils.GetLogger().Warn, err) + utils.Logger().Warn().Err(err).Msg("shard state proposal is different from expected") } } else { // Regular validators fetch the local-shard copy on the beacon chain @@ -90,6 +90,7 @@ func (node *Node) validateNewShardState(block *types.Block) error { // Proposal to discontinue shard if expected != nil { // TODO ek – invoke view change + utils.Logger().Error().Msg("leader proposed to disband against beacon decision") return errors.New( "leader proposed to disband against beacon decision") } @@ -99,6 +100,10 @@ func (node *Node) validateNewShardState(block *types.Block) error { // Sanity check: Shard ID should match if proposed.ShardID != block.ShardID() { // TODO ek – invoke view change + utils.Logger().Error(). + Uint32("proposedShard", proposed.ShardID). + Uint32("blockShard", block.ShardID()). + Msg("proposal has incorrect shard ID") return ctxerror.New("proposal has incorrect shard ID", "proposedShard", proposed.ShardID, "blockShard", block.ShardID()) @@ -106,6 +111,8 @@ func (node *Node) validateNewShardState(block *types.Block) error { // Did beaconchain say we are no more? if expected == nil { // TODO ek – invoke view change + + utils.Logger().Error().Msg("leader proposed to continue against beacon decision") return errors.New( "leader proposed to continue against beacon decision") } @@ -113,10 +120,14 @@ func (node *Node) validateNewShardState(block *types.Block) error { if shard.CompareCommittee(expected, &proposed) != 0 { // TODO ek – log differences // TODO ek – invoke view change + utils.Logger().Error().Msg("proposal differs from one in beacon chain") return errors.New("proposal differs from one in beacon chain") } default: // TODO ek – invoke view change + utils.Logger().Error(). + Int("numShards", len(proposed)). + Msg("regular resharding proposal has incorrect number of shards") return ctxerror.New( "regular resharding proposal has incorrect number of shards", "numShards", len(proposed)) @@ -144,6 +155,7 @@ func (node *Node) broadcastEpochShardState(newBlock *types.Block) error { func (node *Node) epochShardStateMessageHandler(msgPayload []byte) error { epochShardState, err := proto_node.DeserializeEpochShardStateFromMessage(msgPayload) if err != nil { + utils.Logger().Error().Err(err).Msg("Can't get shard state message") return ctxerror.New("Can't get shard state message").WithCause(err) } if node.Consensus == nil { @@ -168,6 +180,9 @@ func (node *Node) epochShardStateMessageHandler(msgPayload []byte) error { err = node.Beaconchain().WriteShardState( receivedEpoch, epochShardState.ShardState) if err != nil { + utils.Logger().Error(). + Uint64("epoch", receivedEpoch.Uint64()). + Err(err).Msg("cannot store shard state") return ctxerror.New("cannot store shard state", "epoch", receivedEpoch). WithCause(err) } diff --git a/node/node_syncing.go b/node/node_syncing.go index a1fdf67c4..b6d7ddf67 100644 --- a/node/node_syncing.go +++ b/node/node_syncing.go @@ -430,7 +430,10 @@ func (node *Node) CalculateResponse(request *downloader_pb.DownloaderRequest, in return response, nil } else if len(node.peerRegistrationRecord) >= maxBroadcastNodes { response.Type = downloader_pb.DownloaderResponse_FAIL - utils.GetLogInstance().Debug("[SYNC] maximum registration limit exceeds", "ip", ip, "port", port) + utils.Logger().Debug(). + Str("ip", ip). + Str("port", port). + Msg("[SYNC] maximum registration limit exceeds") return response, nil } else { response.Type = downloader_pb.DownloaderResponse_FAIL