add provider and consumer logging #628

MSalopek · 2022-12-23T14:53:39Z

Description

Add logging to provider and consumer.
This is a continuation of efforts in #577.

Linked issues

Closes: #576

Type of change

Feature: Changes and/or adds code behavior, irrelevant to bug fixes

shaspitz

Locations of logging look great, thanks for this! I've added some comments on the strings being logged

shaspitz · 2023-01-03T17:17:26Z

tests/integration/actions.go

@@ -499,7 +499,7 @@ gas_multiplier = 1.1
 grpc_addr = "%s"
 id = "%s"
 key_name = "%s"
-max_gas = 2000000
+max_gas = 20000000


Does this change have to do with logging?

For some reason integration tests were failing after I added logging on my local machine, this seemed to have fixed it.

x/ccv/consumer/keeper/relay.go

x/ccv/provider/keeper/relay.go

x/ccv/provider/keeper/throttle.go

Co-authored-by: Shawn <[email protected]>

danwt

LGTM1

x/ccv/consumer/keeper/distribution.go

danwt · 2023-01-04T13:36:53Z

x/ccv/consumer/keeper/relay.go

@@ -102,6 +115,8 @@ func (k Keeper) QueueVSCMaturedPackets(ctx sdk.Context) {

 		k.DeletePacketMaturityTimes(ctx, maturityTime.VscId, maturityTime.MaturityTime)

+		k.Logger(ctx).Info("VSCMaturedPacket enqueued", "vscID", vscPacket.ValsetUpdateId)


Suggested change

k.Logger(ctx).Info("VSCMaturedPacket enqueued", "vscID", vscPacket.ValsetUpdateId)

k.Logger(ctx).Debug("VSCMaturedPacket enqueued", "vscID", vscPacket.ValsetUpdateId)

(Packet enqueue is implementation detail, the info parts are when you send a packet IMO)

Sending the packet is logged by the IBC module. Queueing the packet is important as that should result in an IBC send. Also, it's the only place where we can log the data without having to unmarshal it in SendPackets

danwt · 2023-01-04T13:45:45Z

x/ccv/provider/keeper/relay.go

+		k.Logger(ctx).Debug("unbonding operation matured on consumer", "chainID", chainID, "opID", unbondingOp.Id)

 		// If unbonding op is completely unbonded from all relevant consumer chains
 		if len(unbondingOp.UnbondingConsumerChains) == 0 {


Perhaps only log the case when len(unbondingOp.UnbondingConsumerChains) == 0, it might be too noisy otherwise.

It's debug, it's okay to be noisy :)

x/ccv/provider/keeper/relay.go

x/ccv/consumer/module.go

x/ccv/provider/keeper/relay.go

Co-authored-by: Daniel T <[email protected]>

…ty into 576-add-logging

shaspitz

Sorry if these comments seem nitpicky :), there's just been a lot of times I've said to myself, damn I wish I logged that better

x/ccv/consumer/keeper/relay.go

shaspitz · 2023-01-04T23:37:15Z

x/ccv/consumer/keeper/distribution.go

+
+		k.Logger(ctx).Info("sent block rewards to provider",
+			"fee pool", fpTokens.String(),
+			"sent", remainingTokens.String(),


Is the sent field here similar to remaining tokens in fee pool? If so the latter is prob more descriptive

sent is the amount actually transferred. I've replaced remainingTokens with tstProviderTokens.

shaspitz · 2023-01-04T23:38:33Z

x/ccv/consumer/keeper/distribution.go

@@ -85,6 +85,11 @@ func (k Keeper) DistributeToProviderValidatorSet(ctx sdk.Context) error {
 				return err
 			}
 		}
