Emit a trace when the DB is not clean (#1198)

Closes #1195

Author: jasagredo

ouroboros-consensus-diffusion/changelog.d/js-trace-unclean.md

@@ -0,0 +1,4 @@
+### Non-Breaking
+
+- Emit `ChainDB.TraceEvent(TraceLastShutdownUnclean)` when the `clean` marker is
+  missing and the node will therefore revalidate all the data.

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

@@ -99,7 +99,8 @@ import           Ouroboros.Consensus.Node.RethrowPolicy
 import           Ouroboros.Consensus.Node.Run
 import           Ouroboros.Consensus.Node.Tracers
 import           Ouroboros.Consensus.NodeKernel
-import           Ouroboros.Consensus.Storage.ChainDB (ChainDB, ChainDbArgs)
+import           Ouroboros.Consensus.Storage.ChainDB (ChainDB, ChainDbArgs,
+                     TraceEvent)
 import qualified Ouroboros.Consensus.Storage.ChainDB as ChainDB
 import qualified Ouroboros.Consensus.Storage.ChainDB.Impl.Args as ChainDB
 import           Ouroboros.Consensus.Storage.LedgerDB.DiskPolicy
@@ -657,11 +658,12 @@ runWith RunNodeArgs{..} encAddrNtN decAddrNtN LowLevelRunNodeArgs{..} =
 stdWithCheckedDB ::
      forall blk a. (StandardHash blk, Typeable blk)
   => Proxy blk
+  -> Tracer IO (TraceEvent blk)
   -> FilePath
   -> NetworkMagic
   -> (LastShutDownWasClean -> (ChainDB IO blk -> IO a -> IO a) -> IO a)  -- ^ Body action with last shutdown was clean.
   -> IO a
-stdWithCheckedDB pb databasePath networkMagic body = do
+stdWithCheckedDB pb tracer databasePath networkMagic body = do
 
     -- Check the DB marker first, before doing the lock file, since if the
     -- marker is not present, it expects an empty DB dir.
@@ -671,7 +673,7 @@ stdWithCheckedDB pb databasePath networkMagic body = do
       networkMagic
 
     -- Then create the lock file.
-    withLockDB mountPoint $ runWithCheckedDB pb hasFS body
+    withLockDB mountPoint $ runWithCheckedDB pb tracer hasFS body
   where
     mountPoint = MountPoint databasePath
     hasFS      = ioHasFS mountPoint
@@ -908,7 +910,7 @@ stdLowLevelRunNodeArgsIO RunNodeArgs{ rnProtocolInfo
             snd
             (supportedNodeToClientVersions (Proxy @blk))
       , llrnWithCheckedDB =
-          stdWithCheckedDB (Proxy @blk) srnDatabasePath networkMagic
+          stdWithCheckedDB (Proxy @blk) srnTraceChainDB srnDatabasePath networkMagic
       , llrnMaxCaughtUpAge = secondsToNominalDiffTime $ 20 * 60   -- 20 min
       , llrnMaxClockSkew =
           InFuture.defaultClockSkew

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

@@ -10,6 +10,7 @@ module Ouroboros.Consensus.Node.Recovery (
   ) where
 
 import           Control.Monad (unless, when)
+import           Control.Tracer (Tracer, traceWith)
 import           Data.Proxy (Proxy)
 import           Data.Typeable (Typeable)
 import           Ouroboros.Consensus.Block (StandardHash)
@@ -88,18 +89,19 @@ exceptionRequiresRecovery pb e = case toExitReason pb e of
 runWithCheckedDB ::
      forall a m h blk. (IOLike m, StandardHash blk, Typeable blk)
   => Proxy blk
+  -> Tracer m (TraceEvent blk)
   -> HasFS m h
   -> (LastShutDownWasClean -> (ChainDB m blk -> m a -> m a) -> m a)
   -> m a
-runWithCheckedDB pb hasFS body = do
+runWithCheckedDB pb tracer hasFS body = do
     -- When we shut down cleanly, we create a marker file so that the next
     -- time we start, we know we don't have to validate the contents of the
     -- whole ChainDB. When we shut down with an exception indicating
     -- corruption or something going wrong with the file system, we don't
     -- create this marker file so that the next time we start, we do a full
     -- validation.
     wasClean <- hasCleanShutdownMarker hasFS
-
+    unless wasClean (traceWith tracer TraceLastShutdownUnclean)
     removeMarkerOnUncleanShutdown wasClean
       $ body
           (LastShutDownWasClean wasClean)

ouroboros-consensus/changelog.d/js-trace-unclean.md

@@ -0,0 +1,5 @@
+### Breaking
+
+- New `ChainDB.TraceEvent(TraceLastShutdownUnclean)` trace message to be emitted
+  when the `clean` marker is missing and the node will therefore revalidate all
+  the data.

ouroboros-consensus/src/ouroboros-consensus/Ouroboros/Consensus/Storage/ChainDB/Impl/Types.hs

@@ -544,6 +544,7 @@ data TraceEvent blk
   | TraceLedgerReplayEvent      (LgrDB.TraceReplayEvent       blk)
   | TraceImmutableDBEvent       (ImmutableDB.TraceEvent       blk)
   | TraceVolatileDBEvent        (VolatileDB.TraceEvent        blk)
+  | TraceLastShutdownUnclean
   deriving (Generic)
 
 

ouroboros-consensus/test/storage-test/Test/Ouroboros/Storage/ChainDB/StateMachine.hs

@@ -1631,6 +1631,7 @@ traceEventName = \case
     TraceLedgerReplayEvent      ev    -> "LedgerReplay."      <> constrName ev
     TraceImmutableDBEvent       ev    -> "ImmutableDB."       <> constrName ev
     TraceVolatileDBEvent        ev    -> "VolatileDB."        <> constrName ev
+    TraceLastShutdownUnclean          -> "LastShutdownUnclean"
 
 mkArgs :: IOLike m
        => TopLevelConfig Blk