feat: storage host collects reward (#416)

Co-authored-by: markspanbroek <mark@spanbroek.net>

README.md

@@ -106,6 +106,15 @@ Available sub-commands:
 codex initNode
 ```
 
+#### Logging
+
+Codex uses [Chronicles](https://github.com/status-im/nim-chronicles) logging library, which allows great flexibility in working with logs.
+Chronicles has the concept of topics, which categorize log entries into semantic groups.
+
+Using the `log-level` parameter, you can set the top-level log level like `--log-level="TRACE"`, but more importantly,
+you can set log levels for specific topics like `--log-level="INFO; TRACE: marketplace,node; ERROR: blockexchange"`,
+which sets the top-level log level to `INFO` and then for topics `marketplace` and `node` sets the level to `TRACE` and so on.
+
 ### Example: running two Codex clients
 
 To get acquainted with Codex, consider running the manual two-client test described [HERE](docs/TWOCLIENTTEST.md).

codex/contracts/market.nim

@@ -10,7 +10,7 @@ import ./marketplace
 export market
 
 logScope:
-    topics = "onchain market"
+    topics = "marketplace onchain market"
 
 type
   OnChainMarket* = ref object of Market
@@ -30,7 +30,7 @@ func new*(_: type OnChainMarket, contract: Marketplace): OnChainMarket =
   )
 
 proc approveFunds(market: OnChainMarket, amount: UInt256) {.async.} =
-  notice "approving tokens", amount
+  debug "Approving tokens", amount
   let tokenAddress = await market.contract.token()
   let token = Erc20Token.new(tokenAddress, market.signer)
 
@@ -55,6 +55,7 @@ method mySlots*(market: OnChainMarket): Future[seq[SlotId]] {.async.} =
   return await market.contract.mySlots()
 
 method requestStorage(market: OnChainMarket, request: StorageRequest){.async.} =
+  debug "Requesting storage"
   await market.approveFunds(request.price())
   await market.contract.requestStorage(request)
 

codex/proving.nim

@@ -7,6 +7,9 @@ import ./clock
 
 export sets
 
+logScope:
+    topics = "marketplace proving"
+
 type
   Proving* = ref object
     market: Market
@@ -40,7 +43,12 @@ proc removeEndedContracts(proving: Proving) {.async.} =
   var ended: HashSet[Slot]
   for slot in proving.slots:
     let state = await proving.market.slotState(slot.id)
+    if state == SlotState.Finished:
+      debug "Collecting finished slot's reward", slot = $slot.id
+      await proving.market.freeSlot(slot.id)
+
     if state != SlotState.Filled:
+      debug "Request ended, cleaning up slot", slot = $slot.id
       ended.incl(slot)
   proving.slots.excl(ended)
 
@@ -57,6 +65,7 @@ proc run(proving: Proving) {.async.} =
   try:
     while true:
       let currentPeriod = await proving.getCurrentPeriod()
+      debug "Proving for new period", period = currentPeriod
       await proving.removeEndedContracts()
       for slot in proving.slots:
         let id = slot.id

codex/sales/salesagent.nim

@@ -11,7 +11,7 @@ import ./reservations
 export reservations
 
 logScope:
-  topics = "sales statemachine"
+  topics = "marketplace sales"
 
 type SalesAgent* = ref object of Machine
   context*: SalesContext

codex/sales/states/downloading.nim

@@ -17,7 +17,7 @@ type
   SaleDownloading* = ref object of ErrorHandlingState
 
 logScope:
-    topics = "sales downloading"
+    topics = "marketplace sales downloading"
 
 method `$`*(state: SaleDownloading): string = "SaleDownloading"
 
@@ -46,13 +46,16 @@ method run*(state: SaleDownloading, machine: Machine): Future[?State] {.async.}
   without request =? data.request:
     raiseAssert "no sale request"
 
+  debug "New request detected, downloading info", requestId = $data.requestId
+
   without availability =? await reservations.find(
       request.ask.slotSize,
       request.ask.duration,
       request.ask.pricePerSlot,
       request.ask.collateral,
       used = false):
-    info "no availability found for request, ignoring",
+    info "No availability found for request, ignoring",
+      requestId = $data.requestId,
       slotSize = request.ask.slotSize,
       duration = request.ask.duration,
       pricePerSlot = request.ask.pricePerSlot,

codex/sales/states/errored.nim

@@ -5,6 +5,9 @@ import pkg/chronicles
 import ../statemachine
 import ../salesagent
 
+logScope:
+    topics = "marketplace sales errored"
+
 type SaleErrored* = ref object of SaleState
   error*: ref CatchableError
 
@@ -25,4 +28,4 @@ method run*(state: SaleErrored, machine: Machine): Future[?State] {.async.} =
 
   await agent.unsubscribe()
 
-  error "Sale error", error=state.error.msg
+  error "Sale error", error=state.error.msg, requestId = $data.requestId

codex/sales/states/filling.nim

@@ -1,3 +1,4 @@
+import pkg/chronicles
 import ../../market
 import ../statemachine
 import ../salesagent
@@ -6,6 +7,9 @@ import ./filled
 import ./cancelled
 import ./failed
 
+logScope:
+    topics = "marketplace sales filling"
+
 type
   SaleFilling* = ref object of ErrorHandlingState
     proof*: seq[byte]
@@ -28,4 +32,5 @@ method run(state: SaleFilling, machine: Machine): Future[?State] {.async.} =
   without (collateral =? data.request.?ask.?collateral):
     raiseAssert "Request not set"
 
+  debug "Filling slot", requestId = $data.requestId, slot = $data.slotIndex
   await market.fillSlot(data.requestId, data.slotIndex, state.proof, collateral)

codex/sales/states/finished.nim

@@ -1,10 +1,14 @@
 import pkg/chronos
+import pkg/chronicles
 import ../statemachine
 import ../salesagent
 import ./errorhandling
 import ./cancelled
 import ./failed
 
+logScope:
+    topics = "marketplace sales finished"
+
 type
   SaleFinished* = ref object of ErrorHandlingState
 
@@ -21,8 +25,11 @@ method run*(state: SaleFinished, machine: Machine): Future[?State] {.async.} =
   let data = agent.data
   let context = agent.context
 
+  debug "Request succesfully filled", requestId = $data.requestId
+
   if request =? data.request and
       slotIndex =? data.slotIndex:
+    debug "Adding request to proving list", requestId = $data.requestId
     context.proving.add(Slot(request: request, slotIndex: slotIndex))
 
     if onSale =? context.onSale:

codex/sales/states/proving.nim

@@ -1,3 +1,4 @@
+import pkg/chronicles
 import ../statemachine
 import ../salesagent
 import ./errorhandling
@@ -6,6 +7,9 @@ import ./cancelled
 import ./failed
 import ./filled
 
+logScope:
+    topics = "marketplace sales proving"
+
 type
   SaleProving* = ref object of ErrorHandlingState
 
@@ -31,5 +35,8 @@ method run*(state: SaleProving, machine: Machine): Future[?State] {.async.} =
   without onProve =? context.proving.onProve:
     raiseAssert "onProve callback not set"
 
+  debug "Start proving", requestId = $data.requestId
   let proof = await onProve(Slot(request: request, slotIndex: data.slotIndex))
+  debug "Finished proving", requestId = $data.requestId
+
   return some State(SaleFilling(proof: proof))

tests/integration/nodes.nim

@@ -30,10 +30,10 @@ proc start(node: NodeProcess) =
       if line.contains("Started codex node"):
         break
 
-proc startNode*(args: openArray[string], debug = false): NodeProcess =
+proc startNode*(args: openArray[string], debug: string | bool = false): NodeProcess =
   ## Starts a Codex Node with the specified arguments.
   ## Set debug to 'true' to see output of the node.
-  let node = NodeProcess(arguments: @args, debug: debug)
+  let node = NodeProcess(arguments: @args, debug: ($debug != "false"))
   node.start()
   node
 

tests/integration/testIntegration.nim

@@ -1,10 +1,17 @@
 import std/json
 import pkg/chronos
 import pkg/stint
+import pkg/ethers/erc20
+import codex/contracts
 import ../contracts/time
+import ../contracts/deployment
 import ../codex/helpers/eventually
 import ./twonodes
 
+# For debugging you can enable logging output with debugX = true
+# You can also pass a string in same format like for the `--log-level` parameter
+# to enable custom logging levels for specific topics like: debug2 = "INFO; TRACE: marketplace"
+
 twonodessuite "Integration tests", debug1 = false, debug2 = false:
 
   setup:
@@ -78,3 +85,30 @@ twonodessuite "Integration tests", debug1 = false, debug2 = false:
     check availabilities.len == 1
     let newSize = UInt256.fromHex(availabilities[0]{"size"}.getStr)
     check newSize > 0 and newSize < size.u256
+
+  test "node slots gets paid out":
+    let marketplace = Marketplace.new(Marketplace.address, provider.getSigner())
+    let tokenAddress = await marketplace.token()
+    let token = Erc20Token.new(tokenAddress, provider.getSigner())
+    let reward: uint64 = 400
+    let duration: uint64 = 100
+
+    # client 2 makes storage available
+    let startBalance = await token.balanceOf(account2)
+    discard client2.postAvailability(size=0xFFFFF, duration=200, minPrice=300, maxCollateral=300)
+
+    # client 1 requests storage
+    let expiry = (await provider.currentTime()) + 30
+    let cid = client1.upload("some file contents")
+    let purchase = client1.requestStorage(cid, duration=duration, reward=reward, proofProbability=3, expiry=expiry, collateral=200)
+
+    check eventually client1.getPurchase(purchase){"state"} == %"started"
+    check client1.getPurchase(purchase){"error"} == newJNull()
+
+    # Proving mechanism uses blockchain clock to do proving/collect/cleanup round
+    # hence we must use `advanceTime` over `sleepAsync` as Hardhat does mine new blocks
+    # only with new transaction
+    await provider.advanceTime(duration.u256)
+    await sleepAsync(1.seconds)
+
+    check eventually (await token.balanceOf(account2)) - startBalance == duration.u256*reward.u256

tests/integration/twonodes.nim

@@ -10,7 +10,10 @@ export ethertest
 export codexclient
 export nodes
 
-template twonodessuite*(name: string, debug1, debug2: bool, body) =
+template twonodessuite*(name: string, debug1, debug2: bool | string, body) =
+  twonodessuite(name, $debug1, $debug2, body)
+
+template twonodessuite*(name: string, debug1, debug2: string, body) =
 
   ethersuite name:
 
@@ -18,6 +21,8 @@ template twonodessuite*(name: string, debug1, debug2: bool, body) =
     var node2 {.inject, used.}: NodeProcess
     var client1 {.inject, used.}: CodexClient
     var client2 {.inject, used.}: CodexClient
+    var account1 {.inject, used.}: Address
+    var account2 {.inject, used.}: Address
 
     let dataDir1 = getTempDir() / "Codex1"
     let dataDir2 = getTempDir() / "Codex2"
@@ -25,20 +30,27 @@ template twonodessuite*(name: string, debug1, debug2: bool, body) =
     setup:
       client1 = CodexClient.new("http://localhost:8080/api/codex/v1")
       client2 = CodexClient.new("http://localhost:8081/api/codex/v1")
+      account1 = accounts[0]
+      account2 = accounts[1]
 
-      node1 = startNode([
+      var node1Args = @[
         "--api-port=8080",
         "--data-dir=" & dataDir1,
         "--nat=127.0.0.1",
         "--disc-ip=127.0.0.1",
         "--disc-port=8090",
         "--persistence",
-        "--eth-account=" & $accounts[0]
+        "--eth-account=" & $account1
-      ], debug = debug1)
+      ]
+
+      if debug1 != "true" and debug1 != "false":
+        node1Args.add("--log-level=" & debug1)
+
+      node1 = startNode(node1Args, debug = debug1)
 
       let bootstrap = client1.info()["spr"].getStr()
 
-      node2 = startNode([
+      var node2Args = @[
         "--api-port=8081",
         "--data-dir=" & dataDir2,
         "--nat=127.0.0.1",
@@ -46,8 +58,13 @@ template twonodessuite*(name: string, debug1, debug2: bool, body) =
         "--disc-port=8091",
         "--bootstrap-node=" & bootstrap,
         "--persistence",
-        "--eth-account=" & $accounts[1]
+        "--eth-account=" & $account2
-      ], debug = debug2)
+      ]
+
+      if debug2 != "true" and debug2 != "false":
+        node2Args.add("--log-level=" & debug2)
+
+      node2 = startNode(node2Args, debug = debug2)
 
     teardown:
       client1.close()