Tracing updates

Improve DebugState tracing Add tracing for current ledgerStateJudgement and associationMode. Add TraceMempoolSynced support Add support for tracing TraceMempoolSynced along with a txsSyncDuration which tracks how long it took to sync the mempool after block adoption. Unit is ms.
IntersectMBO · Oct 18, 2024 · cbf3d9b · cbf3d9b
1 parent 7eb10fe
commit cbf3d9b
Show file tree

Hide file tree

Showing 4 changed files with 56 additions and 13 deletions.
diff --git a/cardano-node/src/Cardano/Node/Tracing/Tracers/Consensus.hs b/cardano-node/src/Cardano/Node/Tracing/Tracers/Consensus.hs
@@ -1205,6 +1205,12 @@ instance
       , "mempoolSize" .= forMachine dtal mpSz
       ]
 
+  forMachine _dtal (TraceMempoolSynced et) =
+    mconcat
+      [ "kind" .= String "TraceMempoolSynced"
+      , "enclosingTime" .= et
+      ]
+
   asMetrics (TraceMempoolAddedTx _tx _mpSzBefore mpSz) =
     [ IntM "txsInMempool" (fromIntegral $ msNumTxs mpSz)
     , IntM "mempoolBytes" (fromIntegral . unByteSize32 . msNumBytes $ mpSz)
@@ -1227,6 +1233,13 @@ instance
     , CounterM "txsProcessedNum" (Just (fromIntegral $ length txs))
     ]
 
+  asMetrics (TraceMempoolSynced (FallingEdgeWith duration)) =
+    [ IntM "txsSyncDuration" (round $ 1000 * duration)
+    ]
+
+  asMetrics (TraceMempoolSynced RisingEdge) = []
+
+
 instance LogFormatting MempoolSize where
   forMachine _dtal MempoolSize{msNumTxs, msNumBytes} =
     mconcat
@@ -1240,11 +1253,13 @@ instance MetaTrace (TraceEventMempool blk) where
     namespaceFor TraceMempoolRejectedTx {} = Namespace [] ["RejectedTx"]
     namespaceFor TraceMempoolRemoveTxs {} = Namespace [] ["RemoveTxs"]
     namespaceFor TraceMempoolManuallyRemovedTxs {} = Namespace [] ["ManuallyRemovedTxs"]
+    namespaceFor TraceMempoolSynced {} = Namespace [] ["Synced"]
 
     severityFor (Namespace _ ["AddedTx"]) _ = Just Info
     severityFor (Namespace _ ["RejectedTx"]) _ = Just Info
     severityFor (Namespace _ ["RemoveTxs"]) _ = Just Info
     severityFor (Namespace _ ["ManuallyRemovedTxs"]) _ = Just Info
+    severityFor (Namespace _ ["Synced"]) _ = Just Info
     severityFor _ _ = Nothing
 
     metricsDocFor (Namespace _ ["AddedTx"]) =
@@ -1264,6 +1279,11 @@ instance MetaTrace (TraceEventMempool blk) where
       , ("mempoolBytes", "Byte size of the mempool")
       , ("txsProcessedNum", "")
       ]
+
+    metricsDocFor (Namespace _ ["Synced"]) =
+      [ ("txsSyncDuration", "Time to sync the mempool in ms after block adoption")
+      ]
+
     metricsDocFor _ = []
 
     documentFor (Namespace _ ["AddedTx"]) = Just

diff --git a/cardano-node/src/Cardano/Tracing/OrphanInstances/Consensus.hs b/cardano-node/src/Cardano/Tracing/OrphanInstances/Consensus.hs
@@ -1510,6 +1510,11 @@ instance ( ToObject (ApplyTxErr blk), ToObject (GenTx blk),
       , "txsInvalidated" .= map (toObject verb . txForgetValidated) txs1
       , "mempoolSize" .= toObject verb mpSz
       ]
+  toObject _verb (TraceMempoolSynced et) =
+    mconcat
+      [ "kind" .= String "TraceMempoolSynced"
+      , "enclosingTime" .= et
+      ]
 
 instance ToObject MempoolSize where
   toObject _verb MempoolSize{msNumTxs, msNumBytes} =

diff --git a/cardano-node/src/Cardano/Tracing/OrphanInstances/Network.hs b/cardano-node/src/Cardano/Tracing/OrphanInstances/Network.hs
@@ -61,7 +61,7 @@ import           Ouroboros.Network.NodeToNode (ErrorPolicyTrace (..), NodeToNode
                    NodeToNodeVersionData (..), RemoteAddress, TraceSendRecv (..), WithAddr (..))
 import qualified Ouroboros.Network.NodeToNode as NtN
 import           Ouroboros.Network.PeerSelection.Bootstrap
-import           Ouroboros.Network.PeerSelection.Governor (DebugPeerSelection (..),
+import           Ouroboros.Network.PeerSelection.Governor (AssociationMode (..), DebugPeerSelection (..),
                    DebugPeerSelectionState (..), PeerSelectionCounters, PeerSelectionState (..),
                    PeerSelectionTargets (..), PeerSelectionView (..), TracePeerSelection (..),
                    peerSelectionStateToCounters)
@@ -1956,6 +1956,8 @@ instance ToObject (TracePeerSelection SockAddr) where
             , "inProgressDemoteToCold" .= dpssInProgressDemoteToCold ds
             , "upstreamyness" .= dpssUpstreamyness ds
             , "fetchynessBlocks" .= dpssFetchynessBlocks ds
+            , "ledgerStateJudgement" .= dpssLedgerStateJudgement ds
+            , "associationMode" .= dpssAssociationMode ds
             ]
 
 -- Connection manager abstract state.  For explanation of each state see
@@ -2625,6 +2627,15 @@ instance FromJSON LedgerStateJudgement where
   parseJSON (String "TooOld")      = pure TooOld
   parseJSON _                      = fail "Invalid JSON for LedgerStateJudgement"
 
+instance ToJSON AssociationMode where
+  toJSON LocalRootsOnly = String "LocalRootsOnly"
+  toJSON Unrestricted   = String "Unrestricted"
+
+instance FromJSON AssociationMode where
+  parseJSON (String "LocalRootsOnly") = pure LocalRootsOnly
+  parseJSON (String "Unrestricted")   = pure Unrestricted
+  parseJSON _                      = fail "Invalid JSON for AssociationMode"
+
 instance ToJSON UseLedgerPeers where
   toJSON DontUseLedgerPeers                  = Number (-1)
   toJSON (UseLedgerPeers Always)             = Number 0

diff --git a/cardano-node/src/Cardano/Tracing/Tracers.hs b/cardano-node/src/Cardano/Tracing/Tracers.hs
@@ -1249,25 +1249,32 @@ notifyTxsProcessed fStats tr = Tracer $ \case
     -- so we can treat them as completely processed.
     updatedTxProcessed <- mapForgingStatsTxsProcessed fStats (+ (length txs))
     traceCounter "txsProcessedNum" tr (fromIntegral updatedTxProcessed)
+  TraceMempoolSynced (FallingEdgeWith duration) -> do
+    traceCounter "txsSyncDuration" tr (round $ 1000 * duration :: Int)
+
   -- The rest of the constructors.
   _ -> return ()
 
 
 mempoolMetricsTraceTransformer :: Trace IO a -> Tracer IO (TraceEventMempool blk)
 mempoolMetricsTraceTransformer tr = Tracer $ \mempoolEvent -> do
   let tr' = appendName "metrics" tr
-      (_n, tot) = case mempoolEvent of
-                    TraceMempoolAddedTx     _tx0 _ tot0 -> (1, tot0)
-                    TraceMempoolRejectedTx  _tx0 _ tot0 -> (1, tot0)
-                    TraceMempoolRemoveTxs   txs0   tot0 -> (length txs0, tot0)
-                    TraceMempoolManuallyRemovedTxs txs0 txs1 tot0 -> ( length txs0 + length txs1, tot0)
-      logValue1 :: LOContent a
-      logValue1 = LogValue "txsInMempool" $ PureI $ fromIntegral (msNumTxs tot)
-      logValue2 :: LOContent a
-      logValue2 = LogValue "mempoolBytes" . PureI . fromIntegral . unByteSize32 . msNumBytes $ tot
-  meta <- mkLOMeta Critical Confidential
-  traceNamedObject tr' (meta, logValue1)
-  traceNamedObject tr' (meta, logValue2)
+      (_n, tot_m) = case mempoolEvent of
+                    TraceMempoolAddedTx     _tx0 _ tot0 -> (1, Just tot0)
+                    TraceMempoolRejectedTx  _tx0 _ tot0 -> (1, Just tot0)
+                    TraceMempoolRemoveTxs   txs0   tot0 -> (length txs0, Just tot0)
+                    TraceMempoolManuallyRemovedTxs txs0 txs1 tot0 -> ( length txs0 + length txs1, Just tot0)
+                    TraceMempoolSynced _ -> (0, Nothing)
+  case tot_m of
+    Just tot -> do
+      let logValue1 :: LOContent a
+          logValue1 = LogValue "txsInMempool" $ PureI $ fromIntegral (msNumTxs tot)
+          logValue2 :: LOContent a
+          logValue2 = LogValue "mempoolBytes" . PureI . fromIntegral . unByteSize32 . msNumBytes $ tot
+      meta <- mkLOMeta Critical Confidential
+      traceNamedObject tr' (meta, logValue1)
+      traceNamedObject tr' (meta, logValue2)
+    Nothing -> return ()
 
 mempoolTracer
   :: ( ToJSON (GenTxId blk)