From 85823342e9a9b208b71a5e0fd950b9ef3700bfa6 Mon Sep 17 00:00:00 2001
From: Ben Bierens <39762930+benbierens@users.noreply.github.com>
Date: Tue, 10 Jun 2025 15:27:52 +0200
Subject: [PATCH] Improves logging in maintenance module and erasure. (#1264)

---
 codex/erasure/erasure.nim       |  8 ++++----
 codex/stores/maintenance.nim    | 14 +++++++++-----
 codex/utils/timer.nim           |  5 ++++-
 tests/codex/utils/testtimer.nim |  4 ++--
 4 files changed, 19 insertions(+), 12 deletions(-)

diff --git a/codex/erasure/erasure.nim b/codex/erasure/erasure.nim
index e3d618ea..a83838c6 100644
--- a/codex/erasure/erasure.nim
+++ b/codex/erasure/erasure.nim
@@ -419,8 +419,8 @@ proc encodeData(
 
         trace "Adding parity block", cid = blk.cid, idx
         cids[idx] = blk.cid
-        if isErr (await self.store.putBlock(blk)):
-          trace "Unable to store block!", cid = blk.cid
+        if error =? (await self.store.putBlock(blk)).errorOption:
+          warn "Unable to store block!", cid = blk.cid, msg = error.msg
           return failure("Unable to store block!")
         idx.inc(params.steps)
 
@@ -619,8 +619,8 @@ proc decode*(self: Erasure, encoded: Manifest): Future[?!Manifest] {.async.} =
             return failure(error)
 
           trace "Recovered block", cid = blk.cid, index = i
-          if isErr (await self.store.putBlock(blk)):
-            trace "Unable to store block!", cid = blk.cid
+          if error =? (await self.store.putBlock(blk)).errorOption:
+            warn "Unable to store block!", cid = blk.cid, msg = error.msg
             return failure("Unable to store block!")
 
           cids[idx] = blk.cid
diff --git a/codex/stores/maintenance.nim b/codex/stores/maintenance.nim
index 7568a5d7..1d109031 100644
--- a/codex/stores/maintenance.nim
+++ b/codex/stores/maintenance.nim
@@ -23,6 +23,9 @@ import ../clock
 import ../logutils
 import ../systemclock
 
+logScope:
+  topics = "codex maintenance"
+
 const
   DefaultBlockInterval* = 10.minutes
   DefaultNumBlocksPerInterval* = 1000
@@ -40,7 +43,7 @@ proc new*(
     repoStore: RepoStore,
     interval: Duration,
     numberOfBlocksPerInterval = 100,
-    timer = Timer.new(),
+    timer = Timer.new("maintenance"),
     clock: Clock = SystemClock.new(),
 ): BlockMaintainer =
   ## Create new BlockMaintainer instance
@@ -59,8 +62,8 @@ proc new*(
 proc deleteExpiredBlock(
     self: BlockMaintainer, cid: Cid
 ): Future[void] {.async: (raises: [CancelledError]).} =
-  if isErr (await self.repoStore.delBlock(cid)):
-    trace "Unable to delete block from repoStore"
+  if error =? (await self.repoStore.delBlock(cid)).errorOption:
+    warn "Unable to delete block from repoStore", error = error.msg
 
 proc processBlockExpiration(
     self: BlockMaintainer, be: BlockExpiration
@@ -78,13 +81,13 @@ proc runBlockCheck(
   )
 
   without iter =? expirations, err:
-    trace "Unable to obtain blockExpirations iterator from repoStore"
+    warn "Unable to obtain blockExpirations iterator from repoStore", err = err.msg
     return
 
   var numberReceived = 0
   for beFut in iter:
     without be =? (await beFut), err:
-      trace "Unable to obtain blockExpiration from iterator"
+      warn "Unable to obtain blockExpiration from iterator", err = err.msg
       continue
     inc numberReceived
     await self.processBlockExpiration(be)
@@ -94,6 +97,7 @@ proc runBlockCheck(
   # We're at the end of the dataset and should start from 0 next time.
   if numberReceived < self.numberOfBlocksPerInterval:
     self.offset = 0
+    trace "Cycle completed"
 
 proc start*(self: BlockMaintainer) =
   proc onTimer(): Future[void] {.async: (raises: []).} =
diff --git a/codex/utils/timer.nim b/codex/utils/timer.nim
index b6aa9e7e..c4b6c4a6 100644
--- a/codex/utils/timer.nim
+++ b/codex/utils/timer.nim
@@ -24,7 +24,7 @@ type
     name: string
     loopFuture: Future[void]
 
-proc new*(T: type Timer, timerName = "Unnamed Timer"): Timer =
+proc new*(T: type Timer, timerName: string): Timer =
   ## Create a new Timer intance with the given name
   Timer(name: timerName)
 
@@ -35,6 +35,9 @@ proc timerLoop(timer: Timer) {.async: (raises: []).} =
       await sleepAsync(timer.interval)
   except CancelledError:
     discard # do not propagate as timerLoop is asyncSpawned
+  except CatchableError as err:
+    error "CatchableError in timer loop", name = timer.name, msg = err.msg
+  info "Timer loop has stopped", name = timer.name
 
 method start*(
     timer: Timer, callback: TimerCallback, interval: Duration
diff --git a/tests/codex/utils/testtimer.nim b/tests/codex/utils/testtimer.nim
index 907404c2..47076480 100644
--- a/tests/codex/utils/testtimer.nim
+++ b/tests/codex/utils/testtimer.nim
@@ -36,8 +36,8 @@ asyncchecksuite "Timer":
     timer2.start(lettersCallback, 10.milliseconds)
 
   setup:
-    timer1 = Timer.new()
-    timer2 = Timer.new()
+    timer1 = Timer.new("testtimer1")
+    timer2 = Timer.new("testtimer2")
 
     output = ""
     numbersState = 0