diff --git a/docs/core/telemetry.md b/docs/core/telemetry.md index c218658dbadd..88faa1eef75f 100644 --- a/docs/core/telemetry.md +++ b/docs/core/telemetry.md @@ -76,48 +76,69 @@ The following examples expose too much cardinality and may not even prove to be ## Supported Metrics -| Metric | Description | Unit | Type | -|:--------------------------------|:---------------------------------------------------------------------------------------|:-------------|:--------| -| `tx_count` | Total number of txs processed via `DeliverTx` | tx | counter | -| `tx_successful` | Total number of successful txs processed via `DeliverTx` | tx | counter | -| `tx_failed` | Total number of failed txs processed via `DeliverTx` | tx | counter | -| `tx_gas_used` | The total amount of gas used by a tx | gas | gauge | -| `tx_gas_wanted` | The total amount of gas requested by a tx | gas | gauge | -| `tx_msg_send` | The total amount of tokens sent in a `MsgSend` (per denom) | token | gauge | -| `tx_msg_withdraw_reward` | The total amount of tokens withdrawn in a `MsgWithdrawDelegatorReward` (per denom) | token | gauge | -| `tx_msg_withdraw_commission` | The total amount of tokens withdrawn in a `MsgWithdrawValidatorCommission` (per denom) | token | gauge | -| `tx_msg_delegate` | The total amount of tokens delegated in a `MsgDelegate` | token | gauge | -| `tx_msg_begin_unbonding` | The total amount of tokens undelegated in a `MsgUndelegate` | token | gauge | -| `tx_msg_begin_begin_redelegate` | The total amount of tokens redelegated in a `MsgBeginRedelegate` | token | gauge | -| `new_account` | Total number of new accounts created | account | counter | -| `gov_proposal` | Total number of governance proposals | proposal | counter | -| `gov_vote` | Total number of governance votes for a proposal | vote | counter | -| `gov_deposit` | Total number of governance deposits for a proposal | deposit | counter | -| `staking_delegate` | Total number of delegations | delegation | counter | -| `staking_undelegate` | Total number of undelegations | undelegation | counter | -| `staking_redelegate` | Total number of redelegations | redelegation | counter | -| `abci_check_tx` | Duration of ABCI `CheckTx` | ms | summary | -| `abci_deliver_tx` | Duration of ABCI `DeliverTx` | ms | summary | -| `abci_commit` | Duration of ABCI `Commit` | ms | summary | -| `abci_query` | Duration of ABCI `Query` | ms | summary | -| `abci_begin_block` | Duration of ABCI `BeginBlock` | ms | summary | -| `abci_end_block` | Duration of ABCI `EndBlock` | ms | summary | -| `begin_blocker` | Duration of `BeginBlock` for a given module | ms | summary | -| `end_blocker` | Duration of `EndBlock` for a given module | ms | summary | -| `store_iavl_get` | Duration of an IAVL `Store#Get` call | ms | summary | -| `store_iavl_set` | Duration of an IAVL `Store#Set` call | ms | summary | -| `store_iavl_has` | Duration of an IAVL `Store#Has` call | ms | summary | -| `store_iavl_delete` | Duration of an IAVL `Store#Delete` call | ms | summary | -| `store_iavl_commit` | Duration of an IAVL `Store#Commit` call | ms | summary | -| `store_iavl_query` | Duration of an IAVL `Store#Query` call | ms | summary | -| `store_gaskv_get` | Duration of a GasKV `Store#Get` call | ms | summary | -| `store_gaskv_set` | Duration of a GasKV `Store#Set` call | ms | summary | -| `store_gaskv_has` | Duration of a GasKV `Store#Has` call | ms | summary | -| `store_gaskv_delete` | Duration of a GasKV `Store#Delete` call | ms | summary | -| `store_cachekv_get` | Duration of a CacheKV `Store#Get` call | ms | summary | -| `store_cachekv_set` | Duration of a CacheKV `Store#Set` call | ms | summary | -| `store_cachekv_write` | Duration of a CacheKV `Store#Write` call | ms | summary | -| `store_cachekv_delete` | Duration of a CacheKV `Store#Delete` call | ms | summary | +| Metric | Description | Unit | Type | +|:--------------------------------|:------------------------------------------------------------------------------------------|:----------------|:--------| +| `tx_count` | Total number of txs processed via `DeliverTx` | tx | counter | +| `tx_successful` | Total number of successful txs processed via `DeliverTx` | tx | counter | +| `tx_failed` | Total number of failed txs processed via `DeliverTx` | tx | counter | +| `tx_gas_used` | The total amount of gas used by a tx | gas | gauge | +| `tx_gas_wanted` | The total amount of gas requested by a tx | gas | gauge | +| `tx_msg_send` | The total amount of tokens sent in a `MsgSend` (per denom) | token | gauge | +| `tx_msg_withdraw_reward` | The total amount of tokens withdrawn in a `MsgWithdrawDelegatorReward` (per denom) | token | gauge | +| `tx_msg_withdraw_commission` | The total amount of tokens withdrawn in a `MsgWithdrawValidatorCommission` (per denom) | token | gauge | +| `tx_msg_delegate` | The total amount of tokens delegated in a `MsgDelegate` | token | gauge | +| `tx_msg_begin_unbonding` | The total amount of tokens undelegated in a `MsgUndelegate` | token | gauge | +| `tx_msg_begin_begin_redelegate` | The total amount of tokens redelegated in a `MsgBeginRedelegate` | token | gauge | +| `tx_msg_ibc_transfer` | The total amount of tokens transferred via IBC in a `MsgTransfer` (source or sink chain) | token | gauge | +| `ibc_transfer_packet_receive` | The total amount of tokens received in a `FungibleTokenPacketData` (source or sink chain) | token | gauge | +| `new_account` | Total number of new accounts created | account | counter | +| `gov_proposal` | Total number of governance proposals | proposal | counter | +| `gov_vote` | Total number of governance votes for a proposal | vote | counter | +| `gov_deposit` | Total number of governance deposits for a proposal | deposit | counter | +| `staking_delegate` | Total number of delegations | delegation | counter | +| `staking_undelegate` | Total number of undelegations | undelegation | counter | +| `staking_redelegate` | Total number of redelegations | redelegation | counter | +| `ibc_transfer_send` | Total number of IBC transfers sent from a chain (source or sink) | transfer | counter | +| `ibc_transfer_receive` | Total number of IBC transfers received to a chain (source or sink) | transfer | counter | +| `ibc_client_create` | Total number of clients created | create | counter | +| `ibc_client_update` | Total number of client updates | update | counter | +| `ibc_client_upgrade` | Total number of client upgrades | upgrade | counter | +| `ibc_client_misbehaviour` | Total number of client misbehaviours | misbehaviour | counter | +| `ibc_connection_open-init` | Total number of connection `OpenInit` handshakes | handshake | counter | +| `ibc_connection_open-try` | Total number of connection `OpenTry` handshakes | handshake | counter | +| `ibc_connection_open-ack` | Total number of connection `OpenAck` handshakes | handshake | counter | +| `ibc_connection_open-confirm` | Total number of connection `OpenConfirm` handshakes | handshake | counter | +| `ibc_channel_open-init` | Total number of channel `OpenInit` handshakes | handshake | counter | +| `ibc_channel_open-try` | Total number of channel `OpenTry` handshakes | handshake | counter | +| `ibc_channel_open-ack` | Total number of channel `OpenAck` handshakes | handshake | counter | +| `ibc_channel_open-confirm` | Total number of channel `OpenConfirm` handshakes | handshake | counter | +| `ibc_channel_close-init` | Total number of channel `CloseInit` handshakes | handshake | counter | +| `ibc_channel_close-confirm` | Total number of channel `CloseConfirm` handshakes | handshake | counter | +| `tx_msg_ibc_recv_packet` | Total number of IBC packets received | packet | counter | +| `tx_msg_ibc_acknowledge_packet` | Total number of IBC packets acknowledged | acknowledgement | counter | +| `ibc_timeout_packet` | Total number of IBC timeout packets | timeout | counter | +| `abci_check_tx` | Duration of ABCI `CheckTx` | ms | summary | +| `abci_deliver_tx` | Duration of ABCI `DeliverTx` | ms | summary | +| `abci_commit` | Duration of ABCI `Commit` | ms | summary | +| `abci_query` | Duration of ABCI `Query` | ms | summary | +| `abci_begin_block` | Duration of ABCI `BeginBlock` | ms | summary | +| `abci_end_block` | Duration of ABCI `EndBlock` | ms | summary | +| `begin_blocker` | Duration of `BeginBlock` for a given module | ms | summary | +| `end_blocker` | Duration of `EndBlock` for a given module | ms | summary | +| `store_iavl_get` | Duration of an IAVL `Store#Get` call | ms | summary | +| `store_iavl_set` | Duration of an IAVL `Store#Set` call | ms | summary | +| `store_iavl_has` | Duration of an IAVL `Store#Has` call | ms | summary | +| `store_iavl_delete` | Duration of an IAVL `Store#Delete` call | ms | summary | +| `store_iavl_commit` | Duration of an IAVL `Store#Commit` call | ms | summary | +| `store_iavl_query` | Duration of an IAVL `Store#Query` call | ms | summary | +| `store_gaskv_get` | Duration of a GasKV `Store#Get` call | ms | summary | +| `store_gaskv_set` | Duration of a GasKV `Store#Set` call | ms | summary | +| `store_gaskv_has` | Duration of a GasKV `Store#Has` call | ms | summary | +| `store_gaskv_delete` | Duration of a GasKV `Store#Delete` call | ms | summary | +| `store_cachekv_get` | Duration of a CacheKV `Store#Get` call | ms | summary | +| `store_cachekv_set` | Duration of a CacheKV `Store#Set` call | ms | summary | +| `store_cachekv_write` | Duration of a CacheKV `Store#Write` call | ms | summary | +| `store_cachekv_delete` | Duration of a CacheKV `Store#Delete` call | ms | summary | ## Next {hide} diff --git a/x/ibc/applications/transfer/handler.go b/x/ibc/applications/transfer/handler.go index 30a78ccc0482..81d9d62d8600 100644 --- a/x/ibc/applications/transfer/handler.go +++ b/x/ibc/applications/transfer/handler.go @@ -33,7 +33,7 @@ func handleMsgTransfer(ctx sdk.Context, k keeper.Keeper, msg *types.MsgTransfer) return nil, err } - k.Logger(ctx).Info("IBC fungible token transfer", "token", msg.Token, "sender", msg.Sender, "receiver", msg.Receiver) + k.Logger(ctx).Info("IBC fungible token transfer", "token", msg.Token.Denom, "amount", msg.Token.Amount.String(), "sender", msg.Sender, "receiver", msg.Receiver) ctx.EventManager().EmitEvents(sdk.Events{ sdk.NewEvent( diff --git a/x/ibc/applications/transfer/keeper/relay.go b/x/ibc/applications/transfer/keeper/relay.go index 91d703535f07..45a51a9a2e8b 100644 --- a/x/ibc/applications/transfer/keeper/relay.go +++ b/x/ibc/applications/transfer/keeper/relay.go @@ -3,6 +3,8 @@ package keeper import ( "strings" + "github.com/armon/go-metrics" + "github.com/cosmos/cosmos-sdk/telemetry" sdk "github.com/cosmos/cosmos-sdk/types" sdkerrors "github.com/cosmos/cosmos-sdk/types/errors" "github.com/cosmos/cosmos-sdk/x/ibc/applications/transfer/types" @@ -96,11 +98,18 @@ func (k Keeper) SendTransfer( } } + labels := []metrics.Label{ + telemetry.NewLabel("destination-port", destinationPort), + telemetry.NewLabel("destination-channel", destinationChannel), + } + // NOTE: SendTransfer simply sends the denomination as it exists on its own // chain inside the packet data. The receiving chain will perform denom // prefixing as necessary. if types.SenderChainIsSource(sourcePort, sourceChannel, fullDenomPath) { + labels = append(labels, telemetry.NewLabel("source", "true")) + // create the escrow address for the tokens escrowAddress := types.GetEscrowAddress(sourcePort, sourceChannel) @@ -112,6 +121,8 @@ func (k Keeper) SendTransfer( } } else { + labels = append(labels, telemetry.NewLabel("source", "false")) + // transfer the coins to the module account and burn them if err := k.bankKeeper.SendCoinsFromAccountToModule( ctx, sender, types.ModuleName, sdk.NewCoins(token), @@ -144,7 +155,25 @@ func (k Keeper) SendTransfer( timeoutTimestamp, ) - return k.channelKeeper.SendPacket(ctx, channelCap, packet) + if err := k.channelKeeper.SendPacket(ctx, channelCap, packet); err != nil { + return err + } + + defer func() { + telemetry.SetGaugeWithLabels( + []string{"tx", "msg", "ibc", "transfer"}, + float32(token.Amount.Int64()), + []metrics.Label{telemetry.NewLabel("denom", fullDenomPath)}, + ) + + telemetry.IncrCounterWithLabels( + []string{"ibc", types.ModuleName, "send"}, + 1, + labels, + ) + }() + + return nil } // OnRecvPacket processes a cross chain fungible token transfer. If the @@ -168,6 +197,11 @@ func (k Keeper) OnRecvPacket(ctx sdk.Context, packet channeltypes.Packet, data t return err } + labels := []metrics.Label{ + telemetry.NewLabel("source-port", packet.GetSourcePort()), + telemetry.NewLabel("source-channel", packet.GetSourceChannel()), + } + // This is the prefix that would have been prefixed to the denomination // on sender chain IF and only if the token originally came from the // receiving chain. @@ -186,7 +220,27 @@ func (k Keeper) OnRecvPacket(ctx sdk.Context, packet channeltypes.Packet, data t // unescrow tokens escrowAddress := types.GetEscrowAddress(packet.GetDestPort(), packet.GetDestChannel()) - return k.bankKeeper.SendCoins(ctx, escrowAddress, receiver, sdk.NewCoins(token)) + if err := k.bankKeeper.SendCoins(ctx, escrowAddress, receiver, sdk.NewCoins(token)); err != nil { + return err + } + + defer func() { + telemetry.SetGaugeWithLabels( + []string{"ibc", types.ModuleName, "packet", "receive"}, + float32(data.Amount), + []metrics.Label{telemetry.NewLabel("denom", unprefixedDenom)}, + ) + + telemetry.IncrCounterWithLabels( + []string{"ibc", types.ModuleName, "receive"}, + 1, + append( + labels, telemetry.NewLabel("source", "true"), + ), + ) + }() + + return nil } // sender chain is the source, mint vouchers @@ -223,9 +277,29 @@ func (k Keeper) OnRecvPacket(ctx sdk.Context, packet channeltypes.Packet, data t } // send to receiver - return k.bankKeeper.SendCoinsFromModuleToAccount( + if err := k.bankKeeper.SendCoinsFromModuleToAccount( ctx, types.ModuleName, receiver, sdk.NewCoins(voucher), - ) + ); err != nil { + return err + } + + defer func() { + telemetry.SetGaugeWithLabels( + []string{"ibc", types.ModuleName, "packet", "receive"}, + float32(data.Amount), + []metrics.Label{telemetry.NewLabel("denom", data.Denom)}, + ) + + telemetry.IncrCounterWithLabels( + []string{"ibc", types.ModuleName, "receive"}, + 1, + append( + labels, telemetry.NewLabel("source", "false"), + ), + ) + }() + + return nil } // OnAcknowledgementPacket responds to the the success or failure of a packet diff --git a/x/ibc/core/02-client/keeper/client.go b/x/ibc/core/02-client/keeper/client.go index edd568d2b864..463df9ef46ff 100644 --- a/x/ibc/core/02-client/keeper/client.go +++ b/x/ibc/core/02-client/keeper/client.go @@ -1,8 +1,9 @@ package keeper import ( - "fmt" + "github.com/armon/go-metrics" + "github.com/cosmos/cosmos-sdk/telemetry" sdk "github.com/cosmos/cosmos-sdk/types" sdkerrors "github.com/cosmos/cosmos-sdk/types/errors" "github.com/cosmos/cosmos-sdk/x/ibc/core/02-client/types" @@ -26,7 +27,15 @@ func (k Keeper) CreateClient( } k.SetClientState(ctx, clientID, clientState) - k.Logger(ctx).Info(fmt.Sprintf("client %s created at height %d", clientID, clientState.GetLatestHeight())) + k.Logger(ctx).Info("client created at height", "client-id", clientID, "height", clientState.GetLatestHeight().String()) + + defer func() { + telemetry.IncrCounterWithLabels( + []string{"ibc", "client", "create"}, + 1, + []metrics.Label{telemetry.NewLabel("client-type", clientState.ClientType())}, + ) + }() return nil } @@ -65,7 +74,19 @@ func (k Keeper) UpdateClient(ctx sdk.Context, clientID string, header exported.H consensusHeight = types.GetSelfHeight(ctx) } - k.Logger(ctx).Info("client state updated", "client-id", clientID, "height", consensusHeight) + k.Logger(ctx).Info("client state updated", "client-id", clientID, "height", consensusHeight.String()) + + defer func() { + telemetry.IncrCounterWithLabels( + []string{"ibc", "client", "update"}, + 1, + []metrics.Label{ + telemetry.NewLabel("client-type", clientState.ClientType()), + telemetry.NewLabel("client-id", clientID), + telemetry.NewLabel("update-type", "msg"), + }, + ) + }() // emitting events in the keeper emits for both begin block and handler client updates ctx.EventManager().EmitEvent( @@ -100,7 +121,18 @@ func (k Keeper) UpgradeClient(ctx sdk.Context, clientID string, upgradedClient e k.SetClientState(ctx, clientID, upgradedClient) - k.Logger(ctx).Info("client state upgraded", "client-id", clientID, "height", upgradedClient.GetLatestHeight()) + k.Logger(ctx).Info("client state upgraded", "client-id", clientID, "height", upgradedClient.GetLatestHeight().String()) + + defer func() { + telemetry.IncrCounterWithLabels( + []string{"ibc", "client", "upgrade"}, + 1, + []metrics.Label{ + telemetry.NewLabel("client-type", clientState.ClientType()), + telemetry.NewLabel("client-id", clientID), + }, + ) + }() // emitting events in the keeper emits for client upgrades ctx.EventManager().EmitEvent( @@ -129,7 +161,18 @@ func (k Keeper) CheckMisbehaviourAndUpdateState(ctx sdk.Context, misbehaviour ex } k.SetClientState(ctx, misbehaviour.GetClientID(), clientState) - k.Logger(ctx).Info(fmt.Sprintf("client %s frozen due to misbehaviour", misbehaviour.GetClientID())) + k.Logger(ctx).Info("client frozen due to misbehaviour", "client-id", misbehaviour.GetClientID(), "height", misbehaviour.GetHeight().String()) + + defer func() { + telemetry.IncrCounterWithLabels( + []string{"ibc", "client", "misbehaviour"}, + 1, + []metrics.Label{ + telemetry.NewLabel("client-type", misbehaviour.ClientType()), + telemetry.NewLabel("client-id", misbehaviour.GetClientID()), + }, + ) + }() return nil } diff --git a/x/ibc/core/02-client/keeper/proposal.go b/x/ibc/core/02-client/keeper/proposal.go index 911b79be3308..6b17278e09dd 100644 --- a/x/ibc/core/02-client/keeper/proposal.go +++ b/x/ibc/core/02-client/keeper/proposal.go @@ -1,8 +1,9 @@ package keeper import ( - "fmt" + "github.com/armon/go-metrics" + "github.com/cosmos/cosmos-sdk/telemetry" sdk "github.com/cosmos/cosmos-sdk/types" sdkerrors "github.com/cosmos/cosmos-sdk/types/errors" "github.com/cosmos/cosmos-sdk/x/ibc/core/02-client/types" @@ -34,7 +35,19 @@ func (k Keeper) ClientUpdateProposal(ctx sdk.Context, p *types.ClientUpdatePropo k.SetClientState(ctx, p.ClientId, clientState) k.SetClientConsensusState(ctx, p.ClientId, header.GetHeight(), consensusState) - k.Logger(ctx).Info("client updated after governance proposal passed", "client-id", p.ClientId, "height", clientState.GetLatestHeight()) + k.Logger(ctx).Info("client updated after governance proposal passed", "client-id", p.ClientId, "height", clientState.GetLatestHeight().String()) + + defer func() { + telemetry.IncrCounterWithLabels( + []string{"ibc", "client", "update"}, + 1, + []metrics.Label{ + telemetry.NewLabel("client-type", clientState.ClientType()), + telemetry.NewLabel("client-id", p.ClientId), + telemetry.NewLabel("update-type", "proposal"), + }, + ) + }() // emitting events in the keeper for proposal updates to clients ctx.EventManager().EmitEvent( @@ -42,7 +55,7 @@ func (k Keeper) ClientUpdateProposal(ctx sdk.Context, p *types.ClientUpdatePropo types.EventTypeUpdateClientProposal, sdk.NewAttribute(types.AttributeKeyClientID, p.ClientId), sdk.NewAttribute(types.AttributeKeyClientType, clientState.ClientType()), - sdk.NewAttribute(types.AttributeKeyConsensusHeight, fmt.Sprintf("%d", header.GetHeight())), + sdk.NewAttribute(types.AttributeKeyConsensusHeight, header.GetHeight().String()), ), ) diff --git a/x/ibc/core/03-connection/keeper/handshake.go b/x/ibc/core/03-connection/keeper/handshake.go index 8b8d722bbe0f..56cb9bf362a0 100644 --- a/x/ibc/core/03-connection/keeper/handshake.go +++ b/x/ibc/core/03-connection/keeper/handshake.go @@ -2,8 +2,8 @@ package keeper import ( "bytes" - "fmt" + "github.com/cosmos/cosmos-sdk/telemetry" sdk "github.com/cosmos/cosmos-sdk/types" sdkerrors "github.com/cosmos/cosmos-sdk/types/errors" clienttypes "github.com/cosmos/cosmos-sdk/x/ibc/core/02-client/types" @@ -24,7 +24,7 @@ func (k Keeper) ConnOpenInit( ) error { _, found := k.GetConnection(ctx, connectionID) if found { - return types.ErrConnectionExists + return sdkerrors.Wrap(types.ErrConnectionExists, connectionID) } versions := types.GetCompatibleEncodedVersions() @@ -44,7 +44,12 @@ func (k Keeper) ConnOpenInit( return err } - k.Logger(ctx).Info(fmt.Sprintf("connection %s state updated: NONE -> INIT", connectionID)) + k.Logger(ctx).Info("connection state updated", "connection-id", connectionID, "previous-state", "NONE", "new-state", "INIT") + + defer func() { + telemetry.IncrCounter(1, "ibc", "connection", "open-init") + }() + return nil } @@ -83,7 +88,7 @@ func (k Keeper) ConnOpenTry( expectedConsensusState, found := k.clientKeeper.GetSelfConsensusState(ctx, consensusHeight) if !found { - return clienttypes.ErrSelfConsensusStateNotFound + return sdkerrors.Wrap(clienttypes.ErrSelfConsensusStateNotFound, consensusHeight.String()) } // If the connection id chosen for this connection end by the counterparty is empty then @@ -157,7 +162,12 @@ func (k Keeper) ConnOpenTry( } k.SetConnection(ctx, desiredConnectionID, connection) - k.Logger(ctx).Info(fmt.Sprintf("connection %s state updated: %s -> TRYOPEN ", desiredConnectionID, previousConnection.State)) + k.Logger(ctx).Info("connection state updated", "connection-id", desiredConnectionID, "previous-state", previousConnection.State.String(), "new-state", "TRYOPEN") + + defer func() { + telemetry.IncrCounter(1, "ibc", "connection", "open-try") + }() + return nil } @@ -262,7 +272,11 @@ func (k Keeper) ConnOpenAck( return err } - k.Logger(ctx).Info(fmt.Sprintf("connection %s state updated: %s -> OPEN ", connectionID, connection.State)) + k.Logger(ctx).Info("connection state updated", "connection-id", connectionID, "previous-state", connection.State.String(), "new-state", "OPEN") + + defer func() { + telemetry.IncrCounter(1, "ibc", "connection", "open-ack") + }() // Update connection state to Open connection.State = types.OPEN @@ -311,6 +325,11 @@ func (k Keeper) ConnOpenConfirm( // Update ChainB's connection to Open connection.State = types.OPEN k.SetConnection(ctx, connectionID, connection) - k.Logger(ctx).Info(fmt.Sprintf("connection %s state updated: TRYOPEN -> OPEN ", connectionID)) + k.Logger(ctx).Info("connection state updated", "connection-id", connectionID, "previous-state", "TRYOPEN", "new-state", "OPEN") + + defer func() { + telemetry.IncrCounter(1, "ibc", "connection", "open-confirm") + }() + return nil } diff --git a/x/ibc/core/04-channel/keeper/grpc_query.go b/x/ibc/core/04-channel/keeper/grpc_query.go index bbbd0f68ebc3..433b135fc273 100644 --- a/x/ibc/core/04-channel/keeper/grpc_query.go +++ b/x/ibc/core/04-channel/keeper/grpc_query.go @@ -143,31 +143,12 @@ func (q Keeper) ChannelClientState(c context.Context, req *types.QueryChannelCli ctx := sdk.UnwrapSDKContext(c) - channel, found := q.GetChannel(ctx, req.PortId, req.ChannelId) - if !found { - return nil, status.Error( - codes.NotFound, - sdkerrors.Wrapf(types.ErrChannelNotFound, "port-id: %s, channel-id %s", req.PortId, req.ChannelId).Error(), - ) - } - - connection, found := q.connectionKeeper.GetConnection(ctx, channel.ConnectionHops[0]) - if !found { - return nil, status.Error( - codes.NotFound, - sdkerrors.Wrapf(connectiontypes.ErrConnectionNotFound, "connection-id: %s", channel.ConnectionHops[0]).Error(), - ) - } - - clientState, found := q.clientKeeper.GetClientState(ctx, connection.ClientId) - if !found { - return nil, status.Error( - codes.NotFound, - sdkerrors.Wrapf(clienttypes.ErrClientNotFound, "client-id: %s", connection.ClientId).Error(), - ) + clientID, clientState, err := q.GetChannelClientState(ctx, req.PortId, req.ChannelId) + if err != nil { + return nil, status.Error(codes.NotFound, err.Error()) } - identifiedClientState := clienttypes.NewIdentifiedClientState(connection.ClientId, clientState) + identifiedClientState := clienttypes.NewIdentifiedClientState(clientID, clientState) selfHeight := clienttypes.GetSelfHeight(ctx) return types.NewQueryChannelClientStateResponse(identifiedClientState, nil, selfHeight), nil diff --git a/x/ibc/core/04-channel/keeper/handshake.go b/x/ibc/core/04-channel/keeper/handshake.go index 47a764e505d8..900c234bec75 100644 --- a/x/ibc/core/04-channel/keeper/handshake.go +++ b/x/ibc/core/04-channel/keeper/handshake.go @@ -1,8 +1,7 @@ package keeper import ( - "fmt" - + "github.com/cosmos/cosmos-sdk/telemetry" sdk "github.com/cosmos/cosmos-sdk/types" sdkerrors "github.com/cosmos/cosmos-sdk/types/errors" capabilitytypes "github.com/cosmos/cosmos-sdk/x/capability/types" @@ -85,7 +84,12 @@ func (k Keeper) ChanOpenInit( k.SetNextSequenceRecv(ctx, portID, channelID, 1) k.SetNextSequenceAck(ctx, portID, channelID, 1) - k.Logger(ctx).Info(fmt.Sprintf("channel (port-id: %s, channel-id: %s) state updated: NONE -> INIT", portID, channelID)) + k.Logger(ctx).Info("channel state updated", "port-id", portID, "channel-id", channelID, "previous-state", "NONE", "new-state", "INIT") + + defer func() { + telemetry.IncrCounter(1, "ibc", "channel", "open-init") + }() + return capKey, nil } @@ -194,7 +198,12 @@ func (k Keeper) ChanOpenTry( k.SetNextSequenceRecv(ctx, portID, desiredChannelID, 1) k.SetNextSequenceAck(ctx, portID, desiredChannelID, 1) - k.Logger(ctx).Info(fmt.Sprintf("channel (port-id: %s, channel-id: %s) state updated: NONE -> TRYOPEN", portID, desiredChannelID)) + k.Logger(ctx).Info("channel state updated", "port-id", portID, "channel-id", desiredChannelID, "previous-state", previousChannel.State.String(), "new-state", "TRYOPEN") + + defer func() { + telemetry.IncrCounter(1, "ibc", "channel", "open-try") + }() + return capKey, nil } @@ -269,7 +278,11 @@ func (k Keeper) ChanOpenAck( return err } - k.Logger(ctx).Info(fmt.Sprintf("channel (port-id: %s, channel-id: %s) state updated: %s -> OPEN", portID, channelID, channel.State)) + k.Logger(ctx).Info("channel state updated", "port-id", portID, "channel-id", channelID, "previous-state", channel.State.String(), "new-state", "OPEN") + + defer func() { + telemetry.IncrCounter(1, "ibc", "channel", "open-ack") + }() channel.State = types.OPEN channel.Version = counterpartyVersion @@ -339,8 +352,11 @@ func (k Keeper) ChanOpenConfirm( channel.State = types.OPEN k.SetChannel(ctx, portID, channelID, channel) + k.Logger(ctx).Info("channel state updated", "port-id", portID, "channel-id", channelID, "previous-state", "TRYOPEN", "new-state", "OPEN") - k.Logger(ctx).Info(fmt.Sprintf("channel (port-id: %s, channel-id: %s) state updated: TRYOPEN -> OPEN", portID, channelID)) + defer func() { + telemetry.IncrCounter(1, "ibc", "channel", "open-confirm") + }() return nil } @@ -382,7 +398,11 @@ func (k Keeper) ChanCloseInit( ) } - k.Logger(ctx).Info(fmt.Sprintf("channel (port-id: %s, channel-id: %s) state updated: %s -> CLOSED", portID, channelID, channel.State)) + k.Logger(ctx).Info("channel state updated", "port-id", portID, "channel-id", channelID, "previous-state", channel.State.String(), "new-state", "CLOSED") + + defer func() { + telemetry.IncrCounter(1, "ibc", "channel", "close-init") + }() channel.State = types.CLOSED k.SetChannel(ctx, portID, channelID, channel) @@ -445,7 +465,11 @@ func (k Keeper) ChanCloseConfirm( return err } - k.Logger(ctx).Info(fmt.Sprintf("channel (port-id: %s, channel-id: %s) state updated: %s -> CLOSED", portID, channelID, channel.State)) + k.Logger(ctx).Info("channel state updated", "port-id", portID, "channel-id", channelID, "previous-state", channel.State.String(), "new-state", "CLOSED") + + defer func() { + telemetry.IncrCounter(1, "ibc", "channel", "close-confirm") + }() channel.State = types.CLOSED k.SetChannel(ctx, portID, channelID, channel) diff --git a/x/ibc/core/04-channel/keeper/keeper.go b/x/ibc/core/04-channel/keeper/keeper.go index e87f5673616f..f71abe055289 100644 --- a/x/ibc/core/04-channel/keeper/keeper.go +++ b/x/ibc/core/04-channel/keeper/keeper.go @@ -10,11 +10,15 @@ import ( "github.com/cosmos/cosmos-sdk/codec" sdk "github.com/cosmos/cosmos-sdk/types" + sdkerrors "github.com/cosmos/cosmos-sdk/types/errors" capabilitykeeper "github.com/cosmos/cosmos-sdk/x/capability/keeper" capabilitytypes "github.com/cosmos/cosmos-sdk/x/capability/types" + clienttypes "github.com/cosmos/cosmos-sdk/x/ibc/core/02-client/types" + connectiontypes "github.com/cosmos/cosmos-sdk/x/ibc/core/03-connection/types" "github.com/cosmos/cosmos-sdk/x/ibc/core/04-channel/types" porttypes "github.com/cosmos/cosmos-sdk/x/ibc/core/05-port/types" host "github.com/cosmos/cosmos-sdk/x/ibc/core/24-host" + "github.com/cosmos/cosmos-sdk/x/ibc/core/exported" ) // Keeper defines the IBC channel keeper @@ -331,6 +335,26 @@ func (k Keeper) GetAllChannels(ctx sdk.Context) (channels []types.IdentifiedChan return channels } +// GetChannelClientState returns the associated client state with its ID, from a port and channel identifier. +func (k Keeper) GetChannelClientState(ctx sdk.Context, portID, channelID string) (string, exported.ClientState, error) { + channel, found := k.GetChannel(ctx, portID, channelID) + if !found { + return "", nil, sdkerrors.Wrapf(types.ErrChannelNotFound, "port-id: %s, channel-id: %s", portID, channelID) + } + + connection, found := k.connectionKeeper.GetConnection(ctx, channel.ConnectionHops[0]) + if !found { + return "", nil, sdkerrors.Wrapf(connectiontypes.ErrConnectionNotFound, "connection-id: %s", channel.ConnectionHops[0]) + } + + clientState, found := k.clientKeeper.GetClientState(ctx, connection.ClientId) + if !found { + return "", nil, sdkerrors.Wrapf(clienttypes.ErrClientNotFound, "client-id: %s", connection.ClientId) + } + + return connection.ClientId, clientState, nil +} + // LookupModuleByChannel will return the IBCModule along with the capability associated with a given channel defined by its portID and channelID func (k Keeper) LookupModuleByChannel(ctx sdk.Context, portID, channelID string) (string, *capabilitytypes.Capability, error) { modules, cap, err := k.scopedKeeper.LookupModules(ctx, host.ChannelCapabilityPath(portID, channelID)) diff --git a/x/ibc/core/04-channel/keeper/packet.go b/x/ibc/core/04-channel/keeper/packet.go index 444b3d6f675f..2f662c8021ec 100644 --- a/x/ibc/core/04-channel/keeper/packet.go +++ b/x/ibc/core/04-channel/keeper/packet.go @@ -129,7 +129,7 @@ func (k Keeper) SendPacket( ), }) - k.Logger(ctx).Info(fmt.Sprintf("packet sent: %v", packet)) + k.Logger(ctx).Info("packet sent", "packet", fmt.Sprintf("%v", packet)) return nil } @@ -518,7 +518,7 @@ func (k Keeper) AcknowledgementExecuted( } // log that a packet has been acknowledged - k.Logger(ctx).Info(fmt.Sprintf("packet acknowledged: %v", packet)) + k.Logger(ctx).Info("packet acknowledged", "packet", fmt.Sprintf("%v", packet)) // emit an event marking that we have processed the acknowledgement ctx.EventManager().EmitEvents(sdk.Events{ diff --git a/x/ibc/core/04-channel/keeper/timeout.go b/x/ibc/core/04-channel/keeper/timeout.go index 3c7f9783c9c3..490eb83c8fa4 100644 --- a/x/ibc/core/04-channel/keeper/timeout.go +++ b/x/ibc/core/04-channel/keeper/timeout.go @@ -146,7 +146,7 @@ func (k Keeper) TimeoutExecuted( k.SetChannel(ctx, packet.GetSourcePort(), packet.GetSourceChannel(), channel) } - k.Logger(ctx).Info("packet timed-out", "packet", packet) + k.Logger(ctx).Info("packet timed-out", "packet", fmt.Sprintf("%v", packet)) // emit an event marking that we have processed the timeout ctx.EventManager().EmitEvents(sdk.Events{ diff --git a/x/ibc/core/handler.go b/x/ibc/core/handler.go index 4eac4f39d5cf..3d3ea6280fd7 100644 --- a/x/ibc/core/handler.go +++ b/x/ibc/core/handler.go @@ -1,6 +1,8 @@ package ibc import ( + "github.com/armon/go-metrics" + "github.com/cosmos/cosmos-sdk/telemetry" sdk "github.com/cosmos/cosmos-sdk/types" sdkerrors "github.com/cosmos/cosmos-sdk/types/errors" client "github.com/cosmos/cosmos-sdk/x/ibc/core/02-client" @@ -205,6 +207,19 @@ func NewHandler(k keeper.Keeper) sdk.Handler { } } + defer func() { + telemetry.IncrCounterWithLabels( + []string{"tx", "msg", "ibc", msg.Type()}, + 1, + []metrics.Label{ + telemetry.NewLabel("source-port", msg.Packet.SourcePort), + telemetry.NewLabel("source-channel", msg.Packet.SourceChannel), + telemetry.NewLabel("destination-port", msg.Packet.DestinationPort), + telemetry.NewLabel("destination-channel", msg.Packet.DestinationChannel), + }, + ) + }() + return res, nil case *channeltypes.MsgAcknowledgement: @@ -236,6 +251,19 @@ func NewHandler(k keeper.Keeper) sdk.Handler { return nil, err } + defer func() { + telemetry.IncrCounterWithLabels( + []string{"tx", "msg", "ibc", msg.Type()}, + 1, + []metrics.Label{ + telemetry.NewLabel("source-port", msg.Packet.SourcePort), + telemetry.NewLabel("source-channel", msg.Packet.SourceChannel), + telemetry.NewLabel("destination-port", msg.Packet.DestinationPort), + telemetry.NewLabel("destination-channel", msg.Packet.DestinationChannel), + }, + ) + }() + return res, nil case *channeltypes.MsgTimeout: @@ -267,6 +295,20 @@ func NewHandler(k keeper.Keeper) sdk.Handler { return nil, err } + defer func() { + telemetry.IncrCounterWithLabels( + []string{"ibc", "timeout", "packet"}, + 1, + []metrics.Label{ + telemetry.NewLabel("source-port", msg.Packet.SourcePort), + telemetry.NewLabel("source-channel", msg.Packet.SourceChannel), + telemetry.NewLabel("destination-port", msg.Packet.DestinationPort), + telemetry.NewLabel("destination-channel", msg.Packet.DestinationChannel), + telemetry.NewLabel("timeout-type", "height"), + }, + ) + }() + return res, nil case *channeltypes.MsgTimeoutOnClose: @@ -300,6 +342,20 @@ func NewHandler(k keeper.Keeper) sdk.Handler { return nil, err } + defer func() { + telemetry.IncrCounterWithLabels( + []string{"ibc", "timeout", "packet"}, + 1, + []metrics.Label{ + telemetry.NewLabel("source-port", msg.Packet.SourcePort), + telemetry.NewLabel("source-channel", msg.Packet.SourceChannel), + telemetry.NewLabel("destination-port", msg.Packet.DestinationPort), + telemetry.NewLabel("destination-channel", msg.Packet.DestinationChannel), + telemetry.NewLabel("timeout-type", "channel-closed"), + }, + ) + }() + return res, nil default: