Navigation Menu

Skip to content

Commit

Permalink
Update for new Consensus tracers
Browse files Browse the repository at this point in the history
  • Loading branch information
nfrisby committed May 20, 2022
1 parent b8f5eac commit 54307e6
Show file tree
Hide file tree
Showing 4 changed files with 228 additions and 111 deletions.
61 changes: 46 additions & 15 deletions cardano-node/src/Cardano/Node/Tracing/Tracers/ChainDB.hs
Expand Up @@ -49,6 +49,7 @@ import qualified Ouroboros.Consensus.Storage.LedgerDB.Types as LedgerDB
import qualified Ouroboros.Consensus.Storage.VolatileDB as VolDB
import qualified Ouroboros.Consensus.Storage.VolatileDB.Impl as VolDb
import Ouroboros.Consensus.Util.Condense (condense)
import Ouroboros.Consensus.Util.Enclose

import qualified Data.Aeson.KeyMap as KeyMap
import qualified Ouroboros.Network.AnchoredFragment as AF
Expand Down Expand Up @@ -203,9 +204,11 @@ sevTraceAddBlockEvent ChainDB.IgnoreInvalidBlock {} = Info
sevTraceAddBlockEvent ChainDB.AddedBlockToQueue {} = Debug
sevTraceAddBlockEvent ChainDB.BlockInTheFuture {} = Info
sevTraceAddBlockEvent ChainDB.AddedBlockToVolatileDB {} = Debug
sevTraceAddBlockEvent ChainDB.PoppedBlockFromQueue {} = Debug
sevTraceAddBlockEvent ChainDB.TryAddToCurrentChain {} = Debug
sevTraceAddBlockEvent ChainDB.TrySwitchToAFork {} = Info
sevTraceAddBlockEvent ChainDB.StoreButDontChange {} = Debug
sevTraceAddBlockEvent ChainDB.ChangingSelection {} = Debug
sevTraceAddBlockEvent (ChainDB.AddedToCurrentChain events _ _ _) =
maximumDef Notice (map sevLedgerEvent events)
sevTraceAddBlockEvent (ChainDB.SwitchedToAFork events _ _ _) =
Expand Down Expand Up @@ -234,6 +237,8 @@ namesForChainDBAddBlock (ChainDB.IgnoreInvalidBlock {}) =
["IgnoreInvalidBlock"]
namesForChainDBAddBlock (ChainDB.AddedBlockToQueue {}) =
["AddedBlockToQueue"]
namesForChainDBAddBlock (ChainDB.PoppedBlockFromQueue {}) =
["PoppedBlockFromQueue"]
namesForChainDBAddBlock (ChainDB.BlockInTheFuture {}) =
["BlockInTheFuture"]
namesForChainDBAddBlock (ChainDB.AddedBlockToVolatileDB {}) =
Expand All @@ -248,6 +253,8 @@ namesForChainDBAddBlock (ChainDB.AddedToCurrentChain {}) =
["AddedToCurrentChain"]
namesForChainDBAddBlock (ChainDB.SwitchedToAFork {}) =
["SwitchedToAFork"]
namesForChainDBAddBlock (ChainDB.ChangingSelection {}) =
["ChangingSelection"]
namesForChainDBAddBlock (ChainDB.AddBlockValidation ev') =
"AddBlockValidation" : namesForChainDBAddBlockValidation ev'
namesForChainDBAddBlock (ChainDB.ChainSelectionForFutureBlock {}) =
Expand Down Expand Up @@ -285,8 +292,18 @@ instance ( LogFormatting (Header blk)
"Ignoring block already in DB: " <> renderRealPointAsPhrase pt
forHuman (ChainDB.IgnoreInvalidBlock pt _reason) =
"Ignoring previously seen invalid block: " <> renderRealPointAsPhrase pt
forHuman (ChainDB.AddedBlockToQueue pt sz) =
"Block added to queue: " <> renderRealPointAsPhrase pt <> " queue size " <> condenseT sz
forHuman (ChainDB.AddedBlockToQueue pt edgeSz) =
case edgeSz of
RisingEdge ->
"About to add block to queue: " <> renderRealPointAsPhrase pt
FallingEdgeWith sz ->
"Block added to queue: " <> renderRealPointAsPhrase pt <> " queue size " <> condenseT sz
forHuman (ChainDB.PoppedBlockFromQueue edgePt) =
case edgePt of
RisingEdge ->
"Popping block from queue"
FallingEdgeWith pt ->
"Popped block from queue: " <> renderRealPointAsPhrase pt
forHuman (ChainDB.BlockInTheFuture pt slot) =
"Ignoring block from future: " <> renderRealPointAsPhrase pt <> ", slot " <> condenseT slot
forHuman (ChainDB.StoreButDontChange pt) =
Expand All @@ -295,15 +312,19 @@ instance ( LogFormatting (Header blk)
"Block fits onto the current chain: " <> renderRealPointAsPhrase pt
forHuman (ChainDB.TrySwitchToAFork pt _) =
"Block fits onto some fork: " <> renderRealPointAsPhrase pt
forHuman (ChainDB.ChangingSelection pt) =
"Changing selection to: " <> renderPointAsPhrase pt
forHuman (ChainDB.AddedToCurrentChain es _ _ c) =
"Chain extended, new tip: " <> renderPointAsPhrase (AF.headPoint c) <>
Text.concat [ "\nEvent: " <> showT e | e <- es ]
forHuman (ChainDB.SwitchedToAFork es _ _ c) =
"Switched to a fork, new tip: " <> renderPointAsPhrase (AF.headPoint c) <>
Text.concat [ "\nEvent: " <> showT e | e <- es ]
forHuman (ChainDB.AddBlockValidation ev') = forHuman ev'
forHuman (ChainDB.AddedBlockToVolatileDB pt _ _) =
"Chain added block " <> renderRealPointAsPhrase pt
forHuman (ChainDB.AddedBlockToVolatileDB pt _ _ enclosing) =
case enclosing of
RisingEdge -> "Chain about to add block " <> renderRealPointAsPhrase pt
FallingEdgeWith () -> "Chain added block " <> renderRealPointAsPhrase pt
forHuman (ChainDB.ChainSelectionForFutureBlock pt) =
"Chain selection run for block previously from future: " <> renderRealPointAsPhrase pt
forHuman (ChainDB.PipeliningEvent ev') = forHuman ev'
Expand All @@ -317,10 +338,13 @@ instance ( LogFormatting (Header blk)
mconcat [ "kind" .= String "IgnoreInvalidBlock"
, "block" .= forMachine dtal pt
, "reason" .= showT reason ]
forMachine dtal (ChainDB.AddedBlockToQueue pt sz) =
forMachine dtal (ChainDB.AddedBlockToQueue pt edgeSz) =
mconcat [ "kind" .= String "AddedBlockToQueue"
, "block" .= forMachine dtal pt
, "queueSize" .= toJSON sz ]
, case edgeSz of RisingEdge -> "risingEdge" .= True; FallingEdgeWith sz -> "queueSize" .= toJSON sz ]
forMachine dtal (ChainDB.PoppedBlockFromQueue edgePt) =
mconcat [ "kind" .= String "TraceAddBlockEvent.PoppedBlockFromQueue"
, case edgePt of RisingEdge -> "risingEdge" .= True; FallingEdgeWith pt -> "block" .= forMachine dtal pt ]
forMachine dtal (ChainDB.BlockInTheFuture pt slot) =
mconcat [ "kind" .= String "BlockInTheFuture"
, "block" .= forMachine dtal pt
Expand All @@ -334,6 +358,9 @@ instance ( LogFormatting (Header blk)
forMachine dtal (ChainDB.TrySwitchToAFork pt _) =
mconcat [ "kind" .= String "TraceAddBlockEvent.TrySwitchToAFork"
, "block" .= forMachine dtal pt ]
forMachine dtal (ChainDB.ChangingSelection pt) =
mconcat [ "kind" .= String "TraceAddBlockEvent.ChangingSelection"
, "block" .= forMachine dtal pt ]
forMachine dtal (ChainDB.AddedToCurrentChain events _ base extended) =
mconcat $
[ "kind" .= String "AddedToCurrentChain"
Expand All @@ -354,10 +381,11 @@ instance ( LogFormatting (Header blk)
| not (null events) ]
forMachine dtal (ChainDB.AddBlockValidation ev') =
kindContext "AddBlockEvent" $ forMachine dtal ev'
forMachine dtal (ChainDB.AddedBlockToVolatileDB pt (BlockNo bn) _) =
mconcat [ "kind" .= String "AddedBlockToVolatileDB"
, "block" .= forMachine dtal pt
, "blockNo" .= showT bn ]
forMachine dtal (ChainDB.AddedBlockToVolatileDB pt (BlockNo bn) _ enclosing) =
mconcat $ [ "kind" .= String "AddedBlockToVolatileDB"
, "block" .= forMachine dtal pt
, "blockNo" .= showT bn ]
<> [ "risingEdge" .= True | RisingEdge <- [enclosing] ]
forMachine dtal (ChainDB.ChainSelectionForFutureBlock pt) =
mconcat [ "kind" .= String "TChainSelectionForFutureBlock"
, "block" .= forMachine dtal pt ]
Expand Down Expand Up @@ -387,16 +415,19 @@ instance ( LogFormatting (Header blk)
instance ( ConvertRawHash (Header blk)
, HasHeader (Header blk)
) => LogFormatting (ChainDB.TracePipeliningEvent blk) where
forHuman (ChainDB.SetTentativeHeader hdr) =
"Set tentative header to " <> renderPointAsPhrase (blockPoint hdr)
forHuman (ChainDB.SetTentativeHeader hdr enclosing) =
case enclosing of
RisingEdge -> "About to set tentative header to " <> renderPointAsPhrase (blockPoint hdr)
FallingEdgeWith () -> "Set tentative header to " <> renderPointAsPhrase (blockPoint hdr)
forHuman (ChainDB.TrapTentativeHeader hdr) =
"Discovered trap tentative header " <> renderPointAsPhrase (blockPoint hdr)
forHuman (ChainDB.OutdatedTentativeHeader hdr) =
"Tentative header is now outdated " <> renderPointAsPhrase (blockPoint hdr)

forMachine dtals (ChainDB.SetTentativeHeader hdr) =
mconcat [ "kind" .= String "SetTentativeHeader"
, "block" .= renderPointForDetails dtals (blockPoint hdr) ]
forMachine dtals (ChainDB.SetTentativeHeader hdr enclosing) =
mconcat $ [ "kind" .= String "SetTentativeHeader"
, "block" .= renderPointForDetails dtals (blockPoint hdr) ]
<> [ "risingEdge" .= True | RisingEdge <- [enclosing] ]
forMachine dtals (ChainDB.TrapTentativeHeader hdr) =
mconcat [ "kind" .= String "TrapTentativeHeader"
, "block" .= renderPointForDetails dtals (blockPoint hdr) ]
Expand Down
145 changes: 86 additions & 59 deletions cardano-node/src/Cardano/Node/Tracing/Tracers/Consensus.hs
Expand Up @@ -111,6 +111,7 @@ import Ouroboros.Consensus.MiniProtocol.LocalTxSubmission.Server
import Ouroboros.Consensus.Node.Run (SerialiseNodeToNodeConstraints, estimateBlockSize)
import Ouroboros.Consensus.Node.Tracers
import qualified Ouroboros.Consensus.Protocol.Ledger.HotKey as HotKey
import Ouroboros.Consensus.Util.Enclose



Expand Down Expand Up @@ -249,58 +250,50 @@ docChainSyncClientEvent' = Documented [
--------------------------------------------------------------------------------

severityChainSyncServerEvent :: TraceChainSyncServerEvent blk -> SeverityS
severityChainSyncServerEvent TraceChainSyncServerRead {} = Info
severityChainSyncServerEvent TraceChainSyncServerReadBlocked {} = Info
severityChainSyncServerEvent TraceChainSyncRollForward {} = Info
severityChainSyncServerEvent TraceChainSyncRollBackward {} = Info
severityChainSyncServerEvent (TraceChainSyncServerUpdate _tip _upd _blocking enclosing) =
case enclosing of
RisingEdge -> Info
FallingEdgeWith () -> Debug

namesForChainSyncServerEvent :: TraceChainSyncServerEvent blk -> [Text]
namesForChainSyncServerEvent ev =
"ChainSyncServerEvent" : namesForChainSyncServerEvent' ev


namesForChainSyncServerEvent' :: TraceChainSyncServerEvent blk -> [Text]
namesForChainSyncServerEvent' TraceChainSyncServerRead {} =
namesForChainSyncServerEvent' (TraceChainSyncServerUpdate _tip _update NonBlocking _enclosing) =
["ServerRead"]
namesForChainSyncServerEvent' TraceChainSyncServerReadBlocked {} =
namesForChainSyncServerEvent' (TraceChainSyncServerUpdate _tip _update Blocking _enclosing) =
["ServerReadBlocked"]
namesForChainSyncServerEvent' TraceChainSyncRollForward {} =
["RollForward"]
namesForChainSyncServerEvent' TraceChainSyncRollBackward {} =
["RollBackward"]

instance ConvertRawHash blk
=> LogFormatting (TraceChainSyncServerEvent blk) where
forMachine _dtal (TraceChainSyncServerRead tip (AddBlock _hdr)) =
mconcat
forMachine _dtal (TraceChainSyncServerUpdate tip (AddBlock _hdr) NonBlocking enclosing) =
mconcat $
[ "kind" .= String "ChainSyncServerRead.AddBlock"
, tipToObject tip
]
forMachine _dtal (TraceChainSyncServerRead tip (RollBack _pt)) =
mconcat
<> [ "risingEdge" .= True | RisingEdge <- [enclosing] ]
forMachine _dtal (TraceChainSyncServerUpdate tip (RollBack _pt) NonBlocking enclosing) =
mconcat $
[ "kind" .= String "ChainSyncServerRead.RollBack"
, tipToObject tip
]
forMachine _dtal (TraceChainSyncServerReadBlocked tip (AddBlock _hdr)) =
mconcat
<> [ "risingEdge" .= True | RisingEdge <- [enclosing] ]
forMachine _dtal (TraceChainSyncServerUpdate tip (AddBlock _pt) Blocking enclosing) =
mconcat $
[ "kind" .= String "ChainSyncServerReadBlocked.AddBlock"
, tipToObject tip
]
forMachine _dtal (TraceChainSyncServerReadBlocked tip (RollBack _pt)) =
mconcat
<> [ "risingEdge" .= True | RisingEdge <- [enclosing] ]
forMachine _dtal (TraceChainSyncServerUpdate tip (RollBack _pt) Blocking enclosing) =
mconcat $
[ "kind" .= String "ChainSyncServerReadBlocked.RollBack"
, tipToObject tip
]
forMachine dtal (TraceChainSyncRollForward point) =
mconcat [ "kind" .= String "ChainSyncServerRead.RollForward"
, "point" .= forMachine dtal point
]
forMachine dtal (TraceChainSyncRollBackward point) =
mconcat [ "kind" .= String "ChainSyncServerRead.ChainSyncRollBackward"
, "point" .= forMachine dtal point
]
<> [ "risingEdge" .= True | RisingEdge <- [enclosing] ]

asMetrics (TraceChainSyncRollForward _point) =
asMetrics (TraceChainSyncServerUpdate _tip (AddBlock _hdr) _blocking FallingEdge) =
[CounterM "cardano.node.chainSync.rollForward" Nothing]
asMetrics _ = []

Expand Down Expand Up @@ -912,22 +905,24 @@ severityForge' :: TraceLabelCreds (TraceForgeEvent blk) -> SeverityS
severityForge' (TraceLabelCreds _t e) = severityForge'' e

severityForge'' :: TraceForgeEvent blk -> SeverityS
severityForge'' TraceStartLeadershipCheck {} = Info
severityForge'' TraceSlotIsImmutable {} = Error
severityForge'' TraceBlockFromFuture {} = Error
severityForge'' TraceBlockContext {} = Debug
severityForge'' TraceNoLedgerState {} = Error
severityForge'' TraceLedgerState {} = Debug
severityForge'' TraceNoLedgerView {} = Error
severityForge'' TraceLedgerView {} = Debug
severityForge'' TraceForgeStateUpdateError {} = Error
severityForge'' TraceNodeCannotForge {} = Error
severityForge'' TraceNodeNotLeader {} = Info
severityForge'' TraceNodeIsLeader {} = Info
severityForge'' TraceForgedBlock {} = Info
severityForge'' TraceDidntAdoptBlock {} = Error
severityForge'' TraceForgedInvalidBlock {} = Error
severityForge'' TraceAdoptedBlock {} = Info
severityForge'' TraceStartLeadershipCheck {} = Info
severityForge'' TraceSlotIsImmutable {} = Error
severityForge'' TraceBlockFromFuture {} = Error
severityForge'' TraceBlockContext {} = Debug
severityForge'' TraceNoLedgerState {} = Error
severityForge'' TraceLedgerState {} = Debug
severityForge'' TraceNoLedgerView {} = Error
severityForge'' TraceLedgerView {} = Debug
severityForge'' TraceForgeStateUpdateError {} = Error
severityForge'' TraceNodeCannotForge {} = Error
severityForge'' TraceNodeNotLeader {} = Info
severityForge'' TraceNodeIsLeader {} = Info
severityForge'' TraceForgeTickedLedgerState {} = Debug
severityForge'' TraceForgingMempoolSnapshot {} = Debug
severityForge'' TraceForgedBlock {} = Info
severityForge'' TraceDidntAdoptBlock {} = Error
severityForge'' TraceForgedInvalidBlock {} = Error
severityForge'' TraceAdoptedBlock {} = Info

severityForge''' :: TraceLabelCreds TraceStartLeadershipCheckPlus -> SeverityS
severityForge''' _ = Info
Expand All @@ -940,22 +935,24 @@ namesForForge' :: TraceLabelCreds (TraceForgeEvent blk) -> [Text]
namesForForge' (TraceLabelCreds _t e) = namesForForge'' e

namesForForge'' :: TraceForgeEvent blk -> [Text]
namesForForge'' TraceStartLeadershipCheck {} = ["StartLeadershipCheck"]
namesForForge'' TraceSlotIsImmutable {} = ["SlotIsImmutable"]
namesForForge'' TraceBlockFromFuture {} = ["BlockFromFuture"]
namesForForge'' TraceBlockContext {} = ["BlockContext"]
namesForForge'' TraceNoLedgerState {} = ["NoLedgerState"]
namesForForge'' TraceLedgerState {} = ["LedgerState"]
namesForForge'' TraceNoLedgerView {} = ["NoLedgerView"]
namesForForge'' TraceLedgerView {} = ["LedgerView"]
namesForForge'' TraceForgeStateUpdateError {} = ["ForgeStateUpdateError"]
namesForForge'' TraceNodeCannotForge {} = ["NodeCannotForge"]
namesForForge'' TraceNodeNotLeader {} = ["NodeNotLeader"]
namesForForge'' TraceNodeIsLeader {} = ["NodeIsLeader"]
namesForForge'' TraceForgedBlock {} = ["ForgedBlock"]
namesForForge'' TraceDidntAdoptBlock {} = ["DidntAdoptBlock"]
namesForForge'' TraceForgedInvalidBlock {} = ["ForgedInvalidBlock"]
namesForForge'' TraceAdoptedBlock {} = ["AdoptedBlock"]
namesForForge'' TraceStartLeadershipCheck {} = ["StartLeadershipCheck"]
namesForForge'' TraceSlotIsImmutable {} = ["SlotIsImmutable"]
namesForForge'' TraceBlockFromFuture {} = ["BlockFromFuture"]
namesForForge'' TraceBlockContext {} = ["BlockContext"]
namesForForge'' TraceNoLedgerState {} = ["NoLedgerState"]
namesForForge'' TraceLedgerState {} = ["LedgerState"]
namesForForge'' TraceNoLedgerView {} = ["NoLedgerView"]
namesForForge'' TraceLedgerView {} = ["LedgerView"]
namesForForge'' TraceForgeStateUpdateError {} = ["ForgeStateUpdateError"]
namesForForge'' TraceNodeCannotForge {} = ["NodeCannotForge"]
namesForForge'' TraceNodeNotLeader {} = ["NodeNotLeader"]
namesForForge'' TraceNodeIsLeader {} = ["NodeIsLeader"]
namesForForge'' TraceForgeTickedLedgerState {} = ["ForgeTickedLedgerState"]
namesForForge'' TraceForgingMempoolSnapshot {} = ["ForgingMempoolSnapshot"]
namesForForge'' TraceForgedBlock {} = ["ForgedBlock"]
namesForForge'' TraceDidntAdoptBlock {} = ["DidntAdoptBlock"]
namesForForge'' TraceForgedInvalidBlock {} = ["ForgedInvalidBlock"]
namesForForge'' TraceAdoptedBlock {} = ["AdoptedBlock"]

namesForForge''' :: TraceLabelCreds TraceStartLeadershipCheckPlus -> [Text]
namesForForge''' (TraceLabelCreds _ TraceStartLeadershipCheckPlus {}) =
Expand Down Expand Up @@ -1045,6 +1042,20 @@ instance ( tx ~ GenTx blk
[ "kind" .= String "TraceNodeIsLeader"
, "slot" .= toJSON (unSlotNo slotNo)
]
forMachine dtal (TraceForgeTickedLedgerState slotNo prevPt) =
mconcat
[ "kind" .= String "TraceForgeTickedLedgerState"
, "slot" .= toJSON (unSlotNo slotNo)
, "prev" .= renderPointForDetails dtal prevPt
]
forMachine dtal (TraceForgingMempoolSnapshot slotNo prevPt mpHash mpSlot) =
mconcat
[ "kind" .= String "TraceForgingMempoolSnapshot"
, "slot" .= toJSON (unSlotNo slotNo)
, "prev" .= renderPointForDetails dtal prevPt
, "mempoolHash" .= String (renderChainHash @blk (renderHeaderHash (Proxy @blk)) mpHash)
, "mempoolSlot" .= toJSON (unSlotNo mpSlot)
]
forMachine _dtal (TraceForgedBlock slotNo _ blk _) =
mconcat
[ "kind" .= String "TraceForgedBlock"
Expand Down Expand Up @@ -1133,6 +1144,20 @@ instance ( tx ~ GenTx blk
"Not leading slot " <> showT (unSlotNo slotNo)
forHuman (TraceNodeIsLeader slotNo) =
"Leading slot " <> showT (unSlotNo slotNo)
forHuman (TraceForgeTickedLedgerState slotNo prevPt) =
"While forging in slot "
<> showT (unSlotNo slotNo)
<> " we ticked the ledger state ahead from "
<> renderPointAsPhrase prevPt
forHuman (TraceForgingMempoolSnapshot slotNo prevPt mpHash mpSlot) =
"While forging in slot "
<> showT (unSlotNo slotNo)
<> " we acquired a mempool snapshot valid against "
<> renderPointAsPhrase prevPt
<> " from a mempool that was prepared for "
<> renderChainHash @blk (renderHeaderHash (Proxy @blk)) mpHash
<> " ticked to slot "
<> showT (unSlotNo mpSlot)
forHuman (TraceForgedBlock slotNo _ _ _) =
"Forged block in slot " <> showT (unSlotNo slotNo)
forHuman (TraceDidntAdoptBlock slotNo _) =
Expand Down Expand Up @@ -1189,6 +1214,8 @@ instance ( tx ~ GenTx blk
[IntM "cardano.node.nodeNotLeader" (fromIntegral $ unSlotNo slot)]
asMetrics (TraceNodeIsLeader slot) =
[IntM "cardano.node.nodeIsLeader" (fromIntegral $ unSlotNo slot)]
asMetrics TraceForgeTickedLedgerState {} = []
asMetrics TraceForgingMempoolSnapshot {} = []
asMetrics (TraceForgedBlock slot _ _ _) =
[IntM "cardano.node.forgedSlotLast" (fromIntegral $ unSlotNo slot)]
asMetrics (TraceDidntAdoptBlock slot _) =
Expand Down

0 comments on commit 54307e6

Please sign in to comment.