Add logs

Author: dwasse

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,13 +810,15 @@ 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)),
 					attribute.Int("num_messages", len(messages)),
 					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 {

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)

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.

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 {