Add ouroboros-consensus:tracing sublibrary

changelog.d/20260908_120000_javier.sagredo_tracing_sublibrary.md

@@ -0,0 +1,32 @@
+### Non-Breaking
+
+- Added a new public sublibrary `ouroboros-consensus:tracing`, holding the
+  `LogFormatting` and `MetaTrace` instances for Consensus types. These were in
+  `cardano-node`, and now live next to the types they describe, so that a change
+  to a traced type and the change to its rendering land in the same commit.
+
+  The sublibrary also exports `Ouroboros.Consensus.Tracing.HasIssuer`, the
+  `HasIssuer` class and its instances, and `Ouroboros.Consensus.Tracing.KESInfo`,
+  moved over from `cardano-node` for the same reason.
+
+  Compared to the instances in `cardano-node`:
+
+  - At `DDetailed`, the `tx` field of a transaction is now the hex-encoded CBOR
+    of the transaction instead of its `Show` rendering. For Shelley-based eras
+    this is the ledger `Tx` serialised at the era's protocol version, which
+    reproduces the received bytes of the body, witnesses and auxiliary data. For
+    Byron it is the annotated bytes of the mempool payload, which are its
+    canonical encoding. This affects every mempool trace that carries a
+    transaction.
+  - `TraceMempoolRejectedTx` now includes `errdetails`, the source of the
+    rejection, at every detail level, not only at `DDetailed`.
+  - `Point` and `RealPoint` now have a `forHuman` rendering, "<hash> at slot
+    <slot>".
+  - `Ouroboros.Consensus.Tracing.Render` no longer exports `renderTip`,
+    `renderTipForDetails` or `renderSlotNo`, which no instance used, nor
+    re-exports `showT`, which is available from `Cardano.Logging`.
+  - Fixed `MetaTrace` delegation to nested namespaces. The LSM backend
+    namespaces under `LedgerEvent.Flavor.V2.BackendTrace` are now documented,
+    and the privacy and detail level of `AddBlockEvent.AddBlockValidation`,
+    `ImmDbEvent.ChunkValidation` and `ImmDbEvent.CacheEvent` namespaces are now
+    taken from the nested tracer instead of the default.

golden/tracing/era-shelley-render.golden

