From 4ab74b4dbffbf778cb210cf16ea8fe0cf219c08e Mon Sep 17 00:00:00 2001 From: Nicholas Pettas Date: Thu, 28 Mar 2024 17:58:08 -0700 Subject: [PATCH 1/7] disable llr voting --- gossip/emitter/emitter.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/gossip/emitter/emitter.go b/gossip/emitter/emitter.go index 3003c7929..873ec200c 100644 --- a/gossip/emitter/emitter.go +++ b/gossip/emitter/emitter.go @@ -361,8 +361,8 @@ func (em *Emitter) createEvent(sortedTxs *types.TransactionsByPriceAndNonce) (*i mutEvent.SetCreationTime(inter.MaxTimestamp(inter.Timestamp(time.Now().UnixNano()), selfParentTime+1)) // add LLR votes - em.addLlrEpochVote(mutEvent) - em.addLlrBlockVotes(mutEvent) + //em.addLlrEpochVote(mutEvent) + //em.addLlrBlockVotes(mutEvent) // node version if mutEvent.Seq() <= 1 && len(em.config.VersionToPublish) > 0 { From 4c1386102ab41c59dde06517af3b43f15bb42c2b Mon Sep 17 00:00:00 2001 From: Nicholas Pettas Date: Fri, 29 Mar 2024 10:38:25 -0700 Subject: [PATCH 2/7] use stdout for logging and allow for dynamic log level --- cmd/opera/main.go | 3 +++ ethapi/api.go | 7 +++++++ logger/logger.go | 7 +++++++ 3 files changed, 17 insertions(+) diff --git a/cmd/opera/main.go b/cmd/opera/main.go index 5c29d1501..b7c834cf5 100644 --- a/cmd/opera/main.go +++ b/cmd/opera/main.go @@ -2,12 +2,15 @@ package main import ( "fmt" + "github.com/ethereum/go-ethereum/log" "os" "github.com/Fantom-foundation/go-opera/cmd/opera/launcher" ) func main() { + log.Root().SetHandler(log.LvlFilterHandler(log.LvlInfo, log.StreamHandler(os.Stdout, log.TerminalFormat(true)))) + if err := launcher.Launch(os.Args); err != nil { fmt.Fprintln(os.Stderr, err) os.Exit(1) diff --git a/ethapi/api.go b/ethapi/api.go index ebe08a0a6..88067e13e 100644 --- a/ethapi/api.go +++ b/ethapi/api.go @@ -22,6 +22,7 @@ import ( "fmt" "math/big" "math/rand" + "os" "time" "github.com/Fantom-foundation/lachesis-base/hash" @@ -2122,6 +2123,12 @@ func (api *PrivateDebugAPI) ChaindbProperty(property string) (string, error) { return api.b.ChainDb().Stat(property) } +// Verbosity sets the log level of the node. +func (api *PrivateDebugAPI) Verbosity(level int) { + log.Info("Setting log level", "level", log.Lvl(level).String()) + log.Root().SetHandler(log.LvlFilterHandler(log.Lvl(level), log.StreamHandler(os.Stdout, log.TerminalFormat(true)))) +} + // ChaindbCompact flattens the entire key-value database into a single level, // removing all unused slots and merging all keys. func (api *PrivateDebugAPI) ChaindbCompact() error { diff --git a/logger/logger.go b/logger/logger.go index 1b20913e5..ffc69f74f 100644 --- a/logger/logger.go +++ b/logger/logger.go @@ -47,3 +47,10 @@ func SetLevel(l string) { lvl, log.Root().GetHandler())) } + +func SetLevelInt(l log.Lvl) { + log.Root().SetHandler( + log.LvlFilterHandler( + l, + log.Root().GetHandler())) +} From b59c628a81751e9b0f85b1e9f2889bbac7a9c704 Mon Sep 17 00:00:00 2001 From: Nicholas Pettas Date: Fri, 29 Mar 2024 10:38:48 -0700 Subject: [PATCH 3/7] increase txblaster timeout --- docker/networksimulator/txblaster.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) mode change 100644 => 100755 docker/networksimulator/txblaster.py diff --git a/docker/networksimulator/txblaster.py b/docker/networksimulator/txblaster.py old mode 100644 new mode 100755 index 963df3dc1..1e735d8c4 --- a/docker/networksimulator/txblaster.py +++ b/docker/networksimulator/txblaster.py @@ -65,7 +65,7 @@ def generate_accounts(self, num_accounts: int, menmonic: str, fund_value: int): tx_hashes.append(tx_hash) accounts.append(acc) for tx_hash in tx_hashes: - self.web3.eth.wait_for_transaction_receipt(tx_hash) + self.web3.eth.wait_for_transaction_receipt(tx_hash, timeout=60000) return accounts def run_transactions(self, private_key, args): @@ -104,7 +104,7 @@ def run_transactions(self, private_key, args): continue start_time = time() - self.web3.eth.wait_for_transaction_receipt(tx_hash) + self.web3.eth.wait_for_transaction_receipt(tx_hash, timeout=60000) logging.info("tx confirmed tx_receipt=%s time=%f", tx_hash.hex(), time() - start_time) def sig_int(self, signum, frame): From 08cc2e9e90e03efdbd2ba7a4bc7f2be3aa42ee11 Mon Sep 17 00:00:00 2001 From: Nicholas Pettas Date: Fri, 29 Mar 2024 10:39:35 -0700 Subject: [PATCH 4/7] add dotenv dep to networksimulator --- docker/networksimulator/requirements.txt | 1 + 1 file changed, 1 insertion(+) diff --git a/docker/networksimulator/requirements.txt b/docker/networksimulator/requirements.txt index 59862a5d1..932187990 100644 --- a/docker/networksimulator/requirements.txt +++ b/docker/networksimulator/requirements.txt @@ -1,2 +1,3 @@ jinja2 web3 +dotenv From 739fd71276dc677d34ce0c8b65799559b24f77f4 Mon Sep 17 00:00:00 2001 From: Nicholas Pettas Date: Fri, 29 Mar 2024 10:46:24 -0700 Subject: [PATCH 5/7] add more debugs and metrics --- .run/testnet.run.xml | 12 ----------- gossip/emitter/txs.go | 40 ++++++++++++++++++++++++++++++++++-- gossip/emitter/validators.go | 11 ++++++++++ 3 files changed, 49 insertions(+), 14 deletions(-) delete mode 100644 .run/testnet.run.xml diff --git a/.run/testnet.run.xml b/.run/testnet.run.xml deleted file mode 100644 index b41aa3c23..000000000 --- a/.run/testnet.run.xml +++ /dev/null @@ -1,12 +0,0 @@ - - - - - - - - - - - - \ No newline at end of file diff --git a/gossip/emitter/txs.go b/gossip/emitter/txs.go index c2bc58594..1fbed276a 100644 --- a/gossip/emitter/txs.go +++ b/gossip/emitter/txs.go @@ -1,6 +1,8 @@ package emitter import ( + "github.com/ethereum/go-ethereum/log" + "github.com/ethereum/go-ethereum/metrics" "time" "github.com/Fantom-foundation/lachesis-base/common/bigendian" @@ -24,6 +26,18 @@ const ( TxTurnNonces = 32 ) +var ( + outOfGasPowerCounter = metrics.GetOrRegisterCounter("opera/txs/outOfGasPower", nil) + conflictedOriginatedCounter = metrics.GetOrRegisterCounter("opera/txs/conflictedOriginated", nil) + isMyTurnCounter = metrics.GetOrRegisterCounter("opera/txs/isMyTurn", nil) + isNotMyTurnCounter = metrics.GetOrRegisterCounter("opera/txs/isNotMyTurn", nil) + outdatedCounter = metrics.GetOrRegisterCounter("opera/txs/outdated", nil) + + gasPowerUsedGauge = metrics.GetOrRegisterGauge("opera/txs/gasPowerUsed", nil) + gasPowerLeftShortGauge = metrics.GetOrRegisterGauge("opera/txs/gasPowerLeftShort", nil) + gasPowerLeftLongGauge = metrics.GetOrRegisterGauge("opera/txs/gasPowerLeftLong", nil) +) + func max64(a, b uint64) uint64 { if a > b { return a @@ -123,6 +137,10 @@ func (em *Emitter) isMyTxTurn(txHash common.Hash, sender common.Address, account roundsHash := hash.Of(sender.Bytes(), bigendian.Uint64ToBytes(accountNonce/TxTurnNonces), epoch.Bytes()) rounds := utils.WeightedPermutation(roundIndex+1, validators.SortedWeights(), roundsHash) + + chosen := validators.GetID(idx.Validator(rounds[roundIndex])) + log.Debug("tx turn", "roundIndex", roundIndex, "rounds", rounds, "chosen", chosen, "me", me, "txTime", txTime, "now", now, "txHash", txHash, "sender", sender, "accountNonce", accountNonce, "epoch", epoch) + return validators.GetID(idx.Validator(rounds[roundIndex])) == me } @@ -143,6 +161,8 @@ func (em *Emitter) addTxs(e *inter.MutableEventPayload, sorted *types.Transactio } // check there's enough gas power to originate the transaction if tx.Gas() >= e.GasPowerLeft().Min() || e.GasPowerUsed()+tx.Gas() >= maxGasUsed { + log.Debug("not enough gas power to originate the transaction") + outOfGasPowerCounter.Inc(1) if params.TxGas >= e.GasPowerLeft().Min() || e.GasPowerUsed()+params.TxGas >= maxGasUsed { // stop if cannot originate even an empty transaction break @@ -152,22 +172,38 @@ func (em *Emitter) addTxs(e *inter.MutableEventPayload, sorted *types.Transactio } // check not conflicted with already originated txs (in any connected event) if em.originatedTxs.TotalOf(sender) != 0 { + conflictedOriginatedCounter.Inc(1) + log.Debug("conflicted with already originated txs") sorted.Pop() continue } // my turn, i.e. try to not include the same tx simultaneously by different validators if !em.isMyTxTurn(tx.Hash(), sender, tx.Nonce(), time.Now(), em.validators, e.Creator(), em.epoch) { sorted.Pop() + isNotMyTurnCounter.Inc(1) continue + } else { + isMyTurnCounter.Inc(1) } + // check transaction is not outdated if !em.world.TxPool.Has(tx.Hash()) { + outdatedCounter.Inc(1) sorted.Pop() + log.Debug("transaction is outdated") continue } + gasPowerUsed := e.GasPowerUsed() + tx.Gas() + gasPowerLeft := e.GasPowerLeft().Sub(tx.Gas()) + log.Debug("gas power", "used", gasPowerUsed, "left", gasPowerLeft) + + gasPowerUsedGauge.Update(int64(gasPowerUsed)) + gasPowerLeftShortGauge.Update(int64(gasPowerLeft.Gas[inter.ShortTermGas])) + gasPowerLeftLongGauge.Update(int64(gasPowerLeft.Gas[inter.LongTermGas])) + // add - e.SetGasPowerUsed(e.GasPowerUsed() + tx.Gas()) - e.SetGasPowerLeft(e.GasPowerLeft().Sub(tx.Gas())) + e.SetGasPowerUsed(gasPowerUsed) + e.SetGasPowerLeft(gasPowerLeft) e.SetTxs(append(e.Txs(), tx)) sorted.Shift() } diff --git a/gossip/emitter/validators.go b/gossip/emitter/validators.go index 0292c6e80..9fb79ba06 100644 --- a/gossip/emitter/validators.go +++ b/gossip/emitter/validators.go @@ -1,6 +1,8 @@ package emitter import ( + "github.com/ethereum/go-ethereum/log" + "github.com/ethereum/go-ethereum/metrics" "time" "github.com/Fantom-foundation/lachesis-base/inter/idx" @@ -12,6 +14,10 @@ const ( validatorChallenge = 4 * time.Second ) +var ( + offlineValidatorsGauge = metrics.GetOrRegisterGauge("opera/validators/offline", nil) +) + func (em *Emitter) recountConfirmingIntervals(validators *pos.Validators) { // validators with lower stake should emit fewer events to reduce network load // confirmingEmitInterval = piecefunc(totalStakeBeforeMe / totalStake) * MinEmitInterval @@ -55,6 +61,7 @@ func (em *Emitter) recheckChallenges() { recount := false for vid, challengeDeadline := range em.challenges { if now.After(challengeDeadline) { + log.Debug("validator is offline", "validator", vid) em.offlineValidators[vid] = true recount = true } @@ -63,4 +70,8 @@ func (em *Emitter) recheckChallenges() { em.recountConfirmingIntervals(em.validators) } em.prevRecheckedChallenges = now + + numOfOfflineVals := int64(len(em.offlineValidators)) + log.Debug("offline validators", "num", numOfOfflineVals) + offlineValidatorsGauge.Update(numOfOfflineVals) } From 0fd87f17d915b9a8ebdf7986df4be4ee80f705f3 Mon Sep 17 00:00:00 2001 From: Nicholas Pettas Date: Fri, 29 Mar 2024 11:54:40 -0700 Subject: [PATCH 6/7] bump network release --- version/version.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/version/version.go b/version/version.go index 8800cc18f..98fd919d8 100644 --- a/version/version.go +++ b/version/version.go @@ -13,7 +13,7 @@ func init() { params.VersionMajor = 1 // Major version component of the current release params.VersionMinor = 1 // Minor version component of the current release params.VersionPatch = 5 // Patch version component of the current release - params.VersionMeta = "rc.4" // Version metadata to append to the version string + params.VersionMeta = "rc.5" // Version metadata to append to the version string } func BigToString(b *big.Int) string { From 4c1224ed8056de6670cf42f7e778f5757341bcc1 Mon Sep 17 00:00:00 2001 From: Nicholas Pettas Date: Fri, 29 Mar 2024 16:54:34 -0700 Subject: [PATCH 7/7] add more metrics --- .gitignore | 1 + gossip/emitter/control.go | 12 ++++++++++++ gossip/emitter/emitter.go | 9 +++++++++ gossip/emitter/txs.go | 2 ++ 4 files changed, 24 insertions(+) diff --git a/.gitignore b/.gitignore index e6d8fa534..349a6477b 100644 --- a/.gitignore +++ b/.gitignore @@ -64,3 +64,4 @@ testnet.g dist/ /docker/networksimulator/docker-compose.yaml /docker/networksimulator/prometheus/prometheus.yml +/docker/networksimulator/.env diff --git a/gossip/emitter/control.go b/gossip/emitter/control.go index 5feebeacf..82f33870f 100644 --- a/gossip/emitter/control.go +++ b/gossip/emitter/control.go @@ -1,6 +1,7 @@ package emitter import ( + "github.com/ethereum/go-ethereum/metrics" "time" "github.com/Fantom-foundation/lachesis-base/emitter/ancestor" @@ -11,6 +12,11 @@ import ( "github.com/Fantom-foundation/go-opera/inter" ) +var ( + allowedToEmitCount = metrics.GetOrRegisterGauge("opera/control/allowedToEmit", nil) + notAllowedToEmitCount = metrics.GetOrRegisterGauge("opera/control/notAllowedToEmit", nil) +) + func scalarUpdMetric(diff idx.Event, weight pos.Weight, totalWeight pos.Weight) ancestor.Metric { return ancestor.Metric(scalarUpdMetricF(uint64(diff)*piecefunc.DecimalUnit)) * ancestor.Metric(weight) / ancestor.Metric(totalWeight) } @@ -73,6 +79,7 @@ func (em *Emitter) isAllowedToEmit(e inter.EventI, eTxs bool, metric ancestor.Me "power", e.GasPowerLeft().String(), "selfParentPower", selfParent.GasPowerLeft().String(), "stake%", 100*float64(em.validators.Get(e.Creator()))/float64(em.validators.TotalWeight())) + notAllowedToEmitCount.Inc(1) return false } } @@ -87,6 +94,7 @@ func (em *Emitter) isAllowedToEmit(e inter.EventI, eTxs bool, metric ancestor.Me if passedTime >= em.intervals.Max || passedBlocks >= maxBlocks*4/5 && metric >= piecefunc.DecimalUnit/2 || passedBlocks >= maxBlocks { + allowedToEmitCount.Inc(1) return true } } @@ -109,6 +117,7 @@ func (em *Emitter) isAllowedToEmit(e inter.EventI, eTxs bool, metric ancestor.Me if passedTime < em.intervals.Max && em.idle() && !eTxs { + notAllowedToEmitCount.Inc(1) return false } } @@ -119,15 +128,18 @@ func (em *Emitter) isAllowedToEmit(e inter.EventI, eTxs bool, metric ancestor.Me } if adjustedPassedTime < em.intervals.Min && !em.idle() { + notAllowedToEmitCount.Inc(1) return false } if adjustedPassedIdleTime < em.intervals.Confirming && !em.idle() && !eTxs { + notAllowedToEmitCount.Inc(1) return false } } + allowedToEmitCount.Inc(1) return true } diff --git a/gossip/emitter/emitter.go b/gossip/emitter/emitter.go index 873ec200c..6a99b8f27 100644 --- a/gossip/emitter/emitter.go +++ b/gossip/emitter/emitter.go @@ -31,6 +31,9 @@ const ( ) var eventCounter = metrics.GetOrRegisterCounter("opera/events", nil) +var callCreatedCounter = metrics.GetOrRegisterCounter("opera/events/callCreated", nil) +var callEmitCounter = metrics.GetOrRegisterCounter("opera/events/callEmit", nil) +var worldBusyGauge = metrics.GetOrRegisterGauge("opera/events/worldBusy", nil) type Emitter struct { config Config @@ -189,7 +192,10 @@ func (em *Emitter) tick() { em.busyRate.Mark(1) } if em.world.IsBusy() { + worldBusyGauge.Update(1) return + } else { + worldBusyGauge.Update(0) } em.recheckChallenges() @@ -233,6 +239,8 @@ func (em *Emitter) EmitEvent() (*inter.EventPayload, error) { // short circuit if not a validator return nil, nil } + callEmitCounter.Inc(1) + sortedTxs := em.getSortedTxs() if em.world.IsBusy() { @@ -295,6 +303,7 @@ func (em *Emitter) createEvent(sortedTxs *types.TransactionsByPriceAndNonce) (*i if !em.isValidator() { return nil, nil } + callCreatedCounter.Inc(1) if synced := em.logSyncStatus(em.isSyncedToEmit()); !synced { // I'm reindexing my old events, so don't create events until connect all the existing self-events diff --git a/gossip/emitter/txs.go b/gossip/emitter/txs.go index 1fbed276a..7ba0df0d9 100644 --- a/gossip/emitter/txs.go +++ b/gossip/emitter/txs.go @@ -32,6 +32,7 @@ var ( isMyTurnCounter = metrics.GetOrRegisterCounter("opera/txs/isMyTurn", nil) isNotMyTurnCounter = metrics.GetOrRegisterCounter("opera/txs/isNotMyTurn", nil) outdatedCounter = metrics.GetOrRegisterCounter("opera/txs/outdated", nil) + invalidTxCounter = metrics.GetOrRegisterCounter("opera/txs/invalidTxCounter", nil) gasPowerUsedGauge = metrics.GetOrRegisterGauge("opera/txs/gasPowerUsed", nil) gasPowerLeftShortGauge = metrics.GetOrRegisterGauge("opera/txs/gasPowerLeftShort", nil) @@ -156,6 +157,7 @@ func (em *Emitter) addTxs(e *inter.MutableEventPayload, sorted *types.Transactio sender, _ := types.Sender(em.world.TxSigner, tx) // check transaction epoch rules if epochcheck.CheckTxs(types.Transactions{tx}, rules) != nil { + invalidTxCounter.Inc(1) sorted.Pop() continue }