Callbacks Logs Cleanup - Pt 1 (#523)

Closes: #XXX

## Context and purpose of the change
Continuing the log cleanup

## Brief Changelog
* Cleaned up logs for Delegate, Undelegate, and Redemption callbacks
* Added `LogCallbackWithHostZone` helper function
* Campfire rule - misc cleanup/standardization across functions (e.g. variable naming)

## Author's Checklist

I have...

- [X] Run and PASSED locally all GAIA integration tests
- [ ] If the change is contentful, I either:
    - [ ] Added a new unit test OR 
    - [ ] Added test cases to existing unit tests
- [ ] OR this change is a trivial rework / code cleanup without any test coverage

If skipped any of the tests above, explain.


## Reviewers Checklist

*All items are required. Please add a note if the item is not applicable and please add
your handle next to the items reviewed if you only reviewed selected items.*

I have...

- [ ] reviewed state machine logic
- [ ] reviewed API design and naming
- [ ] manually tested (if applicable)
- [ ] confirmed the author wrote unit tests for new logic
- [ ] reviewed documentation exists and is accurate


## Documentation and Release Note

  - [ ] Does this pull request introduce a new feature or user-facing behavior changes? 
  - [ ] Is a relevant changelog entry added to the `Unreleased` section in `CHANGELOG.md`?
  - [ ] This pull request updates existing proto field values (and require a backend and frontend migration)? 
  - [ ] Does this pull request change existing proto field names (and require a frontend migration)?
  How is the feature or change documented? 
      - [ ] not applicable
      - [ ] jira ticket `XXX` 
      - [ ] specification (`x/<module>/spec/`) 
      - [ ] README.md 
      - [ ] not documented

dockernet/config.sh

@@ -18,7 +18,7 @@ KEYS_LOGS=$SCRIPT_DIR/logs/keys.log
 # List of hosts enabled 
 #  `start-docker` defaults to just GAIA if HOST_CHAINS is empty
 # `start-docker-all` always runs all hosts
-HOST_CHAINS=(GAIA) 
+HOST_CHAINS=() 
 
 if [[ "${ALL_HOST_CHAINS:-false}" == "true" ]]; then 
   HOST_CHAINS=(GAIA JUNO OSMO STARS)

utils/utils.go

@@ -45,12 +45,12 @@ func Min(a int, b int) int {
 }
 
 func StringMapKeys[V any](m map[string]V) []string {
-    keys := make([]string, 0, len(m))
-    for k := range m {
+	keys := make([]string, 0, len(m))
+	for k := range m {
 		keys = append(keys, k)
-    }
-    sort.Strings(keys)
-    return keys
+	}
+	sort.Strings(keys)
+	return keys
 }
 
 func Int32MapKeys[V any](m map[int32]V) []int32 {
@@ -62,7 +62,6 @@ func Int32MapKeys[V any](m map[int32]V) []int32 {
 	return keys
 }
 
-
 //==============================  ADDRESS VERIFICATION UTILS  ================================
 // ref: https://github.com/cosmos/cosmos-sdk/blob/b75c2ebcfab1a6b535723f1ac2889a2fc2509520/types/address.go#L177
 
@@ -205,14 +204,22 @@ func ConvertAddressToStrideAddress(address string) string {
 	return bech32Addr
 }
 
-// Returns a log string with a tab and chainId as the prefix
+// Returns a log string with a chainId and tab as the prefix
 // Ex:
 //   | COSMOSHUB-4   |   string
 func LogWithHostZone(chainId string, s string, a ...any) string {
 	msg := fmt.Sprintf(s, a...)
 	return fmt.Sprintf("|   %-13s |  %s", strings.ToUpper(chainId), msg)
 }
 
+// Returns a log string with a chain Id and callback as a prefix
+// Ex:
+//   | COSMOSHUB-4   |  DELEGATE CALLBACK  |  string
+func LogCallbackWithHostZone(chainId string, callbackId string, s string, a ...any) string {
+	msg := fmt.Sprintf(s, a...)
+	return fmt.Sprintf("|   %-13s |  %s CALLBACK  |  %s", strings.ToUpper(chainId), strings.ToUpper(callbackId), msg)
+}
+
 // Returns a log header string with a dash padding on either side
 // Ex:
 //  ------------------------------ string ------------------------------

x/records/keeper/epoch_unbonding_record.go

@@ -99,6 +99,7 @@ func (k Keeper) GetHostZoneUnbondingByChainId(ctx sdk.Context, epochNumber uint6
 	return &types.HostZoneUnbonding{}, false
 }
 
+// Adds a HostZoneUnbonding to an EpochUnbondingRecord
 func (k Keeper) AddHostZoneToEpochUnbondingRecord(ctx sdk.Context, epochNumber uint64, chainId string, hzu *types.HostZoneUnbonding) (val *types.EpochUnbondingRecord, success bool) {
 	epochUnbondingRecord, found := k.GetEpochUnbondingRecord(ctx, epochNumber)
 	if !found {
@@ -119,6 +120,7 @@ func (k Keeper) AddHostZoneToEpochUnbondingRecord(ctx sdk.Context, epochNumber u
 	return &epochUnbondingRecord, true
 }
 
+// Updates the status for a given host zone across relevant epoch unbonding record IDs
 func (k Keeper) SetHostZoneUnbondings(ctx sdk.Context, chainId string, epochUnbondingRecordIds []uint64, status types.HostZoneUnbonding_Status) error {
 	for _, epochUnbondingRecordId := range epochUnbondingRecordIds {
 		k.Logger(ctx).Info(fmt.Sprintf("Updating host zone unbondings on EpochUnbondingRecord %d to status %s", epochUnbondingRecordId, status.String()))

x/stakeibc/keeper/host_zone.go

@@ -10,6 +10,7 @@ import (
 	sdk "github.com/cosmos/cosmos-sdk/types"
 	sdkerrors "github.com/cosmos/cosmos-sdk/types/errors"
 
+	"github.com/Stride-Labs/stride/v4/utils"
 	"github.com/Stride-Labs/stride/v4/x/stakeibc/types"
 )
 
@@ -93,10 +94,12 @@ func (k Keeper) GetAllHostZone(ctx sdk.Context) (list []types.HostZone) {
 	return
 }
 
-func (k Keeper) AddDelegationToValidator(ctx sdk.Context, hostZone types.HostZone, validatorAddress string, amount sdk.Int) (success bool) {
+func (k Keeper) AddDelegationToValidator(ctx sdk.Context, hostZone types.HostZone, validatorAddress string, amount sdk.Int, callbackId string) (success bool) {
 	for _, validator := range hostZone.Validators {
 		if validator.Address == validatorAddress {
-			k.Logger(ctx).Info(fmt.Sprintf("Validator %s, Current Delegation: %v, Delegation Change: %v", validator.Address, validator.DelegationAmt, amount))
+			k.Logger(ctx).Info(utils.LogCallbackWithHostZone(hostZone.ChainId, callbackId,
+				"  Validator %s, Current Delegation: %v, Delegation Change: %v", validator.Address, validator.DelegationAmt, amount))
+
 			if amount.GTE(sdk.ZeroInt()) {
 				validator.DelegationAmt = validator.DelegationAmt.Add(amount)
 				return true
@@ -111,6 +114,7 @@ func (k Keeper) AddDelegationToValidator(ctx sdk.Context, hostZone types.HostZon
 			}
 		}
 	}
+
 	k.Logger(ctx).Error(fmt.Sprintf("Could not find validator %s on host zone %s", validatorAddress, hostZone.ChainId))
 	return false
 }

x/stakeibc/keeper/icacallbacks_delegate.go

@@ -5,6 +5,7 @@ import (
 
 	"github.com/spf13/cast"
 
+	"github.com/Stride-Labs/stride/v4/utils"
 	"github.com/Stride-Labs/stride/v4/x/icacallbacks"
 	recordstypes "github.com/Stride-Labs/stride/v4/x/records/types"
 	"github.com/Stride-Labs/stride/v4/x/stakeibc/types"
@@ -17,6 +18,7 @@ import (
 	"github.com/golang/protobuf/proto" //nolint:staticcheck
 )
 
+// Marshalls delegate callback arguments
 func (k Keeper) MarshalDelegateCallbackArgs(ctx sdk.Context, delegateCallback types.DelegateCallback) ([]byte, error) {
 	out, err := proto.Marshal(&delegateCallback)
 	if err != nil {
@@ -26,6 +28,7 @@ func (k Keeper) MarshalDelegateCallbackArgs(ctx sdk.Context, delegateCallback ty
 	return out, nil
 }
 
+// Unmarshalls delegate callback arguments into a DelegateCallback struct
 func (k Keeper) UnmarshalDelegateCallbackArgs(ctx sdk.Context, delegateCallback []byte) (*types.DelegateCallback, error) {
 	unmarshalledDelegateCallback := types.DelegateCallback{}
 	if err := proto.Unmarshal(delegateCallback, &unmarshalledDelegateCallback); err != nil {
@@ -35,58 +38,72 @@ func (k Keeper) UnmarshalDelegateCallbackArgs(ctx sdk.Context, delegateCallback
 	return &unmarshalledDelegateCallback, nil
 }
 
+// ICA Callback after delegating deposit records
+//   If successful:
+//      * Updates deposit record status and records delegation changes on the host zone and validators
+//   If timeout:
+//      * Does nothing
+//   If failure:
+//		* Reverts deposit record status
 func DelegateCallback(k Keeper, ctx sdk.Context, packet channeltypes.Packet, ack *channeltypes.Acknowledgement, args []byte) error {
-	k.Logger(ctx).Info("DelegateCallback executing", "packet", packet)
-	// deserialize the args
+	// Deserialize the callback args
 	delegateCallback, err := k.UnmarshalDelegateCallbackArgs(ctx, args)
 	if err != nil {
 		return err
 	}
-	k.Logger(ctx).Info(fmt.Sprintf("DelegateCallback %v", delegateCallback))
-	hostZone := delegateCallback.GetHostZoneId()
-	zone, found := k.GetHostZone(ctx, hostZone)
+	chainId := delegateCallback.HostZoneId
+	k.Logger(ctx).Info(utils.LogCallbackWithHostZone(chainId, ICACallbackID_Delegate,
+		"Starting callback for Deposit Record: %d", delegateCallback.DepositRecordId))
+
+	// Confirm chainId and deposit record Id exist
+	hostZone, found := k.GetHostZone(ctx, chainId)
 	if !found {
-		return sdkerrors.Wrapf(sdkerrors.ErrInvalidRequest, "host zone not found %s", hostZone)
+		return sdkerrors.Wrapf(sdkerrors.ErrInvalidRequest, "host zone not found %s", chainId)
 	}
-	recordId := delegateCallback.GetDepositRecordId()
+	recordId := delegateCallback.DepositRecordId
 	depositRecord, found := k.RecordsKeeper.GetDepositRecord(ctx, recordId)
 	if !found {
 		return sdkerrors.Wrapf(sdkerrors.ErrInvalidRequest, "deposit record not found %d", recordId)
 	}
 
+	// Check for timeout (ack nil)
+	// No need to reset the deposit record status since it will get revertted when the channel is restored
 	if ack == nil {
-		// timeout
-		k.Logger(ctx).Error(fmt.Sprintf("DelegateCallback timeout, ack is nil, packet %v", packet))
+		k.Logger(ctx).Error(utils.LogCallbackWithHostZone(chainId, ICACallbackID_Delegate,
+			"TIMEOUT (ack is nil), Packet: %+v", packet))
 		return nil
 	}
 
+	// Check for a failed transaction (ack error)
+	// Reset the deposit record status upon failure
 	txMsgData, err := icacallbacks.GetTxMsgData(ctx, *ack, k.Logger(ctx))
 	if err != nil {
 		k.Logger(ctx).Error(fmt.Sprintf("failed to fetch txMsgData, packet %v", packet))
 		return sdkerrors.Wrap(icacallbackstypes.ErrTxMsgData, err.Error())
 	}
-
 	if len(txMsgData.Data) == 0 {
-		// failed transaction
+		k.Logger(ctx).Error(utils.LogCallbackWithHostZone(chainId, ICACallbackID_Delegate,
+			"ICA TX FAILED (ack is empty / ack error), Packet: %+v", packet))
+
+		// Reset deposit record status
 		depositRecord.Status = recordstypes.DepositRecord_DELEGATION_QUEUE
 		k.RecordsKeeper.SetDepositRecord(ctx, depositRecord)
-		k.Logger(ctx).Error(fmt.Sprintf("DelegateCallback tx failed, ack is empty (ack error), packet %v", packet))
 		return nil
 	}
 
-	for _, splitDelegation := range delegateCallback.SplitDelegations {
-		validator := splitDelegation.Validator
-		k.Logger(ctx).Info(fmt.Sprintf("incrementing stakedBal %v on %s", splitDelegation.Amount, validator))
+	k.Logger(ctx).Info(utils.LogCallbackWithHostZone(chainId, ICACallbackID_Delegate, "SUCCESS, Packet: %+v", packet))
 
-		zone.StakedBal = zone.StakedBal.Add(splitDelegation.Amount)
-		success := k.AddDelegationToValidator(ctx, zone, validator, splitDelegation.Amount)
+	// Update delegations on the host zone
+	for _, splitDelegation := range delegateCallback.SplitDelegations {
+		hostZone.StakedBal = hostZone.StakedBal.Add(splitDelegation.Amount)
+		success := k.AddDelegationToValidator(ctx, hostZone, splitDelegation.Validator, splitDelegation.Amount, ICACallbackID_Delegate)
 		if !success {
 			return sdkerrors.Wrapf(types.ErrValidatorDelegationChg, "Failed to add delegation to validator")
 		}
-		k.SetHostZone(ctx, zone)
+		k.SetHostZone(ctx, hostZone)
 	}
 
 	k.RecordsKeeper.RemoveDepositRecord(ctx, cast.ToUint64(recordId))
-	k.Logger(ctx).Info(fmt.Sprintf("[DELEGATION] success on %s", hostZone))
+	k.Logger(ctx).Info(fmt.Sprintf("[DELEGATION] success on %s", chainId))
 	return nil
 }

x/stakeibc/keeper/icacallbacks_redemption.go

@@ -3,6 +3,7 @@ package keeper
 import (
 	"fmt"
 
+	"github.com/Stride-Labs/stride/v4/utils"
 	"github.com/Stride-Labs/stride/v4/x/icacallbacks"
 	icacallbackstypes "github.com/Stride-Labs/stride/v4/x/icacallbacks/types"
 	recordstypes "github.com/Stride-Labs/stride/v4/x/records/types"
@@ -14,6 +15,7 @@ import (
 	"github.com/golang/protobuf/proto" //nolint:staticcheck
 )
 
+// Marshalls redemption callback arguments
 func (k Keeper) MarshalRedemptionCallbackArgs(ctx sdk.Context, redemptionCallback types.RedemptionCallback) ([]byte, error) {
 	out, err := proto.Marshal(&redemptionCallback)
 	if err != nil {
@@ -23,6 +25,7 @@ func (k Keeper) MarshalRedemptionCallbackArgs(ctx sdk.Context, redemptionCallbac
 	return out, nil
 }
 
+// Unmarshalls redemption callback arguments into a RedemptionCallback struct
 func (k Keeper) UnmarshalRedemptionCallbackArgs(ctx sdk.Context, redemptionCallback []byte) (types.RedemptionCallback, error) {
 	unmarshalledRedemptionCallback := types.RedemptionCallback{}
 	if err := proto.Unmarshal(redemptionCallback, &unmarshalledRedemptionCallback); err != nil {
@@ -32,51 +35,66 @@ func (k Keeper) UnmarshalRedemptionCallbackArgs(ctx sdk.Context, redemptionCallb
 	return unmarshalledRedemptionCallback, nil
 }
 
+// ICA Callback after undelegating
+//   If successful:
+//      * Updates epoch unbonding record status
+//   If timeout:
+//      * Does nothing
+//   If failure:
+//		* Reverts epoch unbonding record status
 func RedemptionCallback(k Keeper, ctx sdk.Context, packet channeltypes.Packet, ack *channeltypes.Acknowledgement, args []byte) error {
-	logMsg := fmt.Sprintf("RedemptionCallback executing packet: %d, source: %s %s, dest: %s %s",
-		packet.Sequence, packet.SourceChannel, packet.SourcePort, packet.DestinationChannel, packet.DestinationPort)
-	k.Logger(ctx).Info(logMsg)
-
-	// unmarshal the callback args and get the host zone
+	// Fetch callback args
 	redemptionCallback, err := k.UnmarshalRedemptionCallbackArgs(ctx, args)
 	if err != nil {
 		errMsg := fmt.Sprintf("Unable to unmarshal redemption callback args | %s", err.Error())
 		k.Logger(ctx).Error(errMsg)
 		return sdkerrors.Wrapf(types.ErrUnmarshalFailure, errMsg)
 	}
-	k.Logger(ctx).Info(fmt.Sprintf("RedemptionCallback, HostZone: %s", redemptionCallback.HostZoneId))
-	hostZoneId := redemptionCallback.HostZoneId
-	zone, found := k.GetHostZone(ctx, hostZoneId)
-	if !found {
-		return sdkerrors.Wrapf(sdkerrors.ErrKeyNotFound, "Host zone not found: %s", hostZoneId)
-	}
+	chainId := redemptionCallback.HostZoneId
+	k.Logger(ctx).Info(utils.LogCallbackWithHostZone(chainId, ICACallbackID_Redemption,
+		"Starting callback for Epoch Unbonding Records: %+v", redemptionCallback.EpochUnbondingRecordIds))
 
+	// Check for timeout (ack nil)
+	// No need to reset the unbonding record status since it will get revertted when the channel is restored
 	if ack == nil {
-		// handle timeout
-		k.Logger(ctx).Error(fmt.Sprintf("RedemptionCallback timeout, ack is nil, packet %v", packet))
+		k.Logger(ctx).Error(utils.LogCallbackWithHostZone(chainId, ICACallbackID_Redemption,
+			"TIMEOUT (ack is nil), Packet: %+v", packet))
 		return nil
 	}
 
+	// Check for a failed transaction (ack error)
+	// Reset the unbonding record status upon failure
 	txMsgData, err := icacallbacks.GetTxMsgData(ctx, *ack, k.Logger(ctx))
 	if err != nil {
 		k.Logger(ctx).Error(fmt.Sprintf("RedemptionCallback txMsgData could not be parsed, packet %v", packet))
 		return sdkerrors.Wrap(icacallbackstypes.ErrTxMsgData, err.Error())
 	}
-
 	if len(txMsgData.Data) == 0 {
-		// handle tx failure
-		k.Logger(ctx).Error(fmt.Sprintf("RedemptionCallback tx failed, txMsgData is empty, ack error, packet %v", packet))
-		err = k.RecordsKeeper.SetHostZoneUnbondings(ctx, zone.ChainId, redemptionCallback.EpochUnbondingRecordIds, recordstypes.HostZoneUnbonding_EXIT_TRANSFER_QUEUE)
+		k.Logger(ctx).Error(utils.LogCallbackWithHostZone(chainId, ICACallbackID_Redemption,
+			"ICA TX FAILED (ack is empty / ack error), Packet: %+v", packet))
+
+		// Reset unbondings record status
+		err = k.RecordsKeeper.SetHostZoneUnbondings(ctx, chainId, redemptionCallback.EpochUnbondingRecordIds, recordstypes.HostZoneUnbonding_EXIT_TRANSFER_QUEUE)
 		if err != nil {
 			return err
 		}
 		return nil
 	}
 
-	err = k.RecordsKeeper.SetHostZoneUnbondings(ctx, zone.ChainId, redemptionCallback.EpochUnbondingRecordIds, recordstypes.HostZoneUnbonding_CLAIMABLE)
+	k.Logger(ctx).Info(utils.LogCallbackWithHostZone(chainId, ICACallbackID_Redemption, "SUCCESS, Packet: %+v", packet))
+
+	// Confirm host zone exists
+	_, found := k.GetHostZone(ctx, chainId)
+	if !found {
+		return sdkerrors.Wrapf(sdkerrors.ErrKeyNotFound, "Host zone not found: %s", chainId)
+	}
+
+	// Upon success, update the unbonding record status to CLAIMABLE
+	err = k.RecordsKeeper.SetHostZoneUnbondings(ctx, chainId, redemptionCallback.EpochUnbondingRecordIds, recordstypes.HostZoneUnbonding_CLAIMABLE)
 	if err != nil {
 		return err
 	}
-	k.Logger(ctx).Info(fmt.Sprintf("[REDEMPTION] completed on %s", hostZoneId))
+
+	k.Logger(ctx).Info(fmt.Sprintf("[REDEMPTION] completed on %s", chainId))
 	return nil
 }