chore(logging): purchases logging (#567)

codex/purchasing/states/cancelled.nim

@@ -1,10 +1,14 @@
 import pkg/metrics
+import pkg/chronicles
 import ../statemachine
 import ./errorhandling
 import ./error
 
 declareCounter(codexPurchasesCancelled, "codex purchases cancelled")
 
+logScope:
+  topics = "marketplace purchases cancelled"
+
 type PurchaseCancelled* = ref object of ErrorHandlingState
 
 method `$`*(state: PurchaseCancelled): string =
@@ -13,6 +17,9 @@ method `$`*(state: PurchaseCancelled): string =
 method run*(state: PurchaseCancelled, machine: Machine): Future[?State] {.async.} =
   codexPurchasesCancelled.inc()
   let purchase = Purchase(machine)
+
+  warn "Request cancelled, withdrawing remaining funds",  requestId = $purchase.requestId
   await purchase.market.withdrawFunds(purchase.requestId)
+
   let error = newException(Timeout, "Purchase cancelled due to timeout")
   return some State(PurchaseErrored(error: error))

codex/purchasing/states/error.nim

@@ -1,8 +1,13 @@
 import pkg/metrics
+import pkg/chronicles
 import ../statemachine
+import ../../utils/exceptions
 
 declareCounter(codexPurchasesError, "codex purchases error")
 
+logScope:
+  topics = "marketplace purchases errored"
+
 type PurchaseErrored* = ref object of PurchaseState
   error*: ref CatchableError
 
@@ -12,4 +17,7 @@ method `$`*(state: PurchaseErrored): string =
 method run*(state: PurchaseErrored, machine: Machine): Future[?State] {.async.} =
   codexPurchasesError.inc()
   let purchase = Purchase(machine)
+
+  error "Purchasing error", error=state.error.msgDetail, requestId = purchase.requestId
+
   purchase.future.fail(state.error)

codex/purchasing/states/finished.nim

@@ -1,8 +1,12 @@
 import pkg/metrics
+import pkg/chronicles
 import ../statemachine
 
 declareCounter(codexPurchasesFinished, "codex purchases finished")
 
+logScope:
+  topics = "marketplace purchases finished"
+
 type PurchaseFinished* = ref object of PurchaseState
 
 method `$`*(state: PurchaseFinished): string =
@@ -11,4 +15,5 @@ method `$`*(state: PurchaseFinished): string =
 method run*(state: PurchaseFinished, machine: Machine): Future[?State] {.async.} =
   codexPurchasesFinished.inc()
   let purchase = Purchase(machine)
+  info "Purchase finished", requestId = purchase.requestId
   purchase.future.complete()

codex/purchasing/states/started.nim

@@ -1,4 +1,5 @@
 import pkg/metrics
+import pkg/chronicles
 import ../statemachine
 import ./errorhandling
 import ./finished
@@ -6,6 +7,9 @@ import ./failed
 
 declareCounter(codexPurchasesStarted, "codex purchases started")
 
+logScope:
+  topics = "marketplace purchases started"
+
 type PurchaseStarted* = ref object of ErrorHandlingState
 
 method `$`*(state: PurchaseStarted): string =
@@ -17,6 +21,7 @@ method run*(state: PurchaseStarted, machine: Machine): Future[?State] {.async.}
 
   let clock = purchase.clock
   let market = purchase.market
+  info "All required slots filled, purchase started", requestId = purchase.requestId
 
   let failed = newFuture[void]()
   proc callback(_: RequestId) =

codex/purchasing/states/submitted.nim

@@ -1,9 +1,13 @@
 import pkg/metrics
+import pkg/chronicles
 import ../statemachine
 import ./errorhandling
 import ./started
 import ./cancelled
 
+logScope:
+  topics = "marketplace purchases submitted"
+
 declareCounter(codexPurchasesSubmitted, "codex purchases submitted")
 
 type PurchaseSubmitted* = ref object of ErrorHandlingState
@@ -18,6 +22,8 @@ method run*(state: PurchaseSubmitted, machine: Machine): Future[?State] {.async.
   let market = purchase.market
   let clock = purchase.clock
 
+  info "Request submitted, waiting for slots to be filled", requestId = purchase.requestId
+
   proc wait {.async.} =
     let done = newFuture[void]()
     proc callback(_: RequestId) =