Add timetrack to SendCheckMsgs (hyperledger-labs#118)

* Add timetrack to SendCheckMsgs Signed-off-by: Dongri Jin <[email protected]> * Fix logger.TimeTrack Signed-off-by: Dongri Jin <[email protected]> * Add "queried_chain" attribute Signed-off-by: Dongri Jin <[email protected]> --------- Signed-off-by: Dongri Jin <[email protected]>
dongrie · Nov 1, 2023 · 0f26fb7 · 0f26fb7
1 parent 9e602df
commit 0f26fb7
Show file tree

Hide file tree

Showing 2 changed files with 35 additions and 4 deletions.
diff --git a/core/naive-strategy.go b/core/naive-strategy.go
@@ -98,8 +98,13 @@ func (st *NaiveStrategy) UnrelayedPackets(src, dst *ProvableChain, sh SyncHeader
 	eg.Go(func() error {
 		return retry.Do(func() error {
 			var err error
+			now := time.Now()
 			srcPackets, err = src.QueryUnfinalizedRelayPackets(srcCtx, dst)
-			return err
+			if err != nil {
+				return err
+			}
+			logger.TimeTrack(now, "QueryUnfinalizedRelayPackets", "queried_chain", "src", "num_packets", len(srcPackets))
+			return nil
 		}, rtyAtt, rtyDel, rtyErr, retry.OnRetry(func(n uint, err error) {
 			logger.Info(
 				"retrying to query unfinalized packet relays",
@@ -115,8 +120,13 @@ func (st *NaiveStrategy) UnrelayedPackets(src, dst *ProvableChain, sh SyncHeader
 	eg.Go(func() error {
 		return retry.Do(func() error {
 			var err error
+			now := time.Now()
 			dstPackets, err = dst.QueryUnfinalizedRelayPackets(dstCtx, src)
-			return err
+			if err != nil {
+				return err
+			}
+			logger.TimeTrack(now, "QueryUnfinalizedRelayPackets", "queried_chain", "dst", "num_packets", len(dstPackets))
+			return nil
 		}, rtyAtt, rtyDel, rtyErr, retry.OnRetry(func(n uint, err error) {
 			logger.Info(
 				"retrying to query unfinalized packet relays",
@@ -155,19 +165,23 @@ func (st *NaiveStrategy) UnrelayedPackets(src, dst *ProvableChain, sh SyncHeader
 		}
 
 		eg.Go(func() error {
+			now := time.Now()
 			seqs, err := dst.QueryUnreceivedPackets(dstCtx, srcPackets.ExtractSequenceList())
 			if err != nil {
 				return err
 			}
+			logger.TimeTrack(now, "QueryUnreceivedPackets", "queried_chain", "dst", "num_seqs", len(seqs))
 			srcPackets = srcPackets.Filter(seqs)
 			return nil
 		})
 
 		eg.Go(func() error {
+			now := time.Now()
 			seqs, err := src.QueryUnreceivedPackets(srcCtx, dstPackets.ExtractSequenceList())
 			if err != nil {
 				return err
 			}
+			logger.TimeTrack(now, "QueryUnreceivedPackets", "queried_chain", "src", "num_seqs", len(seqs))
 			dstPackets = dstPackets.Filter(seqs)
 			return nil
 		})
@@ -264,8 +278,13 @@ func (st *NaiveStrategy) UnrelayedAcknowledgements(src, dst *ProvableChain, sh S
 		eg.Go(func() error {
 			return retry.Do(func() error {
 				var err error
+				now := time.Now()
 				srcAcks, err = src.QueryUnfinalizedRelayAcknowledgements(srcCtx, dst)
-				return err
+				if err != nil {
+					return err
+				}
+				logger.TimeTrack(now, "QueryUnfinalizedRelayAcknowledgements", "queried_chain", "src", "num_packets", len(srcAcks))
+				return nil
 			}, rtyAtt, rtyDel, rtyErr, retry.OnRetry(func(n uint, err error) {
 				logger.Info(
 					"retrying to query unfinalized ack relays",
@@ -284,8 +303,13 @@ func (st *NaiveStrategy) UnrelayedAcknowledgements(src, dst *ProvableChain, sh S
 		eg.Go(func() error {
 			return retry.Do(func() error {
 				var err error
+				now := time.Now()
 				dstAcks, err = dst.QueryUnfinalizedRelayAcknowledgements(dstCtx, src)
-				return err
+				if err != nil {
+					return err
+				}
+				logger.TimeTrack(now, "QueryUnfinalizedRelayAcknowledgements", "queried_chain", "dst", "num_packets", len(dstAcks))
+				return nil
 			}, rtyAtt, rtyDel, rtyErr, retry.OnRetry(func(n uint, err error) {
 				logger.Info(
 					"retrying to query unfinalized ack relays",
@@ -323,21 +347,25 @@ func (st *NaiveStrategy) UnrelayedAcknowledgements(src, dst *ProvableChain, sh S
 
 		if !st.dstNoAck {
 			eg.Go(func() error {
+				now := time.Now()
 				seqs, err := dst.QueryUnreceivedAcknowledgements(dstCtx, srcAcks.ExtractSequenceList())
 				if err != nil {
 					return err
 				}
+				logger.TimeTrack(now, "QueryUnreceivedAcknowledgements", "queried_chain", "dst", "num_seqs", len(seqs))
 				srcAcks = srcAcks.Filter(seqs)
 				return nil
 			})
 		}
 
 		if !st.srcNoAck {
 			eg.Go(func() error {
+				now := time.Now()
 				seqs, err := src.QueryUnreceivedAcknowledgements(srcCtx, dstAcks.ExtractSequenceList())
 				if err != nil {
 					return err
 				}
+				logger.TimeTrack(now, "QueryUnreceivedAcknowledgements", "queried_chain", "src", "num_seqs", len(seqs))
 				dstAcks = dstAcks.Filter(seqs)
 				return nil
 			})

diff --git a/core/send.go b/core/send.go
@@ -10,10 +10,13 @@ import (
 
 // SendCheckMsgs is an utility function that executes `Chain::SendMsgs` and checks the execution results of all the messages.
 func SendCheckMsgs(chain Chain, msgs []types.Msg) bool {
+	logger := GetChainLogger(chain)
+	now := time.Now()
 	if _, err := chain.SendMsgs(msgs); err != nil {
 		GetChainLogger(chain).Error("failed to send msgs", err, "msgs", msgs)
 		return false
 	}
+	logger.TimeTrack(now, "SendMsgs", "num_msgs", len(msgs))
 	return true
 }