Much quieter replays

node/ChainwebNode.hs

@@ -1,4 +1,5 @@
 {-# LANGUAGE AllowAmbiguousTypes #-}
+{-# LANGUAGE BangPatterns #-}
 {-# LANGUAGE CPP #-}
 {-# LANGUAGE DeriveAnyClass #-}
 {-# LANGUAGE DeriveGeneric #-}
@@ -93,6 +94,7 @@ import Chainweb.Miner.Coordinator (MiningStats)
 import Chainweb.Pact.Backend.DbCache (DbCacheStats)
 import Chainweb.Pact.Service.PactQueue (PactQueueStats)
 import Chainweb.Pact.RestAPI.Server (PactCmdLog(..))
+import Chainweb.Pact.Types(TxFailureLog)
 import Chainweb.Payload
 import Chainweb.Payload.PayloadStore
 import Chainweb.Time
@@ -363,17 +365,24 @@ node conf logger = do
 
 withNodeLogger
     :: LogConfig
+    -> ChainwebConfiguration
     -> ChainwebVersion
     -> (L.Logger SomeLogMessage -> IO ())
     -> IO ()
-withNodeLogger logConfig v f = runManaged $ do
+withNodeLogger logCfg chainwebCfg v f = runManaged $ do
 
     -- This manager is used only for logging backends
     mgr <- liftIO HTTPS.newTlsManager
 
     -- Base Backend
     baseBackend <- managed
-        $ withBaseHandleBackend "ChainwebApp" mgr pkgInfoScopes (_logConfigBackend logConfig)
+        $ withBaseHandleBackend "ChainwebApp" mgr pkgInfoScopes (_logConfigBackend logCfg)
+
+    -- we don't log tx failures in replay
+    let !txFailureHandler =
+            if _configOnlySyncPact chainwebCfg
+            then dropLogHandler (Proxy :: Proxy TxFailureLog)
+            else passthroughLogHandler
 
     -- Telemetry Backends
     monitorBackend <- managed
@@ -415,8 +424,9 @@ withNodeLogger logConfig v f = runManaged $ do
         $ mkTelemetryLogger @ChainwebStatus mgr teleLogConfig
 
     logger <- managed
-        $ L.withLogger (_logConfigLogger logConfig) $ logHandles
-            [ logFilterHandle (_logConfigFilter logConfig)
+        $ L.withLogger (_logConfigLogger logCfg) $ logHandles
+            [ logFilterHandle (_logConfigFilter logCfg)
+            , txFailureHandler
             , logHandler monitorBackend
             , logHandler p2pInfoBackend
             , logHandler rtsBackend
@@ -438,11 +448,11 @@ withNodeLogger logConfig v f = runManaged $ do
             ] baseBackend
 
     liftIO $ f
-        $ maybe id (\x -> addLabel ("cluster", toText x)) (_logConfigClusterId logConfig)
+        $ maybe id (\x -> addLabel ("cluster", toText x)) (_logConfigClusterId logCfg)
         $ addLabel ("chainwebVersion", sshow (_versionName v))
         $ logger
   where
-    teleLogConfig = _logConfigTelemetryBackend logConfig
+    teleLogConfig = _logConfigTelemetryBackend logCfg
 
 mkTelemetryLogger
     :: forall a b
@@ -538,7 +548,7 @@ main = do
         let v = _configChainwebVersion $ _nodeConfigChainweb conf
         registerVersion v
         hSetBuffering stderr LineBuffering
-        withNodeLogger (_nodeConfigLog conf) v $ \logger -> do
+        withNodeLogger (_nodeConfigLog conf) (_nodeConfigChainweb conf) v $ \logger -> do
             logFunctionJson logger Info ProcessStarted
             handles
                 [ Handler $ \(e :: SomeAsyncException) ->

src/Chainweb/Chainweb.hs

@@ -418,7 +418,6 @@ withChainwebInternal conf logger peer serviceSock rocksDb pactDbDir backupDir re
       { _pactReorgLimit = _configReorgLimit conf
       , _pactLocalRewindDepthLimit = _configLocalRewindDepthLimit conf
       , _pactPreInsertCheckTimeout = _configPreInsertCheckTimeout conf
-      , _pactRevalidate = True
       , _pactQueueSize = _configPactQueueSize conf
       , _pactResetDb = resetDb
       , _pactAllowReadsInLocal = _configAllowReadsInLocal conf

src/Chainweb/Pact/PactService.hs

@@ -155,7 +155,6 @@ withPactService ver cid chainwebLogger bhDb pdb sqlenv config act =
                     , _psPreInsertCheckTimeout = _pactPreInsertCheckTimeout config
                     , _psOnFatalError = defaultOnFatalError (logFunctionText chainwebLogger)
                     , _psVersion = ver
-                    , _psValidateHashesOnReplay = _pactRevalidate config
                     , _psAllowReadsInLocal = _pactAllowReadsInLocal config
                     , _psIsBatch = False
                     , _psCheckpointerDepth = 0

src/Chainweb/Pact/PactService/Checkpointer.hs

@@ -400,8 +400,7 @@ rewindTo rewindLimit (Just (ParentHeader parent)) = do
                     withAsync (heightProgress (_blockHeight commonAncestor) heightRef (logInfo_ logger)) $ \_ ->
                       s
                           & S.scanM
-                              -- no need to re-validate hashes, because these blocks have already been validated
-                              (\ !p !c -> runPact (local (psValidateHashesOnReplay .~ False) $ fastForward (ParentHeader p, c)) >> writeIORef heightRef (_blockHeight c) >> return c)
+                              (\ !p !c -> runPact (fastForward (ParentHeader p, c)) >> writeIORef heightRef (_blockHeight c) >> return c)
                               (return h) -- initial parent
                               return
                           & S.length_
@@ -416,7 +415,7 @@ fastForward
     . (HasCallStack, CanReadablePayloadCas tbl, Logger logger)
     => (ParentHeader, BlockHeader)
     -> PactServiceM logger tbl ()
-fastForward (target, block) =
+fastForward (target, block) = do
     -- This does a restore, i.e. it rewinds the checkpointer back in
     -- history, if needed.
     withCheckpointerWithoutRewind (Just target) "fastForward" $ \pdbenv -> do

src/Chainweb/Pact/PactService/ExecBlock.hs

@@ -151,10 +151,8 @@ execBlock currHeader plData pdbenv = do
 
     modify' $ set psStateValidated $ Just currHeader
 
-    -- Validate hashes if requested
-    asks _psValidateHashesOnReplay >>= \x -> when x $
-        either throwM (void . return) $!
-        validateHashes currHeader plData miner results
+    either throwM (void . return) $
+      validateHashes currHeader plData miner results
 
     return $! T2 miner results
 
@@ -356,8 +354,7 @@ runCoinbase False dbEnv miner enfCBFail usePrecomp mc = do
 
     reward <- liftIO $! minerReward v rs bh
 
-    (T2 cr upgradedCacheM) <-
-      liftIO $! applyCoinbase v logger dbEnv miner reward txCtx enfCBFail usePrecomp mc
+    (T2 cr upgradedCacheM) <- liftIO $ applyCoinbase v logger dbEnv miner reward txCtx enfCBFail usePrecomp mc
     mapM_ upgradeInitCache upgradedCacheM
     debugResult "runCoinbase" (P.crLogs %~ fmap J.Array $ cr)
     return $! cr

src/Chainweb/Pact/Service/Types.hs

@@ -89,8 +89,6 @@ data PactServiceConfig = PactServiceConfig
     -- ^ Maximum allowed rewind depth in the local command.
   , _pactPreInsertCheckTimeout :: !Micros
     -- ^ Maximum allowed execution time for the transactions validation.
-  , _pactRevalidate :: !Bool
-    -- ^ Re-validate payload hashes during transaction replay
   , _pactAllowReadsInLocal :: !Bool
     -- ^ Allow direct database reads in local mode
   , _pactQueueSize :: !Natural

src/Chainweb/Pact/TransactionExec.hs

@@ -1,6 +1,10 @@
 {-# LANGUAGE AllowAmbiguousTypes #-}
 {-# LANGUAGE BangPatterns #-}
+{-# LANGUAGE DerivingStrategies #-}
+{-# LANGUAGE DeriveAnyClass #-}
+{-# LANGUAGE DeriveGeneric #-}
 {-# LANGUAGE FlexibleContexts #-}
+{-# LANGUAGE GeneralizedNewtypeDeriving #-}
 {-# LANGUAGE LambdaCase #-}
 {-# LANGUAGE OverloadedStrings #-}
 {-# LANGUAGE RankNTypes #-}
@@ -72,6 +76,7 @@ import Data.Maybe
 import qualified Data.Set as S
 import Data.Text (Text)
 import qualified Data.Text as T
+import qualified System.LogLevel as L
 
 -- internal Pact modules
 
@@ -223,14 +228,14 @@ applyCmd v logger gasLogger pdbenv miner gasModel txCtx spv cmd initialGas mcach
         Right _ -> checkTooBigTx initialGas gasLimit applyPayload redeemAllGas
 
     displayPactError e = do
-      r <- jsonErrorResult e "tx failure for request key when running cmd"
+      r <- failTxWith e "tx failure for request key when running cmd"
       redeemAllGas r
 
     stripPactError e = do
       let e' = case callCtx of
             ApplyLocal -> e
             ApplySend -> toEmptyPactError e
-      r <- jsonErrorResult e' "tx failure for request key when running cmd"
+      r <- failTxWith e' "tx failure for request key when running cmd"
       redeemAllGas r
 
     applyPayload = do
@@ -247,7 +252,7 @@ applyCmd v logger gasLogger pdbenv miner gasModel txCtx spv cmd initialGas mcach
           | chainweb217Pact' -> stripPactError e
           | chainweb213Pact' || not (isOldListErr e) -> displayPactError e
           | otherwise -> do
-              r <- jsonErrorResult (toOldListErr e) "tx failure for request key when running cmd"
+              r <- failTxWith (toOldListErr e) "tx failure for request key when running cmd"
               redeemAllGas r
         Right r -> applyRedeem r
 
@@ -329,7 +334,7 @@ applyGenesisCmd logger dbEnv spv txCtx cmd =
 
     go = do
       -- TODO: fix with version recordification so that this matches the flags at genesis heights.
-      cr <- catchesPactError logger PrintsUnexpectedError $! runGenesis cmd permissiveNamespacePolicy interp
+      cr <- catchesPactError logger (onChainErrorPrintingFor txCtx) $! runGenesis cmd permissiveNamespacePolicy interp
       case cr of
         Left e -> fatal $ "Genesis command failed: " <> sshow e
         Right r -> r <$ debug "successful genesis tx for request key"
@@ -414,7 +419,7 @@ applyCoinbase v logger dbEnv (Miner mid mks@(MinerKeys mk)) reward@(ParsedDecima
       case cr of
         Left e
           | throwCritical -> throwM $ CoinbaseFailure $ sshow e
-          | otherwise -> (`T2` Nothing) <$> jsonErrorResult e "coinbase tx failure"
+          | otherwise -> (`T2` Nothing) <$> failTxWith e "coinbase tx failure"
         Right er -> do
           debug
             $! "successful coinbase of "
@@ -475,7 +480,7 @@ applyLocal logger gasLogger dbEnv gasModel txCtx spv cmdIn mc execConfig =
           applyContinuation gas0 interp cm signers chash managedNamespacePolicy
 
       case cr of
-        Left e -> jsonErrorResult e "applyLocal"
+        Left e -> failTxWith e "applyLocal"
         Right r -> return $! r { _crMetaData = Just (J.toJsonViaEncode $ ctxToPublicData' txCtx) }
 
     go = checkTooBigTx gas0 gasLimit (applyPayload $ _pPayload $ _cmdPayload cmd) return
@@ -623,21 +628,19 @@ applyUpgrades v cid height
           logError $ "Upgrade transaction failed! " <> sshow e
           throwM e
 
-jsonErrorResult
+failTxWith
     :: (Logger logger)
     => PactError
     -> Text
     -> TransactionM logger p (CommandResult [TxLogJson])
-jsonErrorResult err msg = do
+failTxWith err msg = do
     logs <- use txLogs
     gas <- view txGasLimit -- error means all gas was charged
     rk <- view txRequestKey
     l <- view txLogger
 
-    logInfo_ l
-      $! msg
-      <> ": " <> sshow rk
-      <> ": " <> sshow err
+    liftIO $ logFunction l L.Info
+      (TxFailureLog rk err msg)
 
     return $! CommandResult rk Nothing (PactResult (Left err))
       gas (Just logs) Nothing Nothing []
@@ -992,7 +995,7 @@ checkTooBigTx initialGas gasLimit next onFail
             $ "Tx too big (" <> pretty initialGas <> "), limit "
             <> pretty gasLimit
 
-      r <- jsonErrorResult pe "Tx too big"
+      r <- failTxWith pe "Tx too big"
       onFail r
   | otherwise = next
 
@@ -1136,15 +1139,15 @@ gasLog m = do
   l <- view txGasLogger
   rk <- view txRequestKey
   for_ l $ \logger ->
-    logInfo_ logger $! m <> ": " <> sshow rk
+    logInfo_ logger $ m <> ": " <> sshow rk
 
 -- | Log request keys at DEBUG when successful
 --
 debug :: (Logger logger) => Text -> TransactionM logger db ()
 debug s = do
     l <- view txLogger
     rk <- view txRequestKey
-    logDebug_ l $! s <> ": " <> sshow rk
+    logDebug_ l $ s <> ": " <> sshow rk
 
 
 -- | Denotes fatal failure points in the tx exec process
@@ -1155,7 +1158,7 @@ fatal e = do
     rk <- view txRequestKey
 
     logError_ l
-      $! "critical transaction failure: "
+      $ "critical transaction failure: "
       <> sshow rk <> ": " <> e
 
     throwM $ PactTransactionExecError (fromUntypedHash $ unRequestKey rk) e

src/Chainweb/Pact/Types.hs

@@ -38,6 +38,7 @@ module Chainweb.Pact.Types
   , GasId(..)
   , EnforceCoinbaseFailure(..)
   , CoinbaseUsePrecompiled(..)
+  , cleanModuleCache
 
     -- * Transaction State
   , TransactionState(..)
@@ -81,7 +82,6 @@ module Chainweb.Pact.Types
   , psPreInsertCheckTimeout
   , psOnFatalError
   , psVersion
-  , psValidateHashesOnReplay
   , psLogger
   , psGasLogger
   , psAllowReadsInLocal
@@ -147,6 +147,7 @@ module Chainweb.Pact.Types
     -- * types
   , TxTimeout(..)
   , ApplyCmdExecutionContext(..)
+  , TxFailureLog(..)
 
   -- * miscellaneous
   , defaultOnFatalError
@@ -217,7 +218,6 @@ import Chainweb.Time
 import Chainweb.Transaction
 import Chainweb.Utils
 import Chainweb.Version
-import Chainweb.Version.Guards
 import Utils.Logging.Trace
 
 
@@ -288,6 +288,15 @@ moduleCacheKeys :: ModuleCache -> [ModuleName]
 moduleCacheKeys (ModuleCache a) = fst <$> LHM.toList a
 {-# INLINE moduleCacheKeys #-}
 
+-- this can't go in Chainweb.Version.Guards because it causes an import cycle
+-- it uses genesisHeight which is from BlockHeader which imports Guards
+cleanModuleCache :: ChainwebVersion -> ChainId -> BlockHeight -> Bool
+cleanModuleCache v cid bh =
+  case v ^?! versionForks . at Chainweb217Pact . _Just . onChain cid of
+    ForkAtBlockHeight bh' -> bh == bh'
+    ForkAtGenesis -> bh == genesisHeight v cid
+    ForkNever -> False
+
 -- -------------------------------------------------------------------- --
 -- Local vs. Send execution context flag
 
@@ -414,7 +423,6 @@ data PactServiceEnv logger tbl = PactServiceEnv
     -- ^ The limit of checkpointer's rewind in the `execValidationBlock` command.
     , _psOnFatalError :: !(forall a. PactException -> Text -> IO a)
     , _psVersion :: !ChainwebVersion
-    , _psValidateHashesOnReplay :: !Bool
     , _psAllowReadsInLocal :: !Bool
     , _psLogger :: !logger
     , _psGasLogger :: !(Maybe logger)
@@ -464,7 +472,6 @@ testPactServiceConfig = PactServiceConfig
       { _pactReorgLimit = defaultReorgLimit
       , _pactLocalRewindDepthLimit = defaultLocalRewindDepthLimit
       , _pactPreInsertCheckTimeout = defaultPreInsertCheckTimeout
-      , _pactRevalidate = True
       , _pactQueueSize = 1000
       , _pactResetDb = True
       , _pactAllowReadsInLocal = False
@@ -493,6 +500,15 @@ newtype TxTimeout = TxTimeout TransactionHash
     deriving Show
 instance Exception TxTimeout
 
+data TxFailureLog = TxFailureLog !RequestKey !PactError !Text
+  deriving stock (Generic)
+  deriving anyclass (NFData, Typeable)
+instance LogMessage TxFailureLog where
+  logText (TxFailureLog rk err msg) =
+    msg <> ": " <> sshow rk <> ": " <> sshow err
+instance Show TxFailureLog where
+  show m = unpack (logText m)
+
 defaultOnFatalError :: forall a. (LogLevel -> Text -> IO ()) -> PactException -> Text -> IO a
 defaultOnFatalError lf pex t = do
     lf Error errMsg
@@ -728,9 +744,11 @@ catchesPactError :: (MonadCatch m, MonadIO m, Logger logger) => logger -> Unexpe
 catchesPactError logger exnPrinting action = catches (Right <$> action)
   [ Handler $ \(e :: PactError) -> return $ Left e
   , Handler $ \(e :: SomeException) -> do
-      liftIO $ logWarn_ logger ("catchesPactError: unknown error: " <> sshow e)
-      return $ Left $ PactError EvalError def def $
-        case exnPrinting of
-          PrintsUnexpectedError -> viaShow e
-          CensorsUnexpectedError -> "unknown error"
+      !err <- case exnPrinting of
+          PrintsUnexpectedError ->
+            return (viaShow e)
+          CensorsUnexpectedError -> do
+            liftIO $ logWarn_ logger ("catchesPactError: unknown error: " <> sshow e)
+            return "unknown error"
+      return $ Left $ PactError EvalError def def err
   ]

src/Chainweb/Version/Guards.hs

@@ -38,7 +38,6 @@ module Chainweb.Version.Guards
     , chainweb215Pact
     , chainweb216Pact
     , chainweb217Pact
-    , cleanModuleCache
     , chainweb218Pact
     , chainweb219Pact
     , chainweb220Pact
@@ -223,9 +222,6 @@ chainweb216Pact = checkFork after Chainweb216Pact
 chainweb217Pact :: ChainwebVersion -> ChainId -> BlockHeight -> Bool
 chainweb217Pact = checkFork after Chainweb217Pact
 
-cleanModuleCache :: ChainwebVersion -> ChainId -> BlockHeight -> Bool
-cleanModuleCache = checkFork atOrAfter Chainweb217Pact
-
 chainweb218Pact :: ChainwebVersion -> ChainId -> BlockHeight -> Bool
 chainweb218Pact = checkFork atOrAfter Chainweb218Pact