From c984d72cfd3451f978fd932e509bf8579c8e9754 Mon Sep 17 00:00:00 2001
From: Derrick Hammer <derrick@derrickhammer.com>
Date: Wed, 28 Feb 2024 12:33:13 -0500
Subject: [PATCH] refactor: add performance logging for bao

---
 api/s5/s5.go |  2 +-
 bao/bao.go   | 23 ++++++++++++++++++-----
 2 files changed, 19 insertions(+), 6 deletions(-)

diff --git a/api/s5/s5.go b/api/s5/s5.go
index 9847d3c..2ce8966 100644
--- a/api/s5/s5.go
+++ b/api/s5/s5.go
@@ -1684,7 +1684,7 @@ func (s *S5API) pinImportCronJob(cid string, url string, proofUrl string, userId
 	}
 	defer closeBody(res.Body)
 
-	verifier := bao.NewVerifier(res.Body, baoProof)
+	verifier := bao.NewVerifier(res.Body, baoProof, s.logger)
 	defer func(Body io.ReadCloser) {
 		err := Body.Close()
 		if err != nil {
diff --git a/bao/bao.go b/bao/bao.go
index 6af13cf..4a9c73a 100644
--- a/bao/bao.go
+++ b/bao/bao.go
@@ -9,6 +9,9 @@ import (
 	"math"
 	"os"
 	"os/exec"
+	"time"
+
+	"go.uber.org/zap"
 
 	"github.com/docker/go-units"
 	"github.com/hashicorp/go-plugin"
@@ -27,10 +30,12 @@ var _ io.ReadCloser = (*Verifier)(nil)
 var ErrVerifyFailed = errors.New("verification failed")
 
 type Verifier struct {
-	r      io.ReadCloser
-	proof  Result
-	read   uint64
-	buffer *bytes.Buffer
+	r          io.ReadCloser
+	proof      Result
+	read       uint64
+	buffer     *bytes.Buffer
+	logger     *zap.Logger
+	verifyTime time.Duration
 }
 
 func (v *Verifier) Read(p []byte) (int, error) {
@@ -52,10 +57,17 @@ func (v *Verifier) Read(p []byte) (int, error) {
 			return n, err // Return any read error immediately
 		}
 
+		timeStart := time.Now()
+
 		if status, err := bao.Verify(buf[:bytesRead], v.read, v.proof.Proof, v.proof.Hash); err != nil || !status {
 			return n, errors.Join(ErrVerifyFailed, err)
 		}
 
+		timeEnd := time.Now()
+		v.verifyTime += timeEnd.Sub(timeStart)
+		averageVerifyTime := v.verifyTime / time.Duration(v.read/VERIFY_CHUNK_SIZE)
+		v.logger.Debug("Verification time", zap.Duration("duration", timeEnd.Sub(timeStart)), zap.Duration("average", averageVerifyTime))
+
 		v.read += uint64(bytesRead)
 		v.buffer.Write(buf[:bytesRead]) // Append new data to the buffer
 
@@ -163,10 +175,11 @@ func Hash(r io.Reader) (*Result, error) {
 	return &result, nil
 }
 
-func NewVerifier(r io.ReadCloser, proof Result) *Verifier {
+func NewVerifier(r io.ReadCloser, proof Result, logger *zap.Logger) *Verifier {
 	return &Verifier{
 		r:      r,
 		proof:  proof,
 		buffer: new(bytes.Buffer),
+		logger: logger,
 	}
 }