From 4a3dc5d8e0df576280cb8f0e090049b9a70dfac1 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?V=C3=ADctor=20Rold=C3=A1n=20Betancort?=
 <vroldanbet@authzed.com>
Date: Fri, 29 Sep 2023 10:05:18 +0100
Subject: [PATCH] enrich GC logging messages

when there is a lot of data to be GC, it
would be useful to have richer understanding
of what's happening via logs. This commit
changes the completed log messages to info
since this is something operators would want
to monitor under normal operations, and
also enriches the error message to understand
where is it stuck deleting
---
 internal/datastore/common/gc.go         |  5 ++++-
 internal/datastore/postgres/gc.go       | 17 +++++++++--------
 internal/datastore/postgres/postgres.go |  2 +-
 3 files changed, 14 insertions(+), 10 deletions(-)

diff --git a/internal/datastore/common/gc.go b/internal/datastore/common/gc.go
index 6413852a24..a4be724c2d 100644
--- a/internal/datastore/common/gc.go
+++ b/internal/datastore/common/gc.go
@@ -123,6 +123,9 @@ func startGarbageCollectorWithMaxElapsedTime(ctx context.Context, gc GarbageColl
 
 		case <-time.After(nextInterval):
 			log.Ctx(ctx).Info().
+				Dur("interval", nextInterval).
+				Dur("window", window).
+				Dur("timeout", timeout).
 				Msg("running garbage collection worker")
 
 			err := RunGarbageCollection(gc, window, timeout)
@@ -178,7 +181,7 @@ func RunGarbageCollection(gc GarbageCollector, window, timeout time.Duration) er
 	}
 
 	collectionDuration := time.Since(startTime)
-	log.Ctx(ctx).Debug().
+	log.Ctx(ctx).Info().
 		Stringer("highestTxID", watermark).
 		Dur("duration", collectionDuration).
 		Time("nowTime", now).
diff --git a/internal/datastore/postgres/gc.go b/internal/datastore/postgres/gc.go
index e105f6bdf4..3f217a3aaa 100644
--- a/internal/datastore/postgres/gc.go
+++ b/internal/datastore/postgres/gc.go
@@ -66,11 +66,12 @@ func (pgd *pgDatastore) TxIDBefore(ctx context.Context, before time.Time) (datas
 	return postgresRevision{snapshot}, nil
 }
 
-func (pgd *pgDatastore) DeleteBeforeTx(ctx context.Context, txID datastore.Revision) (removed common.DeletionCounts, err error) {
+func (pgd *pgDatastore) DeleteBeforeTx(ctx context.Context, txID datastore.Revision) (common.DeletionCounts, error) {
 	revision := txID.(postgresRevision)
 
 	minTxAlive := newXid8(revision.snapshot.xmin)
-
+	removed := common.DeletionCounts{}
+	var err error
 	// Delete any relationship rows that were already dead when this transaction started
 	removed.Relationships, err = pgd.batchDelete(
 		ctx,
@@ -79,7 +80,7 @@ func (pgd *pgDatastore) DeleteBeforeTx(ctx context.Context, txID datastore.Revis
 		sq.Lt{colDeletedXid: minTxAlive},
 	)
 	if err != nil {
-		return
+		return removed, fmt.Errorf("failed to GC relationships table: %w", err)
 	}
 
 	// Delete all transaction rows with ID < the transaction ID.
@@ -93,7 +94,7 @@ func (pgd *pgDatastore) DeleteBeforeTx(ctx context.Context, txID datastore.Revis
 		sq.Lt{colXID: minTxAlive},
 	)
 	if err != nil {
-		return
+		return removed, fmt.Errorf("failed to GC transactions table: %w", err)
 	}
 
 	// Delete any namespace rows with deleted_transaction <= the transaction ID.
@@ -104,10 +105,10 @@ func (pgd *pgDatastore) DeleteBeforeTx(ctx context.Context, txID datastore.Revis
 		sq.Lt{colDeletedXid: minTxAlive},
 	)
 	if err != nil {
-		return
+		return removed, fmt.Errorf("failed to GC namespaces table: %w", err)
 	}
 
-	return
+	return removed, err
 }
 
 func (pgd *pgDatastore) batchDelete(
@@ -116,7 +117,7 @@ func (pgd *pgDatastore) batchDelete(
 	pkCols []string,
 	filter sqlFilter,
 ) (int64, error) {
-	sql, args, err := psql.Select(pkCols...).From(tableName).Where(filter).Limit(batchDeleteSize).ToSql()
+	sql, args, err := psql.Select(pkCols...).From(tableName).Where(filter).Limit(gcBatchDeleteSize).ToSql()
 	if err != nil {
 		return -1, err
 	}
@@ -137,7 +138,7 @@ func (pgd *pgDatastore) batchDelete(
 
 		rowsDeleted := cr.RowsAffected()
 		deletedCount += rowsDeleted
-		if rowsDeleted < batchDeleteSize {
+		if rowsDeleted < gcBatchDeleteSize {
 			break
 		}
 	}
diff --git a/internal/datastore/postgres/postgres.go b/internal/datastore/postgres/postgres.go
index f5321c38af..5ed8917db9 100644
--- a/internal/datastore/postgres/postgres.go
+++ b/internal/datastore/postgres/postgres.go
@@ -69,7 +69,7 @@ const (
 
 	tracingDriverName = "postgres-tracing"
 
-	batchDeleteSize = 1000
+	gcBatchDeleteSize = 1000
 
 	livingTupleConstraint = "uq_relation_tuple_living_xid"
 )