+
+		k.Logger(ctx).Info("sent block rewards to provider",
+			"fee pool", fpTokens.String(),


I believe this field is fee pool before being decremented, right?

Yes. Replaced with "total fee pool"

x/ccv/consumer/keeper/validators.go

x/ccv/consumer/module.go

shaspitz · 2023-01-04T23:57:57Z

x/ccv/provider/keeper/relay.go

@@ -127,12 +147,14 @@ func (k Keeper) OnAcknowledgementPacket(ctx sdk.Context, packet channeltypes.Pac
 func (k Keeper) OnTimeoutPacket(ctx sdk.Context, packet channeltypes.Packet) error {
 	chainID, found := k.GetChannelToChain(ctx, packet.SourceChannel)
 	if !found {
+		k.Logger(ctx).Error("packet timeout, unknown channel:", "channel", packet.SourceChannel)


shaspitz · 2023-01-04T23:59:16Z

x/ccv/provider/keeper/relay.go

@@ -250,10 +281,20 @@ func (k Keeper) OnRecvSlashPacket(ctx sdk.Context, packet channeltypes.Packet, d
 	if !found {
 		// SlashPacket packet was sent on a channel different than any of the established CCV channels;
 		// this should never happen
+		k.Logger(ctx).Error("SlashPacket received on unknown channel",


Same, could log src channel ID

x/ccv/provider/keeper/relay.go

x/ccv/provider/keeper/throttle.go

mpoke · 2023-01-05T15:43:44Z

make test passes on my machine

MSalopek requested review from jtremback, mpoke, sainoe, danwt and shaspitz as code owners December 23, 2022 14:53

MSalopek marked this pull request as draft December 23, 2022 17:14

MSalopek force-pushed the 576-add-logging branch from 6b7952f to 442f2e3 Compare January 3, 2023 11:29

add provider and consumer logging

dfb052e

MSalopek force-pushed the 576-add-logging branch from f9c3578 to dfb052e Compare January 3, 2023 14:51

MSalopek marked this pull request as ready for review January 3, 2023 15:09

shaspitz reviewed Jan 3, 2023

View reviewed changes

mpoke and others added 15 commits January 4, 2023 10:13

Update x/ccv/consumer/keeper/relay.go

b59e623

Co-authored-by: Shawn <[email protected]>

Update x/ccv/consumer/keeper/relay.go

a0a7591

Co-authored-by: Shawn <[email protected]>

Update x/ccv/consumer/keeper/relay.go

53c85ec

Co-authored-by: Shawn <[email protected]>

Update x/ccv/consumer/keeper/relay.go

f952b57

Co-authored-by: Shawn <[email protected]>

Update x/ccv/consumer/keeper/relay.go

0c7205b

Co-authored-by: Shawn <[email protected]>

Update x/ccv/provider/keeper/key_assignment.go

0d06793

Co-authored-by: Shawn <[email protected]>

Update x/ccv/provider/keeper/proposal.go

b603a5e

Co-authored-by: Shawn <[email protected]>

Update x/ccv/provider/keeper/relay.go

dea4b63

Co-authored-by: Shawn <[email protected]>

Update x/ccv/provider/keeper/relay.go

a3c92c3

Co-authored-by: Shawn <[email protected]>

Update x/ccv/provider/keeper/relay.go

e61d050

Co-authored-by: Shawn <[email protected]>

Update x/ccv/provider/keeper/relay.go

a0d604a

Co-authored-by: Shawn <[email protected]>

Update x/ccv/provider/keeper/throttle.go

e3a2a31

Co-authored-by: Shawn <[email protected]>

Update x/ccv/provider/keeper/throttle.go

811805e

Co-authored-by: Shawn <[email protected]>

add / update logging

21ac2a2

add error some logging

f6c9e4d

danwt approved these changes Jan 4, 2023

View reviewed changes

Merge branch 'main' into 576-add-logging

7ae537f

sainoe reviewed Jan 4, 2023

View reviewed changes

x/ccv/consumer/module.go Outdated Show resolved Hide resolved

sainoe reviewed Jan 4, 2023

View reviewed changes

x/ccv/provider/keeper/relay.go Outdated Show resolved Hide resolved

mpoke approved these changes Jan 4, 2023

View reviewed changes

mpoke and others added 5 commits January 4, 2023 19:21

Update x/ccv/consumer/keeper/distribution.go

163fe28

Co-authored-by: Daniel T <[email protected]>

Update x/ccv/consumer/keeper/distribution.go

62d2aeb

Co-authored-by: Daniel T <[email protected]>

revert block height inc

bc4e4c6

Merge branch '576-add-logging' of github.com:cosmos/interchain-securi…

ed038d4

…ty into 576-add-logging

apply review suggestions

defb3ef

mpoke requested a review from shaspitz January 4, 2023 18:42

shaspitz reviewed Jan 5, 2023

View reviewed changes

mpoke added 2 commits January 5, 2023 13:18

apply review suggestions

50aed10

Merge branch 'main' into 576-add-logging

f0b1721

mpoke merged commit bbb892f into main Jan 5, 2023

mpoke deleted the 576-add-logging branch January 5, 2023 15:44

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

add provider and consumer logging #628

add provider and consumer logging #628

MSalopek commented Dec 23, 2022

shaspitz left a comment

shaspitz Jan 3, 2023

MSalopek Jan 4, 2023

danwt left a comment

danwt Jan 4, 2023

mpoke Jan 4, 2023

danwt Jan 4, 2023

mpoke Jan 4, 2023

shaspitz left a comment

shaspitz Jan 4, 2023

mpoke Jan 5, 2023

shaspitz Jan 4, 2023

mpoke Jan 5, 2023

shaspitz Jan 4, 2023

mpoke Jan 5, 2023

shaspitz Jan 4, 2023

mpoke Jan 5, 2023

mpoke commented Jan 5, 2023

		@@ -102,6 +115,8 @@ func (k Keeper) QueueVSCMaturedPackets(ctx sdk.Context) {

		k.DeletePacketMaturityTimes(ctx, maturityTime.VscId, maturityTime.MaturityTime)

		k.Logger(ctx).Info("VSCMaturedPacket enqueued", "vscID", vscPacket.ValsetUpdateId)

	k.Logger(ctx).Info("VSCMaturedPacket enqueued", "vscID", vscPacket.ValsetUpdateId)
	k.Logger(ctx).Debug("VSCMaturedPacket enqueued", "vscID", vscPacket.ValsetUpdateId)

add provider and consumer logging #628

add provider and consumer logging #628

Conversation

MSalopek commented Dec 23, 2022

Description

Linked issues

Type of change

shaspitz left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

danwt left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

shaspitz left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

mpoke commented Jan 5, 2023