From 88be253cbecbdff40a45145872f9bf7db1f48325 Mon Sep 17 00:00:00 2001 From: Jun Kimura Date: Sun, 2 Jun 2024 21:00:03 +0900 Subject: [PATCH 1/3] add more context to the logger Signed-off-by: Jun Kimura --- relay/db.go | 9 +++--- relay/lcp.go | 75 ++++++++++++++++++++++++------------------------ relay/module.go | 4 ++- relay/prover.go | 16 ++++++++--- relay/restore.go | 5 ++-- 5 files changed, 58 insertions(+), 51 deletions(-) diff --git a/relay/db.go b/relay/db.go index 438b7fc..1c13d73 100644 --- a/relay/db.go +++ b/relay/db.go @@ -10,7 +10,6 @@ import ( "github.com/datachainlab/lcp-go/relay/enclave" "github.com/hyperledger-labs/yui-relayer/core" - "github.com/hyperledger-labs/yui-relayer/log" ) const ( @@ -74,7 +73,7 @@ func (pr *Prover) loadLastUnfinalizedEnclaveKey(context.Context) (*enclave.Encla } func (pr *Prover) saveFinalizedEnclaveKeyInfo(_ context.Context, eki *enclave.EnclaveKeyInfo) error { - log.GetLogger().Info("save finalized enclave key info") + pr.getLogger().Info("save finalized enclave key info") bz, err := json.Marshal(eki) if err != nil { return err @@ -83,7 +82,7 @@ func (pr *Prover) saveFinalizedEnclaveKeyInfo(_ context.Context, eki *enclave.En } func (pr *Prover) saveUnfinalizedEnclaveKeyInfo(_ context.Context, eki *enclave.EnclaveKeyInfo, msgID core.MsgID) error { - log.GetLogger().Info("save unfinalized enclave key info") + pr.getLogger().Info("save unfinalized enclave key info") msgIDBytes, err := pr.codec.MarshalInterface(msgID) if err != nil { return err @@ -100,7 +99,7 @@ func (pr *Prover) saveUnfinalizedEnclaveKeyInfo(_ context.Context, eki *enclave. func (pr *Prover) removeFinalizedEnclaveKeyInfo(context.Context) error { path := pr.lastEnclaveKeyInfoFilePath(true) - log.GetLogger().Info("remove finalized enclave key info", "path", path) + pr.getLogger().Info("remove finalized enclave key info", "path", path) if _, err := os.Stat(path); err != nil { if os.IsNotExist(err) { return nil @@ -112,7 +111,7 @@ func (pr *Prover) removeFinalizedEnclaveKeyInfo(context.Context) error { func (pr *Prover) removeUnfinalizedEnclaveKeyInfo(context.Context) error { path := pr.lastEnclaveKeyInfoFilePath(false) - log.GetLogger().Info("remove unfinalized enclave key info", "path", path) + pr.getLogger().Info("remove unfinalized enclave key info", "path", path) if _, err := os.Stat(path); err != nil { if os.IsNotExist(err) { return nil diff --git a/relay/lcp.go b/relay/lcp.go index 5488a32..4fd3a27 100644 --- a/relay/lcp.go +++ b/relay/lcp.go @@ -12,7 +12,6 @@ import ( ibcexported "github.com/cosmos/ibc-go/v8/modules/core/exported" mapset "github.com/deckarep/golang-set/v2" "github.com/hyperledger-labs/yui-relayer/core" - "github.com/hyperledger-labs/yui-relayer/log" oias "github.com/oasisprotocol/oasis-core/go/common/sgx/ias" lcptypes "github.com/datachainlab/lcp-go/light-clients/lcp/types" @@ -27,7 +26,7 @@ func (pr *Prover) UpdateEKIfNeeded(ctx context.Context, verifier core.FinalityAw if err != nil { return err } - log.GetLogger().Info("loadEKIAndCheckUpdateNeeded", "updateNeeded", updateNeeded) + pr.getLogger().Info("loadEKIAndCheckUpdateNeeded", "updateNeeded", updateNeeded) if !updateNeeded { return nil } @@ -37,19 +36,19 @@ func (pr *Prover) UpdateEKIfNeeded(ctx context.Context, verifier core.FinalityAw pr.activeEnclaveKey, pr.unfinalizedMsgID = nil, nil - log.GetLogger().Info("need to get a new enclave key") + pr.getLogger().Info("need to get a new enclave key") eki, err := pr.selectNewEnclaveKey(ctx) if err != nil { return err } - log.GetLogger().Info("selected available enclave key", "eki", eki) + pr.getLogger().Info("selected available enclave key", "eki", eki) msgID, err := pr.registerEnclaveKey(verifier, eki) if err != nil { return err } - finalized, success, err := checkMsgStatus(verifier, msgID) + finalized, success, err := pr.checkMsgStatus(verifier, msgID) if err != nil { return err } else if !success { @@ -82,17 +81,17 @@ func (pr *Prover) checkEKIUpdateNeeded(ctx context.Context, timestamp time.Time, // TODO consider appropriate buffer time updateTime := attestationTime.Add(time.Duration(pr.config.KeyExpiration) * time.Second / 2) - log.GetLogger().Info("checkEKIUpdateNeeded", "enclave_key", hex.EncodeToString(eki.EnclaveKeyAddress), "now", timestamp.Unix(), "attestation_time", attestationTime.Unix(), "expiration", pr.config.KeyExpiration, "update_time", updateTime.Unix()) + pr.getLogger().Info("checkEKIUpdateNeeded", "enclave_key", hex.EncodeToString(eki.EnclaveKeyAddress), "now", timestamp.Unix(), "attestation_time", attestationTime.Unix(), "expiration", pr.config.KeyExpiration, "update_time", updateTime.Unix()) // For now, a half of expiration is used as a buffer time if timestamp.After(updateTime) { - log.GetLogger().Info("checkEKIUpdateNeeded: enclave key is expired", "enclave_key", hex.EncodeToString(eki.EnclaveKeyAddress)) + pr.getLogger().Info("checkEKIUpdateNeeded: enclave key is expired", "enclave_key", hex.EncodeToString(eki.EnclaveKeyAddress)) return true } // check if the enclave key is still available in the LCP service _, err := pr.lcpServiceClient.EnclaveKey(ctx, &enclave.QueryEnclaveKeyRequest{EnclaveKeyAddress: eki.EnclaveKeyAddress}) if err != nil { - log.GetLogger().Warn("checkEKIUpdateNeeded: enclave key not found", "enclave_key", hex.EncodeToString(eki.EnclaveKeyAddress), "error", err) + pr.getLogger().Warn("checkEKIUpdateNeeded: enclave key not found", "enclave_key", hex.EncodeToString(eki.EnclaveKeyAddress), "error", err) return true } return false @@ -103,7 +102,7 @@ func (pr *Prover) checkEKIUpdateNeeded(ctx context.Context, timestamp time.Time, // finalized: true if the msg is finalized // success: true if the msg is successfully executed in the origin chain // error: non-nil if the msg may not exist in the origin chain -func checkMsgStatus(verifier core.FinalityAwareChain, msgID core.MsgID) (bool, bool, error) { +func (pr *Prover) checkMsgStatus(verifier core.FinalityAwareChain, msgID core.MsgID) (bool, bool, error) { lfHeader, err := verifier.GetLatestFinalizedHeader() if err != nil { return false, false, err @@ -112,7 +111,7 @@ func checkMsgStatus(verifier core.FinalityAwareChain, msgID core.MsgID) (bool, b if err != nil { return false, false, err } else if ok, failureReason := msgRes.Status(); !ok { - log.GetLogger().Warn("msg execution failed", "msg_id", msgID.String(), "reason", failureReason) + pr.getLogger().Warn("msg execution failed", "msg_id", msgID.String(), "reason", failureReason) return false, false, nil } return msgRes.BlockHeight().LTE(lfHeader.GetHeight()), true, nil @@ -128,23 +127,23 @@ func (pr *Prover) loadEKIAndCheckUpdateNeeded(ctx context.Context, verifier core // 2: load the last finalized enclave key if exists // 3: select a new enclave key from the LCP service (i.e. return true) - log.GetLogger().Info("no active enclave key in memory") + pr.getLogger().Info("no active enclave key in memory") if eki, msgID, err := pr.loadLastUnfinalizedEnclaveKey(ctx); err == nil { - log.GetLogger().Info("load last unfinalized enclave key into memory") + pr.getLogger().Info("load last unfinalized enclave key into memory") pr.activeEnclaveKey = eki pr.unfinalizedMsgID = msgID } else if errors.Is(err, ErrEnclaveKeyInfoNotFound) { - log.GetLogger().Info("no unfinalized enclave key info found") + pr.getLogger().Info("no unfinalized enclave key info found") eki, err := pr.loadLastFinalizedEnclaveKey(ctx) if err != nil { if errors.Is(err, ErrEnclaveKeyInfoNotFound) { - log.GetLogger().Info("no enclave key info found") + pr.getLogger().Info("no enclave key info found") return true, nil } return false, err } - log.GetLogger().Info("load last finalized enclave key into memory") + pr.getLogger().Info("load last finalized enclave key into memory") pr.activeEnclaveKey = eki pr.unfinalizedMsgID = nil } else { @@ -154,46 +153,46 @@ func (pr *Prover) loadEKIAndCheckUpdateNeeded(ctx context.Context, verifier core // finalized enclave key if pr.unfinalizedMsgID == nil { - log.GetLogger().Info("active enclave key is finalized") + pr.getLogger().Info("active enclave key is finalized") // check if the enclave key is still available in the LCP service and not expired return pr.checkEKIUpdateNeeded(ctx, now, pr.activeEnclaveKey), nil } // unfinalized enclave key - log.GetLogger().Info("active enclave key is unfinalized") + pr.getLogger().Info("active enclave key is unfinalized") if _, err := verifier.GetMsgResult(pr.unfinalizedMsgID); err != nil { // err means that the msg is not included in the latest block - log.GetLogger().Info("the msg is not included in the latest block", "msg_id", pr.unfinalizedMsgID.String(), "error", err) + pr.getLogger().Info("the msg is not included in the latest block", "msg_id", pr.unfinalizedMsgID.String(), "error", err) if err := pr.removeUnfinalizedEnclaveKeyInfo(ctx); err != nil { return false, err } return true, nil } - finalized, success, err := checkMsgStatus(verifier, pr.unfinalizedMsgID) - log.GetLogger().Info("check the unfinalized msg status", "msg_id", pr.unfinalizedMsgID.String(), "finalized", finalized, "success", success, "error", err) + finalized, success, err := pr.checkMsgStatus(verifier, pr.unfinalizedMsgID) + pr.getLogger().Info("check the unfinalized msg status", "msg_id", pr.unfinalizedMsgID.String(), "finalized", finalized, "success", success, "error", err) if err != nil { return false, err } else if !success { // tx is failed, so remove the unfinalized enclave key info - log.GetLogger().Warn("the msg execution failed", "msg_id", pr.unfinalizedMsgID.String()) + pr.getLogger().Warn("the msg execution failed", "msg_id", pr.unfinalizedMsgID.String()) if err := pr.removeUnfinalizedEnclaveKeyInfo(ctx); err != nil { return false, err } return true, nil } else if finalized { // tx is successfully executed and finalized - log.GetLogger().Info("the msg is finalized", "msg_id", pr.unfinalizedMsgID.String()) + pr.getLogger().Info("the msg is finalized", "msg_id", pr.unfinalizedMsgID.String()) if pr.checkEKIUpdateNeeded(ctx, now, pr.activeEnclaveKey) { return true, nil } - log.GetLogger().Info("save enclave key info as finalized", "enclave_key", hex.EncodeToString(pr.activeEnclaveKey.EnclaveKeyAddress)) + pr.getLogger().Info("save enclave key info as finalized", "enclave_key", hex.EncodeToString(pr.activeEnclaveKey.EnclaveKeyAddress)) if err := pr.saveFinalizedEnclaveKeyInfo(ctx, pr.activeEnclaveKey); err != nil { return false, err } - log.GetLogger().Info("remove old unfinalized enclave key info", "enclave_key", hex.EncodeToString(pr.activeEnclaveKey.EnclaveKeyAddress)) + pr.getLogger().Info("remove old unfinalized enclave key info", "enclave_key", hex.EncodeToString(pr.activeEnclaveKey.EnclaveKeyAddress)) if err := pr.removeUnfinalizedEnclaveKeyInfo(ctx); err != nil { return false, err } @@ -201,7 +200,7 @@ func (pr *Prover) loadEKIAndCheckUpdateNeeded(ctx context.Context, verifier core return false, nil } else { // tx is successfully executed but not finalized yet - log.GetLogger().Info("the msg is not finalized yet", "msg_id", pr.unfinalizedMsgID.String()) + pr.getLogger().Info("the msg is not finalized yet", "msg_id", pr.unfinalizedMsgID.String()) return pr.checkEKIUpdateNeeded(ctx, now, pr.activeEnclaveKey), nil } } @@ -224,15 +223,15 @@ func (pr *Prover) selectNewEnclaveKey(ctx context.Context) (*enclave.EnclaveKeyI return nil, err } if pr.checkEKIUpdateNeeded(ctx, time.Now(), eki) { - log.GetLogger().Info("the key is not allowed to use because of expiration", "enclave_key", hex.EncodeToString(eki.EnclaveKeyAddress)) + pr.getLogger().Info("the key is not allowed to use because of expiration", "enclave_key", hex.EncodeToString(eki.EnclaveKeyAddress)) continue } if !pr.validateISVEnclaveQuoteStatus(avr.ISVEnclaveQuoteStatus) { - log.GetLogger().Info("the key is not allowed to use because of ISVEnclaveQuoteStatus", "enclave_key", hex.EncodeToString(eki.EnclaveKeyAddress), "quote_status", avr.ISVEnclaveQuoteStatus) + pr.getLogger().Info("the key is not allowed to use because of ISVEnclaveQuoteStatus", "enclave_key", hex.EncodeToString(eki.EnclaveKeyAddress), "quote_status", avr.ISVEnclaveQuoteStatus) continue } if !pr.validateAdvisoryIDs(avr.AdvisoryIDs) { - log.GetLogger().Info("the key is not allowed to use because of advisory IDs", "enclave_key", hex.EncodeToString(eki.EnclaveKeyAddress), "advisory_ids", avr.AdvisoryIDs) + pr.getLogger().Info("the key is not allowed to use because of advisory IDs", "enclave_key", hex.EncodeToString(eki.EnclaveKeyAddress), "advisory_ids", avr.AdvisoryIDs) continue } return eki, nil @@ -282,7 +281,7 @@ func (pr *Prover) updateELC(elcClientID string, includeState bool) ([]*elc.MsgUp return nil, nil } - log.GetLogger().Info("try to setup headers", "elc_client_id", elcClientID, "current", clientState.GetLatestHeight(), "latest", latestHeader.GetHeight()) + pr.getLogger().Info("try to setup headers", "elc_client_id", elcClientID, "current", clientState.GetLatestHeight(), "latest", latestHeader.GetHeight()) // 2. query the header from the upstream chain @@ -364,15 +363,15 @@ func (pr *Prover) doCreateELC(elcClientID string, height uint64) (*CreateELCResu return nil, fmt.Errorf("height %v is greater than the latest height %v", height, latestHeight.GetRevisionHeight()) } h := clienttypes.NewHeight(latestHeight.GetRevisionNumber(), height) - log.GetLogger().Info("try to create ELC client", "client_id", elcClientID, "height", h) + pr.getLogger().Info("try to create ELC client", "client_id", elcClientID, "height", h) res, err := pr.createELC(elcClientID, h) if err != nil { return nil, err } else if res == nil { - log.GetLogger().Info("no need to create ELC client", "client_id", elcClientID) + pr.getLogger().Info("no need to create ELC client", "client_id", elcClientID) return &CreateELCResult{Created: false}, nil } - log.GetLogger().Info("created ELC client", "client_id", elcClientID, "height", h) + pr.getLogger().Info("created ELC client", "client_id", elcClientID, "height", h) // ensure the message is valid msg, err := lcptypes.EthABIDecodeHeaderedProxyMessage(res.Message) if err != nil { @@ -382,7 +381,7 @@ func (pr *Prover) doCreateELC(elcClientID string, height uint64) (*CreateELCResu if err != nil { return nil, err } - log.GetLogger().Info("created state", "post_height", m.PostHeight, "post_state_id", m.PostStateID.String(), "timestamp", m.Timestamp.String()) + pr.getLogger().Info("created state", "post_height", m.PostHeight, "post_state_id", m.PostStateID.String(), "timestamp", m.Timestamp.String()) return &CreateELCResult{ Created: true, Message: m, @@ -397,13 +396,13 @@ func (pr *Prover) doUpdateELC(elcClientID string, counterparty core.FinalityAwar if err := pr.UpdateEKIfNeeded(context.TODO(), counterparty); err != nil { return nil, err } - log.GetLogger().Info("try to update the ELC client", "elc_client_id", elcClientID) + pr.getLogger().Info("try to update the ELC client", "elc_client_id", elcClientID) updates, err := pr.updateELC(elcClientID, false) if err != nil { return nil, err } if len(updates) == 0 { - log.GetLogger().Info("no update is needed") + pr.getLogger().Info("no update is needed") return &UpdateELCResult{ Messages: []*lcptypes.UpdateStateProxyMessage{}, }, nil @@ -418,7 +417,7 @@ func (pr *Prover) doUpdateELC(elcClientID string, counterparty core.FinalityAwar if err != nil { return nil, err } - log.GetLogger().Info("updated state", "prev_height", msg.PrevHeight, "prev_state_id", msg.PrevStateID.String(), "post_height", msg.PostHeight, "post_state_id", msg.PostStateID.String(), "timestamp", msg.Timestamp.String()) + pr.getLogger().Info("updated state", "prev_height", msg.PrevHeight, "prev_state_id", msg.PrevStateID.String(), "post_height", msg.PostHeight, "post_state_id", msg.PostStateID.String(), "timestamp", msg.Timestamp.String()) msgs = append(msgs, msg) } return &UpdateELCResult{ @@ -469,11 +468,11 @@ func (pr *Prover) doQueryELC(elcClientID string) (*QueryELCResult, error) { consensusState ibcexported.ConsensusState ) if err := pr.codec.UnpackAny(r.ClientState, &clientState); err != nil { - log.GetLogger().Warn("failed to unpack client state", "error", err) + pr.getLogger().Warn("failed to unpack client state", "error", err) return &result, nil } if err := pr.codec.UnpackAny(r.ConsensusState, &consensusState); err != nil { - log.GetLogger().Warn("failed to unpack consensus state", "error", err) + pr.getLogger().Warn("failed to unpack consensus state", "error", err) return &result, nil } result.Decoded.ClientState = clientState diff --git a/relay/module.go b/relay/module.go index 382978a..6b7ae3f 100644 --- a/relay/module.go +++ b/relay/module.go @@ -6,13 +6,15 @@ import ( "github.com/spf13/cobra" ) +const ModuleName = "lcp-prover" + type Module struct{} var _ config.ModuleI = (*Module)(nil) // Name returns the name of the module func (Module) Name() string { - return "lcp" + return ModuleName } // RegisterInterfaces register the module interfaces to protobuf Any. diff --git a/relay/prover.go b/relay/prover.go index 72f50d2..01eaf50 100644 --- a/relay/prover.go +++ b/relay/prover.go @@ -102,7 +102,7 @@ func (pr *Prover) CreateInitialLightClientState(height exported.Height) (exporte if res, err := pr.createELC(pr.config.ElcClientId, height); err != nil { return nil, nil, err } else if res == nil { - log.GetLogger().Info("no need to create ELC", "client_id", pr.config.ElcClientId) + pr.getLogger().Info("no need to create ELC", "client_id", pr.config.ElcClientId) } clientState := &lcptypes.ClientState{ @@ -167,14 +167,14 @@ func (pr *Prover) SetupHeadersForUpdate(dstChain core.FinalityAwareChain, latest var updates []core.Header // NOTE: assume that the messages length and the signatures length are the same if pr.config.MessageAggregation { - log.GetLogger().Info("aggregateMessages", "num_messages", len(messages)) + pr.getLogger().Info("aggregateMessages", "num_messages", len(messages)) update, err := pr.aggregateMessages(messages, signatures, pr.activeEnclaveKey.EnclaveKeyAddress) if err != nil { return nil, err } updates = append(updates, update) } else { - log.GetLogger().Info("updateClient", "num_messages", len(messages)) + pr.getLogger().Info("updateClient", "num_messages", len(messages)) for i := 0; i < len(messages); i++ { updates = append(updates, &lcptypes.UpdateClientMessage{ ProxyMessage: messages[i], @@ -224,7 +224,7 @@ func (pr *Prover) aggregateMessages(messages [][]byte, signatures [][]byte, sign } else if n == 0 { return nil, fmt.Errorf("unexpected error: batches must not be empty") } else { - log.GetLogger().Info("aggregateMessages", "num_batches", n) + pr.getLogger().Info("aggregateMessages", "num_batches", n) } messages = nil signatures = nil @@ -317,3 +317,11 @@ func (pr *Prover) ProveState(ctx core.QueryContext, path string, value []byte) ( func (pr *Prover) ProveHostConsensusState(ctx core.QueryContext, height exported.Height, consensusState exported.ConsensusState) (proof []byte, err error) { return pr.originProver.ProveHostConsensusState(ctx, height, consensusState) } + +func (pr *Prover) getLogger() *log.RelayLogger { + logger := log.GetLogger().WithModule(ModuleName) + if pr.path == nil { + return logger + } + return logger.WithChain(pr.path.ChainID) +} diff --git a/relay/restore.go b/relay/restore.go index 3daf8a4..2b70cfc 100644 --- a/relay/restore.go +++ b/relay/restore.go @@ -11,7 +11,6 @@ import ( lcptypes "github.com/datachainlab/lcp-go/light-clients/lcp/types" "github.com/datachainlab/lcp-go/relay/elc" "github.com/hyperledger-labs/yui-relayer/core" - "github.com/hyperledger-labs/yui-relayer/log" ) func (pr *Prover) restoreELC(ctx context.Context, counterparty core.FinalityAwareChain, elcClientID string, height uint64) error { @@ -44,7 +43,7 @@ func (pr *Prover) restoreELC(ctx context.Context, counterparty core.FinalityAwar restoreHeight = clienttypes.NewHeight(cs.GetLatestHeight().GetRevisionNumber(), height) } - log.GetLogger().Info("try to restore ELC state", "height", restoreHeight) + pr.getLogger().Info("try to restore ELC state", "height", restoreHeight) counterpartyConsRes, err := counterparty.QueryClientConsensusState(core.NewQueryContext(context.TODO(), cplatestHeight), restoreHeight) if err != nil { @@ -119,7 +118,7 @@ func (pr *Prover) restoreELC(ctx context.Context, counterparty core.FinalityAwar return fmt.Errorf("unexpected height: expected %v, but got %v", restoreHeight, usm.PostHeight) } - log.GetLogger().Info("successfully restored ELC state", "client_id", elcClientID, "state_id", usm.PostStateID.String(), "height", usm.PostHeight) + pr.getLogger().Info("successfully restored ELC state", "client_id", elcClientID, "state_id", usm.PostStateID.String(), "height", usm.PostHeight) return nil } From afb3a926f5b1ac333812804a5b143fe26139aec4 Mon Sep 17 00:00:00 2001 From: Jun Kimura Date: Sun, 2 Jun 2024 23:02:42 +0900 Subject: [PATCH 2/3] add more context to errors Signed-off-by: Jun Kimura --- light-clients/lcp/types/message.go | 16 ++++----- relay/config.go | 8 +++-- relay/db.go | 40 ++++++++++++++-------- relay/lcp.go | 20 +++++------ relay/prover.go | 54 ++++++++++++++++-------------- relay/restore.go | 14 ++++---- 6 files changed, 86 insertions(+), 66 deletions(-) diff --git a/light-clients/lcp/types/message.go b/light-clients/lcp/types/message.go index 1c05948..78e2025 100644 --- a/light-clients/lcp/types/message.go +++ b/light-clients/lcp/types/message.go @@ -330,7 +330,7 @@ func EthABIDecodeCommitmentProof(bz []byte) (*CommitmentProof, error) { } v, err := unpacker.Unpack(bz) if err != nil { - return nil, err + return nil, fmt.Errorf("failed to unpack commitment proof: bz=%x %w", bz, err) } p := CommitmentProof(v[0].(struct { Message []byte `json:"message"` @@ -346,7 +346,7 @@ func EthABIDecodeHeaderedProxyMessage(bz []byte) (*HeaderedProxyMessage, error) } v, err := unpacker.Unpack(bz) if err != nil { - return nil, err + return nil, fmt.Errorf("failed to unpack headered message: bz=%x %w", bz, err) } p := v[0].(struct { Header [32]byte `json:"header"` @@ -431,7 +431,7 @@ func EthABIDecodeMisbehaviourProxyMessage(bz []byte) (*MisbehaviourProxyMessage, } v, err := unpacker.Unpack(bz) if err != nil { - return nil, err + return nil, fmt.Errorf("failed to unpack misbehaviourProxyMessage: bz=%x %w", bz, err) } p := v[0].(struct { PrevStates []struct { @@ -446,7 +446,7 @@ func EthABIDecodeMisbehaviourProxyMessage(bz []byte) (*MisbehaviourProxyMessage, }) cctx, err := EthABIDecodeValidationContext(p.Context) if err != nil { - return nil, err + return nil, fmt.Errorf("failed to decode validation context: bz=%x %w", p.Context, err) } var prevStates []struct { Height clienttypes.Height @@ -474,7 +474,7 @@ func EthABIDecodeValidationContext(bz []byte) (ValidationContext, error) { } v, err := unpacker.Unpack(bz) if err != nil { - return nil, err + return nil, fmt.Errorf("failed to unpack headered message context: bz=%x %w", bz, err) } p := v[0].(struct { Header [32]byte `json:"header"` @@ -500,14 +500,14 @@ func EthABIDecodeValidationContext(bz []byte) (ValidationContext, error) { func EthABIDecodeTrustingPeriodValidationContext(bz []byte) (*TrustingPeriodValidationContext, error) { if len(bz) != 64 { - return nil, fmt.Errorf("unexpected length of trusting period commitment context: %d", len(bz)) + return nil, fmt.Errorf("unexpected length of trusting period commitment context: bz=%x", bz) } unpacker := abi.Arguments{ {Type: trustingPeriodContextABI}, } v, err := unpacker.Unpack(bz) if err != nil { - return nil, err + return nil, fmt.Errorf("failed to unpack trusting period context: bz=%x %w", bz, err) } p := v[0].(struct { Timestamps [32]byte `json:"timestamps"` @@ -522,7 +522,7 @@ func EthABIDecodeVerifyMembershipProxyMessage(bz []byte) (*ELCVerifyMembershipMe } v, err := unpacker.Unpack(bz) if err != nil { - return nil, err + return nil, fmt.Errorf("failed to unpack verify membership message: bz=%x %w", bz, err) } p := v[0].(struct { Prefix []byte `json:"prefix"` diff --git a/relay/config.go b/relay/config.go index 8ef3007..7ce92b6 100644 --- a/relay/config.go +++ b/relay/config.go @@ -89,6 +89,10 @@ func (pc ProverConfig) Validate() error { } func decodeMrenclaveHex(s string) ([]byte, error) { - s = strings.ToLower(strings.TrimPrefix(s, "0x")) - return hex.DecodeString(s) + trimmed := strings.ToLower(strings.TrimPrefix(s, "0x")) + bz, err := hex.DecodeString(trimmed) + if err != nil { + return nil, fmt.Errorf("failed to decode MRENCLAVE: value=%v %w", s, err) + } + return bz, nil } diff --git a/relay/db.go b/relay/db.go index 1c13d73..1f01658 100644 --- a/relay/db.go +++ b/relay/db.go @@ -43,11 +43,11 @@ func (pr *Prover) loadLastFinalizedEnclaveKey(context.Context) (*enclave.Enclave if os.IsNotExist(err) { return nil, fmt.Errorf("%v not found: %w", path, ErrEnclaveKeyInfoNotFound) } - return nil, err + return nil, fmt.Errorf("failed to stat file: path=%v %w", path, err) } var eki enclave.EnclaveKeyInfo if err := json.Unmarshal(bz, &eki); err != nil { - return nil, err + return nil, fmt.Errorf("failed to unmarshal enclave key info: path=%v %w", path, err) } return &eki, nil } @@ -59,15 +59,15 @@ func (pr *Prover) loadLastUnfinalizedEnclaveKey(context.Context) (*enclave.Encla if os.IsNotExist(err) { return nil, nil, fmt.Errorf("%v not found: %w", path, ErrEnclaveKeyInfoNotFound) } - return nil, nil, err + return nil, nil, fmt.Errorf("failed to stat file: path=%v %w", path, err) } var ueki unfinalizedEKI if err := json.Unmarshal(bz, &ueki); err != nil { - return nil, nil, err + return nil, nil, fmt.Errorf("failed to unmarshal unfinalized enclave key info: %w", err) } var unfinalizedMsgID core.MsgID if err := pr.codec.UnmarshalInterface(ueki.MsgIDBytes, &unfinalizedMsgID); err != nil { - return nil, nil, err + return nil, nil, fmt.Errorf("failed to unmarshal msg id: value=%x %w", ueki.MsgIDBytes, err) } return ueki.Info, unfinalizedMsgID, nil } @@ -76,25 +76,31 @@ func (pr *Prover) saveFinalizedEnclaveKeyInfo(_ context.Context, eki *enclave.En pr.getLogger().Info("save finalized enclave key info") bz, err := json.Marshal(eki) if err != nil { - return err + return fmt.Errorf("failed to marshal enclave key info: %w", err) + } + if err := os.WriteFile(pr.lastEnclaveKeyInfoFilePath(true), bz, 0600); err != nil { + return fmt.Errorf("failed to write enclave key info: %w", err) } - return os.WriteFile(pr.lastEnclaveKeyInfoFilePath(true), bz, 0600) + return nil } func (pr *Prover) saveUnfinalizedEnclaveKeyInfo(_ context.Context, eki *enclave.EnclaveKeyInfo, msgID core.MsgID) error { pr.getLogger().Info("save unfinalized enclave key info") msgIDBytes, err := pr.codec.MarshalInterface(msgID) if err != nil { - return err + return fmt.Errorf("failed to marshal msg id: %w", err) } bz, err := json.Marshal(unfinalizedEKI{ Info: eki, MsgIDBytes: msgIDBytes, }) if err != nil { - return err + return fmt.Errorf("failed to marshal enclave key info: %w", err) + } + if err := os.WriteFile(pr.lastEnclaveKeyInfoFilePath(false), bz, 0600); err != nil { + return fmt.Errorf("failed to write enclave key info: %w", err) } - return os.WriteFile(pr.lastEnclaveKeyInfoFilePath(false), bz, 0600) + return nil } func (pr *Prover) removeFinalizedEnclaveKeyInfo(context.Context) error { @@ -104,9 +110,12 @@ func (pr *Prover) removeFinalizedEnclaveKeyInfo(context.Context) error { if os.IsNotExist(err) { return nil } - return err + return fmt.Errorf("failed to stat file: path=%v %w", path, err) + } + if err := os.Remove(path); err != nil { + return fmt.Errorf("failed to remove file: path=%v %w", path, err) } - return os.Remove(path) + return nil } func (pr *Prover) removeUnfinalizedEnclaveKeyInfo(context.Context) error { @@ -116,9 +125,12 @@ func (pr *Prover) removeUnfinalizedEnclaveKeyInfo(context.Context) error { if os.IsNotExist(err) { return nil } - return err + return fmt.Errorf("failed to stat file: path=%v %w", path, err) + } + if err := os.Remove(path); err != nil { + return fmt.Errorf("failed to remove file: path=%v %w", path, err) } - return os.Remove(path) + return nil } func (pr *Prover) removeEnclaveKeyInfos(ctx context.Context) error { diff --git a/relay/lcp.go b/relay/lcp.go index 4fd3a27..4c971d7 100644 --- a/relay/lcp.go +++ b/relay/lcp.go @@ -24,7 +24,7 @@ import ( func (pr *Prover) UpdateEKIfNeeded(ctx context.Context, verifier core.FinalityAwareChain) error { updateNeeded, err := pr.loadEKIAndCheckUpdateNeeded(ctx, verifier) if err != nil { - return err + return fmt.Errorf("failed loadEKIAndCheckUpdateNeeded: %w", err) } pr.getLogger().Info("loadEKIAndCheckUpdateNeeded", "updateNeeded", updateNeeded) if !updateNeeded { @@ -40,17 +40,17 @@ func (pr *Prover) UpdateEKIfNeeded(ctx context.Context, verifier core.FinalityAw eki, err := pr.selectNewEnclaveKey(ctx) if err != nil { - return err + return fmt.Errorf("failed selectNewEnclaveKey: %w", err) } pr.getLogger().Info("selected available enclave key", "eki", eki) msgID, err := pr.registerEnclaveKey(verifier, eki) if err != nil { - return err + return fmt.Errorf("failed registerEnclaveKey: %w", err) } finalized, success, err := pr.checkMsgStatus(verifier, msgID) if err != nil { - return err + return fmt.Errorf("failed checkMsgStatus: %w", err) } else if !success { return fmt.Errorf("msg(id=%v) execution failed", msgID) } @@ -363,15 +363,15 @@ func (pr *Prover) doCreateELC(elcClientID string, height uint64) (*CreateELCResu return nil, fmt.Errorf("height %v is greater than the latest height %v", height, latestHeight.GetRevisionHeight()) } h := clienttypes.NewHeight(latestHeight.GetRevisionNumber(), height) - pr.getLogger().Info("try to create ELC client", "client_id", elcClientID, "height", h) + pr.getLogger().Info("try to create ELC client", "elc_client_id", elcClientID, "height", h) res, err := pr.createELC(elcClientID, h) if err != nil { return nil, err } else if res == nil { - pr.getLogger().Info("no need to create ELC client", "client_id", elcClientID) + pr.getLogger().Info("no need to create ELC client", "elc_client_id", elcClientID) return &CreateELCResult{Created: false}, nil } - pr.getLogger().Info("created ELC client", "client_id", elcClientID, "height", h) + pr.getLogger().Info("created ELC client", "elc_client_id", elcClientID, "height", h) // ensure the message is valid msg, err := lcptypes.EthABIDecodeHeaderedProxyMessage(res.Message) if err != nil { @@ -408,14 +408,14 @@ func (pr *Prover) doUpdateELC(elcClientID string, counterparty core.FinalityAwar }, nil } var msgs []*lcptypes.UpdateStateProxyMessage - for _, update := range updates { + for i, update := range updates { commitment, err := lcptypes.EthABIDecodeHeaderedProxyMessage(update.Message) if err != nil { - return nil, err + return nil, fmt.Errorf("failed EthABIDecodeHeaderedProxyMessage: index=%v %w", i, err) } msg, err := commitment.GetUpdateStateProxyMessage() if err != nil { - return nil, err + return nil, fmt.Errorf("failed GetUpdateStateProxyMessage: index=%v %w", i, err) } pr.getLogger().Info("updated state", "prev_height", msg.PrevHeight, "prev_state_id", msg.PrevStateID.String(), "post_height", msg.PostHeight, "post_state_id", msg.PostStateID.String(), "timestamp", msg.Timestamp.String()) msgs = append(msgs, msg) diff --git a/relay/prover.go b/relay/prover.go index 01eaf50..ea74262 100644 --- a/relay/prover.go +++ b/relay/prover.go @@ -100,9 +100,9 @@ func (pr *Prover) GetChainID() string { // If `height` is nil, the latest finalized height is selected automatically. func (pr *Prover) CreateInitialLightClientState(height exported.Height) (exported.ClientState, exported.ConsensusState, error) { if res, err := pr.createELC(pr.config.ElcClientId, height); err != nil { - return nil, nil, err + return nil, nil, fmt.Errorf("failed to create ELC: %w", err) } else if res == nil { - pr.getLogger().Info("no need to create ELC", "client_id", pr.config.ElcClientId) + pr.getLogger().Info("no need to create ELC", "elc_client_id", pr.config.ElcClientId) } clientState := &lcptypes.ClientState{ @@ -133,7 +133,7 @@ func (pr *Prover) SetupHeadersForUpdate(dstChain core.FinalityAwareChain, latest headers, err := pr.originProver.SetupHeadersForUpdate(dstChain, latestFinalizedHeader) if err != nil { - return nil, err + return nil, fmt.Errorf("failed to setup headers for update: header=%v %w", latestFinalizedHeader, err) } if len(headers) == 0 { return nil, nil @@ -142,23 +142,24 @@ func (pr *Prover) SetupHeadersForUpdate(dstChain core.FinalityAwareChain, latest messages [][]byte signatures [][]byte ) - for _, h := range headers { + for i, h := range headers { anyHeader, err := clienttypes.PackClientMessage(h) if err != nil { - return nil, err + return nil, fmt.Errorf("failed to pack header: i=%v header=%v %w", i, h, err) } - res, err := pr.lcpServiceClient.UpdateClient(context.TODO(), &elc.MsgUpdateClient{ + m := elc.MsgUpdateClient{ ClientId: pr.config.ElcClientId, Header: anyHeader, IncludeState: false, Signer: pr.activeEnclaveKey.EnclaveKeyAddress, - }) + } + res, err := pr.lcpServiceClient.UpdateClient(context.TODO(), &m) if err != nil { - return nil, err + return nil, fmt.Errorf("failed to update ELC: i=%v elc_client_id=%v msg=%v %w", i, pr.config.ElcClientId, m, err) } // ensure the message is valid if _, err := lcptypes.EthABIDecodeHeaderedProxyMessage(res.Message); err != nil { - return nil, err + return nil, fmt.Errorf("failed to decode headered proxy message: i=%v message=%x %w", i, res.Message, err) } messages = append(messages, res.Message) signatures = append(signatures, res.Signature) @@ -167,7 +168,7 @@ func (pr *Prover) SetupHeadersForUpdate(dstChain core.FinalityAwareChain, latest var updates []core.Header // NOTE: assume that the messages length and the signatures length are the same if pr.config.MessageAggregation { - pr.getLogger().Info("aggregateMessages", "num_messages", len(messages)) + pr.getLogger().Info("aggregate messages", "num_messages", len(messages)) update, err := pr.aggregateMessages(messages, signatures, pr.activeEnclaveKey.EnclaveKeyAddress) if err != nil { return nil, err @@ -207,13 +208,14 @@ func (pr *Prover) aggregateMessages(messages [][]byte, signatures [][]byte, sign Signature: batches[0].Signatures[0], }, nil } else { - resp, err := pr.lcpServiceClient.AggregateMessages(context.TODO(), &elc.MsgAggregateMessages{ + m := elc.MsgAggregateMessages{ Signer: batches[0].Signer, Messages: batches[0].Messages, Signatures: batches[0].Signatures, - }) + } + resp, err := pr.lcpServiceClient.AggregateMessages(context.TODO(), &m) if err != nil { - return nil, err + return nil, fmt.Errorf("failed to aggregate messages: msg=%v %w", m, err) } return &lcptypes.UpdateClientMessage{ ProxyMessage: resp.Message, @@ -228,14 +230,15 @@ func (pr *Prover) aggregateMessages(messages [][]byte, signatures [][]byte, sign } messages = nil signatures = nil - for _, b := range batches { - resp, err := pr.lcpServiceClient.AggregateMessages(context.TODO(), &elc.MsgAggregateMessages{ + for i, b := range batches { + m := elc.MsgAggregateMessages{ Signer: b.Signer, Messages: b.Messages, Signatures: b.Signatures, - }) + } + resp, err := pr.lcpServiceClient.AggregateMessages(context.TODO(), &m) if err != nil { - return nil, err + return nil, fmt.Errorf("failed to aggregate messages: i=%v msg=%v %w", i, m, err) } messages = append(messages, resp.Message) signatures = append(signatures, resp.Signature) @@ -248,7 +251,7 @@ func splitIntoMultiBatch(messages [][]byte, signatures [][]byte, signer []byte, var currentMessages [][]byte var currentBatchStartIndex uint64 = 0 if messageBatchSize < 2 { - return nil, fmt.Errorf("messageBatchSize must be greater than 1") + return nil, fmt.Errorf("messageBatchSize must be greater than 1: messageBatchSize=%v", messageBatchSize) } for i := 0; i < len(messages); i++ { currentMessages = append(currentMessages, messages[i]) @@ -279,9 +282,9 @@ func (pr *Prover) CheckRefreshRequired(counterparty core.ChainInfoICS02Querier) func (pr *Prover) ProveState(ctx core.QueryContext, path string, value []byte) ([]byte, clienttypes.Height, error) { proof, proofHeight, err := pr.originProver.ProveState(ctx, path, value) if err != nil { - return nil, clienttypes.Height{}, err + return nil, clienttypes.Height{}, fmt.Errorf("failed originProver.ProveState: path=%v value=%x %w", path, value, err) } - res, err := pr.lcpServiceClient.VerifyMembership(ctx.Context(), &elc.MsgVerifyMembership{ + m := elc.MsgVerifyMembership{ ClientId: pr.config.ElcClientId, Prefix: []byte(exported.StoreKey), Path: path, @@ -289,17 +292,18 @@ func (pr *Prover) ProveState(ctx core.QueryContext, path string, value []byte) ( ProofHeight: proofHeight, Proof: proof, Signer: pr.activeEnclaveKey.EnclaveKeyAddress, - }) + } + res, err := pr.lcpServiceClient.VerifyMembership(ctx.Context(), &m) if err != nil { - return nil, clienttypes.Height{}, err + return nil, clienttypes.Height{}, fmt.Errorf("failed ELC's VerifyMembership: elc_client_id=%v msg=%v %w", pr.config.ElcClientId, m, err) } message, err := lcptypes.EthABIDecodeHeaderedProxyMessage(res.Message) if err != nil { - return nil, clienttypes.Height{}, err + return nil, clienttypes.Height{}, fmt.Errorf("failed to decode headered proxy message: message=%x %w", res.Message, err) } sc, err := message.GetVerifyMembershipProxyMessage() if err != nil { - return nil, clienttypes.Height{}, err + return nil, clienttypes.Height{}, fmt.Errorf("failed GetVerifyMembershipProxyMessage: message=%x %w", res.Message, err) } cp, err := lcptypes.EthABIEncodeCommitmentProof(&lcptypes.CommitmentProof{ Message: res.Message, @@ -307,7 +311,7 @@ func (pr *Prover) ProveState(ctx core.QueryContext, path string, value []byte) ( Signature: res.Signature, }) if err != nil { - return nil, clienttypes.Height{}, err + return nil, clienttypes.Height{}, fmt.Errorf("failed to encode commitment proof: %w", err) } return cp, sc.Height, nil } diff --git a/relay/restore.go b/relay/restore.go index 2b70cfc..1acec9a 100644 --- a/relay/restore.go +++ b/relay/restore.go @@ -18,7 +18,7 @@ func (pr *Prover) restoreELC(ctx context.Context, counterparty core.FinalityAwar if res, err := pr.lcpServiceClient.Client(ctx, &elc.QueryClientRequest{ ClientId: elcClientID, }); err != nil { - return err + return fmt.Errorf("failed to query ELC: elc_client_id=%v %w", elcClientID, err) } else if res.Found { return fmt.Errorf("client '%v' already exists", elcClientID) } @@ -29,11 +29,11 @@ func (pr *Prover) restoreELC(ctx context.Context, counterparty core.FinalityAwar } counterpartyClientRes, err := counterparty.QueryClientState(core.NewQueryContext(context.TODO(), cplatestHeight)) if err != nil { - return err + return fmt.Errorf("failed to query client state: height=%v %w", cplatestHeight, err) } var cs ibcexported.ClientState if err := pr.codec.UnpackAny(counterpartyClientRes.ClientState, &cs); err != nil { - return err + return fmt.Errorf("failed to unpack client state: client_state=%v %w", counterpartyClientRes.ClientState, err) } var restoreHeight ibcexported.Height @@ -51,7 +51,7 @@ func (pr *Prover) restoreELC(ctx context.Context, counterparty core.FinalityAwar } var cons ibcexported.ConsensusState if err := pr.codec.UnpackAny(counterpartyConsRes.ConsensusState, &cons); err != nil { - return err + return fmt.Errorf("failed to unpack consensus state: consensus_state=%v %w", counterpartyConsRes.ConsensusState, err) } clientState := cs.(*lcptypes.ClientState) @@ -77,7 +77,7 @@ func (pr *Prover) restoreELC(ctx context.Context, counterparty core.FinalityAwar originClientState, originConsensusState, err := pr.originProver.CreateInitialLightClientState(clientState.LatestHeight) if err != nil { - return err + return fmt.Errorf("failed to create initial light client state: height=%v %w", clientState.LatestHeight, err) } originAnyClientState, err := clienttypes.PackClientState(originClientState) if err != nil { @@ -98,7 +98,7 @@ func (pr *Prover) restoreELC(ctx context.Context, counterparty core.FinalityAwar Signer: tmpEKI.EnclaveKeyAddress, }) if err != nil { - return err + return fmt.Errorf("failed to create ELC client: elc_client_id=%v %w", elcClientID, err) } // Ensure the restored state is correct @@ -118,7 +118,7 @@ func (pr *Prover) restoreELC(ctx context.Context, counterparty core.FinalityAwar return fmt.Errorf("unexpected height: expected %v, but got %v", restoreHeight, usm.PostHeight) } - pr.getLogger().Info("successfully restored ELC state", "client_id", elcClientID, "state_id", usm.PostStateID.String(), "height", usm.PostHeight) + pr.getLogger().Info("successfully restored ELC state", "elc_client_id", elcClientID, "state_id", usm.PostStateID.String(), "height", usm.PostHeight) return nil } From 974f9c9d5f4cd74144db9c62e68d76765f443c18 Mon Sep 17 00:00:00 2001 From: Jun Kimura Date: Sun, 2 Jun 2024 23:37:05 +0900 Subject: [PATCH 3/3] update README Signed-off-by: Jun Kimura --- README.md | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/README.md b/README.md index 2e3e5b6..74b9a19 100644 --- a/README.md +++ b/README.md @@ -7,9 +7,9 @@ lcp-go includes the followings: ## Dependencies -- [lcp v0.2.6](https://github.com/datachainlab/lcp/releases/tag/v0.2.6) +- [lcp v0.2.8](https://github.com/datachainlab/lcp/releases/tag/v0.2.8) - [ibc-go v8.2](https://github.com/cosmos/ibc-go/releases/tag/v8.2.0) -- [yui-relayer v0.5.1](https://github.com/hyperledger-labs/yui-relayer/releases/tag/v0.5.1) +- [yui-relayer v0.5.3](https://github.com/hyperledger-labs/yui-relayer/releases/tag/v0.5.3) ## How to run tests