From 8637cb68515986b7b7fbbab3d82bdc9556efc044 Mon Sep 17 00:00:00 2001 From: Daniel Wasserman Date: Tue, 12 Sep 2023 10:57:42 -0500 Subject: [PATCH] Add logs --- agents/agents/executor/executor.go | 5 ++++ agents/agents/executor/executor_utils.go | 18 +++++++++++++ agents/agents/guard/fraud.go | 4 +++ agents/agents/guard/fraud_test.go | 33 ++++++++++++++++++++++++ 4 files changed, 60 insertions(+) diff --git a/agents/agents/executor/executor.go b/agents/agents/executor/executor.go index bbd8855d51..b4fef4c065 100644 --- a/agents/agents/executor/executor.go +++ b/agents/agents/executor/executor.go @@ -309,6 +309,7 @@ func (e Executor) Stop(chainID uint32) { // //nolint:cyclop func (e Executor) Execute(parentCtx context.Context, message types.Message) (_ bool, err error) { + fmt.Printf("entering msg execution: %v\n", message) originDomain := message.OriginDomain() destinationDomain := message.DestinationDomain() @@ -402,6 +403,7 @@ func (e Executor) Execute(parentCtx context.Context, message types.Message) (_ b } _, err = e.txSubmitter.SubmitTransaction(ctx, big.NewInt(int64(destinationDomain)), func(transactor *bind.TransactOpts) (tx *ethTypes.Transaction, err error) { + fmt.Printf("executing message with destination %d: %v\n", destinationDomain, message) tx, err = e.chainExecutors[message.DestinationDomain()].boundDestination.Execute( transactor, message, @@ -793,6 +795,7 @@ func (e Executor) executeExecutable(parentCtx context.Context, chainID uint32) ( page := 1 currentTime := uint64(e.NowFunc().Unix()) + fmt.Printf("got current time: %v, real time: %v\n", currentTime, time.Now().Unix()) messageMask := db.DBMessage{ ChainID: &chainID, @@ -807,6 +810,7 @@ func (e Executor) executeExecutable(parentCtx context.Context, chainID uint32) ( if len(messages) == 0 { break } + fmt.Printf("got executable messages: %v\n", messages) ctx, span := e.handler.Tracer().Start(parentCtx, "executeExecutable", trace.WithAttributes( attribute.Int(metrics.ChainID, int(chainID)), @@ -814,6 +818,7 @@ func (e Executor) executeExecutable(parentCtx context.Context, chainID uint32) ( attribute.Int(metrics.Page, page), )) + fmt.Printf("executor processing messages: %v\n", messages) for _, message := range messages { messageExecuted, err := e.checkIfExecuted(ctx, message) if err != nil { diff --git a/agents/agents/executor/executor_utils.go b/agents/agents/executor/executor_utils.go index 585c5a02a9..afe1a81208 100644 --- a/agents/agents/executor/executor_utils.go +++ b/agents/agents/executor/executor_utils.go @@ -154,6 +154,8 @@ func (e Executor) processMessage(ctx context.Context, message types.Message, log // processAttestation processes and stores an attestation. func (e Executor) processSnapshot(ctx context.Context, snapshot types.Snapshot, logBlockNumber uint64) error { + fmt.Printf("processSnapshot at block %d: %v\n", logBlockNumber, snapshot) + fmt.Printf("snapshot states: %v\n", snapshot.States()) for _, state := range snapshot.States() { statePayload, err := state.Encode() if err != nil { @@ -167,9 +169,24 @@ func (e Executor) processSnapshot(ctx context.Context, snapshot types.Snapshot, if err != nil { return fmt.Errorf("could not check validity of state: %w", err) } + + originState, err := e.chainExecutors[state.Origin()].boundOrigin.SuggestLatestState(ctx) + if err != nil { + return err + } + stateHash, err := originState.Hash() + if err != nil { + return err + } + fmt.Printf("suggested latest origin state with root: %v, hash: %v, nonce: %v\n", originState.Root(), common.BytesToHash(stateHash[:]), originState.Nonce()) + stateRoot := state.Root() + fmt.Printf("provided snapshot. Origin: %d. SnapshotRoot: %s, Nonce: %d\n", state.Origin(), common.BytesToHash(stateRoot[:]).String(), state.Nonce()) + if !valid { stateRoot := state.Root() + fmt.Printf("snapshot has invalid state. Origin: %d. SnapshotRoot: %s, Nonce: %d\n", state.Origin(), common.BytesToHash(stateRoot[:]).String(), state.Nonce()) logger.Infof("snapshot has invalid state. Origin: %d. SnapshotRoot: %s", state.Origin(), common.BytesToHash(stateRoot[:]).String()) + return nil } } @@ -178,6 +195,7 @@ func (e Executor) processSnapshot(ctx context.Context, snapshot types.Snapshot, return fmt.Errorf("could not get snapshot root and proofs: %w", err) } + fmt.Println("storing states") err = e.executorDB.StoreStates(ctx, snapshot.States(), snapshotRoot, proofs, logBlockNumber) if err != nil { return fmt.Errorf("could not store states: %w", err) diff --git a/agents/agents/guard/fraud.go b/agents/agents/guard/fraud.go index 7dee240103..604ffa5bb3 100644 --- a/agents/agents/guard/fraud.go +++ b/agents/agents/guard/fraud.go @@ -535,6 +535,7 @@ func (g Guard) handleStatusUpdated(ctx context.Context, log ethTypes.Log, chainI if err != nil { return fmt.Errorf("could not parse status updated: %w", err) } + fmt.Printf("handleStatusUpdated: %v on %d\n", types.AgentFlagType(statusUpdated.Flag).String(), chainID) //nolint:exhaustive switch types.AgentFlagType(statusUpdated.Flag) { @@ -708,6 +709,7 @@ func (g Guard) updateAgentStatus(ctx context.Context, chainID uint32) error { if len(eligibleAgentTrees) == 0 { return nil } + fmt.Printf("got eligible agent trees: %v\n", eligibleAgentTrees) var localRoot [32]byte contractCall := func(ctx context.Context) error { @@ -727,6 +729,7 @@ func (g Guard) updateAgentStatus(ctx context.Context, chainID uint32) error { if err != nil { return fmt.Errorf("could not get block number for local root: %w", err) } + fmt.Printf("got localRootBlockNumber %d for agent root %s on chain %d\n", localRootBlockNumber, common.BytesToHash(localRoot[:]).String(), chainID) // Filter the eligible agent roots by the given block number and call updateAgentStatus(). for _, t := range eligibleAgentTrees { @@ -737,6 +740,7 @@ func (g Guard) updateAgentStatus(ctx context.Context, chainID uint32) error { return fmt.Errorf("could not get block number for local root: %w", err) } //nolint:nestif + fmt.Printf("comparing localRootBlockNumber %d with treeBlockNumber %d\n", localRootBlockNumber, treeBlockNumber) if localRootBlockNumber >= treeBlockNumber { logger.Infof("Relaying agent status for agent %s on chain %d", tree.AgentAddress.String(), chainID) // Fetch the agent status to be relayed from Summit. diff --git a/agents/agents/guard/fraud_test.go b/agents/agents/guard/fraud_test.go index 6ef13a3ebb..3fc9aedb6e 100644 --- a/agents/agents/guard/fraud_test.go +++ b/agents/agents/guard/fraud_test.go @@ -940,6 +940,25 @@ func (g GuardSuite) TestUpdateAgentStatusOnRemote() { originState, err := types.DecodeState(originStateRaw) g.Nil(err) snapshot := types.NewSnapshot([]types.State{originState}) + stateHash, err := originState.Hash() + g.Nil(err) + fmt.Printf("[TEST] submitting suggested latest origin state with root: %v, hash: %v, nonce: %v\n", originState.Root(), common.BytesToHash(stateHash[:]), originState.Nonce()) + + go func() { + for { + originStateRaw, err := g.OriginContract.SuggestLatestState(&bind.CallOpts{Context: g.GetTestContext()}) + if err != nil { + continue + } + g.Nil(err) + originState, err := types.DecodeState(originStateRaw) + g.Nil(err) + stateHash, err := originState.Hash() + g.Nil(err) + fmt.Printf("[TEST] suggested latest origin state with root: %v, hash: %v, nonce: %v\n", originState.Root(), common.BytesToHash(stateHash[:]), originState.Nonce()) + time.Sleep(250 * time.Millisecond) + } + }() // Submit snapshot with Guard. guardSnapshotSignature, encodedSnapshot, _, err = snapshot.SignSnapshot(g.GetTestContext(), g.GuardBondedSigner) @@ -1004,6 +1023,7 @@ func (g GuardSuite) TestUpdateAgentStatusOnRemote() { g.bumpBackends() return false }) + fmt.Println("slashed on summit") // Get the origin state so we can submit it on the Summit. originStateRaw, err = g.OriginContract.SuggestLatestState(&bind.CallOpts{Context: g.GetTestContext()}) @@ -1078,14 +1098,27 @@ func (g GuardSuite) TestUpdateAgentStatusOnRemote() { NotNil(g.T(), tx) g.TestBackendDestination.WaitForConfirmation(g.GetTestContext(), tx) + logAgentRoots := func() { + summitAgentRoot, err := g.SummitDomainClient.BondingManager().GetAgentRoot(g.GetTestContext()) + g.Nil(err) + destAgentRoot, err := g.LightManagerOnDestination.AgentRoot(&bind.CallOpts{Context: g.GetTestContext()}) + g.Nil(err) + nextAgentRoot, err := g.DestinationContract.NextAgentRoot(&bind.CallOpts{Context: g.GetTestContext()}) + g.Nil(err) + fmt.Printf("Summit agent root: %v\n, destination agent root: %v\n, next agent root: %v\n", summitAgentRoot, destAgentRoot, nextAgentRoot) + } // Advance time on destination and call passAgentRoot() so that the latest agent root is accepted. increaseEvmTime(g.TestBackendDestination, optimisticPeriodSeconds+30) g.bumpBackends() + fmt.Println("roots before passing agent root:") + logAgentRoots() txContextDestination := g.TestBackendDestination.GetTxContext(g.GetTestContext(), g.DestinationContractMetadata.OwnerPtr()) tx, err = g.DestinationDomainClient.Destination().PassAgentRoot(txContextDestination.TransactOpts) g.Nil(err) g.TestBackendDestination.WaitForConfirmation(g.GetTestContext(), tx) g.bumpBackends() + fmt.Println("roots after passing agent root:") + logAgentRoots() // Verify that the guard eventually marks the accused agent as Slashed. g.Eventually(func() bool {