From 4b65e6a88fe779dd6ade37bbd2c9ece4b44d6313 Mon Sep 17 00:00:00 2001
From: Ben Johnson <benbjohnson@yahoo.com>
Date: Sun, 17 Jan 2021 07:38:13 -0700
Subject: [PATCH] Log validation position

---
 db.go      | 8 ++++----
 replica.go | 8 +++++++-
 s3/s3.go   | 5 +++++
 3 files changed, 16 insertions(+), 5 deletions(-)

diff --git a/db.go b/db.go
index 8e55cb6..7bac4cc 100644
--- a/db.go
+++ b/db.go
@@ -1319,7 +1319,7 @@ func (db *DB) Restore(ctx context.Context, opt RestoreOptions) error {
 	tmpPath := outputPath + ".tmp"
 
 	// Copy snapshot to output path.
-	logger.Printf("restoring snapshot from replica %q, generation %q, index %08x to %s", r.Name(), generation, minWALIndex, tmpPath)
+	log.Printf("%s(%s): restoring snapshot %s/%08x to %s", db.path, r.Name(), generation, minWALIndex, tmpPath)
 	if !opt.DryRun {
 		if err := db.restoreSnapshot(ctx, r, pos.Generation, pos.Index, tmpPath); err != nil {
 			return fmt.Errorf("cannot restore snapshot: %w", err)
@@ -1328,13 +1328,13 @@ func (db *DB) Restore(ctx context.Context, opt RestoreOptions) error {
 
 	// Restore each WAL file until we reach our maximum index.
 	for index := minWALIndex; index <= maxWALIndex; index++ {
-		logger.Printf("restoring wal from replica %q, generation %q, index %08x to %s-wal", r.Name(), generation, index, tmpPath)
+		log.Printf("%s(%s): restoring wal %s/%08x", db.path, r.Name(), generation, index)
 		if opt.DryRun {
 			continue
 		}
 
 		if err := db.restoreWAL(ctx, r, generation, index, tmpPath); os.IsNotExist(err) && index == minWALIndex && index == maxWALIndex {
-			logger.Printf("no wal available, snapshot only")
+			log.Printf("%s(%s): no wal available, snapshot only", db.path, r.Name())
 			break // snapshot file only, ignore error
 		} else if err != nil {
 			return fmt.Errorf("cannot restore wal: %w", err)
@@ -1342,7 +1342,7 @@ func (db *DB) Restore(ctx context.Context, opt RestoreOptions) error {
 	}
 
 	// Copy file to final location.
-	logger.Printf("renaming database from temporary location")
+	log.Printf("%s(%s): renaming database from temporary location", db.path, r.Name())
 	if !opt.DryRun {
 		if err := os.Rename(tmpPath, outputPath); err != nil {
 			return err
diff --git a/replica.go b/replica.go
index 39bb207..1b96a38 100644
--- a/replica.go
+++ b/replica.go
@@ -461,6 +461,12 @@ func (r *FileReplica) retainer(ctx context.Context) {
 
 // validator runs in a separate goroutine and handles periodic validation.
 func (r *FileReplica) validator(ctx context.Context) {
+	// Initialize counters since validation occurs infrequently.
+	for _, status := range []string{"ok", "error"} {
+		internal.ReplicaValidationTotalCounterVec.WithLabelValues(r.db.Path(), r.Name(), status).Add(0)
+	}
+
+	// Exit validation if interval is not set.
 	if r.ValidationInterval <= 0 {
 		return
 	}
@@ -990,7 +996,7 @@ func ValidateReplica(ctx context.Context, r Replica) error {
 	if err != nil {
 		return fmt.Errorf("cannot compute checksum: %w", err)
 	}
-	log.Printf("%s(%s): primary checksum computed: %08x", db.Path(), r.Name(), chksum0)
+	log.Printf("%s(%s): primary checksum computed: %08x @ %s", db.Path(), r.Name(), chksum0, pos)
 
 	// Wait until replica catches up to position.
 	log.Printf("%s(%s): waiting for replica", db.Path(), r.Name())
diff --git a/s3/s3.go b/s3/s3.go
index 98f47f3..6a11ecd 100644
--- a/s3/s3.go
+++ b/s3/s3.go
@@ -488,6 +488,11 @@ func (r *Replica) retainer(ctx context.Context) {
 
 // validator runs in a separate goroutine and handles periodic validation.
 func (r *Replica) validator(ctx context.Context) {
+	// Initialize counters since validation occurs infrequently.
+	for _, status := range []string{"ok", "error"} {
+		internal.ReplicaValidationTotalCounterVec.WithLabelValues(r.db.Path(), r.Name(), status).Add(0)
+	}
+
 	if r.ValidationInterval <= 0 {
 		return
 	}