Skip to content

Commit cc5e1c0

Browse files
authored
Enhance start up logs (#2486)
<!-- Describe your change here --> Closes #2483 🔑 Motivation Improve node observability by introducing structured lifecycle and sync-status logs. These logs make startup, hydration, and sync transitions explicit, and provide better insight into drift before going out of sync. Overall, this PR makes node startup phases and sync health easier to trace and reason about, while reducing noise when fully in sync. > This PR also fixes the smoke tests by allowing enough time (depending on the actual chain backend used during tests) to observe the node becoming `InSync` before starting the scenario. 🔄 Changes **New Logs Introduced** * `LoadedChainState` Emitted during hydration with the last known chain point loaded into `chainStateHistory`. * `NodeHydrated` Emitted once node hydration completes. * `StartingDecision` Emitted by the chain layer to report the first chain point used as prefix when selecting an intersection during chain-sync. * `ChainBackendStarted` Emitted after successfully establishing the chain layer connection. * `NetworkStarted` Emitted after successfully establishing the network layer connection. * `EnteringMainloop` Emitted right before starting the `runHydraNode` main loop. * `SyncedStatusReport` Emitted: * On every tick while `CatchingUp` * On every tick when drift exceeds 80% of the unsynced policy while `InSync` --- <!-- Consider each and tick it off one way or the other --> * [x] CHANGELOG updated or not needed * [x] Documentation updated or not needed * [x] Haddocks updated or not needed * [x] No new TODOs introduced or explained herafter
2 parents 76715b8 + 3710199 commit cc5e1c0

File tree

17 files changed

+238
-158
lines changed

17 files changed

+238
-158
lines changed

hydra-cluster/bench/Bench/EndToEnd.hs

Lines changed: 2 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -73,7 +73,7 @@ bench startingNodeId timeoutSeconds workDir dataset = do
7373
let cardanoKeys = hydraNodeKeys dataset <&> \sk -> (getVerificationKey sk, sk)
7474
let hydraKeys = generateSigningKey . show <$> [1 .. toInteger (length cardanoKeys)]
7575
statsTvar <- newLabelledTVarIO "bench-stats" mempty
76-
scenarioData <- withCardanoNodeDevnet (contramap FromCardanoNode tracer) workDir $ \_ backend -> do
76+
scenarioData <- withCardanoNodeDevnet (contramap FromCardanoNode tracer) workDir $ \blockTime backend -> do
7777
let nodeSocket' = case Backend.getOptions backend of
7878
Direct DirectOptions{nodeSocket} -> nodeSocket
7979
_ -> error "Unexpected Blockfrost backend"
@@ -83,8 +83,7 @@ bench startingNodeId timeoutSeconds workDir dataset = do
8383
hydraScriptsTxId <- publishHydraScriptsAs backend Faucet
8484
putStrLn $ "Starting hydra cluster in " <> workDir
8585
let hydraTracer = contramap FromHydraNode tracer
86-
87-
withHydraCluster hydraTracer workDir nodeSocket' startingNodeId cardanoKeys hydraKeys hydraScriptsTxId 10 $ \clients -> do
86+
withHydraCluster hydraTracer blockTime workDir nodeSocket' startingNodeId cardanoKeys hydraKeys hydraScriptsTxId 10 $ \clients -> do
8887
waitForNodesConnected hydraTracer 20 clients
8988
scenario hydraTracer backend workDir dataset clients
9089
systemStats <- readTVarIO statsTvar

hydra-cluster/src/Hydra/Cluster/Scenarios.hs

Lines changed: 66 additions & 64 deletions
Large diffs are not rendered by default.

hydra-cluster/src/HydraNode.hs

Lines changed: 13 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -281,6 +281,7 @@ getMetrics HydraClient{hydraNodeId, apiHost = Host{hostname}} = do
281281
withHydraCluster ::
282282
HasCallStack =>
283283
Tracer IO HydraNodeLog ->
284+
NominalDiffTime ->
284285
FilePath ->
285286
SocketPath ->
286287
-- | First node id
@@ -294,7 +295,7 @@ withHydraCluster ::
294295
ContestationPeriod ->
295296
(NonEmpty HydraClient -> IO a) ->
296297
IO a
297-
withHydraCluster tracer workDir nodeSocket firstNodeId allKeys hydraKeys hydraScriptsTxId contestationPeriod action = do
298+
withHydraCluster tracer blockTime workDir nodeSocket firstNodeId allKeys hydraKeys hydraScriptsTxId contestationPeriod action = do
298299
when (clusterSize == 0) $
299300
failure "Cannot run a cluster with 0 number of nodes"
300301
when (length allKeys /= length hydraKeys) $
@@ -332,6 +333,7 @@ withHydraCluster tracer workDir nodeSocket firstNodeId allKeys hydraKeys hydraSc
332333
}
333334
withHydraNode
334335
tracer
336+
blockTime
335337
chainConfig
336338
workDir
337339
nodeId
@@ -438,18 +440,19 @@ prepareHydraNode chainConfig workDir hydraNodeId hydraSKey hydraVKeys allNodeIds
438440
withPreparedHydraNodeInSync ::
439441
HasCallStack =>
440442
Tracer IO HydraNodeLog ->
443+
NominalDiffTime ->
441444
FilePath ->
442445
Int ->
443446
RunOptions ->
444447
(HydraClient -> IO a) ->
445448
IO a
446-
withPreparedHydraNodeInSync tracer workDir hydraNodeId runOptions action =
447-
withPreparedHydraNode tracer workDir hydraNodeId runOptions action'
449+
withPreparedHydraNodeInSync tracer blockTime workDir hydraNodeId runOptions action = do
450+
let waitTime = blockTime * waitFactor
451+
withPreparedHydraNode tracer workDir hydraNodeId runOptions (action' waitTime)
448452
where
449-
action' client = do
450-
getHydraBackend >>= \case
451-
DirectBackendType -> waitForNodesSynced 5 $ client :| []
452-
BlockfrostBackendType -> waitForNodesSynced 10 $ client :| []
453+
waitFactor = 5
454+
action' waitTime client = do
455+
waitForNodesSynced waitTime $ client :| []
453456
action client
454457

455458
-- | Run a hydra-node with given 'RunOptions'.
@@ -496,6 +499,7 @@ withPreparedHydraNode tracer workDir hydraNodeId runOptions action =
496499
withHydraNode ::
497500
HasCallStack =>
498501
Tracer IO HydraNodeLog ->
502+
NominalDiffTime ->
499503
ChainConfig ->
500504
FilePath ->
501505
Int ->
@@ -504,9 +508,9 @@ withHydraNode ::
504508
[Int] ->
505509
(HydraClient -> IO a) ->
506510
IO a
507-
withHydraNode tracer chainConfig workDir hydraNodeId hydraSKey hydraVKeys allNodeIds action = do
511+
withHydraNode tracer blockTime chainConfig workDir hydraNodeId hydraSKey hydraVKeys allNodeIds action = do
508512
opts <- prepareHydraNode chainConfig workDir hydraNodeId hydraSKey hydraVKeys allNodeIds id
509-
withPreparedHydraNodeInSync tracer workDir hydraNodeId opts action
513+
withPreparedHydraNodeInSync tracer blockTime workDir hydraNodeId opts action
510514

511515
-- | Run a hydra-node with given 'ChainConfig' and using the config from
512516
-- config and catching up with chain backend/.

hydra-cluster/test/Test/ChainObserverSpec.hs

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -41,13 +41,13 @@ spec = do
4141
showLogsOnFailure "ChainObserverSpec" $ \tracer -> do
4242
withTempDir "hydra-cluster" $ \tmpDir -> do
4343
-- Start a cardano devnet
44-
withCardanoNodeDevnet (contramap FromCardanoNode tracer) tmpDir $ \_ backend -> do
44+
withCardanoNodeDevnet (contramap FromCardanoNode tracer) tmpDir $ \blockTime backend -> do
4545
-- Prepare a hydra-node
4646
let hydraTracer = contramap FromHydraNode tracer
4747
hydraScriptsTxId <- publishHydraScriptsAs backend Faucet
4848
(aliceCardanoVk, _) <- keysFor Alice
4949
aliceChainConfig <- chainConfigFor Alice tmpDir backend hydraScriptsTxId [] cperiod
50-
withHydraNode hydraTracer aliceChainConfig tmpDir 1 aliceSk [] [1] $ \hydraNode -> do
50+
withHydraNode hydraTracer blockTime aliceChainConfig tmpDir 1 aliceSk [] [1] $ \hydraNode -> do
5151
withChainObserver backend $ \observer -> do
5252
seedFromFaucet_ backend aliceCardanoVk 100_000_000 (contramap FromFaucet tracer)
5353

0 commit comments

Comments
 (0)