Replace ethereum log with zerolog and some ctxerrors

pull/1785/head
flicker-harmony 5 years ago
parent e7a37055c1
commit a90968d379
  1. 7
      accounts/abi/bind/util.go
  2. 19
      accounts/keystore/account_cache.go
  3. 8
      accounts/keystore/file_cache.go
  4. 6
      api/service/explorer/service.go
  5. 3
      api/service/explorer/storage.go
  6. 4
      cmd/client/txgen/main.go
  7. 15
      cmd/harmony/main.go
  8. 6
      consensus/consensus_v2.go
  9. 6
      contracts/contract_caller.go
  10. 448
      node/Find Results
  11. 15
      node/node.go
  12. 23
      node/node_handler.go
  13. 13
      node/node_newblock.go
  14. 19
      node/node_resharding.go
  15. 5
      node/node_syncing.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 {

@ -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
}

@ -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
}

@ -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 == "" {

@ -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")
}
}

@ -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

@ -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

@ -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

@ -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

@ -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:
<binary>
/Users/vladlazarus/go/src/github.com/harmony-one/harmony/bin/bootnode:
<binary>
/Users/vladlazarus/go/src/github.com/harmony-one/harmony/bin/harmony:
<binary>
/Users/vladlazarus/go/src/github.com/harmony-one/harmony/bin/staking-standalone:
<binary>
/Users/vladlazarus/go/src/github.com/harmony-one/harmony/bin/txgen:
<binary>
/Users/vladlazarus/go/src/github.com/harmony-one/harmony/bin/wallet:
<binary>
/Users/vladlazarus/go/src/github.com/harmony-one/harmony/bin/wallet_stress_test:
<binary>
/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

@ -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,

@ -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)

@ -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
}

@ -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)
}

@ -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

Loading…
Cancel
Save