Merge branch 'dataLatencyLogging' into 'release'

added a mechanisim to get the average latency on round packets received

See merge request !619

network/follow.go

@@ -28,6 +28,7 @@ import (
 	jww "github.com/spf13/jwalterweatherman"
 	"gitlab.com/elixxir/client/interfaces"
 	"gitlab.com/elixxir/client/network/rounds"
+	"gitlab.com/xx_network/primitives/netTime"
 	pb "gitlab.com/elixxir/comms/mixmessages"
 	"gitlab.com/elixxir/primitives/knownRounds"
 	"gitlab.com/elixxir/primitives/states"
@@ -63,9 +64,19 @@ func (m *manager) followNetwork(report interfaces.ClientErrorReport, quitCh <-ch
 			m.follow(report, rng, m.Comms, isRunning)
 		case <-TrackTicker.C:
 			numPolls := atomic.SwapUint64(m.tracker, 0)
+			if m.numLatencies !=0{
+				latencyAvg := time.Nanosecond*time.Duration(m.latencySum/m.numLatencies)
+				m.latencySum, m.numLatencies = 0, 0
+
+				jww.INFO.Printf("Polled the network %d times in the "+
+					"last %s, with an average newest packet latency of %s", numPolls,
+					debugTrackPeriod, latencyAvg)
+			}else{
 				jww.INFO.Printf("Polled the network %d times in the "+
 					"last %s", numPolls, debugTrackPeriod)
 			}
+
+		}
 		if !isRunning.IsRunning(){
 			jww.ERROR.Printf("Killing network follower " +
 				"due to failed exit")
@@ -78,6 +89,7 @@ func (m *manager) followNetwork(report interfaces.ClientErrorReport, quitCh <-ch
 func (m *manager) follow(report interfaces.ClientErrorReport, rng csprng.Source,
 	comms followNetworkComms, isRunning interfaces.Running) {
 
+
 	//get the identity we will poll for
 	identity, err := m.Session.Reception().GetIdentity(rng)
 	if err != nil {
@@ -114,6 +126,9 @@ func (m *manager) follow(report interfaces.ClientErrorReport, rng csprng.Source,
 			"due to failed exit")
 		return
 	}
+
+	now := netTime.Now()
+
 	if err != nil {
 		if report != nil {
 			report(
@@ -208,6 +223,22 @@ func (m *manager) follow(report interfaces.ClientErrorReport, rng csprng.Source,
 				}
 			}
 		}
+
+
+		newestTS := uint64(0)
+		for i:=0;i<len(pollResp.Updates[len(pollResp.Updates)-1].Timestamps);i++{
+			if pollResp.Updates[len(pollResp.Updates)-1].Timestamps[i]!=0{
+				newestTS = pollResp.Updates[len(pollResp.Updates)-1].Timestamps[i]
+			}
+		}
+
+		newest := time.Unix(0,int64(newestTS))
+
+		if newest.After(now){
+			deltaDur := newest.Sub(now)
+			m.latencySum = uint64(deltaDur)
+			m.numLatencies++
+		}
 	}
 
 	// ---- Identity Specific Round Processing -----

network/manager.go

@@ -48,6 +48,8 @@ type manager struct {
 
 	//number of polls done in a period of time
 	tracker *uint64
+	latencySum uint64
+	numLatencies uint64
 }
 
 // NewManager builds a new reception manager object using inputted key fields