@@ -0,0 +1,23 @@
+renderScriptHash                   = 4d50a11e297e7783383bf06dd6e4e481230323bd96cd8b8d9ee3888d
+renderScriptIntegrityHash Nothing  = null
+renderScriptIntegrityHash (Just _) = "31237cdb79ae1dfa7ffb87cde7ea8a80352d300ee5ac758a6cddd19d671925ec"
+renderRewardAccount mainnet/key    = stake1u9r87kyn9d2fzpvy5r5w5fdzyhsx59znpvhfd6fcc5ar7gs7uwm3p
+renderRewardAccount testnet/key    = stake_test1upr87kyn9d2fzpvy5r5w5fdzyhsx59znpvhfd6fcc5ar7gsekye4u
+renderRewardAccount mainnet/script = stake17x85vx25lch33lhpmj3r8u6cjplxg0lc88k3lx27f0ejtcc83spxq
+renderTxIn                         = 8928aae63c84d87ea098564d1e03ad813f107add474e56aedd286349c0c03ea4#0
+renderScriptIndex spending         = {"kind":"ScriptWitnessIndexTxIn","value":0}
+renderScriptIndex minting          = {"kind":"ScriptWitnessIndexMint","value":1}
+renderScriptIndex certifying       = {"kind":"ScriptWitnessIndexCertificate","value":2}
+renderScriptIndex withdrawing      = {"kind":"ScriptWitnessIndexWithdrawal","value":3}
+renderScriptIndex voting           = {"kind":"ScriptWitnessIndexVoting","value":4}
+renderScriptIndex proposing        = {"kind":"ScriptWitnessIndexProposing","value":5}
+renderScriptPurpose spending       = {"spending":"8928aae63c84d87ea098564d1e03ad813f107add474e56aedd286349c0c03ea4#0"}
+renderScriptPurpose minting        = {"minting":{"item":"2db8410d969b6ad6b6969703c77ebf6c44061aa51c5d6ceba46557e2"}}
+renderScriptPurpose certifying     = {"certifying":{"item":{"credential":{"keyHash":"dea21a2507d38c552e24df8c4d722e81e1e63de8755d808925deaf9d"},"deposit":null,"kind":"RegCert"}}}
+renderScriptPurpose withdrawing    = {"rewarding":"stake1uyg94rcmk4jyfjkvscmce92zrt8wkvntp7mhg0jf86uzl4gynahcu"}
+renderScriptPurpose voting         = {"voting":{"item":{"contents":"8761dc36fca24f0f3d78ae5a6c2787af7730a9e9eafdc250eb1fffb1","tag":"StakePoolVoter"}}}
+renderScriptPurpose proposing      = {"proposing":{"item":{"anchor":{"dataHash":"8d234302aeb06f2a7effb905e43f037e4dca1c2a0f050e82175328c5ce8d31f4","url":"https://example.com"},"deposit":1000,"govAction":{"tag":"InfoAction"},"returnAddr":{"credential":{"keyHash":"4752e70e4f651479d186955c57142dae87b279ff2c77ef5720af7282"},"network":"Mainnet"}}}}
+renderScriptIndex guarding         = {"kind":"ScriptWitnessIndexGuarding","value":6}
+renderScriptPurpose guarding       = {"guarding":"d1b3884173424c627f4bac9957ef28b8027dcd13f560c42088aa1fbf"}
+renderMissingRedeemers             = {"245d5a7a06fe18358242e81281cd5ba9e6abe4efc54e7b659f25abae":{"spending":"8928aae63c84d87ea098564d1e03ad813f107add474e56aedd286349c0c03ea4#0"},"b0c53e2bf180858da4b64eb5598c5615bba7d723d2b604a83b7f9165":{"minting":{"item":"4a1c412d8e2b3015a7fb7d382808fb7cb721bf93a56e8bb6661cdebe"}}}
+renderIncompleteWithdrawals        = {"stake1uykhy5fggpkusvhtwnz8pxk2q5fynxeu0vt7qrtuktndrvgxnyhra":"Mismatch (RelEQ) {supplied: 1, expected: 2}"}

nix/haskell.nix

@@ -13,11 +13,13 @@ let
       ../NOTICE
       ../cabal
       ../cabal.project
+      ../golden
       ../ouroboros-consensus
       ../ouroboros-consensus-cardano
       ../ouroboros-consensus-diffusion
       ../ouroboros-consensus-protocol
       ../ouroboros-consensus.cabal
