Add/proof gen time (#978)

* Add proof generation time consumption

* Add log

* Store proof gen time as milliseconds

code/go/0chain.net/blobbercore/challenge/protocol.go

@@ -187,6 +187,8 @@ func (cr *ChallengeEntity) LoadValidationTickets(ctx context.Context) error {
 	}
 	postData["write_markers"] = markersArray
 
+	var proofGenTime int64 = -1
+
 	if blockNum > 0 {
 		if objectPath.Meta["type"] != reference.FILE {
 			allocMu.Unlock()
@@ -217,18 +219,40 @@ func (cr *ChallengeEntity) LoadValidationTickets(ctx context.Context) error {
 
 		r := rand.New(rand.NewSource(cr.RandomNumber))
 		blockoffset := r.Intn(maxNumBlocks)
+		t1 := time.Now()
 		blockData, mt, err := filestore.GetFileStore().GetBlocksMerkleTreeForChallenge(cr.AllocationID, inputData, blockoffset)
 
 		if err != nil {
 			allocMu.Unlock()
 			cr.CancelChallenge(ctx, err)
 			return common.NewError("blockdata_not_found", err.Error())
 		}
+
+		proofGenTime = time.Since(t1).Milliseconds()
+
 		postData["data"] = []byte(blockData)
 		postData["merkle_path"] = mt.GetPathByIndex(blockoffset)
 		postData["chunk_size"] = objectPath.ChunkSize
 	}
 
+	logging.Logger.Info("Proof gen logs: ",
+		zap.Int64("block num", blockNum),
+		zap.Int64("file size", objectPath.Meta["size"].(int64)),
+		zap.String("file path", objectPath.Meta["name"].(string)),
+		zap.Int64("proof gen time", proofGenTime),
+	)
+
+	err = UpdateChallengeTimingProofGenerationAndFileSize(
+		cr.ChallengeID,
+		proofGenTime,
+		objectPath.Size,
+	)
+	if err != nil {
+		allocMu.Unlock()
+		logging.Logger.Error(err.Error())
+		return err
+	}
+
 	allocMu.Unlock()
 
 	postDataBytes, err := json.Marshal(postData)

code/go/0chain.net/blobbercore/challenge/timing.go

@@ -5,6 +5,7 @@ import (
 
 	"github.com/0chain/blobber/code/go/0chain.net/blobbercore/datastore"
 	"github.com/0chain/blobber/code/go/0chain.net/core/common"
+	"github.com/0chain/blobber/code/go/0chain.net/core/logging"
 	"gorm.io/gorm"
 	"gorm.io/gorm/clause"
 )
@@ -17,6 +18,10 @@ type ChallengeTiming struct {
 	CreatedAtChain common.Timestamp `gorm:"created_at_chain" json:"created_at_chain"`
 	// CreatedAtBlobber is when synchronized and created at blobber.
 	CreatedAtBlobber common.Timestamp `gorm:"created_at_blobber" json:"created_at_blobber"`
+	// FileSize is size of file that was randomly selected for challenge
+	FileSize int64 `gorm:"file_size" json:"file_size"`
+	// ProofGenTime is the time taken in millisecond to generate challenge proof for the file
+	ProofGenTime int64 `gorm:"proof_gen_time" json:"proof_gen_time"`
 	// CompleteValidation is when all validation tickets are all received.
 	CompleteValidation common.Timestamp `gorm:"complete_validation" json:"complete_validation"`
 	// TxnSubmission is when challenge response is first sent to blockchain.
@@ -95,6 +100,23 @@ func UpdateChallengeTimingCompleteValidation(challengeID string, completeValidat
 	return err
 }
 
+func UpdateChallengeTimingProofGenerationAndFileSize(
+	challengeID string, proofGenTime, size int64) error {
+
+	if proofGenTime == 0 || size == 0 {
+		logging.Logger.Error(fmt.Sprintf("Proof gen time: %d, size: %d", proofGenTime, size))
+	}
+
+	c := &ChallengeTiming{
+		ChallengeID:  challengeID,
+		ProofGenTime: proofGenTime,
+		FileSize:     size,
+	}
+
+	db := datastore.GetStore().GetDB()
+	return db.Save(c).Error
+}
+
 func UpdateChallengeTimingTxnSubmission(challengeID string, txnSubmission common.Timestamp) error {
 	c := &ChallengeTiming{
 		ChallengeID: challengeID,