RPC timeout during proving state

[benbierens]

Found by Wings in vaclab-codex node 3 in the testnet.

A bout of RPC connection timeouts seem to be able to cause the node to crash when a sales statemachine is in the proving state.

While we definitely need to figure out and reduce the RPC connection timeout issue, if they occur they should not be able to crash the node.

WRN 2025-05-04 16:40:58.382+00:00 Exception in blockexc read loop            topics="codex blockexcnetworkpeer" tid=1 msg="Stream Closed!"                            
ERR 2025-05-04 16:40:58.382+00:00 Cannot retrieve the request                topics="marketplace onchain market" tid=1 error="Failed to send POST Request with JSON-RPC: Connection timed out"                                                                                                                                              
ERR 2025-05-04 16:40:58.382+00:00 Error while waiting for expiry to lapse    topics="marketplace sales" tid=1 error="Failed to get request expiry: Failed to send POST Request with JSON-RPC: Connection timed out"                                                                                                                         
ERR 2025-05-04 16:40:58.382+00:00 Error during SalePreparing.run             topics="marketplace sales preparing" tid=1 error="Failed to fetch the slot state from the Marketplace contract: Failed to send POST Request with JSON-RPC: Connection timed out"                                                                               
ERR 2025-05-04 16:40:58.382+00:00 Proving failed                             topics="marketplace sales proving" tid=1 msg="Failed to get future proof requirement: Failed to send POST Request with JSON-RPC: Connection timed out" typ="ref CatchableError" stack="/src/codex.nim(142)      codex\n/src/vendor/nim-chronos/chronos/internal/asyncfutures.nim(150) _ZN11asyncengine4pollE\n/src/vendor/nim-chronos/chronos/internal/asyncengine.nim(371) _ZN12asyncfutures14futureContinueE3refIN7futures26FutureBasecolonObjectType_EE\n/src/codex/contracts/market.nim(63) _ZN19willProofBeRequired50willProofBeRequired\n/src/vendor/nim-chronos/chronos/internal/asyncengine.nim(345) _ZN6system18rawWriteStackTraceE3varI3seqIN6system15StackTraceEntryEEE\n/src/vendor/nimbus-build-system/vendor/Nim/lib/system/stacktraces.nim(62) _ZN11stacktraces30auxWriteStackTraceWithOverrideE3varI3seqIN6system15StackTraceEntryEEE\n[[reraised from:\n/src/codex.nim(142)      codex\n/src/vendor/nim-chronos/chronos/internal/asyncengine.nim(150) _ZN11asyncengine4pollE\n/src/vendor/nim-chronos/chronos/internal/asyncfutures.nim(371) _ZN12asyncfutures14futureContinueE3refIN7futures26FutureBasecolonObjectType_EE\n/src/vendor/nim-chronos/chronos/internal/asyncmacro.nim(450) _ZN19willProofBeRequired50willProofBeRequired\n/src/vendor/nimbus-build-system/vendor/Nim/lib/system/stacktraces.nim(62) _ZN11stacktraces30auxWriteStackTraceWithOverrideE3varI3seqIN6system15StackTraceEntryEEE\n]]\n[[reraised from:\n/src/codex.nim(142)      codex\n/src/vendor/nim-chronos/chronos/internal/asyncengine.nim(150) _ZN11asyncengine4pollE\n/src/vendor/nim-chronos/chronos/internal/asyncfutures.nim(371) _ZN12asyncfutures14futureContinueE3refIN7futures26FutureBasecolonObjectType_EE\n/src/codex/sales/states/proving.nim(79) _ZN9proveLoop9proveLoopE3refIN7futures26FutureBasecolonObjectType_EE\n/src/vendor/nimbus-build-system/vendor/Nim/lib/system/stacktraces.nim(62) _ZN11stacktraces30auxWriteStackTraceWithOverrideE3varI3seqIN6system15StackTraceEntryEEE\n]]\n[[reraised from:\n/src/codex.nim(142)      codex\n/src/vendor/nim-chronos/chronos/internal/asyncengine.nim(150) _ZN11asyncengine4pollE\n/src/vendor/nim-chronos/chronos/internal/asyncfutures.nim(371) _ZN12asyncfutures14futureContinueE3refIN7futures26FutureBasecolonObjectType_EE\n/src/codex/sales/states/proving.nim(139) _ZN3run37run\n/src/vendor/nimbus-build-system/vendor/Nim/lib/system/stacktraces.nim(62) _ZN11stacktraces30auxWriteStackTraceWithOverrideE3varI3seqIN6system15StackTraceEntryEEE\n]]\n" error="Failed to get future proof requirement: Failed to send POST Request with JSON-RPC: Connection timed out"
ERR 2025-05-04 16:40:58.382+00:00 Unhandled exception in async proc, aborting topics="codex" tid=1 msg="no sale request"

[emizzle]

This is good info. We need to handle network-related errors, by retrying with an exponential backoff, then eventually raising an exception so that Defects are not encountered.

This log snippet shows two separate slots: one in SalePreparing state, and one in SaleProving state:

1. Cannot retrieve the request : This occurs while processing a new slot in SalePreparing while attempting to fetch a request via retreiveRequest which times out on getRequest.
2. Error while waiting for expiry to lapse . Because retreiveRequest doesn't raise exceptions, it continues to subscribe to cancellation events, which errors due to the timeout.
3. Proving failed: this is an ongoing filled slot in which regular proofs were being submitted. In the proveLoop, a call to willProofBeRequired timed out and failed. This should have gone to SaleErrored after (not shown in the logs).
4. Unhandled exception in async proc, aborting: this is a Defect ("no sale request") that crashed the node. It was caused by the continuation of SalePreparing since both agent.retrieveRequest and agent.subscribe do not raise exceptions.

Possible solution
agent.retrieveRequest and agent.subscribe should bubble network-related exceptions, and should be retried with exponential backoff. If after a certain amount of time, give up and raise an exception (which would cause the state transition to SaleErrored):

In sales/states/preparing.nim

try:
+  retryNetwork:
    await agent.retrieveRequest()
    await agent.subscribe()
...
except CatchableError as e:
    error "Error during SalePreparing.run", error = e.msgDetail
    return some State(SaleErrored(error: e))

This will require:

1. nim-ethers to bubble network exceptions from nim-json-rpc
2. retryNetwork template, eg:

template retryNetwork(body) =
  try:
    body
  except NetworkException as e:
    if not retryWithBackoffWasSuccessful:
      raise e

3. agent.retrieveRequest and agent.subscribe to bubble network-related exceptions

[markspanbroek]

The crash itself has been fixed in #1248.