+      ../tracing
     ];
   };
   forAllProjectPackages = cfg: args@{ config, lib, ... }: {
@@ -64,13 +66,21 @@ let
         packages.cardano-ledger-dijkstra.components.library.doHaddock = false;
         packages.cardano-ledger-mary.components.library.doHaddock = false;
         packages.cardano-ledger-shelley.components.library.doHaddock = false;
-        # Options related to tasty and tasty-golden:
-        packages.ouroboros-consensus.components.tests =
-          lib.listToAttrs (map
-            (n: lib.nameValuePair "${n}-test" {
-              testFlags = lib.mkForce [ "--no-create --hide-successes" ];
-              extraSrcFiles = [ "ouroboros-consensus-cardano/golden/${n}/**/*" ];
-            }) [ "byron" "shelley" "cardano" ]);
+        # Options related to tasty and tasty-golden. The golden files live
+        # outside their test component's hs-source-dirs, so each one has to be
+        # listed here; otherwise haskell.nix prunes it out of the component
+        # source and tasty-golden creates it and passes instead of comparing.
+        packages.ouroboros-consensus.components.tests = lib.mapAttrs
+          (_: golden: {
+            testFlags = lib.mkForce [ "--no-create --hide-successes" ];
+            extraSrcFiles = [ "${golden}/**/*" ];
+          })
+          {
+            byron-test = "ouroboros-consensus-cardano/golden/byron";
+            shelley-test = "ouroboros-consensus-cardano/golden/shelley";
+            cardano-test = "ouroboros-consensus-cardano/golden/cardano";
+            tracing-test = "golden/tracing";
+          };
       }
       ({ pkgs, lib, ... }: lib.mkIf pkgs.stdenv.hostPlatform.isWindows {
         # https://github.com/input-output-hk/haskell.nix/issues/2332

ouroboros-consensus-diffusion/src/ouroboros-consensus-diffusion/Ouroboros/Consensus/Node/Tracers.hs

@@ -16,6 +16,7 @@ module Ouroboros.Consensus.Node.Tracers
   , TraceForgeEvent (..)
   , TraceLabelCreds (..)
   , TracePerasCertInclusionEvent (..)
+  , TracePerasVoteForgingEvent (..)
   ) where
 
 import Control.Exception (SomeException)
@@ -50,7 +51,7 @@ import Ouroboros.Consensus.Node.GSM (TraceGsmEvent)
 import Ouroboros.Consensus.Peras.Cert.Inclusion.Trace
   ( TracePerasCertInclusionEvent (..)
   )
-import Ouroboros.Consensus.Peras.Voting.Trace (TracePerasVoteForgingEvent)
+import Ouroboros.Consensus.Peras.Voting.Trace (TracePerasVoteForgingEvent (..))
 import Ouroboros.Consensus.Protocol.Praos.AgentClient
   ( KESAgentClientTrace (..)
   )

ouroboros-consensus.cabal

@@ -422,6 +422,95 @@ library
     directory
     latex-svg-image
 
+library tracing
+  import: common-lib
+  visibility: public
+  hs-source-dirs: tracing
+  exposed-modules:
+    Ouroboros.Consensus.Tracing
+    Ouroboros.Consensus.Tracing.Era.Shelley.Render
+    Ouroboros.Consensus.Tracing.Render
+
+  other-modules:
+    Ouroboros.Consensus.Tracing.BlockReplayProgress
+    Ouroboros.Consensus.Tracing.ChainDB
+    Ouroboros.Consensus.Tracing.Consensus
+    Ouroboros.Consensus.Tracing.ConsensusStartupException
+    Ouroboros.Consensus.Tracing.ConvertTxId
+    Ouroboros.Consensus.Tracing.Era.Byron
+    Ouroboros.Consensus.Tracing.Era.HardFork
+    Ouroboros.Consensus.Tracing.Era.Shelley
+    Ouroboros.Consensus.Tracing.Formatting
+    Ouroboros.Consensus.Tracing.HasIssuer
+    Ouroboros.Consensus.Tracing.KESInfo
+
+  build-depends:
+    aeson,
+    base,
+    base16-bytestring,
+    bech32,
+    bytestring,
+    cardano-crypto-class,
+    cardano-crypto-wrapper,
+    cardano-data,
+    cardano-ledger-allegra,
+    cardano-ledger-alonzo,
+    cardano-ledger-api,
+    cardano-ledger-babbage,
+    cardano-ledger-binary,
+    cardano-ledger-byron,
+    cardano-ledger-conway,
+    cardano-ledger-core,
+    cardano-ledger-dijkstra,
+    cardano-ledger-shelley,
+    cardano-protocol,
+    cardano-protocol-tpraos,
+    cardano-slotting,
+    containers,
+    deepseq,
+    kes-agent,
+    ouroboros-consensus:{cardano, diffusion, lsm, ouroboros-consensus, protocol},
+    ouroboros-network:{api, orphan-instances, ouroboros-network},
+    psqueues,
+    sop-core,
+    strict-sop-core,
+    text,
+    time,
+    trace-dispatcher ^>=2.13.0,
+    typed-protocols,
+
+test-suite tracing-test
+  import: common-test
+  type: exitcode-stdio-1.0
+  hs-source-dirs: tracing/test
+  main-is: Main.hs
+  other-modules:
+    Test.Consensus.Tracing.Golden
+    Test.Consensus.Tracing.MetaTrace
+
+  build-depends:
+    aeson,
+    base,
+    bytestring,
+    cardano-crypto-class,
+    cardano-data,
+    cardano-ledger-alonzo,
+    cardano-ledger-conway,
+    cardano-ledger-core,
+    cardano-ledger-dijkstra,
+    cardano-ledger-mary,
+    cardano-protocol-tpraos,
+    containers,
+    filepath,
+    ouroboros-consensus:{cardano, diffusion, ouroboros-consensus, protocol, tracing, unstable-consensus-testlib},
+    ouroboros-network:{api, ouroboros-network},
+    tasty,
+    tasty-golden,
+    tasty-hunit,
+    text,
+    time,
+    trace-dispatcher,
+
 library lsm
   import: common-lib
   visibility: public

scripts/ci/check-changelogs.sh

@@ -18,6 +18,7 @@ libraries=("ouroboros-consensus/src/ouroboros-consensus"
            "ouroboros-consensus-cardano/src/ouroboros-consensus-cardano"
            "ouroboros-consensus-cardano/src/byron"
            "ouroboros-consensus-cardano/src/shelley"
+           "tracing"
           )
 
 echo "####### Checking for Haskell changes"

scripts/ci/run-fourmolu.sh

@@ -20,12 +20,7 @@ if ! command -v "$fdcmd" &> /dev/null; then
     fi
 fi
 
-case "$(uname -s)" in
-    MINGW*)     path="$(pwd -W | sed 's_/_\\\\_g')\\\\ouroboros-consensus";;
-    *)          path="$(pwd -P)/ouroboros-consensus";;
-esac
-
-$fdcmd --full-path "$path" \
+$fdcmd --exclude docs --exclude scripts \
        --extension hs \
        --exec-batch fourmolu --config fourmolu.yaml -i
 

