Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improve logging at SendMsgs and GetMsgResult #44

Merged
merged 6 commits into from
May 28, 2024
+103 −34
Merged

Improve logging at SendMsgs and GetMsgResult #44

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
6 commits
Select commit Hold shift + click to select a range
5152347
improve logging at SendMsgs and GetMsgResult
siburu May 23, 2024
f0ac44f
output raw error data in error logs even if revert reason isn't avail…
siburu May 23, 2024
5178fa5
marshal tx for logging only when SendTx succeeds
siburu May 23, 2024
744dcb9
use slog.Logger.With for cleaning up logging code in SendMsgs
siburu May 24, 2024
a30383b
add "msg_type" log attribute in SendMsgs
siburu May 24, 2024
71c6368
avoid outputing an empty string as "revert_reason" to error logs
siburu May 26, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
15 changes: 15 additions & 0 deletions pkg/relay/ethereum/log.go
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,15 @@
package ethereum

const (
logAttrMsgIndex = "msg_index"
logAttrMsgType = "msg_type"
logAttrRevertReason = "revert_reason"
logAttrRawErrorData = "raw_error_data"
logAttrRawTxData = "raw_tx_data"
logAttrTxHash = "tx_hash"
logAttrBlockHash = "block_hash"
logAttrBlockNumber = "block_number"
logAttrTxIndex = "tx_index"
logAttrEstimatedGas = "estimated_gas"
logAttrMaxGasLimit = "max_gas_limit"
)
122 changes: 88 additions & 34 deletions pkg/relay/ethereum/tx.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -36,61 +36,109 @@ func (c *Chain) SendMsgs(msgs []sdk.Msg) ([]core.MsgID, error) {
logger := c.GetChainLogger()
var msgIDs []core.MsgID
for i, msg := range msgs {
var (
tx *gethtypes.Transaction
err error
)
logger := &log.RelayLogger{Logger: logger.With(
logAttrMsgIndex, i,
logAttrMsgType, fmt.Sprintf("%T", msg),
)}

opts, err := c.TxOpts(ctx)
if err != nil {
return nil, err
}
opts.GasLimit = math.MaxUint64
opts.NoSend = true
tx, err = c.SendTx(opts, msg, skipUpdateClientCommitment)
if err != nil {
logger.Error("failed to send msg / NoSend: true", err, "msg_index", i)
return nil, err
}
estimatedGas, err := c.client.EstimateGasFromTx(ctx, tx)
if err != nil {
revertReason, rawErrorData, err2 := c.getRevertReasonFromEstimateGas(err)
if err2 != nil {
logger.Error("failed to get revert reason", err2, "msg_index", i)

// gas estimation
{
logger := &log.RelayLogger{Logger: logger.Logger}

opts.GasLimit = math.MaxUint64
opts.NoSend = true
tx, err := c.SendTx(opts, msg, skipUpdateClientCommitment)
if err != nil {
logger.Error("failed to build tx for gas estimation", err)
return nil, err
}

logger.Error("failed to estimate gas", err, "revert_reason", revertReason, "raw_error_data", hex.EncodeToString(rawErrorData), "msg_index", i)
return nil, err
}
txGasLimit := estimatedGas * c.Config().GasEstimateRate.Numerator / c.Config().GasEstimateRate.Denominator
if txGasLimit > c.Config().MaxGasLimit {
logger.Warn("estimated gas exceeds max gas limit", "estimated_gas", txGasLimit, "max_gas_limit", c.Config().MaxGasLimit, "msg_index", i)
txGasLimit = c.Config().MaxGasLimit
if rawTxData, err := tx.MarshalBinary(); err != nil {
logger.Error("failed to encode tx", err)
} else {
logger.Logger = logger.With(logAttrRawTxData, hex.EncodeToString(rawTxData))
}

estimatedGas, err := c.client.EstimateGasFromTx(ctx, tx)
if err != nil {
if revertReason, rawErrorData, err := c.getRevertReasonFromEstimateGas(err); err != nil {
// Raw error data may be available even if revert reason isn't available.
logger.Logger = logger.With(logAttrRawErrorData, hex.EncodeToString(rawErrorData))
logger.Error("failed to get revert reason", err)
} else {
logger.Logger = logger.With(
logAttrRawErrorData, hex.EncodeToString(rawErrorData),
logAttrRevertReason, revertReason,
)
}

logger.Error("failed to estimate gas", err)
return nil, err
}

txGasLimit := estimatedGas * c.Config().GasEstimateRate.Numerator / c.Config().GasEstimateRate.Denominator
if txGasLimit > c.Config().MaxGasLimit {
logger.Warn("estimated gas exceeds max gas limit",
logAttrEstimatedGas, txGasLimit,
logAttrMaxGasLimit, c.Config().MaxGasLimit,
)
txGasLimit = c.Config().MaxGasLimit
}
opts.GasLimit = txGasLimit
}
opts.GasLimit = txGasLimit

opts.NoSend = false
tx, err = c.SendTx(opts, msg, skipUpdateClientCommitment)
tx, err := c.SendTx(opts, msg, skipUpdateClientCommitment)
if err != nil {
logger.Error("failed to send msg / NoSend: false", err, "msg_index", i)
logger.Error("failed to send msg", err)
return nil, err
} else {
logger.Logger = logger.With(logAttrTxHash, tx.Hash())
}

if rawTxData, err := tx.MarshalBinary(); err != nil {
logger.Error("failed to encode tx", err)
} else {
logger.Logger = logger.With(logAttrRawTxData, hex.EncodeToString(rawTxData))
}

receipt, err := c.client.WaitForReceiptAndGet(ctx, tx.Hash())
if err != nil {
logger.Error("failed to get receipt", err, "msg_index", i, "tx_hash", tx.Hash())
logger.Error("failed to get receipt", err)
return nil, err
} else {
logger.Logger = logger.With(
logAttrBlockHash, receipt.BlockHash,
logAttrBlockNumber, receipt.BlockNumber.Uint64(),
logAttrTxIndex, receipt.TransactionIndex,
)
}

if receipt.Status == gethtypes.ReceiptStatusFailed {
revertReason, rawErrorData, err2 := c.getRevertReasonFromReceipt(ctx, receipt)
if err2 != nil {
logger.Error("failed to get revert reason", err2, "msg_index", i, "tx_hash", tx.Hash())
if revertReason, rawErrorData, err := c.getRevertReasonFromReceipt(ctx, receipt); err != nil {
// Raw error data may be available even if revert reason isn't available.
logger.Logger = logger.With(logAttrRawErrorData, hex.EncodeToString(rawErrorData))
logger.Error("failed to get revert reason", err)
} else {
logger.Logger = logger.With(
logAttrRawErrorData, hex.EncodeToString(rawErrorData),
logAttrRevertReason, revertReason,
)
}

err := fmt.Errorf("tx execution reverted: revertReason=%s, rawErrorData=%x, msgIndex=%d, txHash=%s", revertReason, rawErrorData, i, tx.Hash())
logger.Error("tx execution reverted", err, "revert_reason", revertReason, "raw_error_data", hex.EncodeToString(rawErrorData), "msg_index", i, "tx_hash", tx.Hash())
err := errors.New("tx execution reverted")
logger.Error("tx execution reverted", err)
return nil, err
}
logger.Info("successfully sent tx")
if c.msgEventListener != nil {
if err := c.msgEventListener.OnSentMsg([]sdk.Msg{msg}); err != nil {
logger.Error("failed to OnSendMsg call", err, "msg_index", i, "tx_hash", tx.Hash())
logger.Error("failed to OnSendMsg call", err)
}
}
msgIDs = append(msgIDs, NewMsgID(tx.Hash()))
Expand All @@ -116,7 +164,13 @@ func (c *Chain) GetMsgResult(id core.MsgID) (core.MsgResult, error) {
}
revertReason, rawErrorData, err := c.getRevertReasonFromReceipt(ctx, receipt)
if err != nil {
logger.Error("failed to get revert reason", err, "raw_error_data", hex.EncodeToString(rawErrorData), "tx_hash", msgID.TxHashHex)
logger.Error("failed to get revert reason", err,
logAttrRawErrorData, hex.EncodeToString(rawErrorData),
logAttrTxHash, msgID.TxHashHex,
logAttrBlockHash, receipt.BlockHash.Hex(),
logAttrBlockNumber, receipt.BlockNumber.Uint64(),
logAttrTxIndex, receipt.TransactionIndex,
)
}
return c.makeMsgResultFromReceipt(&receipt.Receipt, revertReason)
}
Expand Down