From 7af37a7147a85c212181531038d5a84701a83bda Mon Sep 17 00:00:00 2001 From: Karl Knutsson Date: Fri, 11 Oct 2024 08:01:06 +0200 Subject: [PATCH] Trace forkSyncStateOnTipPointChange Trace when forkSyncStateOnTipPointChange completes an itteration. --- .../20241011_091242_karl.fb.knutsson_sync_tracing.md | 4 ++++ .../Ouroboros/Consensus/Mempool/Impl/Common.hs | 5 +++++ .../ouroboros-consensus/Ouroboros/Consensus/Mempool/Init.hs | 6 +++++- 3 files changed, 14 insertions(+), 1 deletion(-) create mode 100644 ouroboros-consensus/changelog.d/20241011_091242_karl.fb.knutsson_sync_tracing.md diff --git a/ouroboros-consensus/changelog.d/20241011_091242_karl.fb.knutsson_sync_tracing.md b/ouroboros-consensus/changelog.d/20241011_091242_karl.fb.knutsson_sync_tracing.md new file mode 100644 index 0000000000..5f03960fff --- /dev/null +++ b/ouroboros-consensus/changelog.d/20241011_091242_karl.fb.knutsson_sync_tracing.md @@ -0,0 +1,4 @@ +### Breaking + +- Add TraceMempoolSynced to TraceEventMempool for tracing mempool sync time. + diff --git a/ouroboros-consensus/src/ouroboros-consensus/Ouroboros/Consensus/Mempool/Impl/Common.hs b/ouroboros-consensus/src/ouroboros-consensus/Ouroboros/Consensus/Mempool/Impl/Common.hs index 119940dca3..0e67f2e210 100644 --- a/ouroboros-consensus/src/ouroboros-consensus/Ouroboros/Consensus/Mempool/Impl/Common.hs +++ b/ouroboros-consensus/src/ouroboros-consensus/Ouroboros/Consensus/Mempool/Impl/Common.hs @@ -56,6 +56,7 @@ import qualified Ouroboros.Consensus.Mempool.TxSeq as TxSeq import Ouroboros.Consensus.Storage.ChainDB (ChainDB) import qualified Ouroboros.Consensus.Storage.ChainDB.API as ChainDB import Ouroboros.Consensus.Util (repeatedly) +import Ouroboros.Consensus.Util.Enclose (EnclosingTimed) import Ouroboros.Consensus.Util.IOLike hiding (newMVar) {------------------------------------------------------------------------------- @@ -556,6 +557,10 @@ data TraceEventMempool blk -- transactions. MempoolSize -- ^ The current size of the Mempool. + | TraceMempoolSynced + -- ^ Emitted when the mempool is adjusted after the tip has changed. + EnclosingTimed + -- ^ How long the sync operation took. deriving instance ( Eq (GenTx blk) , Eq (Validated (GenTx blk)) diff --git a/ouroboros-consensus/src/ouroboros-consensus/Ouroboros/Consensus/Mempool/Init.hs b/ouroboros-consensus/src/ouroboros-consensus/Ouroboros/Consensus/Mempool/Init.hs index 43dc439fd4..fdaf362035 100644 --- a/ouroboros-consensus/src/ouroboros-consensus/Ouroboros/Consensus/Mempool/Init.hs +++ b/ouroboros-consensus/src/ouroboros-consensus/Ouroboros/Consensus/Mempool/Init.hs @@ -9,6 +9,7 @@ module Ouroboros.Consensus.Mempool.Init ( import Control.Monad (void) import Control.Tracer +import Data.Functor.Contravariant ((>$<)) import Ouroboros.Consensus.Block import Ouroboros.Consensus.HeaderValidation import Ouroboros.Consensus.Ledger.Abstract @@ -18,6 +19,7 @@ import Ouroboros.Consensus.Mempool.Capacity import Ouroboros.Consensus.Mempool.Impl.Common import Ouroboros.Consensus.Mempool.Query import Ouroboros.Consensus.Mempool.Update +import Ouroboros.Consensus.Util.Enclose import Ouroboros.Consensus.Util.IOLike import Ouroboros.Consensus.Util.ResourceRegistry import Ouroboros.Consensus.Util.STM (Watcher (..), forkLinkedWatcher) @@ -68,7 +70,9 @@ forkSyncStateOnTipPointChange registry menv = } where action :: Point blk -> m () - action _tipPoint = void $ implSyncWithLedger menv + action _tipPoint = + encloseTimedWith (TraceMempoolSynced >$< mpEnvTracer menv) $ + void $ implSyncWithLedger menv -- Using the tip ('Point') allows for quicker equality checks getCurrentTip :: STM m (Point blk)