tracing/Ouroboros/Consensus/Tracing.hs

@@ -0,0 +1,23 @@
+module Ouroboros.Consensus.Tracing
+  ( module Ouroboros.Consensus.Tracing.BlockReplayProgress
+  , module Ouroboros.Consensus.Tracing.ChainDB
+  , module Ouroboros.Consensus.Tracing.Consensus
+  , module Ouroboros.Consensus.Tracing.ConsensusStartupException
+  , module Ouroboros.Consensus.Tracing.ConvertTxId
+  , module Ouroboros.Consensus.Tracing.HasIssuer
+  , module Ouroboros.Consensus.Tracing.KESInfo
+  , module Ouroboros.Consensus.Tracing.Render
+  ) where
+
+import Ouroboros.Consensus.Tracing.BlockReplayProgress
+import Ouroboros.Consensus.Tracing.ChainDB
+import Ouroboros.Consensus.Tracing.Consensus
+import Ouroboros.Consensus.Tracing.ConsensusStartupException
+import Ouroboros.Consensus.Tracing.ConvertTxId
+import Ouroboros.Consensus.Tracing.Era.Byron ()
+import Ouroboros.Consensus.Tracing.Era.HardFork ()
+import Ouroboros.Consensus.Tracing.Era.Shelley ()
+import Ouroboros.Consensus.Tracing.Formatting ()
+import Ouroboros.Consensus.Tracing.HasIssuer
+import Ouroboros.Consensus.Tracing.KESInfo
+import Ouroboros.Consensus.Tracing.Render

tracing/Ouroboros/Consensus/Tracing/BlockReplayProgress.hs

