From 68d82390ed7f9907de478c786ded977fee044612 Mon Sep 17 00:00:00 2001
From: Derrick Hammer <derrick@derrickhammer.com>
Date: Wed, 28 Feb 2024 12:56:39 -0500
Subject: [PATCH] refactor: add timing tracking for reading

---
 bao/bao.go | 13 +++++++++++++
 1 file changed, 13 insertions(+)

diff --git a/bao/bao.go b/bao/bao.go
index 4eda1ed..d124b72 100644
--- a/bao/bao.go
+++ b/bao/bao.go
@@ -11,6 +11,8 @@ import (
 	"os/exec"
 	"time"
 
+	"github.com/samber/lo"
+
 	"go.uber.org/zap"
 
 	"github.com/docker/go-units"
@@ -35,6 +37,7 @@ type Verifier struct {
 	read       uint64
 	buffer     *bytes.Buffer
 	logger     *zap.Logger
+	readTime   []time.Duration
 	verifyTime time.Duration
 }
 
@@ -52,11 +55,21 @@ func (v *Verifier) Read(p []byte) (int, error) {
 	buf := make([]byte, VERIFY_CHUNK_SIZE)
 	// Continue reading from the source and verifying until we have enough data or hit an error
 	for v.buffer.Len() < len(p)-n {
+		readStart := time.Now()
 		bytesRead, err := io.ReadFull(v.r, buf)
 		if err != nil && err != io.EOF && err != io.ErrUnexpectedEOF {
 			return n, err // Return any read error immediately
 		}
 
+		readEnd := time.Now()
+
+		v.readTime = append(v.readTime, readEnd.Sub(readStart))
+		averageReadTime := lo.Reduce(v.readTime, func(acc time.Duration, cur time.Duration, _ int) time.Duration {
+			return acc + cur
+		}, time.Duration(0)) / time.Duration(len(v.readTime))
+
+		v.logger.Debug("Read time", zap.Duration("average", averageReadTime))
+
 		timeStart := time.Now()
 
 		if status, err := bao.Verify(buf[:bytesRead], v.read, v.proof.Proof, v.proof.Hash); err != nil || !status {