diff --git a/README.md b/README.md index 4527c18e..a158f52d 100644 --- a/README.md +++ b/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). diff --git a/codex/contracts/market.nim b/codex/contracts/market.nim index 068f02c5..841e4138 100644 --- a/codex/contracts/market.nim +++ b/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) diff --git a/codex/proving.nim b/codex/proving.nim index 30b4ed60..101baae2 100644 --- a/codex/proving.nim +++ b/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 diff --git a/codex/sales/salesagent.nim b/codex/sales/salesagent.nim index 372c3da8..7a1f7876 100644 --- a/codex/sales/salesagent.nim +++ b/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 diff --git a/codex/sales/states/downloading.nim b/codex/sales/states/downloading.nim index b2b57958..efae5e25 100644 --- a/codex/sales/states/downloading.nim +++ b/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, diff --git a/codex/sales/states/errored.nim b/codex/sales/states/errored.nim index d8fb21d5..78dbcb6c 100644 --- a/codex/sales/states/errored.nim +++ b/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 diff --git a/codex/sales/states/filling.nim b/codex/sales/states/filling.nim index 251b97e7..266f65e4 100644 --- a/codex/sales/states/filling.nim +++ b/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) diff --git a/codex/sales/states/finished.nim b/codex/sales/states/finished.nim index 73054d87..18c0a52c 100644 --- a/codex/sales/states/finished.nim +++ b/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: diff --git a/codex/sales/states/proving.nim b/codex/sales/states/proving.nim index c7694c5b..1b62247d 100644 --- a/codex/sales/states/proving.nim +++ b/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)) diff --git a/tests/integration/nodes.nim b/tests/integration/nodes.nim index feba45f2..e3ff84d2 100644 --- a/tests/integration/nodes.nim +++ b/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 diff --git a/tests/integration/testIntegration.nim b/tests/integration/testIntegration.nim index 9f06481b..796c95bf 100644 --- a/tests/integration/testIntegration.nim +++ b/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 diff --git a/tests/integration/twonodes.nim b/tests/integration/twonodes.nim index 306a8af1..bb5d8dfd 100644 --- a/tests/integration/twonodes.nim +++ b/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] - ], debug = debug1) + "--eth-account=" & $account1 + ] + + 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] - ], debug = debug2) + "--eth-account=" & $account2 + ] + + if debug2 != "true" and debug2 != "false": + node2Args.add("--log-level=" & debug2) + + node2 = startNode(node2Args, debug = debug2) teardown: client1.close()