@@ -0,0 +1,134 @@
+{-# LANGUAGE BangPatterns #-}
+{-# LANGUAGE OverloadedStrings #-}
+{-# LANGUAGE RecordWildCards #-}
+{-# LANGUAGE TupleSections #-}
+
+module Ouroboros.Consensus.Tracing.BlockReplayProgress
+  ( withReplayedBlock
+  , ReplayBlockStats (..)
+  ) where
+
+import Cardano.Logging
+import Control.Concurrent.MVar
+import Data.Aeson (Value (String), (.=))
+import Data.Text (Text, pack)
+import Numeric (showFFloat)
+import Ouroboros.Consensus.Block (SlotNo, realPointSlot)
+import qualified Ouroboros.Consensus.Storage.ChainDB as ChainDB
+import qualified Ouroboros.Consensus.Storage.LedgerDB as LedgerDB
+import Ouroboros.Network.Block (pointSlot, unSlotNo)
+import Ouroboros.Network.Point (withOrigin)
+
+textShow :: Show a => a -> Text
+textShow = pack . show
+
+newtype ReplayBlockState = ReplayBlockState
+  { rpsLastSlot :: Maybe SlotNo
+  -- ^ Last slot for which a `ReplayBlockStats` message has been issued.
+  }
+
+data ReplayBlockStats = ReplayBlockStats
+  { rpsCurSlot :: SlotNo
+  , rpsGoalSlot :: SlotNo
+  }
+
+initialReplayBlockState :: ReplayBlockState
+initialReplayBlockState = ReplayBlockState{rpsLastSlot = Nothing}
+
+progressForMachine :: ReplayBlockStats -> Double
+progressForMachine (ReplayBlockStats curSlot goalSlot) =
+  (fromIntegral (unSlotNo curSlot) * 100.0) / fromIntegral (unSlotNo $ max curSlot goalSlot)
+
+progressForHuman :: ReplayBlockStats -> Double
+progressForHuman = round2 . progressForMachine
+ where
+  round2 :: Double -> Double
+  round2 num =
+    let
+      f :: Int
+      f = round $ num * 100
+     in
+      fromIntegral f / 100
+
+--------------------------------------------------------------------------------
+-- ReplayBlockStats Tracer
+--------------------------------------------------------------------------------
+
+instance LogFormatting ReplayBlockStats where
+  forMachine _ stats =
+    mconcat
+      [ "kind" .= String "ReplayBlockStats"
+      , "progress" .= String (pack $ show $ progressForMachine stats)
+      ]
+
+  forHuman stats@ReplayBlockStats{..} =
+    "Replayed block: slot "
+      <> textShow (unSlotNo rpsCurSlot)
+      <> " out of "
+      <> textShow (unSlotNo rpsGoalSlot)
+      <> ". Progress: "
+      <> pack (showFFloat (Just 2) (progressForHuman stats) mempty)
+      <> "%"
+
+  asMetrics stats =
+    [DoubleM "blockReplayProgress" (progressForMachine stats)]
+
+instance MetaTrace ReplayBlockStats where
+  namespaceFor ReplayBlockStats{} = Namespace [] ["LedgerReplay"]
+
+  severityFor (Namespace _ ["LedgerReplay"]) _ = Just Info
+  severityFor _ _ = Nothing
+
+  documentFor (Namespace _ ["LedgerReplay"]) =
+    Just
+      "Counts block replays and calculates the percent."
+  documentFor _ = Nothing
+
+  metricsDocFor (Namespace _ ["LedgerReplay"]) =
+    [("blockReplayProgress", "Progress in percent")]
+  metricsDocFor _ = []
+
+  allNamespaces =
+    [ Namespace [] ["LedgerReplay"]
+    ]
+
+withReplayedBlock ::
+  Trace IO ReplayBlockStats ->
+  IO (Trace IO (ChainDB.TraceEvent blk))
+withReplayedBlock tr = do
+  var <- newMVar initialReplayBlockState
+  contramapMCond tr (process var)
+ where
+  process ::
+    MVar ReplayBlockState ->
+    (LoggingContext, Either TraceControl (ChainDB.TraceEvent blk)) ->
+    IO (Maybe (LoggingContext, Either TraceControl ReplayBlockStats))
+  process var (ctx, Right msg) = modifyMVar var $ \st -> do
+    let !(!st', mbStats) = mbProduceBlockStats msg st
+    pure (st', fmap ((ctx,) . Right) mbStats)
+  process _ (ctx, Left control) = pure (Just (ctx, Left control))
+
+  mbProduceBlockStats ::
+    ChainDB.TraceEvent blk -> ReplayBlockState -> (ReplayBlockState, Maybe ReplayBlockStats)
+  mbProduceBlockStats
+    ( ChainDB.TraceLedgerDBEvent
+        ( LedgerDB.LedgerReplayEvent
+            ( LedgerDB.TraceReplayProgressEvent
+                (LedgerDB.ReplayedBlock curSlot [] _ (LedgerDB.ReplayGoal replayToSlot))
+              )
+          )
+      )
+    st@(ReplayBlockState mLastSlot) =
+      let curSlotNo = realPointSlot curSlot
+          goalSlotNo = withOrigin 0 id $ pointSlot replayToSlot
+          stats = ReplayBlockStats curSlotNo goalSlotNo
+          progressFor soFar goal = progressForHuman (ReplayBlockStats soFar goal)
+          shouldEmit =
+            maybe
+              True
+              (\lastSlot -> progressFor curSlotNo goalSlotNo - progressFor lastSlot goalSlotNo >= 0.01)
+              mLastSlot
+       in if shouldEmit
+            then (ReplayBlockState (Just curSlotNo), Just stats)
+            else (st, Nothing)
+  mbProduceBlockStats _ st = (st, Nothing)