From 7d92da4d0daad3f5e9b4afa882273c31028ef2f3 Mon Sep 17 00:00:00 2001 From: Vitaly Drogan Date: Wed, 28 Sep 2022 19:23:26 +0300 Subject: [PATCH] better logs (#36) * miner logs * builder logs --- builder/builder.go | 7 ++----- miner/algo_common.go | 8 ++++---- miner/algo_greedy.go | 6 +++--- miner/worker.go | 20 +++++--------------- 4 files changed, 14 insertions(+), 27 deletions(-) diff --git a/builder/builder.go b/builder/builder.go index ceb5732a5e16..0272ddf39c17 100644 --- a/builder/builder.go +++ b/builder/builder.go @@ -92,7 +92,6 @@ func (b *Builder) Stop() error { } func (b *Builder) onSealedBlock(block *types.Block, bundles []types.SimulatedBundle, proposerPubkey boostTypes.PublicKey, proposerFeeRecipient boostTypes.Address, attrs *BuilderPayloadAttributes) error { - start := time.Now() executableData := beacon.BlockToExecutableData(block) payload, err := executableDataToExecutionPayload(executableData) if err != nil { @@ -137,11 +136,9 @@ func (b *Builder) onSealedBlock(block *types.Block, bundles []types.SimulatedBun if err != nil { log.Error("could not submit block", "err", err, "bundles", len(bundles)) return err - } else { - log.Info("could submit block", "bundles", len(bundles)) } - log.Info("submitted block", "header", block.Header(), "bid", blockBidMsg, "time", time.Since(start)) + log.Info("submitted block", "slot", blockBidMsg.Slot, "value", blockBidMsg.Value.String(), "parent", blockBidMsg.ParentHash, "hash", block.Hash(), "bundles", len(bundles)) return nil } @@ -172,7 +169,7 @@ func (b *Builder) OnPayloadAttribute(attrs *BuilderPayloadAttributes) error { parentBlock := b.eth.GetBlockByHash(attrs.HeadHash) if parentBlock == nil { - log.Info("Block hash not found in blocktree", "head block hash", attrs.HeadHash) + log.Warn("Block hash not found in blocktree", "head block hash", attrs.HeadHash) return errors.New("parent block not found in blocktree") } diff --git a/miner/algo_common.go b/miner/algo_common.go index d6c3f503922c..db85457ce0e3 100644 --- a/miner/algo_common.go +++ b/miner/algo_common.go @@ -174,7 +174,7 @@ func (envDiff *environmentDiff) commitTx(tx *types.Transaction, chData chainData default: // Strange error, discard the transaction and get the next in line (note, the // nonce-too-high clause will prevent us from executing in vain). - log.Debug("Transaction failed, account skipped", "hash", tx.Hash(), "err", err) + log.Trace("Transaction failed, account skipped", "hash", tx.Hash(), "err", err) return nil, shiftTx, err } } @@ -231,12 +231,12 @@ func (envDiff *environmentDiff) commitBundle(bundle *types.SimulatedBundle, chDa receipt, _, err := tmpEnvDiff.commitTx(tx, chData) if err != nil { - log.Debug("Bundle tx error", "bundle", bundle.OriginalBundle.Hash, "tx", tx.Hash(), "err", err) + log.Trace("Bundle tx error", "bundle", bundle.OriginalBundle.Hash, "tx", tx.Hash(), "err", err) return err } if receipt.Status != types.ReceiptStatusSuccessful && !bundle.OriginalBundle.RevertingHash(tx.Hash()) { - log.Debug("Bundle tx failed", "bundle", bundle.OriginalBundle.Hash, "tx", tx.Hash(), "err", err) + log.Trace("Bundle tx failed", "bundle", bundle.OriginalBundle.Hash, "tx", tx.Hash(), "err", err) return errors.New("bundle tx revert") } @@ -256,7 +256,7 @@ func (envDiff *environmentDiff) commitBundle(bundle *types.SimulatedBundle, chDa bundleSimEffGP.Mul(bundleSimEffGP, big.NewInt(99)) if bundleSimEffGP.Cmp(bundleActualEffGP) == 1 { - log.Debug("Bundle underpays after inclusion", "bundle", bundle.OriginalBundle.Hash) + log.Trace("Bundle underpays after inclusion", "bundle", bundle.OriginalBundle.Hash) return errors.New("bundle underpays") } diff --git a/miner/algo_greedy.go b/miner/algo_greedy.go index 479254bf2686..d4912e4fa354 100644 --- a/miner/algo_greedy.go +++ b/miner/algo_greedy.go @@ -66,7 +66,7 @@ func (b *greedyBuilder) buildBlock(simBundles []types.SimulatedBundle, transacti } if err != nil { - log.Info("could not apply tx", "hash", order.Tx.Hash(), "err", err) + log.Trace("could not apply tx", "hash", order.Tx.Hash(), "err", err) continue } effGapPrice, err := order.Tx.EffectiveGasTip(env.header.BaseFee) @@ -79,11 +79,11 @@ func (b *greedyBuilder) buildBlock(simBundles []types.SimulatedBundle, transacti err := envDiff.commitBundle(bundle, b.chainData, b.interrupt) orders.Pop() if err != nil { - log.Info("Could not apply bundle", "bundle", bundle.OriginalBundle.Hash, "err", err) + log.Trace("Could not apply bundle", "bundle", bundle.OriginalBundle.Hash, "err", err) continue } - log.Info("Included bundle", "bundleEGP", bundle.MevGasPrice.String(), "gasUsed", bundle.TotalGasUsed, "ethToCoinbase", ethIntToFloat(bundle.TotalEth)) + log.Trace("Included bundle", "bundleEGP", bundle.MevGasPrice.String(), "gasUsed", bundle.TotalGasUsed, "ethToCoinbase", ethIntToFloat(bundle.TotalEth)) usedBundles = append(usedBundles, *bundle) } } diff --git a/miner/worker.go b/miner/worker.go index 81caf3d8f4a2..5957fe17151f 100644 --- a/miner/worker.go +++ b/miner/worker.go @@ -1382,30 +1382,25 @@ func (w *worker) fillTransactions(interrupt *int32, env *environment, validatorC if validatorCoinbase != nil && w.config.BuilderTxSigningKey != nil { builderCoinbaseBalanceAfter := env.state.GetBalance(w.coinbase) - log.Info("Before creating validator profit", "validatorCoinbase", validatorCoinbase.String(), "builderCoinbase", w.coinbase.String(), "builderCoinbaseBalanceBefore", builderCoinbaseBalanceBefore.String(), "builderCoinbaseBalanceAfter", builderCoinbaseBalanceAfter.String()) + log.Trace("Before creating validator profit", "validatorCoinbase", validatorCoinbase.String(), "builderCoinbase", w.coinbase.String(), "builderCoinbaseBalanceBefore", builderCoinbaseBalanceBefore.String(), "builderCoinbaseBalanceAfter", builderCoinbaseBalanceAfter.String()) profit := new(big.Int).Sub(builderCoinbaseBalanceAfter, builderCoinbaseBalanceBefore) env.gasPool.AddGas(paymentTxGas) if profit.Sign() == 1 { tx, err := w.createProposerPayoutTx(env, validatorCoinbase, profit) if err != nil { - log.Error("Proposer payout create tx failed", "err", err) return fmt.Errorf("proposer payout create tx failed - %v", err), nil } if tx != nil { - log.Info("Proposer payout create tx succeeded, proceeding to commit tx") _, err = w.commitTransaction(env, tx) if err != nil { - log.Error("Proposer payout commit tx failed", "hash", tx.Hash().String(), "err", err) return fmt.Errorf("proposer payout commit tx failed - %v", err), nil } - log.Info("Proposer payout commit tx succeeded", "hash", tx.Hash().String()) env.tcount++ } else { return errors.New("proposer payout create tx failed due to tx is nil"), nil } } else { - log.Warn("Proposer payout create tx failed due to not enough balance", "profit", profit.String()) return errors.New("proposer payout create tx failed due to not enough balance"), nil } } @@ -1452,35 +1447,30 @@ func (w *worker) fillTransactionsAlgoWorker(interrupt *int32, env *environment, start := time.Now() builder := newGreedyBuilder(w.chain, w.chainConfig, w.blockList, env, interrupt) newEnv, blockBundles := builder.buildBlock(bundlesToConsider, pending) - log.Debug("Build block", "time", time.Since(start), "gas used", newEnv.header.GasUsed) + log.Debug("Build block", "time", time.Since(start), "gasUsed", newEnv.header.GasUsed) *env = *newEnv if validatorCoinbase != nil && w.config.BuilderTxSigningKey != nil { builderCoinbaseBalanceAfter := env.state.GetBalance(w.coinbase) - log.Info("Before creating validator profit", "validatorCoinbase", validatorCoinbase.String(), "builderCoinbase", w.coinbase.String(), "builderCoinbaseBalanceBefore", builderCoinbaseBalanceBefore.String(), "builderCoinbaseBalanceAfter", builderCoinbaseBalanceAfter.String()) + log.Trace("Before creating validator profit", "validatorCoinbase", validatorCoinbase.String(), "builderCoinbase", w.coinbase.String(), "builderCoinbaseBalanceBefore", builderCoinbaseBalanceBefore.String(), "builderCoinbaseBalanceAfter", builderCoinbaseBalanceAfter.String()) profit := new(big.Int).Sub(builderCoinbaseBalanceAfter, builderCoinbaseBalanceBefore) env.gasPool.AddGas(params.TxGas) if profit.Sign() == 1 { tx, err := w.createProposerPayoutTx(env, validatorCoinbase, profit) if err != nil { - log.Error("Proposer payout create tx failed", "err", err) return fmt.Errorf("proposer payout create tx failed - %v", err), nil } if tx != nil { - log.Info("Proposer payout create tx succeeded, proceeding to commit tx") _, err = w.commitTransaction(env, tx) if err != nil { - log.Error("Proposer payout commit tx failed", "hash", tx.Hash().String(), "err", err) return fmt.Errorf("proposer payout commit tx failed - %v", err), nil } - log.Info("Proposer payout commit tx succeeded", "hash", tx.Hash().String()) env.tcount++ } else { return errors.New("proposer payout create tx failed due to tx is nil"), nil } } else { - log.Warn("Proposer payout create tx failed due to not enough balance", "profit", profit.String()) return errors.New("proposer payout create tx failed due to not enough balance"), nil } @@ -1509,7 +1499,7 @@ func (w *worker) generateWork(params *generateParams) (*types.Block, *big.Int, e if errors.Is(err, errBlockInterruptedByTimeout) { log.Warn("Block building is interrupted", "allowance", common.PrettyDuration(w.newpayloadTimeout)) } - log.Info("Filled block with transactions", "time", time.Since(start), "gas used", work.header.GasUsed, "txs", work.txs) + log.Debug("Filled block with transactions", "time", time.Since(start), "gas used", work.header.GasUsed, "txs", len(work.txs)) } block, err := w.engine.FinalizeAndAssemble(w.chain, work.header, work.state, work.txs, work.unclelist(), work.receipts, params.withdrawals) if err != nil { @@ -1936,7 +1926,7 @@ func (w *worker) createProposerPayoutTx(env *environment, recipient *common.Addr } gasPrice := new(big.Int).Set(env.header.BaseFee) chainId := w.chainConfig.ChainID - log.Debug("createProposerPayoutTx", "sender", sender, "chainId", chainId.String(), "nonce", nonce, "amount", amount.String(), "baseFee", env.header.BaseFee.String(), "fee", fee) + log.Trace("createProposerPayoutTx", "sender", sender, "chainId", chainId.String(), "nonce", nonce, "amount", amount.String(), "baseFee", env.header.BaseFee.String(), "fee", fee) tx := types.NewTransaction(nonce, *recipient, amount, paymentTxGas, gasPrice, nil) return types.SignTx(tx, types.LatestSignerForChainID(chainId), w.config.BuilderTxSigningKey) }