From b458c6faed75911558407fbeaf2be7408006b4a8 Mon Sep 17 00:00:00 2001 From: Cmdv Date: Tue, 19 Nov 2024 21:18:35 +0000 Subject: [PATCH 1/2] 1903 - extend logging --- cardano-db-sync/cardano-db-sync.cabal | 1 + cardano-db-sync/src/Cardano/DbSync.hs | 84 ++++++++----- cardano-db-sync/src/Cardano/DbSync/Api.hs | 89 +++++++++----- .../src/Cardano/DbSync/Api/Ledger.hs | 37 +++--- cardano-db-sync/src/Cardano/DbSync/Cache.hs | 32 +++-- .../src/Cardano/DbSync/Database.hs | 18 +-- cardano-db-sync/src/Cardano/DbSync/Default.hs | 24 ++-- cardano-db-sync/src/Cardano/DbSync/Epoch.hs | 23 +++- .../src/Cardano/DbSync/Era/Byron/Genesis.hs | 29 +++-- .../src/Cardano/DbSync/Era/Byron/Insert.hs | 87 ++++++++------ .../src/Cardano/DbSync/Era/Shelley/Genesis.hs | 24 ++-- .../Cardano/DbSync/Era/Universal/Adjust.hs | 22 ++-- .../src/Cardano/DbSync/Era/Universal/Block.hs | 78 +++++++----- .../src/Cardano/DbSync/Era/Universal/Epoch.hs | 12 +- .../Era/Universal/Insert/Certificate.hs | 7 +- .../DbSync/Era/Universal/Insert/GovAction.hs | 43 ++++--- .../DbSync/Era/Universal/Insert/Grouped.hs | 8 +- .../Era/Universal/Insert/LedgerEvent.hs | 19 +-- .../DbSync/Era/Universal/Insert/Other.hs | 5 +- .../Cardano/DbSync/Era/Universal/Insert/Tx.hs | 8 +- .../Cardano/DbSync/Era/Universal/Validate.hs | 46 ++++--- .../src/Cardano/DbSync/Era/Util.hs | 10 +- .../src/Cardano/DbSync/Fix/ConsumedBy.hs | 21 ++-- .../src/Cardano/DbSync/Fix/EpochStake.hs | 28 +++-- .../src/Cardano/DbSync/Fix/PlutusDataBytes.hs | 96 +++++++++------ .../src/Cardano/DbSync/Fix/PlutusScripts.hs | 31 +++-- .../src/Cardano/DbSync/Ledger/State.hs | 98 ++++++++------- .../src/Cardano/DbSync/LocalStateQuery.hs | 12 +- .../src/Cardano/DbSync/OffChain.hs | 17 +-- .../src/Cardano/DbSync/Rollback.hs | 86 ++++++++----- cardano-db-sync/src/Cardano/DbSync/Sync.hs | 113 ++++++++++-------- cardano-db-sync/src/Cardano/DbSync/Util.hs | 40 ------- .../src/Cardano/DbSync/Util/Constraint.hs | 24 ++-- .../src/Cardano/DbSync/Util/Logging.hs | 108 +++++++++++++++++ 34 files changed, 857 insertions(+), 523 deletions(-) create mode 100644 cardano-db-sync/src/Cardano/DbSync/Util/Logging.hs diff --git a/cardano-db-sync/cardano-db-sync.cabal b/cardano-db-sync/cardano-db-sync.cabal index 6bd0516d0..6bc713fee 100644 --- a/cardano-db-sync/cardano-db-sync.cabal +++ b/cardano-db-sync/cardano-db-sync.cabal @@ -143,6 +143,7 @@ library Cardano.DbSync.Util.Bech32 Cardano.DbSync.Util.Cbor Cardano.DbSync.Util.Constraint + Cardano.DbSync.Util.Logging Paths_cardano_db_sync diff --git a/cardano-db-sync/src/Cardano/DbSync.hs b/cardano-db-sync/src/Cardano/DbSync.hs index 9df654d4c..a7555c6b2 100644 --- a/cardano-db-sync/src/Cardano/DbSync.hs +++ b/cardano-db-sync/src/Cardano/DbSync.hs @@ -24,7 +24,7 @@ module Cardano.DbSync ( extractSyncOptions, ) where -import Cardano.BM.Trace (Trace, logError, logInfo, logWarning) +import Cardano.BM.Trace (Trace) import qualified Cardano.Crypto as Crypto import qualified Cardano.Db as DB import qualified Cardano.Db as Db @@ -44,6 +44,7 @@ import Cardano.DbSync.Sync (runSyncNodeClient) import Cardano.DbSync.Tracing.ToObjectOrphans () import Cardano.DbSync.Types import Cardano.DbSync.Util.Constraint (queryIsJsonbInSchema) +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logErrorCtx, logInfoCtx, logWarningCtx) import Cardano.Prelude hiding (Nat, (%)) import Cardano.Slotting.Slot (EpochNo (..)) import Control.Concurrent.Async @@ -79,7 +80,8 @@ runDbSync :: Bool -> IO () runDbSync metricsSetters knownMigrations iomgr trce params syncNodeConfigFromFile abortOnPanic = do - logInfo trce $ textShow syncOpts + let logCtx = initLogCtx "runDbSync" "Cardano.DbSync" + logInfoCtx trce $ logCtx {lcMessage = "Current sync options: " <> textShow syncOpts} -- Read the PG connection info pgConfig <- runOrThrowIO (Db.readPGPass $ enpPGPassSource params) @@ -87,33 +89,40 @@ runDbSync metricsSetters knownMigrations iomgr trce params syncNodeConfigFromFil mErrors <- liftIO $ Db.validateMigrations dbMigrationDir knownMigrations whenJust mErrors $ \(unknown, stage4orNewStage3) -> if stage4orNewStage3 - then logWarning trce $ Db.renderMigrationValidateError unknown + then logWarningCtx trce $ logCtx {lcMessage = Db.renderMigrationValidateError unknown} else do let msg = Db.renderMigrationValidateError unknown - logError trce msg + logErrorCtx trce $ logCtx {lcMessage = msg} throwIO unknown - logInfo trce "Schema migration files validated" + logInfoCtx trce $ logCtx {lcMessage = "Schema migration files validated"} let runMigration mode = do msg <- Db.getMaintenancePsqlConf pgConfig - logInfo trce $ "Running database migrations in mode " <> textShow mode - logInfo trce msg - when (mode `elem` [Db.Indexes, Db.Full]) $ logWarning trce indexesMsg + logInfoCtx trce $ logCtx {lcMessage = "Running database migrations in mode " <> textShow mode} + logInfoCtx trce $ logCtx {lcMessage = msg} + when (mode `elem` [Db.Indexes, Db.Full]) $ logWarningCtx trce $ logCtx {lcMessage = indexesMsg} Db.runMigrations pgConfig True dbMigrationDir (Just $ Db.LogFileDir "/tmp") mode (txOutConfigToTableType txOutConfig) (ranMigrations, unofficial) <- if enpForceIndexes params then runMigration Db.Full else runMigration Db.Initial unless (null unofficial) $ - logWarning trce $ - "Unofficial migration scripts found: " - <> textShow unofficial + logWarningCtx trce $ + logCtx {lcMessage = "Unofficial migration scripts found: " <> textShow unofficial} - if ranMigrations - then logInfo trce "All migrations were executed" - else logInfo trce "Some migrations were not executed. They need to run when syncing has started." + logInfoCtx trce $ + logCtx + { lcMessage = + if ranMigrations + then "All migrations were executed" + else "Some migrations were not executed. They need to run when syncing has started." + } - if enpForceIndexes params - then logInfo trce "All user indexes were created" - else logInfo trce "New user indexes were not created. They may be created later if necessary." + logInfoCtx trce $ + logCtx + { lcMessage = + if enpForceIndexes params + then "All user indexes were created" + else "New user indexes were not created. They may be created later if necessary." + } let connectionString = Db.toConnectionString pgConfig @@ -162,12 +171,16 @@ runSyncNode :: SyncOptions -> IO () runSyncNode metricsSetters trce iomgr dbConnString ranMigrations runMigrationFnc syncNodeConfigFromFile syncNodeParams syncOptions = do + let logCtx = initLogCtx "runSyncNode" "Cardano.DbSync" whenJust maybeLedgerDir $ \enpLedgerStateDir -> do createDirectoryIfMissing True (unLedgerStateDir enpLedgerStateDir) - logInfo trce $ "Using byron genesis file from: " <> (show . unGenesisFile $ dncByronGenesisFile syncNodeConfigFromFile) - logInfo trce $ "Using shelley genesis file from: " <> (show . unGenesisFile $ dncShelleyGenesisFile syncNodeConfigFromFile) - logInfo trce $ "Using alonzo genesis file from: " <> (show . unGenesisFile $ dncAlonzoGenesisFile syncNodeConfigFromFile) + logInfoCtx trce $ + logCtx {lcMessage = "Using byron genesis file from: " <> (show . unGenesisFile $ dncByronGenesisFile syncNodeConfigFromFile)} + logInfoCtx trce $ + logCtx {lcMessage = "Using shelley genesis file from: " <> (show . unGenesisFile $ dncShelleyGenesisFile syncNodeConfigFromFile)} + logInfoCtx trce $ + logCtx {lcMessage = "Using alonzo genesis file from: " <> (show . unGenesisFile $ dncAlonzoGenesisFile syncNodeConfigFromFile)} let useLedger = shouldUseLedger (sioLedger $ dncInsertOptions syncNodeConfigFromFile) @@ -193,16 +206,16 @@ runSyncNode metricsSetters trce iomgr dbConnString ranMigrations runMigrationFnc -- Warn the user that jsonb datatypes are being removed from the database schema. when (isJsonbInSchema && removeJsonbFromSchemaConfig) $ do - liftIO $ logWarning trce "Removing jsonb datatypes from the database. This can take time." + liftIO $ logWarningCtx trce $ logCtx {lcMessage = "Removing jsonb datatypes from the database. This can take time."} liftIO $ runRemoveJsonbFromSchema syncEnv -- Warn the user that jsonb datatypes are being added to the database schema. when (not isJsonbInSchema && not removeJsonbFromSchemaConfig) $ do - liftIO $ logWarning trce "Adding jsonb datatypes back to the database. This can take time." + liftIO $ logWarningCtx trce $ logCtx {lcMessage = "Adding jsonb datatypes back to the database. This can take time."} liftIO $ runAddJsonbToSchema syncEnv liftIO $ runExtraMigrationsMaybe syncEnv unless useLedger $ liftIO $ do - logInfo trce "Migrating to a no ledger schema" + logInfoCtx trce $ logCtx {lcMessage = "Migrating to a no ledger schema"} Db.noLedgerMigrations backend trce insertValidateGenesisDist syncEnv (dncNetworkName syncNodeConfigFromFile) genCfg (useShelleyInit syncNodeConfigFromFile) @@ -227,13 +240,17 @@ runSyncNode metricsSetters trce iomgr dbConnString ranMigrations runMigrationFnc maybeLedgerDir = enpMaybeLedgerStateDir syncNodeParams logProtocolMagicId :: Trace IO Text -> Crypto.ProtocolMagicId -> ExceptT SyncNodeError IO () -logProtocolMagicId tracer pm = +logProtocolMagicId tracer pm = do + let logCtx = initLogCtx "logProtocolMagicId" "Cardano.DbSync" liftIO - . logInfo tracer - $ mconcat - [ "NetworkMagic: " - , textShow (Crypto.unProtocolMagicId pm) - ] + . logInfoCtx tracer + $ logCtx + { lcMessage = + mconcat + [ "NetworkMagic: " + , textShow (Crypto.unProtocolMagicId pm) + ] + } -- ------------------------------------------------------------------------------------------------- @@ -299,10 +316,11 @@ extractSyncOptions snp aop snc = startupReport :: Trace IO Text -> Bool -> SyncNodeParams -> IO () startupReport trce aop params = do - logInfo trce $ mconcat ["Version number: ", Text.pack (showVersion version)] - logInfo trce $ mconcat ["Git hash: ", Db.gitRev] - logInfo trce $ mconcat ["Enviroment variable DbSyncAbortOnPanic: ", textShow aop] - logInfo trce $ textShow params + let logCtx = initLogCtx "runSyncNode" "Cardano.DbSync" + logInfoCtx trce $ logCtx {lcMessage = mconcat ["Version number: ", Text.pack (showVersion version)]} + logInfoCtx trce $ logCtx {lcMessage = mconcat ["Git hash: ", Db.gitRev]} + logInfoCtx trce $ logCtx {lcMessage = mconcat ["Enviroment variable DbSyncAbortOnPanic: ", textShow aop]} + logInfoCtx trce $ logCtx {lcMessage = textShow params} txOutConfigToTableType :: TxOutConfig -> DB.TxOutTableType txOutConfigToTableType config = case config of diff --git a/cardano-db-sync/src/Cardano/DbSync/Api.hs b/cardano-db-sync/src/Cardano/DbSync/Api.hs index 02f0b9745..a37b135da 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Api.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Api.hs @@ -51,7 +51,7 @@ module Cardano.DbSync.Api ( convertToPoint, ) where -import Cardano.BM.Trace (Trace, logInfo, logWarning) +import Cardano.BM.Trace (Trace) import qualified Cardano.Chain.Genesis as Byron import Cardano.Crypto.ProtocolMagic (ProtocolMagicId (..)) import qualified Cardano.Db as DB @@ -73,6 +73,7 @@ import Cardano.DbSync.LocalStateQuery import Cardano.DbSync.Types import Cardano.DbSync.Util import Cardano.DbSync.Util.Constraint (dbConstraintNamesExists) +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logInfoCtx, logWarningCtx) import qualified Cardano.Ledger.BaseTypes as Ledger import qualified Cardano.Ledger.Shelley.Genesis as Shelley import Cardano.Prelude @@ -101,7 +102,8 @@ import qualified Ouroboros.Network.Point as Point setConsistentLevel :: SyncEnv -> ConsistentLevel -> IO () setConsistentLevel env cst = do - logInfo (getTrace env) $ "Setting ConsistencyLevel to " <> textShow cst + let logCtx = initLogCtx "setConsistentLevel" "Cardano.DbSync.Api" + logInfoCtx (getTrace env) $ logCtx {lcMessage = "Setting ConsistencyLevel to " <> textShow cst} atomically $ writeTVar (envConsistentLevel env) cst getConsistentLevel :: SyncEnv -> IO ConsistentLevel @@ -158,10 +160,11 @@ getRanIndexes env = do runIndexMigrations :: SyncEnv -> IO () runIndexMigrations env = do + let logCtx = initLogCtx "runIndexMigrations" "Cardano.DbSync.Api" haveRan <- readTVarIO $ envIndexes env unless haveRan $ do envRunDelayedMigration env DB.Indexes - logInfo (getTrace env) "Indexes were created" + logInfoCtx (getTrace env) $ logCtx {lcMessage = "Indexes were created"} atomically $ writeTVar (envIndexes env) True initPruneConsumeMigration :: Bool -> Bool -> Bool -> Bool -> DB.PruneConsumeMigration @@ -178,8 +181,9 @@ getPruneConsume = soptPruneConsumeMigration . envOptions runExtraMigrationsMaybe :: SyncEnv -> IO () runExtraMigrationsMaybe syncEnv = do let pcm = getPruneConsume syncEnv + logCtx = initLogCtx "runExtraMigrationsMaybe" "Cardano.DbSync.Api" txOutTableType = getTxOutTableType syncEnv - logInfo (getTrace syncEnv) $ "runExtraMigrationsMaybe: " <> textShow pcm + logInfoCtx (getTrace syncEnv) $ logCtx {lcMessage = "runExtraMigrationsMaybe: " <> textShow pcm} DB.runDbIohkNoLogging (envBackend syncEnv) $ DB.runExtraMigrations (getTrace syncEnv) @@ -306,12 +310,23 @@ getDbTipBlockNo env = do mblk <- getDbLatestBlockInfo (envBackend env) pure $ maybe Point.Origin (Point.At . bBlockNo) mblk -logDbState :: SyncEnv -> IO () -logDbState env = do +getCurrentTipBlockNo :: SyncEnv -> IO (WithOrigin BlockNo) +getCurrentTipBlockNo env = do + maybeTip <- getDbLatestBlockInfo (envBackend env) + case maybeTip of + Just tip -> pure $ At (bBlockNo tip) + Nothing -> pure Origin + +logDbState :: SyncEnv -> LogContext -> IO () +logDbState env logCtx = do mblk <- getDbLatestBlockInfo (envBackend env) case mblk of - Nothing -> logInfo tracer "Database is empty" - Just tip -> logInfo tracer $ mconcat ["Database tip is at ", showTip tip] + Nothing -> + logInfoCtx tracer $ + logCtx {lcMessage = "Database is empty"} + Just tip -> + logInfoCtx tracer $ + logCtx {lcMessage = mconcat ["Database tip is at ", showTip tip]} where showTip :: TipInfo -> Text showTip tipInfo = @@ -325,13 +340,6 @@ logDbState env = do tracer :: Trace IO Text tracer = getTrace env -getCurrentTipBlockNo :: SyncEnv -> IO (WithOrigin BlockNo) -getCurrentTipBlockNo env = do - maybeTip <- getDbLatestBlockInfo (envBackend env) - case maybeTip of - Just tip -> pure $ At (bBlockNo tip) - Nothing -> pure Origin - mkSyncEnv :: Trace IO Text -> SqlBackend -> @@ -347,6 +355,7 @@ mkSyncEnv :: RunMigration -> IO SyncEnv mkSyncEnv trce backend connectionString syncOptions protoInfo nw nwMagic systemStart syncNodeConfigFromFile syncNP ranMigrations runMigrationFnc = do + let logCtx = initLogCtx "mkSyncEnv" "Cardano.DbSync.Api" dbCNamesVar <- newTVarIO =<< dbConstraintNamesExists backend cache <- if soptCache syncOptions @@ -384,9 +393,13 @@ mkSyncEnv trce backend connectionString syncOptions protoInfo nw nwMagic systemS syncOptions (Nothing, False) -> NoLedger <$> mkNoLedgerEnv trce protoInfo nw systemStart (Just _, False) -> do - logWarning trce $ - "Disabling the ledger doesn't require having a --state-dir." - <> " For more details view https://github.com/IntersectMBO/cardano-db-sync/blob/master/doc/configuration.md#ledger" + logWarningCtx trce $ + logCtx + { lcMessage = + "Disabling the ledger doesn't require having a --state-dir." + <> " For more details view " + <> " https://github.com/IntersectMBO/cardano-db-sync/blob/master/doc/configuration.md#ledger" + } NoLedger <$> mkNoLedgerEnv trce protoInfo nw systemStart -- This won't ever call because we error out this combination at parse time (Nothing, True) -> NoLedger <$> mkNoLedgerEnv trce protoInfo nw systemStart @@ -534,6 +547,7 @@ getBootstrapInProgress :: SqlBackend -> IO Bool getBootstrapInProgress trce bootstrapFlag sqlBackend = do + let logCtx = initLogCtx "getBootstrapInProgress" "Cardano.DbSync.Api" DB.runDbIohkNoLogging sqlBackend $ do ems <- DB.queryAllExtraMigrations let btsState = DB.bootstrapState ems @@ -547,26 +561,35 @@ getBootstrapInProgress trce bootstrapFlag sqlBackend = do liftIO $ DB.logAndThrowIO trce "Bootstrap flag not set, but still in progress" (True, DB.BootstrapNotStarted) -> do liftIO $ - logInfo trce $ - mconcat - [ "Syncing with bootstrap. " - , "This won't populate tx_out until the tip of the chain." - ] + logInfoCtx trce $ + logCtx + { lcMessage = + mconcat + [ "Syncing with bootstrap. " + , "This won't populate tx_out until the tip of the chain." + ] + } DB.insertExtraMigration DB.BootstrapStarted pure True (True, DB.BootstrapInProgress) -> do liftIO $ - logInfo trce $ - mconcat - [ "Syncing with bootstrap is in progress. " - , "This won't populate tx_out until the tip of the chain." - ] + logInfoCtx trce $ + logCtx + { lcMessage = + mconcat + [ "Syncing with bootstrap is in progress. " + , "This won't populate tx_out until the tip of the chain." + ] + } pure True (True, DB.BootstrapDone) -> do liftIO $ - logWarning trce $ - mconcat - [ "Bootstrap flag is set, but it will be ignored, " - , "since bootstrap is already done." - ] + logWarningCtx trce $ + logCtx + { lcMessage = + mconcat + [ "Bootstrap flag is set, but it will be ignored, " + , "since bootstrap is already done." + ] + } pure False diff --git a/cardano-db-sync/src/Cardano/DbSync/Api/Ledger.hs b/cardano-db-sync/src/Cardano/DbSync/Api/Ledger.hs index 399541c49..f3433bea1 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Api/Ledger.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Api/Ledger.hs @@ -6,7 +6,6 @@ module Cardano.DbSync.Api.Ledger where -import Cardano.BM.Trace (logError, logInfo, logWarning) import qualified Cardano.Db as DB import Cardano.DbSync.Api import Cardano.DbSync.Api.Types @@ -20,6 +19,7 @@ import Cardano.DbSync.Era.Util (liftLookupFail) import Cardano.DbSync.Error import Cardano.DbSync.Ledger.State import Cardano.DbSync.Types +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logErrorCtx, logInfoCtx, logWarningCtx) import Cardano.Ledger.Allegra.Scripts (Timelock) import Cardano.Ledger.Alonzo.Scripts import Cardano.Ledger.Babbage.Core @@ -63,28 +63,30 @@ migrateBootstrapUTxO :: migrateBootstrapUTxO syncEnv = do case envLedgerEnv syncEnv of HasLedger lenv -> do - liftIO $ logInfo trce "Starting UTxO bootstrap migration" + liftIO $ logInfoCtx trce logCtx {lcMessage = "Starting UTxO bootstrap migration"} cls <- liftIO $ readCurrentStateUnsafe lenv count <- lift $ DB.deleteTxOut (getTxOutTableType syncEnv) when (count > 0) $ liftIO $ - logWarning trce $ - "Found and deleted " <> textShow count <> " tx_out." + logWarningCtx trce $ + logCtx {lcMessage = "Found and deleted " <> textShow count <> " tx_out."} storeUTxOFromLedger syncEnv cls lift $ DB.insertExtraMigration DB.BootstrapFinished - liftIO $ logInfo trce "UTxO bootstrap migration done" + liftIO $ logInfoCtx trce $ logCtx {lcMessage = "UTxO bootstrap migration done"} liftIO $ atomically $ writeTVar (envBootstrap syncEnv) False NoLedger _ -> - liftIO $ logWarning trce "Tried to bootstrap, but ledger state is not enabled. Please stop db-sync and restart without --disable-ledger-state" + liftIO $ logWarningCtx trce $ logCtx {lcMessage = "Tried to bootstrap, but ledger state is not enabled. Please stop db-sync and restart without --disable-ledger-state"} where + logCtx = initLogCtx "migrateBootstrapUTxO" "Cardano.DbSync.Api.Ledger" trce = getTrace syncEnv storeUTxOFromLedger :: (MonadBaseControl IO m, MonadIO m) => SyncEnv -> ExtLedgerState CardanoBlock -> ExceptT SyncNodeError (ReaderT SqlBackend m) () storeUTxOFromLedger env st = case ledgerState st of LedgerStateBabbage bts -> storeUTxO env (getUTxO bts) LedgerStateConway stc -> storeUTxO env (getUTxO stc) - _otherwise -> liftIO $ logError trce "storeUTxOFromLedger is only supported after Babbage" + _otherwise -> liftIO $ logErrorCtx trce logCtx {lcMessage = "storeUTxOFromLedger is only supported after Babbage"} where + logCtx = initLogCtx "storeUTxOFromLedger" "Cardano.DbSync.Api.Ledger" trce = getTrace env getUTxO st' = unUTxO $ Consensus.shelleyLedgerState st' ^. (nesEsL . esLStateL . lsUTxOStateL . utxosUtxoL) @@ -108,15 +110,19 @@ storeUTxO :: ExceptT SyncNodeError (ReaderT SqlBackend m) () storeUTxO env mp = do liftIO $ - logInfo trce $ - mconcat - [ "Inserting " - , textShow size - , " tx_out as pages of " - , textShow pageSize - ] + logInfoCtx trce $ + logCtx + { lcMessage = + mconcat + [ "Inserting " + , textShow size + , " tx_out as pages of " + , textShow pageSize + ] + } mapM_ (storePage env pagePerc) . zip [0 ..] . chunksOf pageSize . Map.toList $ mp where + logCtx = initLogCtx "storeUTxO" "Cardano.DbSync.Api.Ledger" trce = getTrace env npages = size `div` pageSize pagePerc :: Float = if npages == 0 then 100.0 else 100.0 / fromIntegral npages @@ -138,13 +144,14 @@ storePage :: (Int, [(TxIn StandardCrypto, BabbageTxOut era)]) -> ExceptT SyncNodeError (ReaderT SqlBackend m) () storePage syncEnv percQuantum (n, ls) = do - when (n `mod` 10 == 0) $ liftIO $ logInfo trce $ "Bootstrap in progress " <> prc <> "%" + when (n `mod` 10 == 0) $ liftIO $ logInfoCtx trce $ logCtx {lcMessage = "Bootstrap in progress " <> prc <> "%"} txOuts <- mapM (prepareTxOut syncEnv) ls txOutIds <- lift . DB.insertManyTxOut False $ etoTxOut . fst <$> txOuts let maTxOuts = concatMap (mkmaTxOuts txOutTableType) $ zip txOutIds (snd <$> txOuts) void . lift $ DB.insertManyMaTxOut maTxOuts where + logCtx = initLogCtx "storePage" "Cardano.DbSync.Api.Ledger" txOutTableType = getTxOutTableType syncEnv trce = getTrace syncEnv prc = Text.pack $ showGFloat (Just 1) (max 0 $ min 100.0 (fromIntegral n * percQuantum)) "" diff --git a/cardano-db-sync/src/Cardano/DbSync/Cache.hs b/cardano-db-sync/src/Cardano/DbSync/Cache.hs index 67818311e..73e14b3fd 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Cache.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Cache.hs @@ -39,6 +39,7 @@ import Cardano.DbSync.Era.Shelley.Query import Cardano.DbSync.Era.Util import Cardano.DbSync.Error import Cardano.DbSync.Types +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logInfoCtx, logWarningCtx) import qualified Cardano.Ledger.Address as Ledger import Cardano.Ledger.BaseTypes (Network) import Cardano.Ledger.Mary.Value @@ -280,35 +281,42 @@ queryPoolKeyOrInsert :: PoolKeyHash -> ReaderT SqlBackend m DB.PoolHashId queryPoolKeyOrInsert txt trce cache cacheUA logsWarning hsh = do + let logCtx = initLogCtx "queryPoolKeyOrInsert" "Cardano.DbSync.Cache" pk <- queryPoolKeyWithCache cache cacheUA hsh case pk of Right poolHashId -> pure poolHashId Left err -> do when logsWarning $ liftIO $ - logWarning trce $ - mconcat - [ "Failed with " - , textShow err - , " while trying to find pool " - , textShow hsh - , " for " - , txt - , ". We will assume that the pool exists and move on." - ] + logWarningCtx trce $ + logCtx + { lcMessage = + mconcat + [ "Failed with " + , textShow err + , " while trying to find pool " + , textShow hsh + , " for " + , txt + , ". We will assume that the pool exists and move on." + ] + } insertPoolKeyWithCache cache cacheUA hsh queryMAWithCache :: MonadIO m => + Trace IO Text -> CacheStatus -> PolicyID StandardCrypto -> AssetName -> ReaderT SqlBackend m (Either (ByteString, ByteString) DB.MultiAssetId) -queryMAWithCache cache policyId asset = +queryMAWithCache trce cache policyId asset = do + let logCtx = initLogCtx "queryMAWithCache" "Cardano.DbSync.Cache" case cache of NoCache -> do let !policyBs = Generic.unScriptHash $ policyID policyId - let !assetNameBs = Generic.unAssetName asset + !assetNameBs = Generic.unAssetName asset + liftIO $ logInfoCtx trce $ logCtx {lcMessage = mconcat ["Querying MultiAssetId for ", textShow policyId, " ", textShow asset]} maybe (Left (policyBs, assetNameBs)) Right <$> DB.queryMultiAssetId policyBs assetNameBs ActiveCache ci -> do mp <- liftIO $ readTVarIO (cMultiAssets ci) diff --git a/cardano-db-sync/src/Cardano/DbSync/Database.hs b/cardano-db-sync/src/Cardano/DbSync/Database.hs index 4583b8204..807f4efe8 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Database.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Database.hs @@ -11,7 +11,6 @@ module Cardano.DbSync.Database ( runDbThread, ) where -import Cardano.BM.Trace (logDebug, logError, logInfo) import Cardano.DbSync.Api import Cardano.DbSync.Api.Types (ConsistentLevel (..), LedgerEnv (..), SyncEnv (..)) import Cardano.DbSync.DbAction @@ -23,6 +22,7 @@ import Cardano.DbSync.Metrics import Cardano.DbSync.Rollback import Cardano.DbSync.Types import Cardano.DbSync.Util +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logDebugCtx, logErrorCtx, logExceptionCtx, logInfoCtx) import Cardano.Prelude hiding (atomically) import Cardano.Slotting.Slot (WithOrigin (..)) import Control.Concurrent.Class.MonadSTM.Strict @@ -44,16 +44,18 @@ runDbThread :: ThreadChannels -> IO () runDbThread syncEnv metricsSetters queue = do - logInfo trce "Running DB thread" - logException trce "runDBThread: " loop - logInfo trce "Shutting down DB thread" + let logCtx = initLogCtx "runDbThread" "DbSync.Database" + logInfoCtx trce $ logCtx {lcMessage = "Running DB thread"} + logExceptionCtx trce logCtx loop + logInfoCtx trce $ logCtx {lcMessage = "Shutting down DB thread"} where trce = getTrace syncEnv loop = do + let logCtx = initLogCtx "runDbThread Loop" "DbSync.Database" xs <- blockingFlushDbActionQueue queue when (length xs > 1) $ do - logDebug trce $ "runDbThread: " <> textShow (length xs) <> " blocks" + logDebugCtx trce $ logCtx {lcMessage = "runDbThread: " <> textShow (length xs) <> " blocks"} case hasRestart xs of Nothing -> do @@ -65,16 +67,16 @@ runDbThread syncEnv metricsSetters queue = do setDbSlotHeight metricsSetters $ bSlotNo block case eNextState of - Left err -> logError trce $ show err + Left err -> logErrorCtx trce $ logCtx {lcMessage = show err} Right Continue -> loop Right Done -> pure () Just resultVar -> do -- In this case the syncing thread has restarted, so ignore all blocks that are not -- inserted yet. - logInfo trce "Chain Sync client thread has restarted" + logInfoCtx trce $ logCtx {lcMessage = "Chain Sync client thread has restarted"} latestPoints <- getLatestPoints syncEnv currentTip <- getCurrentTipBlockNo syncEnv - logDbState syncEnv + logDbState syncEnv logCtx atomically $ putTMVar resultVar (latestPoints, currentTip) loop diff --git a/cardano-db-sync/src/Cardano/DbSync/Default.hs b/cardano-db-sync/src/Cardano/DbSync/Default.hs index 010ee9fcc..75b8db383 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Default.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Default.hs @@ -11,7 +11,6 @@ module Cardano.DbSync.Default ( insertListBlocks, ) where -import Cardano.BM.Trace (logInfo) import qualified Cardano.Db as DB import Cardano.DbSync.Api import Cardano.DbSync.Api.Ledger @@ -32,6 +31,7 @@ import Cardano.DbSync.Rollback import Cardano.DbSync.Types import Cardano.DbSync.Util import Cardano.DbSync.Util.Constraint (addConstraintsIfNotExist) +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logInfoCtx) import qualified Cardano.Ledger.Alonzo.Scripts as Ledger import Cardano.Ledger.Shelley.AdaPots as Shelley import Cardano.Node.Configuration.Logging (Trace) @@ -76,12 +76,15 @@ applyAndInsertBlockMaybe syncEnv tracer cblk = do case eiBlockInDbAlreadyId of Left _ -> do liftIO - . logInfo tracer - $ mconcat - [ "Received block which is not in the db with " - , textShow (getHeaderFields cblk) - , ". Time to restore consistency." - ] + . logInfoCtx tracer + $ logCtx + { lcMessage = + mconcat + [ "Received block which is not in the db with " + , textShow (getHeaderFields cblk) + , ". Time to restore consistency." + ] + } rollbackFromBlockNo syncEnv (blockNo cblk) void $ migrateStakeDistr syncEnv (apOldLedger applyRes) insertBlock syncEnv cblk applyRes True tookSnapshot @@ -89,13 +92,14 @@ applyAndInsertBlockMaybe syncEnv tracer cblk = do Right blockId | Just (adaPots, slotNo, epochNo) <- getAdaPots applyRes -> do replaced <- lift $ DB.replaceAdaPots blockId $ mkAdaPots blockId slotNo epochNo adaPots if replaced - then liftIO $ logInfo tracer $ "Fixed AdaPots for " <> textShow epochNo - else liftIO $ logInfo tracer $ "Reached " <> textShow epochNo + then liftIO $ logInfoCtx tracer $ logCtx {lcMessage = "Fixed AdaPots for " <> textShow epochNo} + else liftIO $ logInfoCtx tracer $ logCtx {lcMessage = "Reached " <> textShow epochNo} Right _ | Just epochNo <- getNewEpoch applyRes -> - liftIO $ logInfo tracer $ "Reached " <> textShow epochNo + liftIO $ logInfoCtx tracer $ logCtx {lcMessage = "Reached " <> textShow epochNo} _ -> pure () where + logCtx = initLogCtx "applyAndInsertBlockMaybe" "Cardano.DbSync.Default" mkApplyResult :: Bool -> IO (ApplyResult, Bool) mkApplyResult isCons = do case envLedgerEnv syncEnv of diff --git a/cardano-db-sync/src/Cardano/DbSync/Epoch.hs b/cardano-db-sync/src/Cardano/DbSync/Epoch.hs index 113c032e4..9e512d318 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Epoch.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Epoch.hs @@ -7,7 +7,7 @@ module Cardano.DbSync.Epoch ( epochHandler, ) where -import Cardano.BM.Trace (Trace, logError, logInfo) +import Cardano.BM.Trace (Trace, logError) import qualified Cardano.Chain.Block as Byron import qualified Cardano.Db as DB import Cardano.DbSync.Api (getTrace) @@ -21,6 +21,7 @@ import Cardano.DbSync.Types ( SyncState (SyncFollowing), ) import Cardano.DbSync.Util +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logInfoCtx) import Cardano.Prelude hiding (from, on, replace) import Cardano.Slotting.Slot (unEpochNo) import Control.Monad.Logger (LoggingT) @@ -176,6 +177,7 @@ updateEpochWhenSyncing :: ReaderT SqlBackend m (Either SyncNodeError ()) updateEpochWhenSyncing syncEnv cache mEpochBlockDiff mLastMapEpochFromCache epochNo isBoundaryBlock = do let trce = getTrace syncEnv + logCtx = initLogCtx "updateEpochWhenSyncing" "Cardano.DbSync.Era.Universal.Epoch" isFirstEpoch = epochNo == 0 -- count boundary block in the first epoch additionalBlockCount = if isBoundaryBlock && isFirstEpoch then 1 else 0 @@ -202,11 +204,19 @@ updateEpochWhenSyncing syncEnv cache mEpochBlockDiff mLastMapEpochFromCache epoc mEpochID <- DB.queryForEpochId epochNo case mEpochID of Nothing -> do - liftIO . logInfo trce $ epochSucessMsg "Inserted" "updateEpochWhenSyncing" "Cache" lastMapEpochFromCache + liftIO . logInfoCtx trce $ + logCtx + { lcMessage = epochSucessMsg "Inserted" "updateEpochWhenSyncing" "Cache" lastMapEpochFromCache + , lcEpochNo = Just $ DB.epochNo lastMapEpochFromCache + } _ <- DB.insertEpoch lastMapEpochFromCache pure $ Right () Just epochId -> do - liftIO . logInfo trce $ epochSucessMsg "Replaced" "updateEpochWhenSyncing" "Cache" calculatedEpoch + liftIO . logInfoCtx trce $ + logCtx + { lcMessage = epochSucessMsg "Replaced" "updateEpochWhenSyncing" "Cache" calculatedEpoch + , lcEpochNo = Just $ DB.epochNo calculatedEpoch + } Right <$> replace epochId calculatedEpoch -- When syncing, on every block we update the Map epoch in cache. Making sure to handle restarts @@ -246,6 +256,7 @@ makeEpochWithDBQuery :: ReaderT SqlBackend m (Either SyncNodeError ()) makeEpochWithDBQuery syncEnv cache mInitEpoch epochNo callSiteMsg = do let trce = getTrace syncEnv + logCtx = initLogCtx "makeEpochWithDBQuery" "Cardano.DbSync.Era.Universal.Epoch" calcEpoch <- DB.queryCalcEpochEntry epochNo mEpochID <- DB.queryForEpochId epochNo let epochInitOrCalc = fromMaybe calcEpoch mInitEpoch @@ -253,12 +264,14 @@ makeEpochWithDBQuery syncEnv cache mInitEpoch epochNo callSiteMsg = do Nothing -> do _ <- writeToMapEpochCache syncEnv cache epochInitOrCalc _ <- DB.insertEpoch calcEpoch - liftIO . logInfo trce $ epochSucessMsg "Inserted " callSiteMsg "DB query" calcEpoch + liftIO . logInfoCtx trce $ + logCtx {lcMessage = epochSucessMsg "Inserted " callSiteMsg "DB query" calcEpoch} pure $ Right () Just epochId -> do -- write the newly calculated epoch to cache. _ <- writeToMapEpochCache syncEnv cache epochInitOrCalc - liftIO . logInfo trce $ epochSucessMsg "Replaced " callSiteMsg "DB query" calcEpoch + liftIO . logInfoCtx trce $ + logCtx {lcMessage = epochSucessMsg "Replaced " callSiteMsg "DB query" calcEpoch} Right <$> replace epochId calcEpoch -- Because we store a Map of epochs, at every iteration we take the newest epoch and it's values diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Byron/Genesis.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Byron/Genesis.hs index 8fcf8993c..2b621b456 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Byron/Genesis.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Byron/Genesis.hs @@ -10,7 +10,7 @@ module Cardano.DbSync.Era.Byron.Genesis ( insertValidateGenesisDist, ) where -import Cardano.BM.Trace (Trace, logInfo) +import Cardano.BM.Trace (Trace) import Cardano.Binary (serialize') import qualified Cardano.Chain.Common as Byron import qualified Cardano.Chain.Genesis as Byron @@ -26,6 +26,7 @@ import qualified Cardano.DbSync.Era.Byron.Util as Byron import Cardano.DbSync.Era.Util (liftLookupFail) import Cardano.DbSync.Error import Cardano.DbSync.Util +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logErrorCtx, logInfoCtx) import Cardano.Prelude import Control.Monad.Trans.Control (MonadBaseControl) import Control.Monad.Trans.Except.Extra (newExceptT) @@ -50,6 +51,8 @@ insertValidateGenesisDist syncEnv (NetworkName networkName) cfg = do then newExceptT $ DB.runDbIohkLogging (envBackend syncEnv) tracer insertAction else newExceptT $ DB.runDbIohkNoLogging (envBackend syncEnv) insertAction where + logCtx = initLogCtx "insertValidateGenesisDist" "Cardano.DbSync.Era.Byron.Genesis" + tracer = getTrace syncEnv insertAction :: (MonadBaseControl IO m, MonadIO m) => ReaderT SqlBackend m (Either SyncNodeError ()) @@ -62,9 +65,10 @@ insertValidateGenesisDist syncEnv (NetworkName networkName) cfg = do Right bid -> validateGenesisDistribution syncEnv prunes disInOut tracer networkName cfg bid Left _ -> runExceptT $ do - liftIO $ logInfo tracer "Inserting Byron Genesis distribution" + liftIO $ logInfoCtx tracer $ logCtx {lcMessage = "Inserting Byron Genesis distribution"} count <- lift DB.queryBlockCount - when (not disInOut && count > 0) $ + when (not disInOut && count > 0) $ do + liftIO $ logErrorCtx tracer $ logCtx {lcMessage = "Genesis data mismatch"} dbSyncNodeError "insertValidateGenesisDist: Genesis data mismatch." void . lift $ DB.insertMeta $ @@ -108,12 +112,16 @@ insertValidateGenesisDist syncEnv (NetworkName networkName) cfg = do , DB.blockOpCertCounter = Nothing } mapM_ (insertTxOutsByron syncEnv disInOut bid) $ genesisTxos cfg - liftIO . logInfo tracer $ - "Initial genesis distribution populated. Hash " - <> renderByteArray (configGenesisHash cfg) - + liftIO . logInfoCtx tracer $ + logCtx + { lcMessage = + "Initial genesis distribution populated. Hash " + <> renderByteArray (configGenesisHash cfg) + } supply <- lift $ DB.queryTotalSupply $ getTxOutTableType syncEnv - liftIO $ logInfo tracer ("Total genesis supply of Ada: " <> DB.renderAda supply) + liftIO $ + logInfoCtx tracer $ + logCtx {lcMessage = "Total genesis supply of Ada: " <> DB.renderAda supply} -- | Validate that the initial Genesis distribution in the DB matches the Genesis data. validateGenesisDistribution :: @@ -128,6 +136,7 @@ validateGenesisDistribution :: ReaderT SqlBackend m (Either SyncNodeError ()) validateGenesisDistribution syncEnv prunes disInOut tracer networkName cfg bid = runExceptT $ do + let logCtx = initLogCtx "validateGenesisDistribution" "Cardano.DbSync.Era.Byron.Genesis" meta <- liftLookupFail "validateGenesisDistribution" DB.queryMeta when (DB.metaStartTime meta /= Byron.configStartTime cfg) $ @@ -172,8 +181,8 @@ validateGenesisDistribution syncEnv prunes disInOut tracer networkName cfg bid = , DB.renderAda totalSupply ] liftIO $ do - logInfo tracer "Initial genesis distribution present and correct" - logInfo tracer ("Total genesis supply of Ada: " <> DB.renderAda totalSupply) + logInfoCtx tracer $ logCtx {lcMessage = "Initial genesis distribution present and correct"} + logInfoCtx tracer $ logCtx {lcMessage = "Total genesis supply of Ada: " <> DB.renderAda totalSupply} ------------------------------------------------------------------------------- diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Byron/Insert.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Byron/Insert.hs index 90e03c85f..ec7466fce 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Byron/Insert.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Byron/Insert.hs @@ -11,7 +11,7 @@ module Cardano.DbSync.Era.Byron.Insert ( resolveTxInputs, ) where -import Cardano.BM.Trace (Trace, logDebug, logInfo) +import Cardano.BM.Trace (Trace) import Cardano.Binary (serialize') import qualified Cardano.Chain.Block as Byron hiding (blockHash) import qualified Cardano.Chain.Common as Byron @@ -35,6 +35,7 @@ import Cardano.DbSync.Era.Util (liftLookupFail) import Cardano.DbSync.Error import Cardano.DbSync.Types import Cardano.DbSync.Util +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logDebugCtx, logInfoCtx) import Cardano.Prelude import Cardano.Slotting.Slot (EpochNo (..), EpochSize (..)) import Control.Monad.Trans.Control (MonadBaseControl) @@ -78,6 +79,7 @@ insertABOBBoundary :: ExceptT SyncNodeError (ReaderT SqlBackend m) () insertABOBBoundary syncEnv blk details = do let tracer = getTrace syncEnv + logCtx = initLogCtx "insertABOBBoundary" "Cardano.DbSync.Era.Byron.Insert" cache = envCache syncEnv -- Will not get called in the OBFT part of the Byron era. pbid <- queryPrevBlockWithCache "insertABOBBoundary" cache (Byron.ebbPrevHash blk) @@ -128,13 +130,17 @@ insertABOBBoundary syncEnv blk details = do , ebdTime = sdSlotTime details } - liftIO . logInfo tracer $ - Text.concat - [ "insertABOBBoundary: epoch " - , textShow (Byron.boundaryEpoch $ Byron.boundaryHeader blk) - , ", hash " - , Byron.renderAbstractHash (Byron.boundaryHashAnnotated blk) - ] + liftIO . logInfoCtx tracer $ + logCtx + { lcEpochNo = Just epochNo + , lcMessage = + Text.concat + [ "insertABOBBoundary: epoch " + , textShow (Byron.boundaryEpoch $ Byron.boundaryHeader blk) + , ", hash " + , Byron.renderAbstractHash (Byron.boundaryHashAnnotated blk) + ] + } insertABlock :: (MonadBaseControl IO m, MonadIO m) => @@ -144,6 +150,7 @@ insertABlock :: SlotDetails -> ExceptT SyncNodeError (ReaderT SqlBackend m) () insertABlock syncEnv firstBlockOfEpoch blk details = do + let logCtx = initLogCtx "insertABlock" "Cardano.DbSync.Era.Byron.Insert" pbid <- queryPrevBlockWithCache "insertABlock" cache (Byron.blockPreviousHash blk) slid <- lift . DB.insertSlotLeader $ Byron.mkSlotLeader blk let txs = Byron.blockPayload blk @@ -189,32 +196,44 @@ insertABlock syncEnv firstBlockOfEpoch blk details = do } liftIO $ do - let epoch = unEpochNo (sdEpochNo details) + let epochNumber = unEpochNo (sdEpochNo details) slotWithinEpoch = unEpochSlot (sdEpochSlot details) followingClosely = getSyncStatus details == SyncFollowing when (followingClosely && slotWithinEpoch /= 0 && Byron.blockNumber blk `mod` 20 == 0) $ do - logInfo tracer $ - mconcat - [ "Insert Byron Block: continuing epoch " - , textShow epoch - , " (slot " - , textShow slotWithinEpoch - , "/" - , textShow (unEpochSize $ sdEpochSize details) - , ")" - ] + logInfoCtx tracer $ + logCtx + { lcEpochNo = Just epochNumber + , lcBlockNo = Just $ Byron.blockNumber blk + , lcSlotNo = Just slotWithinEpoch + , lcMessage = + mconcat + [ "Insert Byron Block: continuing epoch " + , textShow epochNumber + , " (slot " + , textShow slotWithinEpoch + , "/" + , textShow (unEpochSize $ sdEpochSize details) + , ")" + ] + } logger followingClosely tracer $ - mconcat - [ "Insert Byron Block: epoch " - , textShow (unEpochNo $ sdEpochNo details) - , ", slot " - , textShow (Byron.slotNumber blk) - , ", block " - , textShow (Byron.blockNumber blk) - , ", hash " - , renderByteArray (Byron.blockHash blk) - ] + logCtx + { lcEpochNo = Just epochNumber + , lcBlockNo = Just $ Byron.blockNumber blk + , lcSlotNo = Just slotWithinEpoch + , lcMessage = + mconcat + [ "Insert Byron Block: epoch " + , textShow (unEpochNo $ sdEpochNo details) + , ", slot " + , textShow (Byron.slotNumber blk) + , ", block " + , textShow (Byron.blockNumber blk) + , ", hash " + , renderByteArray (Byron.blockHash blk) + ] + } where tracer :: Trace IO Text tracer = getTrace syncEnv @@ -222,12 +241,12 @@ insertABlock syncEnv firstBlockOfEpoch blk details = do cache :: CacheStatus cache = envCache syncEnv - logger :: Bool -> Trace IO a -> a -> IO () + logger :: Bool -> Trace IO Text -> LogContext -> IO () logger followingClosely - | firstBlockOfEpoch = logInfo - | followingClosely = logInfo - | Byron.blockNumber blk `mod` 1000 == 0 = logInfo - | otherwise = logDebug + | firstBlockOfEpoch = logInfoCtx + | followingClosely = logInfoCtx + | Byron.blockNumber blk `mod` 1000 == 0 = logInfoCtx + | otherwise = logDebugCtx insertByronTx :: (MonadBaseControl IO m, MonadIO m) => diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Shelley/Genesis.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Shelley/Genesis.hs index 0dcde23af..6c9c11539 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Shelley/Genesis.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Shelley/Genesis.hs @@ -11,7 +11,7 @@ module Cardano.DbSync.Era.Shelley.Genesis ( insertValidateGenesisDist, ) where -import Cardano.BM.Trace (Trace, logError, logInfo) +import Cardano.BM.Trace (Trace, logError) import qualified Cardano.Db as DB import qualified Cardano.Db.Schema.Core.TxOut as C import qualified Cardano.Db.Schema.Variant.TxOut as V @@ -26,6 +26,7 @@ import Cardano.DbSync.Era.Universal.Insert.Pool (insertPoolRegister) import Cardano.DbSync.Era.Util (liftLookupFail) import Cardano.DbSync.Error import Cardano.DbSync.Util +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logInfoCtx) import Cardano.Ledger.Address (serialiseAddr) import qualified Cardano.Ledger.Coin as Ledger import qualified Cardano.Ledger.Core as Core @@ -88,12 +89,13 @@ insertValidateGenesisDist syncEnv networkName cfg shelleyInitiation = do insertAction :: (MonadBaseControl IO m, MonadIO m) => Bool -> ReaderT SqlBackend m (Either SyncNodeError ()) insertAction prunes = do + let logCtx = initLogCtx "insertValidateGenesisDist" "Shelley" ebid <- DB.queryBlockId (configGenesisHash cfg) case ebid of Right bid -> validateGenesisDistribution syncEnv prunes networkName cfg bid expectedTxCount Left _ -> runExceptT $ do - liftIO $ logInfo tracer "Inserting Shelley Genesis distribution" + liftIO $ logInfoCtx tracer logCtx {lcMessage = "Inserting Shelley Genesis distribution"} emeta <- lift DB.queryMeta case emeta of Right _ -> pure () -- Metadata from Shelley era already exists. TODO Validate metadata. @@ -129,7 +131,7 @@ insertValidateGenesisDist syncEnv networkName cfg shelleyInitiation = do -- This means the previous block will have two blocks after it, resulting in a -- tree format, which is unavoidable. pid <- lift DB.queryLatestBlockId - liftIO $ logInfo tracer $ textShow pid + liftIO $ logInfoCtx tracer $ logCtx {lcMessage = textShow pid} bid <- lift . DB.insertBlock $ DB.Block @@ -154,9 +156,8 @@ insertValidateGenesisDist syncEnv networkName cfg shelleyInitiation = do disInOut <- liftIO $ getDisableInOutState syncEnv unless disInOut $ do lift $ mapM_ (insertTxOuts syncEnv tracer bid) $ genesisUtxOs cfg - liftIO . logInfo tracer $ - "Initial genesis distribution populated. Hash " - <> renderByteArray (configGenesisHash cfg) + liftIO . logInfoCtx tracer $ + logCtx {lcMessage = "Initial genesis distribution populated. Hash " <> renderByteArray (configGenesisHash cfg)} when hasStakes $ insertStaking tracer useNoCache bid cfg @@ -170,11 +171,12 @@ validateGenesisDistribution :: DB.BlockId -> Word64 -> ReaderT SqlBackend m (Either SyncNodeError ()) -validateGenesisDistribution syncEnv prunes networkName cfg bid expectedTxCount = +validateGenesisDistribution syncEnv prunes networkName cfg bid expectedTxCount = do + let logCtx = initLogCtx "validateGenesisDistribution" "Shelley" runExceptT $ do let tracer = getTrace syncEnv txOutTableType = getTxOutTableType syncEnv - liftIO $ logInfo tracer "Validating Genesis distribution" + liftIO $ logInfoCtx tracer logCtx {lcMessage = "Validating Genesis distribution"} meta <- liftLookupFail "Shelley.validateGenesisDistribution" DB.queryMeta when (DB.metaStartTime meta /= configStartTime cfg) $ @@ -215,10 +217,8 @@ validateGenesisDistribution syncEnv prunes networkName cfg bid expectedTxCount = , textShow totalSupply ] liftIO $ do - logInfo tracer "Initial genesis distribution present and correct" - logInfo tracer ("Total genesis supply of Ada: " <> DB.renderAda totalSupply) - --- ----------------------------------------------------------------------------- + logInfoCtx tracer $ logCtx {lcMessage = "Initial genesis distribution present and correct"} + logInfoCtx tracer $ logCtx {lcMessage = "Total genesis supply of Ada: " <> DB.renderAda totalSupply} insertTxOuts :: (MonadBaseControl IO m, MonadIO m) => diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Adjust.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Adjust.hs index 942e6fc82..703933baa 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Adjust.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Adjust.hs @@ -7,7 +7,7 @@ module Cardano.DbSync.Era.Universal.Adjust ( adjustEpochRewards, ) where -import Cardano.BM.Trace (Trace, logInfo) +import Cardano.BM.Trace (Trace) import qualified Cardano.Db as Db import Cardano.DbSync.Cache ( queryPoolKeyWithCache, @@ -16,6 +16,7 @@ import Cardano.DbSync.Cache ( import Cardano.DbSync.Cache.Types (CacheAction (..), CacheStatus) import qualified Cardano.DbSync.Era.Shelley.Generic.Rewards as Generic import Cardano.DbSync.Types (StakeCred) +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logInfoCtx) import Cardano.Ledger.BaseTypes (Network) import Cardano.Prelude hiding (from, groupBy, on) import Cardano.Slotting.Slot (EpochNo (..)) @@ -57,13 +58,18 @@ adjustEpochRewards :: ReaderT SqlBackend m () adjustEpochRewards trce nw cache epochNo rwds creds = do let eraIgnored = Map.toList $ Generic.unRewards rwds - liftIO . logInfo trce $ - mconcat - [ "Removing " - , if null eraIgnored then "" else textShow (length eraIgnored) <> " rewards and " - , show (length creds) - , " orphaned rewards" - ] + logCtx = initLogCtx "adjustEpochRewards" "Cardano.DbSync.Era.Universal.Adjust" + liftIO . logInfoCtx trce $ + logCtx + { lcEpochNo = Just (unEpochNo epochNo) + , lcMessage = + mconcat + [ "Removing " + , if null eraIgnored then "" else textShow (length eraIgnored) <> " rewards and " + , show (length creds) + , " orphaned rewards" + ] + } forM_ eraIgnored $ \(cred, rewards) -> forM_ (Set.toList rewards) $ \rwd -> deleteReward trce nw cache epochNo (cred, rwd) diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Block.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Block.hs index 2eed5603c..af189605b 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Block.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Block.hs @@ -11,7 +11,7 @@ module Cardano.DbSync.Era.Universal.Block ( insertBlockUniversal, ) where -import Cardano.BM.Trace (Trace, logDebug, logInfo) +import Cardano.BM.Trace (Trace) import qualified Cardano.Db as DB import Cardano.DbSync.Api import Cardano.DbSync.Api.Types (InsertOptions (..), SyncEnv (..), SyncOptions (..)) @@ -40,6 +40,7 @@ import qualified Cardano.Ledger.BaseTypes as Ledger import Cardano.Ledger.Keys import Cardano.Prelude +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logDebugCtx, logInfoCtx) import Control.Monad.Trans.Control (MonadBaseControl) import Control.Monad.Trans.Except.Extra (newExceptT) import Data.Either.Extra (eitherToMaybe) @@ -52,7 +53,7 @@ import Database.Persist.Sql (SqlBackend) insertBlockUniversal :: (MonadBaseControl IO m, MonadIO m) => SyncEnv -> - -- | Should log + -- | Is start event or rollback Bool -> -- | Within two minutes Bool -> @@ -63,7 +64,8 @@ insertBlockUniversal :: IsPoolMember -> ApplyResult -> ReaderT SqlBackend m (Either SyncNodeError ()) -insertBlockUniversal syncEnv shouldLog withinTwoMins withinHalfHour blk details isMember applyResult = do +insertBlockUniversal syncEnv isStartEventOrRollback withinTwoMins withinHalfHour blk details isMember applyResult = do + let logCtx = initLogCtx "insertBlockUniversal" "Cardano.DbSync.Era.Universal.Block" runExceptT $ do pbid <- case Generic.blkPreviousHash blk of Nothing -> liftLookupFail (renderErrorMessage (Generic.blkEra blk)) DB.queryGenesis -- this is for networks that fork from Byron on epoch 0. @@ -118,33 +120,43 @@ insertBlockUniversal syncEnv shouldLog withinTwoMins withinHalfHour blk details insertReverseIndex blkId minIds liftIO $ do - let epoch = unEpochNo epochNo - slotWithinEpoch = unEpochSlot (sdEpochSlot details) - + let slotWithinEpoch = unEpochSlot (sdEpochSlot details) when (withinTwoMins && slotWithinEpoch /= 0 && unBlockNo (Generic.blkBlockNo blk) `mod` 20 == 0) $ do - logInfo tracer $ - mconcat - [ renderInsertName (Generic.blkEra blk) - , ": continuing epoch " - , textShow epoch - , " (slot " - , textShow slotWithinEpoch - , "/" - , textShow (unEpochSize $ sdEpochSize details) - , ")" - ] + logInfoCtx tracer $ + logCtx + { lcBlockNo = Just (unBlockNo (Generic.blkBlockNo blk)) + , lcSlotNo = Just (unSlotNo (Generic.blkSlotNo blk)) + , lcEpochNo = Just (unEpochNo epochNo) + , lcMessage = + mconcat + [ renderInsertName (Generic.blkEra blk) + , ": continuing epoch " + , textShow $ unEpochNo epochNo + , " (slot " + , textShow slotWithinEpoch + , "/" + , textShow (unEpochSize $ sdEpochSize details) + , ")" + ] + } logger tracer $ - mconcat - [ renderInsertName (Generic.blkEra blk) - , ": epoch " - , textShow (unEpochNo epochNo) - , ", slot " - , textShow (unSlotNo $ Generic.blkSlotNo blk) - , ", block " - , textShow (unBlockNo $ Generic.blkBlockNo blk) - , ", hash " - , renderByteArray (Generic.blkHash blk) - ] + logCtx + { lcBlockNo = Just (unBlockNo (Generic.blkBlockNo blk)) + , lcSlotNo = Just (unSlotNo (Generic.blkSlotNo blk)) + , lcEpochNo = Just (unEpochNo epochNo) + , lcMessage = + mconcat + [ renderInsertName (Generic.blkEra blk) + , ": epoch " + , textShow (unEpochNo epochNo) + , ", slot " + , textShow (unSlotNo $ Generic.blkSlotNo blk) + , ", block " + , textShow (unBlockNo $ Generic.blkBlockNo blk) + , ", hash " + , renderByteArray (Generic.blkHash blk) + ] + } whenStrictJust (apNewEpoch applyResult) $ \newEpoch -> do insertOnNewEpoch syncEnv blkId (Generic.blkSlotNo blk) epochNo newEpoch @@ -161,12 +173,12 @@ insertBlockUniversal syncEnv shouldLog withinTwoMins withinHalfHour blk details where iopts = getInsertOptions syncEnv - logger :: Trace IO a -> a -> IO () + logger :: Trace IO Text -> LogContext -> IO () logger - | shouldLog = logInfo - | withinTwoMins = logInfo - | unBlockNo (Generic.blkBlockNo blk) `mod` 5000 == 0 = logInfo - | otherwise = logDebug + | isStartEventOrRollback = logInfoCtx + | withinTwoMins = logInfoCtx + | unBlockNo (Generic.blkBlockNo blk) `mod` 5000 == 0 = logInfoCtx + | otherwise = logDebugCtx renderInsertName :: Generic.BlockEra -> Text renderInsertName eraText = diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Epoch.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Epoch.hs index cc1f86205..cdd611a5f 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Epoch.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Epoch.hs @@ -22,7 +22,7 @@ module Cardano.DbSync.Era.Universal.Epoch ( sumRewardTotal, ) where -import Cardano.BM.Trace (Trace, logInfo) +import Cardano.BM.Trace (Trace) import qualified Cardano.Db as DB import Cardano.DbSync.Api import Cardano.DbSync.Api.Types (InsertOptions (..), SyncEnv (..)) @@ -37,6 +37,7 @@ import Cardano.DbSync.Ledger.Event import Cardano.DbSync.Types import Cardano.DbSync.Util (whenDefault, whenStrictJust, whenStrictJustDefault) import Cardano.DbSync.Util.Constraint (constraintNameEpochStake, constraintNameReward) +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logInfoCtx) import Cardano.Ledger.Address (RewardAccount (..)) import Cardano.Ledger.BaseTypes (Network, unEpochInterval) import qualified Cardano.Ledger.BaseTypes as Ledger @@ -205,12 +206,14 @@ insertStakeSlice syncEnv (Generic.Slice slice finalSlice) = do lift $ DB.updateSetComplete $ unEpochNo $ Generic.sliceEpochNo slice size <- lift $ DB.queryEpochStakeCount (unEpochNo $ Generic.sliceEpochNo slice) liftIO - . logInfo tracer - $ mconcat ["Inserted ", show size, " EpochStake for ", show (Generic.sliceEpochNo slice)] + . logInfoCtx tracer + $ logCtx {lcMessage = mconcat ["Inserted ", show size, " EpochStake for ", show (Generic.sliceEpochNo slice)]} where tracer :: Trace IO Text tracer = getTrace syncEnv + logCtx = initLogCtx "insertStakeSlice" "Cardano.DbSync.Era.Universal.Epoch" + network :: Network network = getNetwork syncEnv @@ -379,8 +382,9 @@ insertPoolDepositRefunds :: ExceptT SyncNodeError (ReaderT SqlBackend m) () insertPoolDepositRefunds syncEnv epochNo refunds = do insertRewards syncEnv nw epochNo epochNo (envCache syncEnv) (Map.toList rwds) - liftIO . logInfo tracer $ "Inserted " <> show (Generic.rewardsCount refunds) <> " deposit refund rewards" + liftIO . logInfoCtx tracer $ logCtx {lcMessage = "Inserted " <> show (Generic.rewardsCount refunds) <> " deposit refund rewards"} where + logCtx = initLogCtx "insertPoolDepositRefunds" "Cardano.DbSync.Era.Universal.Epoch" tracer = getTrace syncEnv rwds = Generic.unRewards refunds nw = getNetwork syncEnv diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Certificate.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Certificate.hs index 46aac293a..b7cf7f8c9 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Certificate.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Certificate.hs @@ -22,7 +22,7 @@ module Cardano.DbSync.Era.Universal.Insert.Certificate ( mkAdaPots, ) where -import Cardano.BM.Trace (Trace, logWarning) +import Cardano.BM.Trace (Trace) import qualified Cardano.Db as DB import Cardano.DbSync.Api import Cardano.DbSync.Api.Types (InsertOptions (..), SyncEnv (..)) @@ -38,6 +38,7 @@ import Cardano.DbSync.Era.Universal.Insert.Pool (IsPoolMember, insertPoolCert) import Cardano.DbSync.Error import Cardano.DbSync.Types import Cardano.DbSync.Util +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logWarningCtx) import Cardano.Ledger.BaseTypes import qualified Cardano.Ledger.BaseTypes as Ledger import Cardano.Ledger.CertState @@ -80,7 +81,8 @@ insertCertificate syncEnv isMember mDeposits blkId txId epochNo slotNo redeemers Left (ShelleyTxCertGenesisDeleg _gen) -> when (ioShelley iopts) $ liftIO $ - logWarning tracer "insertCertificate: Unhandled DCertGenesis certificate" + logWarningCtx tracer $ + logCtx {lcMessage = "insertCertificate: Unhandled DCertGenesis certificate"} Right (ConwayTxCertDeleg deleg) -> insertConwayDelegCert syncEnv mDeposits txId idx mRedeemerId epochNo slotNo deleg Right (ConwayTxCertPool pool) -> @@ -98,6 +100,7 @@ insertCertificate syncEnv isMember mDeposits blkId txId epochNo slotNo redeemers ConwayUpdateDRep cred anchor -> lift $ insertDrepRegistration blkId txId idx cred Nothing (strictMaybeToMaybe anchor) where + logCtx = initLogCtx "insertCertificate" "Cardano.DbSync.Era.Universal.Insert.Certificate" tracer = getTrace syncEnv cache = envCache syncEnv iopts = getInsertOptions syncEnv diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/GovAction.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/GovAction.hs index 6de4a5362..8823b9a99 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/GovAction.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/GovAction.hs @@ -28,7 +28,7 @@ module Cardano.DbSync.Era.Universal.Insert.GovAction ( ) where -import Cardano.BM.Trace (Trace, logWarning) +import Cardano.BM.Trace (Trace) import qualified Cardano.Crypto as Crypto import Cardano.Db (DbWord64 (..)) import qualified Cardano.Db as DB @@ -42,6 +42,7 @@ import Cardano.DbSync.Error import Cardano.DbSync.Ledger.State import Cardano.DbSync.Util import Cardano.DbSync.Util.Bech32 (serialiseDrepToBech32) +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logWarningCtx) import Cardano.Ledger.BaseTypes import qualified Cardano.Ledger.BaseTypes as Ledger import Cardano.Ledger.CertState (DRep (..)) @@ -114,6 +115,7 @@ insertGovActionProposal trce cache blkId txId govExpiresAt mcgs (index, (govId, NewConstitution _ constitution -> lift $ void $ insertConstitution blkId (Just govActionProposalId) constitution _ -> pure () where + logCtx = initLogCtx "insertGovActionProposal" "Cardano.DbSync.Era.Universal.Insert.GovAction" mprevGovAction :: Maybe (GovActionId StandardCrypto) = case pProcGovAction pp of ParameterChange prv _ _ -> unGovPurposeId <$> strictMaybeToMaybe prv HardForkInitiation prv _ -> unGovPurposeId <$> strictMaybeToMaybe prv @@ -140,7 +142,9 @@ insertGovActionProposal trce cache blkId txId govExpiresAt mcgs (index, (govId, case findProposedCommittee govId cgs of Right (Just committee) -> void $ insertCommittee (Just govActionProposalId) committee other -> - liftIO $ logWarning trce $ textShow other <> ": Failed to find committee for " <> textShow pp + liftIO $ + logWarningCtx trce $ + logCtx {lcMessage = textShow other <> ": Failed to find committee for " <> textShow pp} insertCommittee :: (MonadIO m, MonadBaseControl IO m) => Maybe DB.GovActionProposalId -> Committee StandardConway -> ReaderT SqlBackend m DB.CommitteeId insertCommittee mgapId committee = do @@ -441,6 +445,7 @@ insertUpdateEnacted trce cache blkId epochNo enactedState = do , DB.epochStateEpochNo = unEpochNo epochNo } where + logCtx = initLogCtx "insertUpdateEnacted" "Cardano.DbSync.Era.Universal.Insert.GovAction" govIds = govStatePrevGovActionIds enactedState handleCommittee = do @@ -470,13 +475,16 @@ insertUpdateEnacted trce cache blkId epochNo enactedState = do -- This should never happen. Having a committee and an enacted action, means -- the committee came from a proposal which should be returned from the query. liftIO $ - logWarning trce $ - mconcat - [ "The impossible happened! Couldn't find the committee " - , textShow committee - , " which was enacted by a proposal " - , textShow committeeGaId - ] + logWarningCtx trce $ + logCtx + { lcMessage = + mconcat + [ "The impossible happened! Couldn't find the committee " + , textShow committee + , " which was enacted by a proposal " + , textShow committeeGaId + ] + } pure (Nothing, Nothing) (committeeId : _rest) -> pure (Just committeeId, Nothing) @@ -495,11 +503,14 @@ insertUpdateEnacted trce cache blkId epochNo enactedState = do constitutionId : rest -> do unless (null rest) $ liftIO $ - logWarning trce $ - mconcat - [ "Found multiple constitutions for proposal " - , textShow mConstitutionGaId - , ": " - , textShow constitutionIds - ] + logWarningCtx trce $ + logCtx + { lcMessage = + mconcat + [ "Found multiple constitutions for proposal " + , textShow mConstitutionGaId + , ": " + , textShow constitutionIds + ] + } pure constitutionId diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Grouped.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Grouped.hs index dc6b61234..639331824 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Grouped.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Grouped.hs @@ -14,7 +14,7 @@ module Cardano.DbSync.Era.Universal.Insert.Grouped ( mkmaTxOuts, ) where -import Cardano.BM.Trace (Trace, logWarning) +import Cardano.BM.Trace (Trace) import Cardano.Db (DbLovelace (..), MinIds (..), minIdsCoreToText, minIdsVariantToText) import qualified Cardano.Db as DB import qualified Cardano.Db.Schema.Core.TxOut as C @@ -26,6 +26,7 @@ import qualified Cardano.DbSync.Era.Shelley.Generic as Generic import Cardano.DbSync.Era.Shelley.Query import Cardano.DbSync.Era.Util import Cardano.DbSync.Error +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logErrorCtx) import Cardano.Prelude import Control.Monad.Trans.Control (MonadBaseControl) import qualified Data.List as List @@ -157,7 +158,10 @@ prepareUpdates :: prepareUpdates trce eti = case etiTxOutId eti of Right txOutId -> pure $ Just (txOutId, DB.txInTxInId (etiTxIn eti)) Left _ -> do - liftIO $ logWarning trce $ "Failed to find output for " <> Text.pack (show eti) + let logCtx = initLogCtx "prepareUpdates" "Cardano.DbSync.Era.Universal.Insert.Grouped" + liftIO $ + logErrorCtx trce $ + logCtx {lcMessage = "Failed to find output for " <> Text.pack (show eti)} pure Nothing insertReverseIndex :: diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/LedgerEvent.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/LedgerEvent.hs index c4938e8f6..6846ca36f 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/LedgerEvent.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/LedgerEvent.hs @@ -10,7 +10,6 @@ module Cardano.DbSync.Era.Universal.Insert.LedgerEvent ( insertNewEpochLedgerEvents, ) where -import Cardano.BM.Trace (logInfo) import qualified Cardano.Db as DB import Cardano.DbSync.Api import Cardano.DbSync.Api.Types (SyncEnv (..)) @@ -25,6 +24,7 @@ import Cardano.DbSync.Error import Cardano.DbSync.Ledger.Event import Cardano.DbSync.Types import Cardano.DbSync.Util +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logInfoCtx) import qualified Cardano.Ledger.Address as Ledger import Cardano.Prelude import Cardano.Slotting.Slot (EpochNo (..)) @@ -47,6 +47,7 @@ insertNewEpochLedgerEvents :: insertNewEpochLedgerEvents syncEnv currentEpochNo@(EpochNo curEpoch) = mapM_ handler where + logCtx = initLogCtx "insertNewEpochLedgerEvents" "Cardano.DbSync.Era.Universal.Insert.LedgerEvent" tracer = getTrace syncEnv cache = envCache syncEnv ntw = getNetwork syncEnv @@ -72,19 +73,19 @@ insertNewEpochLedgerEvents syncEnv currentEpochNo@(EpochNo curEpoch) = insertEpochSyncTime en (toSyncState ss) (envEpochSyncTime syncEnv) sqlBackend <- lift ask persistantCacheSize <- liftIO $ statementCacheSize $ connStmtMap sqlBackend - liftIO . logInfo tracer $ "Persistant SQL Statement Cache size is " <> textShow persistantCacheSize + liftIO . logInfoCtx tracer $ logCtx {lcMessage = "Persistant SQL Statement Cache size is " <> textShow persistantCacheSize} stats <- liftIO $ textShowStats cache - liftIO . logInfo tracer $ stats - liftIO . logInfo tracer $ "Starting epoch " <> textShow (unEpochNo en) + liftIO . logInfoCtx tracer $ logCtx {lcMessage = stats} + liftIO . logInfoCtx tracer $ logCtx {lcMessage = "Starting epoch " <> textShow (unEpochNo en)} LedgerStartAtEpoch en -> -- This is different from the previous case in that the db-sync started -- in this epoch, for example after a restart, instead of after an epoch boundary. - liftIO . logInfo tracer $ "Starting at epoch " <> textShow (unEpochNo en) + liftIO . logInfoCtx tracer $ logCtx {lcMessage = "Starting at epoch " <> textShow (unEpochNo en)} LedgerDeltaRewards _e rwd -> do let rewards = Map.toList $ Generic.unRewards rwd insertRewards syncEnv ntw (subFromCurrentEpoch 2) currentEpochNo cache (Map.toList $ Generic.unRewards rwd) -- This event is only created when it's not empty, so we don't need to check for null here. - liftIO . logInfo tracer $ "Inserted " <> show (length rewards) <> " Delta rewards" + liftIO . logInfoCtx tracer $ logCtx {lcMessage = "Inserted " <> show (length rewards) <> " Delta rewards"} LedgerIncrementalRewards _ rwd -> do let rewards = Map.toList $ Generic.unRewards rwd insertRewards syncEnv ntw (subFromCurrentEpoch 1) (EpochNo $ curEpoch + 1) cache rewards @@ -97,8 +98,8 @@ insertNewEpochLedgerEvents syncEnv currentEpochNo@(EpochNo curEpoch) = LedgerGovInfo enacted dropped expired uncl -> do unless (Set.null uncl) $ liftIO $ - logInfo tracer $ - "Found " <> textShow (Set.size uncl) <> " unclaimed proposal refunds" + logInfoCtx tracer $ + logCtx {lcMessage = "Found " <> textShow (Set.size uncl) <> " unclaimed proposal refunds"} updateDropped cache (EpochNo curEpoch) (garGovActionId <$> (dropped <> expired)) let refunded = filter (\e -> Set.notMember (garGovActionId e) uncl) (enacted <> dropped <> expired) insertProposalRefunds tracer ntw (subFromCurrentEpoch 1) currentEpochNo cache refunded -- TODO: check if they are disjoint to avoid double entries. @@ -112,7 +113,7 @@ insertNewEpochLedgerEvents syncEnv currentEpochNo@(EpochNo curEpoch) = unless (Map.null rwd) $ do let rewards = Map.toList rwd insertRewardRests tracer ntw (subFromCurrentEpoch 1) currentEpochNo cache rewards - liftIO . logInfo tracer $ "Inserted " <> show (length rewards) <> " Mir rewards" + liftIO . logInfoCtx tracer $ logCtx {lcMessage = "Inserted " <> show (length rewards) <> " Mir rewards"} LedgerPoolReap en drs -> unless (Map.null $ Generic.unRewards drs) $ do insertPoolDepositRefunds syncEnv en drs diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Other.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Other.hs index 4099e8427..6b23ae43c 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Other.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Other.hs @@ -165,12 +165,13 @@ insertStakeAddressRefIfMissing trce cache addr = insertMultiAsset :: (MonadBaseControl IO m, MonadIO m) => + Trace IO Text -> CacheStatus -> PolicyID StandardCrypto -> AssetName -> ReaderT SqlBackend m DB.MultiAssetId -insertMultiAsset cache policy aName = do - mId <- queryMAWithCache cache policy aName +insertMultiAsset trce cache policy aName = do + mId <- queryMAWithCache trce cache policy aName case mId of Right maId -> pure maId Left (policyBs, assetNameBs) -> diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Tx.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Tx.hs index 8674e1f02..b76dbec84 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Tx.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Tx.hs @@ -350,7 +350,7 @@ insertMaTxMint :: DB.TxId -> MultiAsset StandardCrypto -> ExceptT SyncNodeError (ReaderT SqlBackend m) [DB.MaTxMint] -insertMaTxMint _tracer cache txId (MultiAsset mintMap) = +insertMaTxMint trce cache txId (MultiAsset mintMap) = concatMapM (lift . prepareOuter) $ Map.toList mintMap where prepareOuter :: @@ -366,7 +366,7 @@ insertMaTxMint _tracer cache txId (MultiAsset mintMap) = (AssetName, Integer) -> ReaderT SqlBackend m DB.MaTxMint prepareInner policy (aname, amount) = do - maId <- insertMultiAsset cache policy aname + maId <- insertMultiAsset trce cache policy aname pure $ DB.MaTxMint { DB.maTxMintIdent = maId @@ -380,7 +380,7 @@ insertMaTxOuts :: CacheStatus -> Map (PolicyID StandardCrypto) (Map AssetName Integer) -> ExceptT SyncNodeError (ReaderT SqlBackend m) [MissingMaTxOut] -insertMaTxOuts _tracer cache maMap = +insertMaTxOuts trce cache maMap = concatMapM (lift . prepareOuter) $ Map.toList maMap where prepareOuter :: @@ -396,7 +396,7 @@ insertMaTxOuts _tracer cache maMap = (AssetName, Integer) -> ReaderT SqlBackend m MissingMaTxOut prepareInner policy (aname, amount) = do - maId <- insertMultiAsset cache policy aname + maId <- insertMultiAsset trce cache policy aname pure $ MissingMaTxOut { mmtoIdent = maId diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Validate.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Validate.hs index d155df128..0ad8ab3fa 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Validate.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Validate.hs @@ -9,12 +9,13 @@ module Cardano.DbSync.Era.Universal.Validate ( validateEpochRewards, ) where -import Cardano.BM.Trace (Trace, logError, logInfo, logWarning) +import Cardano.BM.Trace (Trace) import Cardano.Db (DbLovelace, RewardSource) import qualified Cardano.Db as Db import qualified Cardano.DbSync.Era.Shelley.Generic as Generic import Cardano.DbSync.Ledger.Event import Cardano.DbSync.Types +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logErrorCtx, logInfoCtx, logWarningCtx) import Cardano.Ledger.Coin (Coin (..)) import Cardano.Ledger.Crypto (StandardCrypto) import Cardano.Ledger.Shelley.API (Network) @@ -57,27 +58,34 @@ validateEpochRewards :: Map StakeCred (Set (Ledger.Reward StandardCrypto)) -> ReaderT SqlBackend m () validateEpochRewards tracer network _earnedEpochNo spendableEpochNo rmap = do + let logCtx = initLogCtx "validateEpochRewards" "Cardano.DbSync.Era.Universal.Validate" actualCount <- Db.queryNormalEpochRewardCount (unEpochNo spendableEpochNo) if actualCount /= expectedCount then do - liftIO . logWarning tracer $ - mconcat - [ "validateEpochRewards: rewards spendable in epoch " - , textShow (unEpochNo spendableEpochNo) - , " expected total of " - , textShow expectedCount - , " but got " - , textShow actualCount - ] + liftIO . logWarningCtx tracer $ + logCtx + { lcMessage = + mconcat + [ "validateEpochRewards: rewards spendable in epoch " + , textShow (unEpochNo spendableEpochNo) + , " expected total of " + , textShow expectedCount + , " but got " + , textShow actualCount + ] + } logFullRewardMap tracer spendableEpochNo network (convertPoolRewards rmap) else do - liftIO . logInfo tracer $ - mconcat - [ "Validate Epoch Rewards: total rewards that become spendable in epoch " - , textShow (unEpochNo spendableEpochNo) - , " are " - , textShow actualCount - ] + liftIO . logInfoCtx tracer $ + logCtx + { lcMessage = + mconcat + [ "Validate Epoch Rewards: total rewards that become spendable in epoch " + , textShow (unEpochNo spendableEpochNo) + , " are " + , textShow actualCount + ] + } where expectedCount :: Word64 expectedCount = fromIntegral . sum $ map Set.size (Map.elems rmap) @@ -137,8 +145,8 @@ diffRewardMap :: IO () diffRewardMap tracer _nw dbMap ledgerMap = do when (Map.size diffMap > 0) $ do - logError tracer "diffRewardMap:" - mapM_ (logError tracer . render) $ Map.toList diffMap + let logCtx = initLogCtx "diffRewardMap" "Cardano.DbSync.Era.Universal.Validate" + logErrorCtx tracer logCtx {lcMessage = mconcat $ map render (Map.toList diffMap)} where keys :: [ByteString] keys = List.nubOrd (Map.keys dbMap ++ Map.keys ledgerMap) diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Util.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Util.hs index e9a4a5430..76827cdd9 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Util.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Util.hs @@ -8,9 +8,10 @@ module Cardano.DbSync.Era.Util ( safeDecodeToJson, ) where -import Cardano.BM.Trace (Trace, logWarning) +import Cardano.BM.Trace (Trace) import qualified Cardano.Db as DB import Cardano.DbSync.Error +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logWarningCtx) import Cardano.Prelude import Control.Monad.Trans.Except.Extra (firstExceptT, newExceptT) import qualified Data.ByteString.Char8 as BS @@ -35,18 +36,17 @@ containsUnicodeNul = Text.isInfixOf "\\u000" safeDecodeToJson :: MonadIO m => Trace IO Text -> Text -> ByteString -> m (Maybe Text) safeDecodeToJson tracer tracePrefix jsonBs = do + let logCtx = initLogCtx "safeDecodeToJson" "Cardano.DbSync.Era.Util" ejson <- liftIO $ safeDecodeUtf8 jsonBs case ejson of Left err -> do - liftIO . logWarning tracer $ - mconcat - [tracePrefix, ": Could not decode to UTF8: ", textShow err] + liftIO . logWarningCtx tracer $ logCtx {lcMessage = mconcat [tracePrefix, ": Could not decode to UTF8: ", textShow err]} -- We have to insert pure Nothing Right json -> -- See https://github.com/IntersectMBO/cardano-db-sync/issues/297 if containsUnicodeNul json then do - liftIO $ logWarning tracer $ tracePrefix <> "was recorded as null, due to a Unicode NUL character found when trying to parse the json." + liftIO $ logWarningCtx tracer $ logCtx {lcMessage = tracePrefix <> "was recorded as null, due to a Unicode NUL character found when trying to parse the json."} pure Nothing else pure $ Just json diff --git a/cardano-db-sync/src/Cardano/DbSync/Fix/ConsumedBy.hs b/cardano-db-sync/src/Cardano/DbSync/Fix/ConsumedBy.hs index e340706e5..dcd58f3eb 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Fix/ConsumedBy.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Fix/ConsumedBy.hs @@ -2,7 +2,7 @@ module Cardano.DbSync.Fix.ConsumedBy (FixEntry, fixConsumedBy, fixEntriesConsumed) where -import Cardano.BM.Trace (Trace, logWarning) +import Cardano.BM.Trace (Trace) import qualified Cardano.Chain.Block as Byron hiding (blockHash) import qualified Cardano.Chain.UTxO as Byron import qualified Cardano.Crypto as Crypto (serializeCborHash) @@ -14,6 +14,7 @@ import Cardano.DbSync.Era.Byron.Util (blockPayload, unTxHash) import Cardano.DbSync.Era.Util import Cardano.DbSync.Error import Cardano.DbSync.Types +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logWarningCtx) import Cardano.Prelude hiding (length, (.)) import Database.Persist.SqlBackend.Internal import Ouroboros.Consensus.Byron.Ledger (ByronBlock (..)) @@ -35,14 +36,18 @@ fixBlock backend syncEnv bblk = case byronBlockRaw bblk of case mEntries of Right newEntries -> pure $ Just $ concat newEntries Left err -> do + let logCtx = initLogCtx "fixBlock" "Cardano.DbSync.Fix.ConsumedBy" liftIO $ - logWarning (getTrace syncEnv) $ - mconcat - [ "While fixing block " - , textShow bblk - , ", encountered error " - , textShow err - ] + logWarningCtx (getTrace syncEnv) $ + logCtx + { lcMessage = + mconcat + [ "While fixing block " + , textShow bblk + , ", encountered error " + , textShow err + ] + } pure Nothing fixTx :: MonadIO m => SyncEnv -> Byron.TxAux -> ExceptT SyncNodeError (ReaderT SqlBackend m) [FixEntry] diff --git a/cardano-db-sync/src/Cardano/DbSync/Fix/EpochStake.hs b/cardano-db-sync/src/Cardano/DbSync/Fix/EpochStake.hs index c1ff28caf..b793aebdc 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Fix/EpochStake.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Fix/EpochStake.hs @@ -3,7 +3,6 @@ module Cardano.DbSync.Fix.EpochStake where -import Cardano.BM.Trace (logInfo, logWarning) import qualified Cardano.Db as DB import Cardano.DbSync.Api import Cardano.DbSync.Api.Types @@ -12,6 +11,7 @@ import Cardano.DbSync.Era.Universal.Epoch import Cardano.DbSync.Error import Cardano.DbSync.Ledger.State import Cardano.DbSync.Ledger.Types +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logInfoCtx, logWarningCtx) import Cardano.Prelude import Control.Monad.Trans.Control import qualified Data.Map.Strict as Map @@ -24,7 +24,7 @@ migrateStakeDistr env mcls = (HasLedger lenv, Strict.Just cls) -> do ems <- lift DB.queryAllExtraMigrations runWhen (not $ DB.isStakeDistrComplete ems) $ do - liftIO $ logInfo trce "Starting Stake Distribution migration on table epoch_stake" + liftIO $ logInfoCtx trce $ logCtx {lcMessage = "Starting Stake Distribution migration on table epoch_stake"} let stakeSlice = getStakeSlice lenv cls True case stakeSlice of NoSlices -> @@ -44,6 +44,7 @@ migrateStakeDistr env mcls = lift $ DB.insertExtraMigration DB.StakeDistrEnded _ -> pure False where + logCtx = initLogCtx "migrateStakeDistr" "Cardano.DbSync.Fix.EpochStake" trce = getTrace env mkProgress isCompleted e = DB.EpochStakeProgress @@ -53,18 +54,21 @@ migrateStakeDistr env mcls = logInsert :: Int -> IO () logInsert n - | n == 0 = logInfo trce "No missing epoch_stake found" - | n > 100000 = logWarning trce $ "Found " <> textShow n <> " epoch_stake. This may take a while" - | otherwise = logInfo trce $ "Found " <> textShow n <> " epoch_stake" + | n == 0 = logInfoCtx trce $ logCtx {lcMessage = "No missing epoch_stake found"} + | n > 100000 = logWarningCtx trce $ logCtx {lcMessage = "Found " <> textShow n <> " epoch_stake. This may take a while"} + | otherwise = logInfoCtx trce $ logCtx {lcMessage = "Found " <> textShow n <> " epoch_stake"} logMinMax mmin mmax = - logInfo trce $ - mconcat - [ "Min epoch_stake at " - , textShow mmin - , " and max at " - , textShow mmax - ] + logInfoCtx trce $ + logCtx + { lcMessage = + mconcat + [ "Min epoch_stake at " + , textShow mmin + , " and max at " + , textShow mmax + ] + } runWhen :: Monad m => Bool -> m () -> m Bool runWhen a action = do diff --git a/cardano-db-sync/src/Cardano/DbSync/Fix/PlutusDataBytes.hs b/cardano-db-sync/src/Cardano/DbSync/Fix/PlutusDataBytes.hs index 29e189867..b253435b2 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Fix/PlutusDataBytes.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Fix/PlutusDataBytes.hs @@ -11,7 +11,7 @@ module Cardano.DbSync.Fix.PlutusDataBytes where -import Cardano.BM.Trace (Trace, logInfo, logWarning) +import Cardano.BM.Trace (Trace) import qualified Cardano.Db.Version.V13_0 as DB_V_13_0 import Cardano.DbSync.Api import Cardano.DbSync.Era.Shelley.Generic.Block @@ -19,6 +19,7 @@ import Cardano.DbSync.Era.Shelley.Generic.Tx.Alonzo import Cardano.DbSync.Era.Shelley.Generic.Tx.Types import Cardano.DbSync.Error (bsBase16Encode) import Cardano.DbSync.Types +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logInfoCtx, logWarningCtx) import qualified Cardano.Ledger.Alonzo.Tx as Alonzo import qualified Cardano.Ledger.Alonzo.TxWits as Alonzo import qualified Cardano.Ledger.Babbage.TxBody as Babbage @@ -92,13 +93,16 @@ getWrongPlutusData :: ReaderT SqlBackend m FixData getWrongPlutusData tracer = do liftIO $ - logInfo tracer $ - mconcat - [ "Starting the fixing Plutus Data bytes procedure. This may take a couple hours on mainnet if there are wrong values." - , " You can skip it using --skip-plutus-data-fix." - , " It will fix Datum and RedeemerData with wrong bytes. See more in Issue #1214 and #1278." - , " This procedure makes resyncing unnecessary." - ] + logInfoCtx tracer $ + logCtx + { lcMessage = + mconcat + [ "Starting the fixing Plutus Data bytes procedure. This may take a couple hours on mainnet if there are wrong values." + , " You can skip it using --skip-plutus-data-fix." + , " It will fix Datum and RedeemerData with wrong bytes. See more in Issue #1214 and #1278." + , " This procedure makes resyncing unnecessary." + ] + } datumList <- findWrongPlutusData tracer @@ -121,6 +125,7 @@ getWrongPlutusData tracer = do (mapLeft Just . hashPlutusData . getRedeemerDataBytes) pure $ FixData datumList redeemerDataList where + logCtx = initLogCtx "getWrongPlutusData" "Cardano.DbSync.Fix.PlutusDataBytes" f queryRes = do (prevBlockHsh, mPrevSlotNo) <- queryRes prevSlotNo <- mPrevSlotNo @@ -148,34 +153,44 @@ findWrongPlutusData :: m [FixPlutusInfo] findWrongPlutusData tracer tableName qCount qPage qGetInfo getHash getBytes hashBytes = do liftIO $ - logInfo tracer $ - mconcat - ["Trying to find ", tableName, " with wrong bytes"] + logInfoCtx tracer $ + logCtx + { lcMessage = + mconcat + ["Trying to find ", tableName, " with wrong bytes"] + } count <- qCount liftIO $ - logInfo tracer $ - mconcat - ["There are ", textShow count, " ", tableName, ". Need to scan them all."] + logInfoCtx tracer $ + logCtx + { lcMessage = + mconcat + ["There are ", textShow count, " ", tableName, ". Need to scan them all."] + } datums <- findRec False 0 [] liftIO $ - logInfo tracer $ - Text.concat - [ "Found " - , textShow (length datums) - , " " - , tableName - , " with mismatch between bytes and hash." - ] + logInfoCtx tracer $ + logCtx + { lcMessage = + Text.concat + [ "Found " + , textShow (length datums) + , " " + , tableName + , " with mismatch between bytes and hash." + ] + } pure datums where + logCtx = initLogCtx "findWrongPlutusData" "Cardano.DbSync.Fix.PlutusDataBytes" showBytes = maybe "" bsBase16Encode findRec :: Bool -> Int64 -> [[FixPlutusInfo]] -> m [FixPlutusInfo] findRec printedSome offset acc = do when (mod offset (10 * limit) == 0 && offset > 0) $ liftIO $ - logInfo tracer $ - mconcat ["Checked ", textShow offset, " ", tableName] + logInfoCtx tracer $ + logCtx {lcMessage = mconcat ["Checked ", textShow offset, " ", tableName]} ls <- qPage offset limit ls' <- filterM checkValidBytes ls ls'' <- mapMaybeM convertToFixPlutusInfo ls' @@ -184,11 +199,14 @@ findWrongPlutusData tracer tableName qCount qPage qGetInfo getHash getBytes hash then pure printedSome else do liftIO $ - logInfo tracer $ - Text.concat - [ "Found some wrong values already. The oldest ones are (hash, bytes): " - , textShow $ (\a -> (bsBase16Encode $ getHash a, showBytes $ getBytes a)) <$> take 5 ls' - ] + logInfoCtx tracer $ + logCtx + { lcMessage = + Text.concat + [ "Found some wrong values already. The oldest ones are (hash, bytes): " + , textShow $ (\a -> (bsBase16Encode $ getHash a, showBytes $ getBytes a)) <$> take 5 ls' + ] + } pure True let !newAcc = ls'' : acc if fromIntegral (length ls) < limit @@ -200,8 +218,8 @@ findWrongPlutusData tracer tableName qCount qPage qGetInfo getHash getBytes hash Left Nothing -> pure False Left (Just msg) -> do liftIO $ - logWarning tracer $ - Text.concat ["Invalid Binary Data for hash ", textShow actualHash, ": ", Text.pack msg] + logWarningCtx tracer $ + logCtx {lcMessage = Text.concat ["Invalid Binary Data for hash ", textShow actualHash, ": ", Text.pack msg]} pure False Right hashedBytes -> pure $ hashedBytes /= actualHash where @@ -227,6 +245,8 @@ fixPlutusData tracer cblk fds = do mapM_ (fixData True) $ fdDatum fds mapM_ (fixData False) $ fdRedeemerData fds where + logCtx = initLogCtx "fixPlutusData" "Cardano.DbSync.Fix.PlutusDataBytes" + fixData :: MonadIO m => Bool -> FixPlutusInfo -> ReaderT SqlBackend m () fixData isDatum fd = do case Map.lookup (fpHash fd) correctBytesMap of @@ -238,9 +258,12 @@ fixPlutusData tracer cblk fds = do DB_V_13_0.upateDatumBytes datumId correctBytes Nothing -> liftIO $ - logWarning tracer $ - mconcat - ["Datum", " not found in block"] + logWarningCtx tracer $ + logCtx + { lcMessage = + mconcat + ["Datum", " not found in block"] + } Just correctBytes -> do mRedeemerDataId <- DB_V_13_0.queryRedeemerData $ fpHash fd case mRedeemerDataId of @@ -248,9 +271,8 @@ fixPlutusData tracer cblk fds = do DB_V_13_0.upateRedeemerDataBytes redeemerDataId correctBytes Nothing -> liftIO $ - logWarning tracer $ - mconcat - ["RedeemerData", " not found in block"] + logWarningCtx tracer $ + logCtx {lcMessage = "RedeemerData not found in block"} correctBytesMap = Map.union (scrapDatumsBlock cblk) (scrapRedeemerDataBlock cblk) diff --git a/cardano-db-sync/src/Cardano/DbSync/Fix/PlutusScripts.hs b/cardano-db-sync/src/Cardano/DbSync/Fix/PlutusScripts.hs index 31c0724fa..773e318ce 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Fix/PlutusScripts.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Fix/PlutusScripts.hs @@ -33,7 +33,7 @@ import qualified Cardano.Ledger.Core as Ledger import Cardano.Db (ScriptType (..), maybeToEither) import qualified Cardano.Db.Version.V13_0 as DB_V_13_0 -import Cardano.BM.Trace (Trace, logInfo, logWarning) +import Cardano.BM.Trace (Trace) import Cardano.DbSync.Api import qualified Cardano.DbSync.Era.Shelley.Generic as Generic @@ -50,6 +50,7 @@ import Ouroboros.Consensus.Cardano.Block (HardForkBlock (BlockAllegra, BlockAlon import Ouroboros.Consensus.Shelley.Eras import Cardano.DbSync.Fix.PlutusDataBytes +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logInfoCtx, logWarningCtx) import Cardano.Ledger.Babbage.TxOut import Cardano.Ledger.Plutus.Language (Plutus (..)) @@ -77,14 +78,18 @@ getWrongPlutusScripts :: Trace IO Text -> ReaderT SqlBackend m FixPlutusScripts getWrongPlutusScripts tracer = do + let logCtx = initLogCtx "getWrongPlutusScripts" "Cardano.DbSync.Fix.PlutusScripts" liftIO $ - logInfo tracer $ - mconcat - [ "Starting the fixing Plutus Script procedure. This may take a couple minutes on mainnet if there are wrong values." - , " You can skip it using --skip-plutus-script-fix." - , " It will fix Script with wrong bytes. See more in Issue #1214 and #1348." - , " This procedure makes resyncing unnecessary." - ] + logInfoCtx tracer $ + logCtx + { lcMessage = + mconcat + [ "Starting the fixing Plutus Script procedure. This may take a couple minutes on mainnet if there are wrong values." + , " You can skip it using --skip-plutus-script-fix." + , " It will fix Script with wrong bytes. See more in Issue #1214 and #1348." + , " This procedure makes resyncing unnecessary." + ] + } FixPlutusScripts <$> findWrongPlutusScripts tracer findWrongPlutusScripts :: @@ -137,11 +142,15 @@ fixPlutusScripts tracer cblk fpss = do DB_V_13_0.updateScriptBytes scriptId correctBytes Nothing -> liftIO $ - logWarning tracer $ - mconcat - ["Script", " not found in block"] + logWarningCtx tracer $ + logCtx + { lcMessage = + mconcat + ["Script", " not found in block"] + } correctBytesMap = scrapScriptBlock cblk + logCtx = initLogCtx "fixPlutusScripts" "Cardano.DbSync.Fix.PlutusScripts" scrapScriptBlock :: CardanoBlock -> Map ByteString ByteString scrapScriptBlock cblk = case cblk of diff --git a/cardano-db-sync/src/Cardano/DbSync/Ledger/State.hs b/cardano-db-sync/src/Cardano/DbSync/Ledger/State.hs index c0875e511..84e16d34c 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Ledger/State.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Ledger/State.hs @@ -37,7 +37,7 @@ module Cardano.DbSync.Ledger.State ( findProposedCommittee, ) where -import Cardano.BM.Trace (Trace, logInfo, logWarning) +import Cardano.BM.Trace (Trace) import Cardano.Binary (Decoder, DecoderError) import qualified Cardano.Binary as Serialize import Cardano.DbSync.Config.Types @@ -76,6 +76,7 @@ import qualified Data.ByteString.Base16 as Base16 import Cardano.DbSync.Api.Types (InsertOptions (..), LedgerEnv (..), SyncOptions (..)) import Cardano.DbSync.Error (SyncNodeError (..), fromEitherSTM) +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logInfoCtx, logWarningCtx) import Cardano.Ledger.BaseTypes (StrictMaybe) import Cardano.Ledger.Conway.Core as Shelley import Cardano.Ledger.Conway.Governance @@ -353,15 +354,19 @@ storeSnapshotAndCleanupMaybe env oldState appResult blkNo isCons syncState = saveCurrentLedgerState :: HasLedgerEnv -> CardanoLedgerState -> Maybe EpochNo -> IO () saveCurrentLedgerState env lState mEpochNo = do + let logCtx = initLogCtx "saveCurrentLedgerState" "Cardano.DbSync.Ledger.State" case mkLedgerStateFilename (leDir env) (clsState lState) mEpochNo of Origin -> pure () -- we don't store genesis At file -> do exists <- doesFileExist file if exists then - logInfo (leTrace env) $ - mconcat - ["File ", Text.pack file, " exists"] + logInfoCtx (leTrace env) $ + logCtx + { lcMessage = + mconcat + ["File ", Text.pack file, " exists"] + } else atomically $ writeTBQueue (leStateWriteQueue env) (file, lState) runLedgerStateWriteThread :: Trace IO Text -> LedgerEnv -> IO () @@ -374,6 +379,8 @@ ledgerStateWriteLoop :: Trace IO Text -> TBQueue (FilePath, CardanoLedgerState) ledgerStateWriteLoop tracer swQueue codecConfig = loop where + logCtx = initLogCtx "ledgerStateWriteLoop" "Cardano.DbSync.Ledger.State" + loop :: IO () loop = do (file, ledger) <- atomically $ readTBQueue swQueue -- Blocks until the queue has elements. @@ -395,14 +402,8 @@ ledgerStateWriteLoop tracer swQueue codecConfig = ) ledger endTime <- getCurrentTime - logInfo tracer $ - mconcat - [ "Asynchronously wrote a ledger snapshot to " - , Text.pack file - , " in " - , textShow (diffUTCTime endTime startTime) - , "." - ] + logInfoCtx tracer $ + logCtx {lcMessage = mconcat ["Asynchronously wrote a ledger snapshot to ", Text.pack file, " in ", textShow (diffUTCTime endTime startTime), "."]} mkLedgerStateFilename :: LedgerStateDir -> ExtLedgerState CardanoBlock -> Maybe EpochNo -> WithOrigin FilePath mkLedgerStateFilename dir ledger mEpochNo = @@ -499,6 +500,7 @@ cleanupLedgerStateFiles env slotNo = do loadLedgerAtPoint :: HasLedgerEnv -> CardanoPoint -> IO (Either [LedgerStateFile] CardanoLedgerState) loadLedgerAtPoint hasLedgerEnv point = do + let logCtx = initLogCtx "loadLedgerAtPoint" "Cardano.DbSync.Ledger.State" mLedgerDB <- atomically $ readTVar $ leStateVar hasLedgerEnv -- First try to find the ledger in memory let mAnchoredSeq = rollbackLedger mLedgerDB @@ -513,11 +515,13 @@ loadLedgerAtPoint hasLedgerEnv point = do case mst of Right st -> do writeLedgerState hasLedgerEnv (Strict.Just . LedgerDB $ AS.Empty st) - logInfo (leTrace hasLedgerEnv) $ mconcat ["Found snapshot file for ", renderPoint point] + logInfoCtx (leTrace hasLedgerEnv) $ + logCtx {lcMessage = mconcat ["Found snapshot file for ", renderPoint point]} pure $ Right st Left lsfs -> pure $ Left lsfs Just anchoredSeq' -> do - logInfo (leTrace hasLedgerEnv) $ mconcat ["Found in memory ledger snapshot at ", renderPoint point] + logInfoCtx (leTrace hasLedgerEnv) $ + logCtx {lcMessage = mconcat ["Found in memory ledger snapshot at ", renderPoint point]} let ledgerDB' = LedgerDB anchoredSeq' let st = ledgerDbCurrent ledgerDB' deleteNewerFiles hasLedgerEnv point @@ -546,14 +550,15 @@ deleteNewerFiles env point = do deleteAndLogStateFile env "newer" newerFiles deleteAndLogFiles :: HasLedgerEnv -> Text -> [FilePath] -> IO () -deleteAndLogFiles env descr files = +deleteAndLogFiles env descr files = do + let logCtx = initLogCtx "deleteAndLogFiles" "Cardano.DbSync.Ledger.State" case files of [] -> pure () [fl] -> do - logInfo (leTrace env) $ mconcat ["Removing ", descr, " file ", Text.pack fl] + logInfoCtx (leTrace env) $ logCtx {lcMessage = mconcat ["Removing ", descr, " file ", Text.pack fl]} safeRemoveFile fl - _ -> do - logInfo (leTrace env) $ mconcat ["Removing ", descr, " files ", textShow files] + _otherwise -> do + logInfoCtx (leTrace env) $ logCtx {lcMessage = mconcat ["Removing ", descr, " files ", textShow files]} mapM_ safeRemoveFile files deleteAndLogStateFile :: HasLedgerEnv -> Text -> [LedgerStateFile] -> IO () @@ -585,24 +590,32 @@ findStateFromPoint env point = do logNewerFiles olderFiles pure $ Left olderFiles where + logCtx = initLogCtx "findStateFromPoint" "Cardano.DbSync.Ledger.State" + deleteLedgerFile :: Text -> LedgerStateFile -> IO () deleteLedgerFile err lsf = do - logWarning (leTrace env) $ - mconcat - [ "Failed to parse ledger state file " - , Text.pack (lsfFilePath lsf) - , " with error '" - , err - , "'. Deleting it." - ] + logWarningCtx (leTrace env) $ + logCtx + { lcMessage = + mconcat + [ "Failed to parse ledger state file " + , Text.pack (lsfFilePath lsf) + , " with error '" + , err + , "'. Deleting it." + ] + } safeRemoveFile $ lsfFilePath lsf logNewerFiles :: [LedgerStateFile] -> IO () logNewerFiles lsfs = - logWarning (leTrace env) $ - case lsfs of - [] -> "Rollback failed. No more ledger state files." - (x : _) -> mconcat ["Needs to Rollback further to slot ", textShow (unSlotNo $ lsfSlotNo x)] + logWarningCtx (leTrace env) $ + logCtx + { lcMessage = + case lsfs of + [] -> "Rollback failed. No more ledger state files." + (x : _) -> mconcat ["Needs to Rollback further to slot ", textShow (unSlotNo $ lsfSlotNo x)] + } -- Splits the files based on the comparison with the given point. It will return -- a list of newer files, a file at the given point if found and a list of older @@ -643,6 +656,8 @@ loadLedgerStateFromFile tracer config delete point lsf = do Left err -> when delete (safeRemoveFile $ lsfFilePath lsf) >> pure (Left err) Right st -> pure $ Right st where + logCtx = initLogCtx "loadLedgerStateFromFile" "Cardano.DbSync.Ledger.State" + safeReadFile :: FilePath -> IO (Either Text CardanoLedgerState) safeReadFile fp = do startTime <- getCurrentTime @@ -655,16 +670,19 @@ loadLedgerStateFromFile tracer config delete point lsf = do Left err -> pure $ Left $ textShow err Right ls -> do endTime <- getCurrentTime - logInfo tracer $ - mconcat - [ "Found snapshot file for " - , renderPoint point - , ". It took " - , textShow (diffUTCTime mediumTime startTime) - , " to read from disk and " - , textShow (diffUTCTime endTime mediumTime) - , " to parse." - ] + logInfoCtx tracer $ + logCtx + { lcMessage = + mconcat + [ "Found snapshot file for " + , renderPoint point + , ". It took " + , textShow (diffUTCTime mediumTime startTime) + , " to read from disk and " + , textShow (diffUTCTime endTime mediumTime) + , " to parse." + ] + } pure $ Right ls codecConfig :: CodecConfig CardanoBlock diff --git a/cardano-db-sync/src/Cardano/DbSync/LocalStateQuery.hs b/cardano-db-sync/src/Cardano/DbSync/LocalStateQuery.hs index 11d31ad2b..19d69816d 100644 --- a/cardano-db-sync/src/Cardano/DbSync/LocalStateQuery.hs +++ b/cardano-db-sync/src/Cardano/DbSync/LocalStateQuery.hs @@ -10,10 +10,11 @@ module Cardano.DbSync.LocalStateQuery ( newStateQueryTMVar, ) where -import Cardano.BM.Trace (Trace, logInfo) +import Cardano.BM.Trace (Trace) import Cardano.DbSync.Error (SyncNodeError (..)) import Cardano.DbSync.StateQuery import Cardano.DbSync.Types +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logErrorCtx, logInfoCtx) import qualified Cardano.Ledger.BaseTypes as Ledger import Cardano.Ledger.Crypto (StandardCrypto) import Cardano.Prelude hiding (atomically, (.)) @@ -30,6 +31,7 @@ import Control.Concurrent.Class.MonadSTM.Strict ( writeTVar, ) import qualified Data.Strict.Maybe as Strict +import Data.Text (pack) import Data.Time.Clock (getCurrentTime) import Ouroboros.Consensus.BlockchainTime.WallClock.Types (SystemStart (..)) import Ouroboros.Consensus.Cardano.Block (BlockQuery (QueryHardFork), CardanoEras) @@ -118,14 +120,16 @@ getHistoryInterpreter :: NoLedgerEnv -> IO CardanoInterpreter getHistoryInterpreter nlEnv = do + let logCtx = initLogCtx "getHistoryInterpreter" "DbSync.LocalStateQuery" respVar <- newEmptyTMVarIO atomically $ putTMVar reqVar (BlockQuery $ QueryHardFork GetInterpreter, respVar) res <- atomically $ takeTMVar respVar case res of - Left err -> - throwIO $ SNErrLocalStateQuery $ "getHistoryInterpreter: " <> Prelude.show err + Left err -> do + logErrorCtx tracer $ logCtx {lcMessage = pack $ Prelude.show err} + throwIO $ SNErrLocalStateQuery $ Prelude.show err Right interp -> do - logInfo tracer "getHistoryInterpreter: acquired" + logInfoCtx tracer $ logCtx {lcMessage = "Acquired"} atomically $ writeTVar interVar $ Strict.Just interp pure interp where diff --git a/cardano-db-sync/src/Cardano/DbSync/OffChain.hs b/cardano-db-sync/src/Cardano/DbSync/OffChain.hs index b89201791..bb08aca7f 100644 --- a/cardano-db-sync/src/Cardano/DbSync/OffChain.hs +++ b/cardano-db-sync/src/Cardano/DbSync/OffChain.hs @@ -17,7 +17,7 @@ module Cardano.DbSync.OffChain ( fetchOffChainVoteData, ) where -import Cardano.BM.Trace (Trace, logInfo) +import Cardano.BM.Trace (Trace) import Cardano.Db (runIohkLogging) import qualified Cardano.Db as DB import Cardano.DbSync.Api @@ -27,6 +27,7 @@ import Cardano.DbSync.OffChain.Http import Cardano.DbSync.OffChain.Query import qualified Cardano.DbSync.OffChain.Vote.Types as Vote import Cardano.DbSync.Types +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logInfoCtx) import Cardano.Prelude import Control.Concurrent.Class.MonadSTM.Strict ( StrictTBQueue (..), @@ -111,10 +112,10 @@ insertOffChainPoolResults trce resultQueue = do unless (null res) $ do let resLength = length res resErrorsLength = length $ filter isFetchError res - liftIO . logInfo trce $ - logInsertOffChainResults "Pool" resLength resErrorsLength + liftIO . logInfoCtx trce $ logCtx {lcMessage = logInsertOffChainResults "Pool" resLength resErrorsLength} mapM_ insert res where + logCtx = initLogCtx "insertOffChainPoolResults" "Cardano.DbSync.OffChain" insert :: (MonadBaseControl IO m, MonadIO m) => OffChainPoolResult -> ReaderT SqlBackend m () insert = \case OffChainPoolResultMetadata md -> void $ DB.insertCheckOffChainPoolData md @@ -135,10 +136,10 @@ insertOffChainVoteResults trce resultQueue = do unless (null res) $ do let resLength = length res resErrorsLength = length $ filter isFetchError res - liftIO . logInfo trce $ - logInsertOffChainResults "Voting Anchor" resLength resErrorsLength + liftIO . logInfoCtx trce $ logCtx {lcMessage = logInsertOffChainResults "Voting Anchor" resLength resErrorsLength} mapM_ insert res where + logCtx = initLogCtx "insertOffChainVoteResults" "Cardano.DbSync.OffChain" insert :: (MonadBaseControl IO m, MonadIO m) => OffChainVoteResult -> ReaderT SqlBackend m () insert = \case OffChainVoteResultMetadata md accessors -> do @@ -181,7 +182,7 @@ runFetchOffChainPoolThread :: SyncEnv -> IO () runFetchOffChainPoolThread syncEnv = do -- if dissable gov is active then don't run voting anchor thread when (ioOffChainPoolData iopts) $ do - logInfo trce "Running Offchain Pool fetch thread" + logInfoCtx trce $ logCtx {lcMessage = "Running Offchain Pool fetch thread"} runIohkLogging trce $ withPostgresqlConn (envConnectionString syncEnv) $ \backendPool -> liftIO $ @@ -194,6 +195,7 @@ runFetchOffChainPoolThread syncEnv = do now <- liftIO Time.getPOSIXTime mapM_ (queuePoolInsert <=< fetchOffChainPoolData trce manager now) poolq where + logCtx = initLogCtx "runFetchOffChainPoolThread" "Cardano.DbSync.OffChain" trce = getTrace syncEnv iopts = getInsertOptions syncEnv @@ -204,7 +206,7 @@ runFetchOffChainVoteThread :: SyncEnv -> IO () runFetchOffChainVoteThread syncEnv = do -- if dissable gov is active then don't run voting anchor thread when (ioGov iopts) $ do - logInfo trce "Running Offchain Vote Anchor fetch thread" + logInfoCtx trce $ logCtx {lcMessage = "Running Offchain Vote Anchor fetch thread"} runIohkLogging trce $ withPostgresqlConn (envConnectionString syncEnv) $ \backendVote -> liftIO $ @@ -216,6 +218,7 @@ runFetchOffChainVoteThread syncEnv = do now <- liftIO Time.getPOSIXTime mapM_ (queueVoteInsert <=< fetchOffChainVoteData gateways now) voteq where + logCtx = initLogCtx "runFetchOffChainVoteThread" "Cardano.DbSync.OffChain" trce = getTrace syncEnv iopts = getInsertOptions syncEnv gateways = dncIpfsGateway $ envSyncNodeConfig syncEnv diff --git a/cardano-db-sync/src/Cardano/DbSync/Rollback.hs b/cardano-db-sync/src/Cardano/DbSync/Rollback.hs index 9124bae6d..216a61807 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Rollback.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Rollback.hs @@ -9,7 +9,7 @@ module Cardano.DbSync.Rollback ( unsafeRollback, ) where -import Cardano.BM.Trace (Trace, logInfo, logWarning) +import Cardano.BM.Trace (Trace) import qualified Cardano.Db as DB import Cardano.DbSync.Api import Cardano.DbSync.Api.Types (SyncEnv (..)) @@ -19,6 +19,7 @@ import Cardano.DbSync.Error import Cardano.DbSync.Types import Cardano.DbSync.Util import Cardano.DbSync.Util.Constraint (addConstraintsIfNotExist) +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logInfoCtx, logWarningCtx) import Cardano.Prelude import Control.Monad.Extra (whenJust) import Control.Monad.Trans.Control (MonadBaseControl) @@ -36,17 +37,23 @@ rollbackFromBlockNo :: BlockNo -> ExceptT SyncNodeError (ReaderT SqlBackend m) () rollbackFromBlockNo syncEnv blkNo = do + let logCtx = initLogCtx "rollbackFromBlockNo" "Cardano.DbSync.Rollback" nBlocks <- lift $ DB.queryBlockCountAfterBlockNo (unBlockNo blkNo) True mres <- lift $ DB.queryBlockNoAndEpoch (unBlockNo blkNo) whenJust mres $ \(blockId, epochNo) -> do liftIO - . logInfo trce - $ mconcat - [ "Deleting " - , textShow nBlocks - , " numbered equal to or greater than " - , textShow blkNo - ] + . logInfoCtx trce + $ logCtx + { lcBlockNo = Just $ unBlockNo blkNo + , lcEpochNo = Just epochNo + , lcMessage = + mconcat + [ "Deleting " + , textShow nBlocks + , " numbered equal to or greater than " + , textShow blkNo + ] + } lift $ do deletedBlockCount <- DB.deleteBlocksBlockId trce txOutTableType blockId epochNo (DB.pcmConsumedTxOut $ getPruneConsume syncEnv) when (deletedBlockCount > 0) $ do @@ -57,7 +64,12 @@ rollbackFromBlockNo syncEnv blkNo = do lift $ rollbackCache cache blockId - liftIO . logInfo trce $ "Blocks deleted" + liftIO . logInfoCtx trce $ + logCtx + { lcEpochNo = Just epochNo + , lcBlockNo = Just $ unBlockNo blkNo + , lcMessage = "Blocks deleted" + } where trce = getTrace syncEnv cache = envCache syncEnv @@ -67,6 +79,7 @@ prepareRollback :: SyncEnv -> CardanoPoint -> Tip CardanoBlock -> IO (Either Syn prepareRollback syncEnv point serverTip = DB.runDbIohkNoLogging (envBackend syncEnv) $ runExceptT action where + logCtx = initLogCtx "prepareRollback" "Cardano.DbSync.Rollback" trce = getTrace syncEnv action :: MonadIO m => ExceptT SyncNodeError (ReaderT SqlBackend m) Bool @@ -76,39 +89,50 @@ prepareRollback syncEnv point serverTip = nBlocks <- lift DB.queryCountSlotNo if nBlocks == 0 then do - liftIO . logInfo trce $ "Starting from Genesis" + liftIO . logInfoCtx trce $ logCtx {lcMessage = "Starting from Genesis"} else do liftIO - . logInfo trce - $ mconcat - [ "Delaying delete of " - , textShow nBlocks - , " while rolling back to genesis." - , " Applying blocks until a new block is found." - , " The node is currently at " - , textShow serverTip - ] + . logInfoCtx trce + $ logCtx + { lcMessage = + mconcat + [ "Delaying delete of " + , textShow nBlocks + , " while rolling back to genesis." + , " Applying blocks until a new block is found." + , " The node is currently at " + , textShow serverTip + ] + } At blk -> do nBlocks <- lift $ DB.queryCountSlotNosGreaterThan (unSlotNo $ blockPointSlot blk) mBlockNo <- liftLookupFail "Rollback.prepareRollback" $ DB.queryBlockHashBlockNo (SBS.fromShort . getOneEraHash $ blockPointHash blk) liftIO - . logInfo trce - $ mconcat - [ "Delaying delete of " - , textShow nBlocks - , " blocks after " - , textShow mBlockNo - , " while rolling back to (" - , renderPoint point - , "). Applying blocks until a new block is found. The node is currently at " - , textShow serverTip - ] + . logInfoCtx trce + $ logCtx + { lcMessage = + mconcat + [ "Delaying delete of " + , textShow nBlocks + , " blocks after " + , textShow mBlockNo + , " while rolling back to (" + , renderPoint point + , "). Applying blocks until a new block is found. The node is currently at " + , textShow serverTip + ] + } pure False -- For testing and debugging. unsafeRollback :: Trace IO Text -> DB.TxOutTableType -> DB.PGConfig -> SlotNo -> IO (Either SyncNodeError ()) unsafeRollback trce txOutTableType config slotNo = do - logWarning trce $ "Starting a forced rollback to slot: " <> textShow (unSlotNo slotNo) + let logCtx = initLogCtx "unsafeRollback" "Cardano.DbSync.Rollback" + logWarningCtx trce $ + logCtx + { lcSlotNo = Just $ unSlotNo slotNo + , lcMessage = "Starting a forced rollback to slot: " <> textShow (unSlotNo slotNo) + } Right <$> DB.runDbNoLogging (DB.PGPassCached config) (void $ DB.deleteBlocksSlotNo trce txOutTableType slotNo True) diff --git a/cardano-db-sync/src/Cardano/DbSync/Sync.hs b/cardano-db-sync/src/Cardano/DbSync/Sync.hs index 656f81b4e..ec25e2f0c 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Sync.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Sync.hs @@ -25,7 +25,7 @@ module Cardano.DbSync.Sync ( ) where import Cardano.BM.Data.Tracer (ToLogObject (..), ToObject) -import Cardano.BM.Trace (Trace, appendName, logInfo, logWarning) +import Cardano.BM.Trace (Trace, appendName) import qualified Cardano.BM.Trace as Logging import Cardano.Client.Subscription (subscribe) import Cardano.Db (runDbIohkLogging) @@ -42,6 +42,7 @@ import Cardano.DbSync.Metrics import Cardano.DbSync.Tracing.ToObjectOrphans () import Cardano.DbSync.Types import Cardano.DbSync.Util +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logExceptionCtx, logInfoCtx, logWarningCtx) import Cardano.Prelude hiding (Meta, Nat, (%)) import Cardano.Slotting.Slot (WithOrigin (..)) import qualified Codec.CBOR.Term as CBOR @@ -129,7 +130,7 @@ runSyncNodeClient :: SocketPath -> IO () runSyncNodeClient metricsSetters syncEnv iomgr trce tc (SocketPath socketPath) = do - logInfo trce $ "Connecting to node via " <> textShow socketPath + logInfoCtx trce $ logCtx {lcMessage = "Connecting to node via " <> textShow socketPath} void $ subscribe (localSnocket iomgr) @@ -139,6 +140,7 @@ runSyncNodeClient metricsSetters syncEnv iomgr trce tc (SocketPath socketPath) = clientSubscriptionParams (dbSyncProtocols syncEnv metricsSetters tc codecConfig) where + logCtx = initLogCtx "runSyncNodeClient" "Cardano.DbSync.Sync" codecConfig :: CodecConfig CardanoBlock codecConfig = configCodec $ getTopLevelConfig syncEnv @@ -198,6 +200,7 @@ dbSyncProtocols syncEnv metricsSetters tc codecConfig version bversion = (Logging.nullTracer, cTxMonitorCodec codecs, localTxMonitorPeerNull) } where + logCtx = initLogCtx "dbSyncProtocols" "Cardano.DbSync.Sync" codecs = clientCodecs codecConfig bversion version localChainSyncTracer :: Tracer IO (TraceSendRecv (ChainSync CardanoBlock (Point CardanoBlock) (Tip CardanoBlock))) @@ -214,11 +217,10 @@ dbSyncProtocols syncEnv metricsSetters tc codecConfig version bversion = case consumedFixed of Nothing -> oldActionFixes channel Just wrongEntriesSize | wrongEntriesSize == 0 -> do - logInfo tracer "Found no wrong consumed_by_tx_id entries" + logInfoCtx tracer $ logCtx {lcMessage = "Found no wrong consumed_by_tx_id entries"} oldActionFixes channel Just wrongEntriesSize -> do - logInfo tracer $ - mconcat ["Found ", textShow wrongEntriesSize, " consumed_by_tx_id wrong entries"] + logInfoCtx tracer $ logCtx {lcMessage = mconcat ["Found ", textShow wrongEntriesSize, " consumed_by_tx_id wrong entries"]} fixedEntries <- runPeer localChainSyncTracer @@ -227,8 +229,8 @@ dbSyncProtocols syncEnv metricsSetters tc codecConfig version bversion = ( Client.chainSyncClientPeer $ chainSyncClientFixConsumed backend syncEnv wrongEntriesSize ) - logInfo tracer $ - mconcat ["Fixed ", textShow fixedEntries, " consumed_by_tx_id wrong entries"] + logInfoCtx tracer $ + logCtx {lcMessage = mconcat ["Fixed ", textShow fixedEntries, " consumed_by_tx_id wrong entries"]} pure False oldActionFixes channel = do @@ -274,22 +276,26 @@ dbSyncProtocols syncEnv metricsSetters tc codecConfig version bversion = localChainSyncPtcl :: RunMiniProtocolWithMinimalCtx 'InitiatorMode LocalAddress BSL.ByteString IO () Void localChainSyncPtcl = InitiatorProtocolOnly $ - MiniProtocolCb $ \_ctx channel -> - liftIO . logException tracer "ChainSyncWithBlocksPtcl: " $ do + MiniProtocolCb $ \_ctx channel -> do + let logCtx' = initLogCtx "localChainSyncPtcl" "Cardano.DbSync.Sync" + liftIO . logExceptionCtx tracer logCtx' {lcMessage = "ChainSyncWithBlocksPtcl "} $ do isInitComplete <- runAndSetDone tc $ initAction channel when isInitComplete $ do - logInfo tracer "Starting ChainSync client" + logInfoCtx tracer $ logCtx' {lcMessage = "Starting ChainSync client"} setConsistentLevel syncEnv Unchecked (latestPoints, currentTip) <- waitRestartState tc let (inMemory, onDisk) = List.span snd latestPoints - logInfo tracer $ - mconcat - [ "Suggesting intersection points from memory: " - , textShow (fst <$> inMemory) - , " and from disk: " - , textShow (fst <$> onDisk) - ] + logInfoCtx tracer $ + logCtx' + { lcMessage = + mconcat + [ "Suggesting intersection points from memory: " + , textShow (fst <$> inMemory) + , " and from disk: " + , textShow (fst <$> onDisk) + ] + } void $ runPipelinedPeer localChainSyncTracer @@ -424,7 +430,7 @@ chainSyncClient metricsSetters trce latestPoints currentTip tc = do mkClientStNext finish = ClientStNext { recvMsgRollForward = \blk tip -> - logException trce "recvMsgRollForward: " $ do + logExceptionCtx trce (logCtx {lcMessage = "recvMsgRollForward: "}) $ do setNodeBlockHeight metricsSetters (getTipBlockNo tip) newSize <- atomically $ do @@ -435,12 +441,14 @@ chainSyncClient metricsSetters trce latestPoints currentTip tc = do pure $ finish (At (blockNo blk)) tip Nothing , recvMsgRollBackward = \point tip -> - logException trce "recvMsgRollBackward: " $ do + logExceptionCtx trce (logCtx {lcMessage = "recvMsgRollBackward: "}) $ do -- This will get the current tip rather than what we roll back to -- but will only be incorrect for a short time span. (mPoints, newTip) <- waitRollback tc point tip pure $ finish newTip tip mPoints } + where + logCtx = initLogCtx "mkClientStNext" "Cardano.DbSync.Sync" drainThePipe :: Nat n -> @@ -465,10 +473,11 @@ drainThePipe n0 client = go n0 chainSyncClientFixConsumed :: SqlBackend -> SyncEnv -> Word64 -> ChainSyncClient CardanoBlock (Point CardanoBlock) (Tip CardanoBlock) IO Integer chainSyncClientFixConsumed backend syncEnv wrongTotalSize = Client.ChainSyncClient $ do - liftIO $ logInfo tracer "Starting chainsync to fix consumed_by_tx_id Byron entries. See issue https://github.com/IntersectMBO/cardano-db-sync/issues/1821. This makes resyncing unnecessary." + liftIO $ logInfoCtx tracer $ logCtx {lcMessage = "Starting chainsync to fix consumed_by_tx_id Byron entries. See issue https://github.com/IntersectMBO/cardano-db-sync/issues/1821. This makes resyncing unnecessary."} pure $ Client.SendMsgFindIntersect [genesisPoint] clientStIntersect where tracer = getTrace syncEnv + logCtx = initLogCtx "chainSyncClientFixConsumed" "Cardano.DbSync.Sync" clientStIntersect = Client.ClientStIntersect { Client.recvMsgIntersectFound = \_blk _tip -> @@ -511,21 +520,22 @@ chainSyncClientFixConsumed backend syncEnv wrongTotalSize = Client.ChainSyncClie logSize :: Integer -> Integer -> IO () logSize lastSize newSize = do when (newSize `div` 200_000 > lastSize `div` 200_000) $ - logInfo tracer $ - mconcat ["Fixed ", textShow newSize, "/", textShow wrongTotalSize, " entries"] + logInfoCtx tracer $ + logCtx {lcMessage = mconcat ["Fixed ", textShow newSize, "/", textShow wrongTotalSize, " entries"]} chainSyncClientFixData :: SqlBackend -> Trace IO Text -> FixData -> ChainSyncClient CardanoBlock (Point CardanoBlock) (Tip CardanoBlock) IO () chainSyncClientFixData backend tracer fixData = Client.ChainSyncClient $ do - liftIO $ logInfo tracer "Starting chainsync to fix Plutus Data. This will update database values in tables datum and redeemer_data." + liftIO $ logInfoCtx tracer $ logCtx {lcMessage = "Starting chainsync to fix Plutus Data. This will update database values in tables datum and redeemer_data."} clientStIdle True (sizeFixData fixData) fixData where + logCtx = initLogCtx "chainSyncClientFixData" "Cardano.DbSync.Sync" updateSizeAndLog :: Int -> Int -> IO Int updateSizeAndLog lastSize currentSize = do let diffSize = lastSize - currentSize if lastSize >= currentSize && diffSize >= 200_000 then do - liftIO $ logInfo tracer $ mconcat ["Fixed ", textShow (sizeFixData fixData - currentSize), " Plutus Data"] + liftIO $ logInfoCtx tracer $ logCtx {lcMessage = mconcat ["Fixed ", textShow (sizeFixData fixData - currentSize), " Plutus Data"]} pure currentSize else pure lastSize @@ -533,13 +543,13 @@ chainSyncClientFixData backend tracer fixData = Client.ChainSyncClient $ do clientStIdle shouldLog lastSize fds = do case spanFDOnNextPoint fds of Nothing -> do - liftIO $ logInfo tracer "Finished chainsync to fix Plutus Data." + liftIO $ logInfoCtx tracer logCtx {lcMessage = "Finished chainsync to fix Plutus Data."} pure $ Client.SendMsgDone () Just (point, fdOnPoint, fdRest) -> do when shouldLog $ liftIO $ - logInfo tracer $ - mconcat ["Starting fixing Plutus Data ", textShow point] + logInfoCtx tracer $ + logCtx {lcMessage = mconcat ["Starting fixing Plutus Data ", textShow point]} newLastSize <- liftIO $ updateSizeAndLog lastSize (sizeFixData fds) let clientStIntersect = Client.ClientStIntersect @@ -549,14 +559,17 @@ chainSyncClientFixData backend tracer fixData = Client.ChainSyncClient $ do Client.SendMsgRequestNext (pure ()) (clientStNext newLastSize fdOnPoint fdRest) , Client.recvMsgIntersectNotFound = \tip -> Client.ChainSyncClient $ do liftIO $ - logWarning tracer $ - mconcat - [ "Node can't find block " - , textShow point - , ". It's probably behind, at " - , textShow tip - , ". Sleeping for 3 mins and retrying.." - ] + logWarningCtx tracer $ + logCtx + { lcMessage = + mconcat + [ "Node can't find block " + , textShow point + , ". It's probably behind, at " + , textShow tip + , ". Sleeping for 3 mins and retrying.." + ] + } liftIO $ threadDelay $ 180 * 1_000_000 pure $ Client.SendMsgFindIntersect [point] clientStIntersect } @@ -577,15 +590,16 @@ chainSyncClientFixData backend tracer fixData = Client.ChainSyncClient $ do chainSyncClientFixScripts :: SqlBackend -> Trace IO Text -> FixPlutusScripts -> ChainSyncClient CardanoBlock (Point CardanoBlock) (Tip CardanoBlock) IO () chainSyncClientFixScripts backend tracer fps = Client.ChainSyncClient $ do - liftIO $ logInfo tracer "Starting chainsync to fix Plutus Scripts. This will update database values in tables script." + liftIO $ logInfoCtx tracer $ logCtx {lcMessage = "Starting chainsync to fix Plutus Scripts. This will update database values in tables script."} clientStIdle True (sizeFixPlutusScripts fps) fps where + logCtx = initLogCtx "chainSyncClientFixScripts" "Cardano.DbSync.Sync" updateSizeAndLog :: Int -> Int -> IO Int updateSizeAndLog lastSize currentSize = do let diffSize = lastSize - currentSize if lastSize >= currentSize && diffSize >= 200_000 then do - liftIO $ logInfo tracer $ mconcat ["Fixed ", textShow (sizeFixPlutusScripts fps - currentSize), " Plutus Scripts"] + liftIO $ logInfoCtx tracer $ logCtx {lcMessage = mconcat ["Fixed ", textShow (sizeFixPlutusScripts fps - currentSize), " Plutus Scripts"]} pure currentSize else pure lastSize @@ -593,13 +607,13 @@ chainSyncClientFixScripts backend tracer fps = Client.ChainSyncClient $ do clientStIdle shouldLog lastSize fps' = do case spanFPSOnNextPoint fps' of Nothing -> do - liftIO $ logInfo tracer "Finished chainsync to fix Plutus Scripts." + liftIO $ logInfoCtx tracer $ logCtx {lcMessage = "Finished chainsync to fix Plutus Scripts."} pure $ Client.SendMsgDone () Just (point, fpsOnPoint, fpsRest) -> do when shouldLog $ liftIO $ - logInfo tracer $ - mconcat ["Starting fixing Plutus Scripts ", textShow point] + logInfoCtx tracer $ + logCtx {lcMessage = mconcat ["Starting fixing Plutus Scripts ", textShow point]} newLastSize <- liftIO $ updateSizeAndLog lastSize (sizeFixPlutusScripts fps') let clientStIntersect = Client.ClientStIntersect @@ -609,14 +623,17 @@ chainSyncClientFixScripts backend tracer fps = Client.ChainSyncClient $ do Client.SendMsgRequestNext (pure ()) (clientStNext newLastSize fpsOnPoint fpsRest) , Client.recvMsgIntersectNotFound = \tip -> Client.ChainSyncClient $ do liftIO $ - logWarning tracer $ - mconcat - [ "Node can't find block " - , textShow point - , ". It's probably behind, at " - , textShow tip - , ". Sleeping for 3 mins and retrying.." - ] + logWarningCtx tracer $ + logCtx + { lcMessage = + mconcat + [ "Node can't find block " + , textShow point + , ". It's probably behind, at " + , textShow tip + , ". Sleeping for 3 mins and retrying.." + ] + } liftIO $ threadDelay $ 180 * 1_000_000 pure $ Client.SendMsgFindIntersect [point] clientStIntersect } diff --git a/cardano-db-sync/src/Cardano/DbSync/Util.hs b/cardano-db-sync/src/Cardano/DbSync/Util.hs index 961ad5546..bc24d97f4 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Util.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Util.hs @@ -14,9 +14,6 @@ module Cardano.DbSync.Util ( fmap3, getSyncStatus, isSyncedWithinSeconds, - liftedLogException, - logActionDuration, - logException, maybeFromStrict, maybeToStrict, nullMetricSetters, @@ -42,7 +39,6 @@ module Cardano.DbSync.Util ( whenFalseMempty, ) where -import Cardano.BM.Trace (Trace, logError, logInfo) import Cardano.Db (RewardSource (..)) import Cardano.DbSync.Config.Types () import Cardano.DbSync.Types @@ -50,8 +46,6 @@ import Cardano.Ledger.Coin (Coin (..)) import qualified Cardano.Ledger.Shelley.Rewards as Shelley import Cardano.Prelude hiding (catch) import Cardano.Slotting.Slot (SlotNo (..), WithOrigin (..)) -import Control.Exception.Lifted (catch) -import Control.Monad.Trans.Control (MonadBaseControl) import Data.ByteArray (ByteArrayAccess) import qualified Data.ByteArray import qualified Data.ByteString.Base16 as Base16 @@ -99,40 +93,6 @@ traverseMEither action xs = do (y : ys) -> action y >>= either (pure . Left) (const $ traverseMEither action ys) --- | Needed when debugging disappearing exceptions. -liftedLogException :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> Text -> m a -> m a -liftedLogException tracer txt action = - action `catch` logger - where - logger :: MonadIO m => SomeException -> m a - logger e = - liftIO $ do - putStrLn $ "Caught exception: txt " ++ show e - logError tracer $ txt <> textShow e - throwIO e - --- | Log the runtime duration of an action. Mainly for debugging. -logActionDuration :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> Text -> m a -> m a -logActionDuration tracer label action = do - before <- liftIO Time.getCurrentTime - a <- action - after <- liftIO Time.getCurrentTime - liftIO . logInfo tracer $ mconcat [label, ": duration ", textShow (Time.diffUTCTime after before)] - pure a - --- | ouroboros-network catches 'SomeException' and if a 'nullTracer' is passed into that --- code, the caught exception will not be logged. Therefore wrap all cardano-db-sync code that --- is called from network with an exception logger so at least the exception will be --- logged (instead of silently swallowed) and then rethrown. -logException :: Trace IO Text -> Text -> IO a -> IO a -logException tracer txt action = - action `catch` logger - where - logger :: SomeException -> IO a - logger e = do - logError tracer $ txt <> textShow e - throwIO e - -- | Eequired for testing or when disabling the metrics. nullMetricSetters :: MetricSetters nullMetricSetters = diff --git a/cardano-db-sync/src/Cardano/DbSync/Util/Constraint.hs b/cardano-db-sync/src/Cardano/DbSync/Util/Constraint.hs index af266a6e2..4659966e4 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Util/Constraint.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Util/Constraint.hs @@ -16,10 +16,10 @@ module Cardano.DbSync.Util.Constraint ( ) where import Cardano.BM.Data.Trace (Trace) -import Cardano.BM.Trace (logInfo) import Cardano.Db (ManualDbConstraints (..)) import qualified Cardano.Db as DB import Cardano.DbSync.Api.Types (SyncEnv (..)) +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logInfoCtx) import Cardano.Prelude (MonadIO (..), Proxy (..), ReaderT (runReaderT), atomically) import Control.Concurrent.Class.MonadSTM.Strict (readTVarIO, writeTVar) import Control.Monad (unless) @@ -100,6 +100,7 @@ addRewardTableConstraint :: ReaderT SqlBackend m () addRewardTableConstraint trce = do let entityD = entityDef $ Proxy @DB.Reward + logCtx = initLogCtx "addRewardTableConstraint" "Cardano.DbSync.Util" DB.alterTable entityD ( DB.AddUniqueConstraint @@ -110,7 +111,7 @@ addRewardTableConstraint trce = do , FieldNameDB "pool_id" ] ) - liftIO $ logNewConstraint trce entityD (unConstraintNameDB constraintNameReward) + liftIO $ logNewConstraint trce logCtx entityD (unConstraintNameDB constraintNameReward) addEpochStakeTableConstraint :: forall m. @@ -119,6 +120,7 @@ addEpochStakeTableConstraint :: ReaderT SqlBackend m () addEpochStakeTableConstraint trce = do let entityD = entityDef $ Proxy @DB.EpochStake + logCtx = initLogCtx "addEpochStakeTableConstraint" "Cardano.DbSync.Util" DB.alterTable entityD ( DB.AddUniqueConstraint @@ -128,16 +130,20 @@ addEpochStakeTableConstraint trce = do , FieldNameDB "pool_id" ] ) - liftIO $ logNewConstraint trce entityD (unConstraintNameDB constraintNameEpochStake) + liftIO $ logNewConstraint trce logCtx entityD (unConstraintNameDB constraintNameEpochStake) logNewConstraint :: Trace IO Text -> + LogContext -> EntityDef -> Text -> IO () -logNewConstraint trce table constraintName = - logInfo trce $ - "The table " - <> unEntityNameDB (entityDB table) - <> " was given a new unique constraint called " - <> constraintName +logNewConstraint trce logCtx table constraintName = + logInfoCtx trce $ + logCtx + { lcMessage = + "The table " + <> unEntityNameDB (entityDB table) + <> " was given a new unique constraint called " + <> constraintName + } diff --git a/cardano-db-sync/src/Cardano/DbSync/Util/Logging.hs b/cardano-db-sync/src/Cardano/DbSync/Util/Logging.hs new file mode 100644 index 000000000..51d08fd63 --- /dev/null +++ b/cardano-db-sync/src/Cardano/DbSync/Util/Logging.hs @@ -0,0 +1,108 @@ +{-# LANGUAGE FlexibleContexts #-} +{-# LANGUAGE OverloadedStrings #-} + +module Cardano.DbSync.Util.Logging ( + LogContext (..), + logInfoCtx, + logWarningCtx, + logErrorCtx, + logDebugCtx, + initLogCtx, + liftedLogExceptionCtx, + logActionDurationCtx, + logExceptionCtx, +) where + +import Cardano.BM.Trace (Trace, logDebug, logError, logInfo, logWarning) +import Cardano.Prelude hiding (catch) +import Control.Exception.Lifted (catch) +import Control.Monad.Trans.Control (MonadBaseControl) +import Data.Text (pack) +import qualified Data.Time.Clock as Time +import Prelude hiding (show, unwords, (.)) + +data LogContext = LogContext + { lcFunction :: Text + , lcComponent :: Text + , lcBlockNo :: Maybe Word64 + , lcSlotNo :: Maybe Word64 + , lcEpochNo :: Maybe Word64 + , lcMessage :: Text + } + +-- TODO: We could select what to show here with a debug flag! +formatLogMessage :: LogContext -> Text +formatLogMessage ctx = + unwords + [ lcMessage ctx + , "[Function:" + , lcFunction ctx + , "| Component:" + , lcComponent ctx + , "| Block No:" + , maybe "None" (pack . show) (lcBlockNo ctx) + , "| Slot No:" + , maybe "None" (pack . show) (lcSlotNo ctx) + , "| Epoch No:" + , maybe "None" (pack . show) (lcEpochNo ctx) + , "]" + ] + +-- Wrapper functions using LogContext +logInfoCtx :: Trace IO Text -> LogContext -> IO () +logInfoCtx trce ctx = logInfo trce (formatLogMessage ctx) + +logWarningCtx :: Trace IO Text -> LogContext -> IO () +logWarningCtx trce ctx = logWarning trce (formatLogMessage ctx) + +logErrorCtx :: Trace IO Text -> LogContext -> IO () +logErrorCtx trce ctx = logError trce (formatLogMessage ctx) + +logDebugCtx :: Trace IO Text -> LogContext -> IO () +logDebugCtx trce ctx = logDebug trce (formatLogMessage ctx) + +initLogCtx :: Text -> Text -> LogContext +initLogCtx functionName componentName = + LogContext + { lcFunction = functionName + , lcComponent = componentName + , lcBlockNo = Nothing + , lcSlotNo = Nothing + , lcEpochNo = Nothing + , lcMessage = "" + } + +-- | Needed when debugging disappearing exceptions. +liftedLogExceptionCtx :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> Text -> m a -> m a +liftedLogExceptionCtx tracer txt action = + action `catch` logger + where + logCtx = LogContext txt "Cardano.DbSync.Util" Nothing Nothing Nothing + + logger :: MonadIO m => SomeException -> m a + logger e = + liftIO $ do + logErrorCtx tracer $ logCtx ("Caught exception: txt " <> show e) + throwIO e + +-- | Log the runtime duration of an action. Mainly for debugging. +logActionDurationCtx :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> LogContext -> m a -> m a +logActionDurationCtx tracer logCtx action = do + before <- liftIO Time.getCurrentTime + a <- action + after <- liftIO Time.getCurrentTime + liftIO . logInfoCtx tracer $ logCtx {lcMessage = mconcat ["duration: ", textShow (Time.diffUTCTime after before)]} + pure a + +-- | ouroboros-network catches 'SomeException' and if a 'nullTracer' is passed into that +-- code, the caught exception will not be logged. Therefore wrap all cardano-db-sync code that +-- is called from network with an exception logger so at least the exception will be +-- logged (instead of silently swallowed) and then rethrown. +logExceptionCtx :: Trace IO Text -> LogContext -> IO a -> IO a +logExceptionCtx tracer logCtx action = + action `catch` logger + where + logger :: SomeException -> IO a + logger e = do + logErrorCtx tracer $ logCtx {lcMessage = lcMessage logCtx <> textShow e} + throwIO e From 6ff3e37d48e1dd5c1dc1ef5a031d613a4942f87f Mon Sep 17 00:00:00 2001 From: Cmdv Date: Mon, 25 Nov 2024 17:10:10 +0000 Subject: [PATCH 2/2] use iohk-monitoring Severity to handle debug --- cardano-chain-gen/cardano-chain-gen.cabal | 1 + .../test/Test/Cardano/Db/Mock/Config.hs | 5 +- cardano-db-sync/cardano-db-sync.cabal | 1 + cardano-db-sync/src/Cardano/DbSync.hs | 36 +++-- cardano-db-sync/src/Cardano/DbSync/Api.hs | 38 +++-- .../src/Cardano/DbSync/Api/Functions.hs | 11 ++ .../src/Cardano/DbSync/Api/Ledger.hs | 25 +-- .../src/Cardano/DbSync/Api/Types.hs | 2 +- cardano-db-sync/src/Cardano/DbSync/Cache.hs | 11 +- .../src/Cardano/DbSync/Database.hs | 10 +- cardano-db-sync/src/Cardano/DbSync/Default.hs | 9 +- cardano-db-sync/src/Cardano/DbSync/Epoch.hs | 7 +- .../src/Cardano/DbSync/Era/Byron/Genesis.hs | 151 +++++++++--------- .../src/Cardano/DbSync/Era/Byron/Insert.hs | 7 +- .../src/Cardano/DbSync/Era/Shelley/Genesis.hs | 30 ++-- .../Cardano/DbSync/Era/Universal/Adjust.hs | 6 +- .../src/Cardano/DbSync/Era/Universal/Block.hs | 8 +- .../src/Cardano/DbSync/Era/Universal/Epoch.hs | 47 +++--- .../Era/Universal/Insert/Certificate.hs | 36 +++-- .../DbSync/Era/Universal/Insert/GovAction.hs | 21 ++- .../DbSync/Era/Universal/Insert/Grouped.hs | 10 +- .../Era/Universal/Insert/LedgerEvent.hs | 12 +- .../DbSync/Era/Universal/Insert/Other.hs | 34 ++-- .../DbSync/Era/Universal/Insert/Pool.hs | 11 +- .../Cardano/DbSync/Era/Universal/Insert/Tx.hs | 51 +++--- .../Cardano/DbSync/Era/Universal/Validate.hs | 18 ++- .../src/Cardano/DbSync/Era/Util.hs | 7 +- .../src/Cardano/DbSync/Fix/ConsumedBy.hs | 43 ++--- .../src/Cardano/DbSync/Fix/EpochStake.hs | 16 +- .../src/Cardano/DbSync/Fix/PlutusDataBytes.hs | 20 ++- .../src/Cardano/DbSync/Fix/PlutusScripts.hs | 18 ++- .../src/Cardano/DbSync/Ledger/State.hs | 98 ++++++------ .../src/Cardano/DbSync/LocalStateQuery.hs | 13 +- .../src/Cardano/DbSync/OffChain.hs | 18 ++- .../src/Cardano/DbSync/Rollback.hs | 27 ++-- cardano-db-sync/src/Cardano/DbSync/Sync.hs | 53 +++--- .../src/Cardano/DbSync/Util/Constraint.hs | 18 ++- .../src/Cardano/DbSync/Util/Logging.hs | 70 +++++--- cardano-db-sync/test/Cardano/DbSync/Gen.hs | 1 - cardano-db-tool/cardano-db-tool.cabal | 1 + .../src/Cardano/DbTool/Validate/Ledger.hs | 3 +- 41 files changed, 598 insertions(+), 406 deletions(-) create mode 100644 cardano-db-sync/src/Cardano/DbSync/Api/Functions.hs diff --git a/cardano-chain-gen/cardano-chain-gen.cabal b/cardano-chain-gen/cardano-chain-gen.cabal index aadee81c1..75dee0664 100644 --- a/cardano-chain-gen/cardano-chain-gen.cabal +++ b/cardano-chain-gen/cardano-chain-gen.cabal @@ -195,6 +195,7 @@ test-suite cardano-chain-gen , esqueleto , extra , filepath + , iohk-monitoring , silently , stm , strict-stm diff --git a/cardano-chain-gen/test/Test/Cardano/Db/Mock/Config.hs b/cardano-chain-gen/test/Test/Cardano/Db/Mock/Config.hs index e9414732a..b6674ed46 100644 --- a/cardano-chain-gen/test/Test/Cardano/Db/Mock/Config.hs +++ b/cardano-chain-gen/test/Test/Cardano/Db/Mock/Config.hs @@ -62,6 +62,7 @@ module Test.Cardano.Db.Mock.Config ( ) where import Cardano.Api (NetworkMagic (..)) +import qualified Cardano.BM.Data.Severity as BM import qualified Cardano.Db as DB import Cardano.DbSync import Cardano.DbSync.Config @@ -555,12 +556,14 @@ withFullConfig' WithConfigArgs {..} cmdLineArgs mSyncNodeConfig configFilePath t cfg <- mkConfig configFilePath mutableDir cmdLineArgs syncNodeConfig fingerFile <- if hasFingerprint then Just <$> prepareFingerprintFile testLabelFilePath else pure Nothing let dbsyncParams = syncNodeParams cfg + -- if shouldLog is True, we will log at Debug level + debugLogs = if shouldLog then BM.Debug else BM.Info trce <- if shouldLog then configureLogging syncNodeConfig "db-sync-node" else pure nullTracer -- runDbSync is partially applied so we can pass in syncNodeParams at call site / within tests - let partialDbSyncRun params cfg' = runDbSync emptyMetricsSetters migr iom trce params cfg' True + let partialDbSyncRun params cfg' = runDbSync emptyMetricsSetters migr iom trce debugLogs params cfg' True initSt = Consensus.pInfoInitLedger $ protocolInfo cfg withInterpreter (protocolInfoForging cfg) (protocolInfoForger cfg) nullTracer fingerFile $ \interpreter -> do diff --git a/cardano-db-sync/cardano-db-sync.cabal b/cardano-db-sync/cardano-db-sync.cabal index 6bc713fee..55dc8389f 100644 --- a/cardano-db-sync/cardano-db-sync.cabal +++ b/cardano-db-sync/cardano-db-sync.cabal @@ -43,6 +43,7 @@ library exposed-modules: Cardano.DbSync Cardano.DbSync.Api + Cardano.DbSync.Api.Functions Cardano.DbSync.Api.Ledger Cardano.DbSync.Api.Types Cardano.DbSync.Config diff --git a/cardano-db-sync/src/Cardano/DbSync.hs b/cardano-db-sync/src/Cardano/DbSync.hs index a7555c6b2..d79853a05 100644 --- a/cardano-db-sync/src/Cardano/DbSync.hs +++ b/cardano-db-sync/src/Cardano/DbSync.hs @@ -24,6 +24,8 @@ module Cardano.DbSync ( extractSyncOptions, ) where +import qualified Cardano.BM.Configuration as BM +import qualified Cardano.BM.Data.Severity as BM import Cardano.BM.Trace (Trace) import qualified Cardano.Crypto as Crypto import qualified Cardano.Db as DB @@ -62,25 +64,27 @@ import Prelude (id) runDbSyncNode :: MetricSetters -> [(Text, Text)] -> SyncNodeParams -> SyncNodeConfig -> IO () runDbSyncNode metricsSetters knownMigrations params syncNodeConfigFromFile = withIOManager $ \iomgr -> do + severity <- BM.minSeverity . dncLoggingConfig $ syncNodeConfigFromFile trce <- configureLogging syncNodeConfigFromFile "db-sync-node" abortOnPanic <- hasAbortOnPanicEnv - startupReport trce abortOnPanic params + startupReport trce severity abortOnPanic params - runDbSync metricsSetters knownMigrations iomgr trce params syncNodeConfigFromFile abortOnPanic + runDbSync metricsSetters knownMigrations iomgr trce severity params syncNodeConfigFromFile abortOnPanic runDbSync :: MetricSetters -> [(Text, Text)] -> IOManager -> Trace IO Text -> + BM.Severity -> SyncNodeParams -> SyncNodeConfig -> -- Should abort on panic Bool -> IO () -runDbSync metricsSetters knownMigrations iomgr trce params syncNodeConfigFromFile abortOnPanic = do - let logCtx = initLogCtx "runDbSync" "Cardano.DbSync" +runDbSync metricsSetters knownMigrations iomgr trce severity params syncNodeConfigFromFile abortOnPanic = do + let logCtx = initLogCtx severity "runDbSync" "Cardano.DbSync" logInfoCtx trce $ logCtx {lcMessage = "Current sync options: " <> textShow syncOpts} -- Read the PG connection info @@ -128,10 +132,11 @@ runDbSync metricsSetters knownMigrations iomgr trce params syncNodeConfigFromFil -- For testing and debugging. whenJust (enpMaybeRollback params) $ \slotNo -> - void $ unsafeRollback trce (txOutConfigToTableType txOutConfig) pgConfig slotNo + void $ unsafeRollback trce severity (txOutConfigToTableType txOutConfig) pgConfig slotNo runSyncNode metricsSetters trce + severity iomgr connectionString ranMigrations @@ -160,6 +165,7 @@ runDbSync metricsSetters knownMigrations iomgr trce params syncNodeConfigFromFil runSyncNode :: MetricSetters -> Trace IO Text -> + BM.Severity -> IOManager -> ConnectionString -> -- | migrations were ran on startup @@ -170,8 +176,8 @@ runSyncNode :: SyncNodeParams -> SyncOptions -> IO () -runSyncNode metricsSetters trce iomgr dbConnString ranMigrations runMigrationFnc syncNodeConfigFromFile syncNodeParams syncOptions = do - let logCtx = initLogCtx "runSyncNode" "Cardano.DbSync" +runSyncNode metricsSetters trce severity iomgr dbConnString ranMigrations runMigrationFnc syncNodeConfigFromFile syncNodeParams syncOptions = do + let logCtx = initLogCtx severity "runSyncNode" "Cardano.DbSync" whenJust maybeLedgerDir $ \enpLedgerStateDir -> do createDirectoryIfMissing True (unLedgerStateDir enpLedgerStateDir) @@ -190,7 +196,7 @@ runSyncNode metricsSetters trce iomgr dbConnString ranMigrations runMigrationFnc runOrThrowIO $ runExceptT $ do genCfg <- readCardanoGenesisConfig syncNodeConfigFromFile isJsonbInSchema <- queryIsJsonbInSchema backend - logProtocolMagicId trce $ genesisProtocolMagicId genCfg + logProtocolMagicId trce severity $ genesisProtocolMagicId genCfg syncEnv <- ExceptT $ mkSyncEnvFromConfig @@ -228,7 +234,7 @@ runSyncNode metricsSetters trce iomgr dbConnString ranMigrations runMigrationFnc , runSyncNodeClient metricsSetters syncEnv iomgr trce threadChannels (enpSocketPath syncNodeParams) , runFetchOffChainPoolThread syncEnv , runFetchOffChainVoteThread syncEnv - , runLedgerStateWriteThread (getTrace syncEnv) (envLedgerEnv syncEnv) + , runLedgerStateWriteThread (getTrace syncEnv) severity (envLedgerEnv syncEnv) ] where useShelleyInit :: SyncNodeConfig -> Bool @@ -239,9 +245,9 @@ runSyncNode metricsSetters trce iomgr dbConnString ranMigrations runMigrationFnc removeJsonbFromSchemaConfig = ioRemoveJsonbFromSchema $ soptInsertOptions syncOptions maybeLedgerDir = enpMaybeLedgerStateDir syncNodeParams -logProtocolMagicId :: Trace IO Text -> Crypto.ProtocolMagicId -> ExceptT SyncNodeError IO () -logProtocolMagicId tracer pm = do - let logCtx = initLogCtx "logProtocolMagicId" "Cardano.DbSync" +logProtocolMagicId :: Trace IO Text -> BM.Severity -> Crypto.ProtocolMagicId -> ExceptT SyncNodeError IO () +logProtocolMagicId tracer severity pm = do + let logCtx = initLogCtx severity "logProtocolMagicId" "Cardano.DbSync" liftIO . logInfoCtx tracer $ logCtx @@ -314,9 +320,9 @@ extractSyncOptions snp aop snc = forceTxIn' = forceTxIn . sioTxOut . dncInsertOptions $ snc ioTxOutTableType' = txOutConfigToTableType $ sioTxOut $ dncInsertOptions snc -startupReport :: Trace IO Text -> Bool -> SyncNodeParams -> IO () -startupReport trce aop params = do - let logCtx = initLogCtx "runSyncNode" "Cardano.DbSync" +startupReport :: Trace IO Text -> BM.Severity -> Bool -> SyncNodeParams -> IO () +startupReport trce severity aop params = do + let logCtx = initLogCtx severity "runSyncNode" "Cardano.DbSync" logInfoCtx trce $ logCtx {lcMessage = mconcat ["Version number: ", Text.pack (showVersion version)]} logInfoCtx trce $ logCtx {lcMessage = mconcat ["Git hash: ", Db.gitRev]} logInfoCtx trce $ logCtx {lcMessage = mconcat ["Enviroment variable DbSyncAbortOnPanic: ", textShow aop]} diff --git a/cardano-db-sync/src/Cardano/DbSync/Api.hs b/cardano-db-sync/src/Cardano/DbSync/Api.hs index a37b135da..f551c43ff 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Api.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Api.hs @@ -51,10 +51,13 @@ module Cardano.DbSync.Api ( convertToPoint, ) where +import qualified Cardano.BM.Configuration.Model as BM +import qualified Cardano.BM.Data.Severity as BM import Cardano.BM.Trace (Trace) import qualified Cardano.Chain.Genesis as Byron import Cardano.Crypto.ProtocolMagic (ProtocolMagicId (..)) import qualified Cardano.Db as DB +import Cardano.DbSync.Api.Functions (getSeverity) import Cardano.DbSync.Api.Types import Cardano.DbSync.Cache.Types (CacheCapacity (..), newEmptyCache, useNoCache) import Cardano.DbSync.Config.Cardano @@ -101,10 +104,11 @@ import Ouroboros.Network.Magic (NetworkMagic (..)) import qualified Ouroboros.Network.Point as Point setConsistentLevel :: SyncEnv -> ConsistentLevel -> IO () -setConsistentLevel env cst = do - let logCtx = initLogCtx "setConsistentLevel" "Cardano.DbSync.Api" - logInfoCtx (getTrace env) $ logCtx {lcMessage = "Setting ConsistencyLevel to " <> textShow cst} - atomically $ writeTVar (envConsistentLevel env) cst +setConsistentLevel syncEnv cst = do + severity <- getSeverity syncEnv + let logCtx = initLogCtx severity "setConsistentLevel" "Cardano.DbSync.Api" + logInfoCtx (getTrace syncEnv) $ logCtx {lcMessage = "Setting ConsistencyLevel to " <> textShow cst} + atomically $ writeTVar (envConsistentLevel syncEnv) cst getConsistentLevel :: SyncEnv -> IO ConsistentLevel getConsistentLevel env = @@ -159,13 +163,14 @@ getRanIndexes env = do readTVarIO $ envIndexes env runIndexMigrations :: SyncEnv -> IO () -runIndexMigrations env = do - let logCtx = initLogCtx "runIndexMigrations" "Cardano.DbSync.Api" - haveRan <- readTVarIO $ envIndexes env +runIndexMigrations syncEnv = do + severity <- getSeverity syncEnv + let logCtx = initLogCtx severity "runIndexMigrations" "Cardano.DbSync.Api" + haveRan <- readTVarIO $ envIndexes syncEnv unless haveRan $ do - envRunDelayedMigration env DB.Indexes - logInfoCtx (getTrace env) $ logCtx {lcMessage = "Indexes were created"} - atomically $ writeTVar (envIndexes env) True + envRunDelayedMigration syncEnv DB.Indexes + logInfoCtx (getTrace syncEnv) $ logCtx {lcMessage = "Indexes were created"} + atomically $ writeTVar (envIndexes syncEnv) True initPruneConsumeMigration :: Bool -> Bool -> Bool -> Bool -> DB.PruneConsumeMigration initPruneConsumeMigration consumed pruneTxOut bootstrap forceTxIn' = @@ -180,8 +185,9 @@ getPruneConsume = soptPruneConsumeMigration . envOptions runExtraMigrationsMaybe :: SyncEnv -> IO () runExtraMigrationsMaybe syncEnv = do + severity <- getSeverity syncEnv let pcm = getPruneConsume syncEnv - logCtx = initLogCtx "runExtraMigrationsMaybe" "Cardano.DbSync.Api" + logCtx = initLogCtx severity "runExtraMigrationsMaybe" "Cardano.DbSync.Api" txOutTableType = getTxOutTableType syncEnv logInfoCtx (getTrace syncEnv) $ logCtx {lcMessage = "runExtraMigrationsMaybe: " <> textShow pcm} DB.runDbIohkNoLogging (envBackend syncEnv) $ @@ -355,7 +361,8 @@ mkSyncEnv :: RunMigration -> IO SyncEnv mkSyncEnv trce backend connectionString syncOptions protoInfo nw nwMagic systemStart syncNodeConfigFromFile syncNP ranMigrations runMigrationFnc = do - let logCtx = initLogCtx "mkSyncEnv" "Cardano.DbSync.Api" + severity <- BM.minSeverity . dncLoggingConfig $ syncNodeConfigFromFile + let logCtx = initLogCtx severity "mkSyncEnv" "Cardano.DbSync.Api" dbCNamesVar <- newTVarIO =<< dbConstraintNamesExists backend cache <- if soptCache syncOptions @@ -371,7 +378,7 @@ mkSyncEnv trce backend connectionString syncOptions protoInfo nw nwMagic systemS consistentLevelVar <- newTVarIO Unchecked fixDataVar <- newTVarIO $ if ranMigrations then DataFixRan else NoneFixRan indexesVar <- newTVarIO $ enpForceIndexes syncNP - bts <- getBootstrapInProgress trce (isTxOutConsumedBootstrap' syncNodeConfigFromFile) backend + bts <- getBootstrapInProgress trce severity (isTxOutConsumedBootstrap' syncNodeConfigFromFile) backend bootstrapVar <- newTVarIO bts -- Offline Pool + Anchor queues opwq <- newTBQueueIO 1000 @@ -543,11 +550,12 @@ getMaxRollbacks = maxRollbacks . configSecurityParam . pInfoConfig getBootstrapInProgress :: Trace IO Text -> + BM.Severity -> Bool -> SqlBackend -> IO Bool -getBootstrapInProgress trce bootstrapFlag sqlBackend = do - let logCtx = initLogCtx "getBootstrapInProgress" "Cardano.DbSync.Api" +getBootstrapInProgress trce severity bootstrapFlag sqlBackend = do + let logCtx = initLogCtx severity "getBootstrapInProgress" "Cardano.DbSync.Api" DB.runDbIohkNoLogging sqlBackend $ do ems <- DB.queryAllExtraMigrations let btsState = DB.bootstrapState ems diff --git a/cardano-db-sync/src/Cardano/DbSync/Api/Functions.hs b/cardano-db-sync/src/Cardano/DbSync/Api/Functions.hs new file mode 100644 index 000000000..2db1d12ce --- /dev/null +++ b/cardano-db-sync/src/Cardano/DbSync/Api/Functions.hs @@ -0,0 +1,11 @@ +module Cardano.DbSync.Api.Functions ( + getSeverity, +) where + +import qualified Cardano.BM.Configuration.Model as BM +import qualified Cardano.BM.Data.Severity as BM +import Cardano.DbSync.Api.Types (SyncEnv (..)) +import Cardano.DbSync.Config.Types (SyncNodeConfig (..)) + +getSeverity :: SyncEnv -> IO BM.Severity +getSeverity = BM.minSeverity . dncLoggingConfig . envSyncNodeConfig diff --git a/cardano-db-sync/src/Cardano/DbSync/Api/Ledger.hs b/cardano-db-sync/src/Cardano/DbSync/Api/Ledger.hs index f3433bea1..474a922f2 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Api/Ledger.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Api/Ledger.hs @@ -8,6 +8,7 @@ module Cardano.DbSync.Api.Ledger where import qualified Cardano.Db as DB import Cardano.DbSync.Api +import Cardano.DbSync.Api.Functions (getSeverity) import Cardano.DbSync.Api.Types import Cardano.DbSync.Cache (queryTxIdWithCache) import Cardano.DbSync.Era.Shelley.Generic.Tx.Babbage (fromTxOut) @@ -61,6 +62,8 @@ migrateBootstrapUTxO :: SyncEnv -> ExceptT SyncNodeError (ReaderT SqlBackend m) () migrateBootstrapUTxO syncEnv = do + severity <- liftIO $ getSeverity syncEnv + let logCtx = initLogCtx severity "migrateBootstrapUTxO" "Cardano.DbSync.Api.Ledger" case envLedgerEnv syncEnv of HasLedger lenv -> do liftIO $ logInfoCtx trce logCtx {lcMessage = "Starting UTxO bootstrap migration"} @@ -77,16 +80,17 @@ migrateBootstrapUTxO syncEnv = do NoLedger _ -> liftIO $ logWarningCtx trce $ logCtx {lcMessage = "Tried to bootstrap, but ledger state is not enabled. Please stop db-sync and restart without --disable-ledger-state"} where - logCtx = initLogCtx "migrateBootstrapUTxO" "Cardano.DbSync.Api.Ledger" trce = getTrace syncEnv storeUTxOFromLedger :: (MonadBaseControl IO m, MonadIO m) => SyncEnv -> ExtLedgerState CardanoBlock -> ExceptT SyncNodeError (ReaderT SqlBackend m) () -storeUTxOFromLedger env st = case ledgerState st of - LedgerStateBabbage bts -> storeUTxO env (getUTxO bts) - LedgerStateConway stc -> storeUTxO env (getUTxO stc) - _otherwise -> liftIO $ logErrorCtx trce logCtx {lcMessage = "storeUTxOFromLedger is only supported after Babbage"} +storeUTxOFromLedger env st = do + severity <- liftIO $ getSeverity env + let logCtx = initLogCtx severity "storeUTxOFromLedger" "Cardano.DbSync.Api.Ledger" + case ledgerState st of + LedgerStateBabbage bts -> storeUTxO env (getUTxO bts) + LedgerStateConway stc -> storeUTxO env (getUTxO stc) + _otherwise -> liftIO $ logErrorCtx trce logCtx {lcMessage = "storeUTxOFromLedger is only supported after Babbage"} where - logCtx = initLogCtx "storeUTxOFromLedger" "Cardano.DbSync.Api.Ledger" trce = getTrace env getUTxO st' = unUTxO $ Consensus.shelleyLedgerState st' ^. (nesEsL . esLStateL . lsUTxOStateL . utxosUtxoL) @@ -109,6 +113,8 @@ storeUTxO :: Map (TxIn StandardCrypto) (BabbageTxOut era) -> ExceptT SyncNodeError (ReaderT SqlBackend m) () storeUTxO env mp = do + severity <- liftIO $ getSeverity env + let logCtx = initLogCtx severity "storeUTxO" "Cardano.DbSync.Api.Ledger" liftIO $ logInfoCtx trce $ logCtx @@ -122,7 +128,6 @@ storeUTxO env mp = do } mapM_ (storePage env pagePerc) . zip [0 ..] . chunksOf pageSize . Map.toList $ mp where - logCtx = initLogCtx "storeUTxO" "Cardano.DbSync.Api.Ledger" trce = getTrace env npages = size `div` pageSize pagePerc :: Float = if npages == 0 then 100.0 else 100.0 / fromIntegral npages @@ -144,6 +149,8 @@ storePage :: (Int, [(TxIn StandardCrypto, BabbageTxOut era)]) -> ExceptT SyncNodeError (ReaderT SqlBackend m) () storePage syncEnv percQuantum (n, ls) = do + severity <- liftIO $ getSeverity syncEnv + let logCtx = initLogCtx severity "storePage" "Cardano.DbSync.Api.Ledger" when (n `mod` 10 == 0) $ liftIO $ logInfoCtx trce $ logCtx {lcMessage = "Bootstrap in progress " <> prc <> "%"} txOuts <- mapM (prepareTxOut syncEnv) ls txOutIds <- @@ -151,7 +158,6 @@ storePage syncEnv percQuantum (n, ls) = do let maTxOuts = concatMap (mkmaTxOuts txOutTableType) $ zip txOutIds (snd <$> txOuts) void . lift $ DB.insertManyMaTxOut maTxOuts where - logCtx = initLogCtx "storePage" "Cardano.DbSync.Api.Ledger" txOutTableType = getTxOutTableType syncEnv trce = getTrace syncEnv prc = Text.pack $ showGFloat (Just 1) (max 0 $ min 100.0 (fromIntegral n * percQuantum)) "" @@ -171,10 +177,11 @@ prepareTxOut :: (TxIn StandardCrypto, BabbageTxOut era) -> ExceptT SyncNodeError (ReaderT SqlBackend m) (ExtendedTxOut, [MissingMaTxOut]) prepareTxOut syncEnv (TxIn txIntxId (TxIx index), txOut) = do + severity <- liftIO $ getSeverity syncEnv let txHashByteString = Generic.safeHashToByteString $ unTxId txIntxId let genTxOut = fromTxOut index txOut txId <- liftLookupFail "prepareTxOut" $ queryTxIdWithCache cache txIntxId - insertTxOut trce cache iopts (txId, txHashByteString) genTxOut + insertTxOut trce severity cache iopts (txId, txHashByteString) genTxOut where trce = getTrace syncEnv cache = envCache syncEnv diff --git a/cardano-db-sync/src/Cardano/DbSync/Api/Types.hs b/cardano-db-sync/src/Cardano/DbSync/Api/Types.hs index ac7e85666..4b783302d 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Api/Types.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Api/Types.hs @@ -15,7 +15,7 @@ module Cardano.DbSync.Api.Types ( import qualified Cardano.Db as DB import Cardano.DbSync.Cache.Types (CacheStatus) -import Cardano.DbSync.Config.Types (SyncNodeConfig) +import Cardano.DbSync.Config.Types (SyncNodeConfig (..)) import Cardano.DbSync.Ledger.Types (HasLedgerEnv) import Cardano.DbSync.LocalStateQuery (NoLedgerEnv) import Cardano.DbSync.Types ( diff --git a/cardano-db-sync/src/Cardano/DbSync/Cache.hs b/cardano-db-sync/src/Cardano/DbSync/Cache.hs index 73e14b3fd..237f95026 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Cache.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Cache.hs @@ -28,6 +28,7 @@ module Cardano.DbSync.Cache ( getCacheStatistics, ) where +import qualified Cardano.BM.Data.Severity as BM import Cardano.BM.Trace import qualified Cardano.Db as DB import Cardano.DbSync.Cache.Epoch (rollbackMapEpochInCache) @@ -275,13 +276,14 @@ queryPoolKeyOrInsert :: (MonadBaseControl IO m, MonadIO m) => Text -> Trace IO Text -> + BM.Severity -> CacheStatus -> CacheAction -> Bool -> PoolKeyHash -> ReaderT SqlBackend m DB.PoolHashId -queryPoolKeyOrInsert txt trce cache cacheUA logsWarning hsh = do - let logCtx = initLogCtx "queryPoolKeyOrInsert" "Cardano.DbSync.Cache" +queryPoolKeyOrInsert txt trce severity cache cacheUA logsWarning hsh = do + let logCtx = initLogCtx severity "queryPoolKeyOrInsert" "Cardano.DbSync.Cache" pk <- queryPoolKeyWithCache cache cacheUA hsh case pk of Right poolHashId -> pure poolHashId @@ -306,12 +308,13 @@ queryPoolKeyOrInsert txt trce cache cacheUA logsWarning hsh = do queryMAWithCache :: MonadIO m => Trace IO Text -> + BM.Severity -> CacheStatus -> PolicyID StandardCrypto -> AssetName -> ReaderT SqlBackend m (Either (ByteString, ByteString) DB.MultiAssetId) -queryMAWithCache trce cache policyId asset = do - let logCtx = initLogCtx "queryMAWithCache" "Cardano.DbSync.Cache" +queryMAWithCache trce severity cache policyId asset = do + let logCtx = initLogCtx severity "queryMAWithCache" "Cardano.DbSync.Cache" case cache of NoCache -> do let !policyBs = Generic.unScriptHash $ policyID policyId diff --git a/cardano-db-sync/src/Cardano/DbSync/Database.hs b/cardano-db-sync/src/Cardano/DbSync/Database.hs index 807f4efe8..5f08fa084 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Database.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Database.hs @@ -12,6 +12,7 @@ module Cardano.DbSync.Database ( ) where import Cardano.DbSync.Api +import Cardano.DbSync.Api.Functions (getSeverity) import Cardano.DbSync.Api.Types (ConsistentLevel (..), LedgerEnv (..), SyncEnv (..)) import Cardano.DbSync.DbAction import Cardano.DbSync.Default @@ -44,14 +45,16 @@ runDbThread :: ThreadChannels -> IO () runDbThread syncEnv metricsSetters queue = do - let logCtx = initLogCtx "runDbThread" "DbSync.Database" + severity <- liftIO $ getSeverity syncEnv + let logCtx = initLogCtx severity "runDbThread" "DbSync.Database" logInfoCtx trce $ logCtx {lcMessage = "Running DB thread"} logExceptionCtx trce logCtx loop logInfoCtx trce $ logCtx {lcMessage = "Shutting down DB thread"} where trce = getTrace syncEnv loop = do - let logCtx = initLogCtx "runDbThread Loop" "DbSync.Database" + severity <- liftIO $ getSeverity syncEnv + let logCtx = initLogCtx severity "runDbThread Loop" "DbSync.Database" xs <- blockingFlushDbActionQueue queue when (length xs > 1) $ do @@ -126,7 +129,8 @@ rollbackLedger :: SyncEnv -> CardanoPoint -> IO (Maybe [CardanoPoint]) rollbackLedger syncEnv point = case envLedgerEnv syncEnv of HasLedger hle -> do - mst <- loadLedgerAtPoint hle point + severity <- liftIO $ getSeverity syncEnv + mst <- loadLedgerAtPoint hle severity point case mst of Right st -> do let statePoint = headerStatePoint $ headerState $ clsState st diff --git a/cardano-db-sync/src/Cardano/DbSync/Default.hs b/cardano-db-sync/src/Cardano/DbSync/Default.hs index 75b8db383..54908f975 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Default.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Default.hs @@ -13,6 +13,7 @@ module Cardano.DbSync.Default ( import qualified Cardano.Db as DB import Cardano.DbSync.Api +import Cardano.DbSync.Api.Functions (getSeverity) import Cardano.DbSync.Api.Ledger import Cardano.DbSync.Api.Types (ConsistentLevel (..), InsertOptions (..), LedgerEnv (..), SyncEnv (..), SyncOptions (..)) import Cardano.DbSync.Epoch (epochHandler) @@ -64,6 +65,8 @@ applyAndInsertBlockMaybe :: CardanoBlock -> ExceptT SyncNodeError (ReaderT SqlBackend (LoggingT IO)) () applyAndInsertBlockMaybe syncEnv tracer cblk = do + severity <- liftIO $ getSeverity syncEnv + let logCtx = initLogCtx severity "applyAndInsertBlockMaybe" "Cardano.DbSync.Default" bl <- liftIO $ isConsistent syncEnv (!applyRes, !tookSnapshot) <- liftIO (mkApplyResult bl) if bl @@ -99,13 +102,13 @@ applyAndInsertBlockMaybe syncEnv tracer cblk = do liftIO $ logInfoCtx tracer $ logCtx {lcMessage = "Reached " <> textShow epochNo} _ -> pure () where - logCtx = initLogCtx "applyAndInsertBlockMaybe" "Cardano.DbSync.Default" mkApplyResult :: Bool -> IO (ApplyResult, Bool) mkApplyResult isCons = do + severity <- getSeverity syncEnv case envLedgerEnv syncEnv of - HasLedger hle -> applyBlockAndSnapshot hle cblk isCons + HasLedger hle -> applyBlockAndSnapshot hle severity cblk isCons NoLedger nle -> do - slotDetails <- getSlotDetailsNode nle (cardanoBlockSlotNo cblk) + slotDetails <- getSlotDetailsNode severity nle (cardanoBlockSlotNo cblk) pure (defaultApplyResult slotDetails, False) getAdaPots :: ApplyResult -> Maybe (Shelley.AdaPots, SlotNo, EpochNo) diff --git a/cardano-db-sync/src/Cardano/DbSync/Epoch.hs b/cardano-db-sync/src/Cardano/DbSync/Epoch.hs index 9e512d318..05e76ae9c 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Epoch.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Epoch.hs @@ -11,6 +11,7 @@ import Cardano.BM.Trace (Trace, logError) import qualified Cardano.Chain.Block as Byron import qualified Cardano.Db as DB import Cardano.DbSync.Api (getTrace) +import Cardano.DbSync.Api.Functions (getSeverity) import Cardano.DbSync.Api.Types (SyncEnv) import Cardano.DbSync.Cache.Epoch (readEpochBlockDiffFromCache, readLastMapEpochFromCache, writeToMapEpochCache) import Cardano.DbSync.Cache.Types (CacheStatus (..), EpochBlockDiff (..)) @@ -176,8 +177,9 @@ updateEpochWhenSyncing :: Bool -> ReaderT SqlBackend m (Either SyncNodeError ()) updateEpochWhenSyncing syncEnv cache mEpochBlockDiff mLastMapEpochFromCache epochNo isBoundaryBlock = do + severity <- liftIO $ getSeverity syncEnv let trce = getTrace syncEnv - logCtx = initLogCtx "updateEpochWhenSyncing" "Cardano.DbSync.Era.Universal.Epoch" + logCtx = initLogCtx severity "updateEpochWhenSyncing" "Cardano.DbSync.Era.Universal.Epoch" isFirstEpoch = epochNo == 0 -- count boundary block in the first epoch additionalBlockCount = if isBoundaryBlock && isFirstEpoch then 1 else 0 @@ -255,8 +257,9 @@ makeEpochWithDBQuery :: Text -> ReaderT SqlBackend m (Either SyncNodeError ()) makeEpochWithDBQuery syncEnv cache mInitEpoch epochNo callSiteMsg = do + severity <- liftIO $ getSeverity syncEnv let trce = getTrace syncEnv - logCtx = initLogCtx "makeEpochWithDBQuery" "Cardano.DbSync.Era.Universal.Epoch" + logCtx = initLogCtx severity "makeEpochWithDBQuery" "Cardano.DbSync.Era.Universal.Epoch" calcEpoch <- DB.queryCalcEpochEntry epochNo mEpochID <- DB.queryForEpochId epochNo let epochInitOrCalc = fromMaybe calcEpoch mInitEpoch diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Byron/Genesis.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Byron/Genesis.hs index 2b621b456..fe40e1445 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Byron/Genesis.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Byron/Genesis.hs @@ -11,6 +11,7 @@ module Cardano.DbSync.Era.Byron.Genesis ( ) where import Cardano.BM.Trace (Trace) +import qualified Cardano.BM.Tracing as BM import Cardano.Binary (serialize') import qualified Cardano.Chain.Common as Byron import qualified Cardano.Chain.Genesis as Byron @@ -20,6 +21,7 @@ import qualified Cardano.Db as DB import qualified Cardano.Db.Schema.Core.TxOut as C import qualified Cardano.Db.Schema.Variant.TxOut as V import Cardano.DbSync.Api +import Cardano.DbSync.Api.Functions (getSeverity) import Cardano.DbSync.Api.Types (SyncEnv (..)) import Cardano.DbSync.Config.Types import qualified Cardano.DbSync.Era.Byron.Util as Byron @@ -47,81 +49,81 @@ insertValidateGenesisDist :: insertValidateGenesisDist syncEnv (NetworkName networkName) cfg = do -- Setting this to True will log all 'Persistent' operations which is great -- for debugging, but otherwise *way* too chatty. - if False - then newExceptT $ DB.runDbIohkLogging (envBackend syncEnv) tracer insertAction - else newExceptT $ DB.runDbIohkNoLogging (envBackend syncEnv) insertAction - where - logCtx = initLogCtx "insertValidateGenesisDist" "Cardano.DbSync.Era.Byron.Genesis" - - tracer = getTrace syncEnv + severity <- liftIO $ getSeverity syncEnv + let logCtx = initLogCtx severity "insertValidateGenesisDist" "Cardano.DbSync.Era.Byron.Genesis" + tracer = getTrace syncEnv + insertAction :: (MonadBaseControl IO m, MonadIO m) => ReaderT SqlBackend m (Either SyncNodeError ()) + insertAction = do + disInOut <- liftIO $ getDisableInOutState syncEnv + let prunes = getPrunes syncEnv - insertAction :: (MonadBaseControl IO m, MonadIO m) => ReaderT SqlBackend m (Either SyncNodeError ()) - insertAction = do - disInOut <- liftIO $ getDisableInOutState syncEnv - let prunes = getPrunes syncEnv + ebid <- DB.queryBlockId (configGenesisHash cfg) + case ebid of + Right bid -> validateGenesisDistribution syncEnv prunes disInOut tracer networkName cfg bid + Left _ -> + runExceptT $ do + liftIO $ logInfoCtx tracer $ logCtx {lcMessage = "Inserting Byron Genesis distribution"} + count <- lift DB.queryBlockCount + when (not disInOut && count > 0) $ do + liftIO $ logErrorCtx tracer $ logCtx {lcMessage = "Genesis data mismatch"} + dbSyncNodeError "insertValidateGenesisDist: Genesis data mismatch." + void . lift $ + DB.insertMeta $ + DB.Meta + { DB.metaStartTime = Byron.configStartTime cfg + , DB.metaNetworkName = networkName + , DB.metaVersion = textShow version + } - ebid <- DB.queryBlockId (configGenesisHash cfg) - case ebid of - Right bid -> validateGenesisDistribution syncEnv prunes disInOut tracer networkName cfg bid - Left _ -> - runExceptT $ do - liftIO $ logInfoCtx tracer $ logCtx {lcMessage = "Inserting Byron Genesis distribution"} - count <- lift DB.queryBlockCount - when (not disInOut && count > 0) $ do - liftIO $ logErrorCtx tracer $ logCtx {lcMessage = "Genesis data mismatch"} - dbSyncNodeError "insertValidateGenesisDist: Genesis data mismatch." - void . lift $ - DB.insertMeta $ - DB.Meta - { DB.metaStartTime = Byron.configStartTime cfg - , DB.metaNetworkName = networkName - , DB.metaVersion = textShow version - } - - -- Insert an 'artificial' Genesis block (with a genesis specific slot leader). We - -- need this block to attach the genesis distribution transactions to. - -- It would be nice to not need this artificial block, but that would - -- require plumbing the Genesis.Config into 'insertByronBlockOrEBB' - -- which would be a pain in the neck. - slid <- - lift . DB.insertSlotLeader $ - DB.SlotLeader - { DB.slotLeaderHash = BS.take 28 $ configGenesisHash cfg - , DB.slotLeaderPoolHashId = Nothing - , DB.slotLeaderDescription = "Genesis slot leader" - } - bid <- - lift . DB.insertBlock $ - DB.Block - { DB.blockHash = configGenesisHash cfg - , DB.blockEpochNo = Nothing - , DB.blockSlotNo = Nothing - , DB.blockEpochSlotNo = Nothing - , DB.blockBlockNo = Nothing - , DB.blockPreviousId = Nothing - , DB.blockSlotLeaderId = slid - , DB.blockSize = 0 - , DB.blockTime = Byron.configStartTime cfg - , DB.blockTxCount = fromIntegral (length $ genesisTxos cfg) - , -- Genesis block does not have a protocol version, so set this to '0'. - DB.blockProtoMajor = 0 - , DB.blockProtoMinor = 0 - , -- Shelley specific - DB.blockVrfKey = Nothing - , DB.blockOpCert = Nothing - , DB.blockOpCertCounter = Nothing + -- Insert an 'artificial' Genesis block (with a genesis specific slot leader). We + -- need this block to attach the genesis distribution transactions to. + -- It would be nice to not need this artificial block, but that would + -- require plumbing the Genesis.Config into 'insertByronBlockOrEBB' + -- which would be a pain in the neck. + slid <- + lift . DB.insertSlotLeader $ + DB.SlotLeader + { DB.slotLeaderHash = BS.take 28 $ configGenesisHash cfg + , DB.slotLeaderPoolHashId = Nothing + , DB.slotLeaderDescription = "Genesis slot leader" + } + bid <- + lift . DB.insertBlock $ + DB.Block + { DB.blockHash = configGenesisHash cfg + , DB.blockEpochNo = Nothing + , DB.blockSlotNo = Nothing + , DB.blockEpochSlotNo = Nothing + , DB.blockBlockNo = Nothing + , DB.blockPreviousId = Nothing + , DB.blockSlotLeaderId = slid + , DB.blockSize = 0 + , DB.blockTime = Byron.configStartTime cfg + , DB.blockTxCount = fromIntegral (length $ genesisTxos cfg) + , -- Genesis block does not have a protocol version, so set this to '0'. + DB.blockProtoMajor = 0 + , DB.blockProtoMinor = 0 + , -- Shelley specific + DB.blockVrfKey = Nothing + , DB.blockOpCert = Nothing + , DB.blockOpCertCounter = Nothing + } + mapM_ (insertTxOutsByron syncEnv disInOut bid) $ genesisTxos cfg + liftIO . logInfoCtx tracer $ + logCtx + { lcMessage = + "Initial genesis distribution populated. Hash " + <> renderByteArray (configGenesisHash cfg) } - mapM_ (insertTxOutsByron syncEnv disInOut bid) $ genesisTxos cfg - liftIO . logInfoCtx tracer $ - logCtx - { lcMessage = - "Initial genesis distribution populated. Hash " - <> renderByteArray (configGenesisHash cfg) - } - supply <- lift $ DB.queryTotalSupply $ getTxOutTableType syncEnv - liftIO $ - logInfoCtx tracer $ - logCtx {lcMessage = "Total genesis supply of Ada: " <> DB.renderAda supply} + supply <- lift $ DB.queryTotalSupply $ getTxOutTableType syncEnv + liftIO $ + logInfoCtx tracer $ + logCtx {lcMessage = "Total genesis supply of Ada: " <> DB.renderAda supply} + case severity of + BM.Debug -> do + newExceptT $ DB.runDbIohkLogging (envBackend syncEnv) tracer insertAction + _otherwise -> + newExceptT $ DB.runDbIohkNoLogging (envBackend syncEnv) insertAction -- | Validate that the initial Genesis distribution in the DB matches the Genesis data. validateGenesisDistribution :: @@ -134,9 +136,10 @@ validateGenesisDistribution :: Byron.Config -> DB.BlockId -> ReaderT SqlBackend m (Either SyncNodeError ()) -validateGenesisDistribution syncEnv prunes disInOut tracer networkName cfg bid = +validateGenesisDistribution syncEnv prunes disInOut tracer networkName cfg bid = do + severity <- liftIO $ getSeverity syncEnv runExceptT $ do - let logCtx = initLogCtx "validateGenesisDistribution" "Cardano.DbSync.Era.Byron.Genesis" + let logCtx = initLogCtx severity "validateGenesisDistribution" "Cardano.DbSync.Era.Byron.Genesis" meta <- liftLookupFail "validateGenesisDistribution" DB.queryMeta when (DB.metaStartTime meta /= Byron.configStartTime cfg) $ diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Byron/Insert.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Byron/Insert.hs index ec7466fce..19118f5cc 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Byron/Insert.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Byron/Insert.hs @@ -23,6 +23,7 @@ import qualified Cardano.Db as DB import qualified Cardano.Db.Schema.Core.TxOut as C import qualified Cardano.Db.Schema.Variant.TxOut as V import Cardano.DbSync.Api +import Cardano.DbSync.Api.Functions (getSeverity) import Cardano.DbSync.Api.Types (InsertOptions (..), SyncEnv (..), SyncOptions (..)) import Cardano.DbSync.Cache ( insertBlockAndCache, @@ -78,8 +79,9 @@ insertABOBBoundary :: SlotDetails -> ExceptT SyncNodeError (ReaderT SqlBackend m) () insertABOBBoundary syncEnv blk details = do + severity <- liftIO $ getSeverity syncEnv let tracer = getTrace syncEnv - logCtx = initLogCtx "insertABOBBoundary" "Cardano.DbSync.Era.Byron.Insert" + logCtx = initLogCtx severity "insertABOBBoundary" "Cardano.DbSync.Era.Byron.Insert" cache = envCache syncEnv -- Will not get called in the OBFT part of the Byron era. pbid <- queryPrevBlockWithCache "insertABOBBoundary" cache (Byron.ebbPrevHash blk) @@ -150,7 +152,8 @@ insertABlock :: SlotDetails -> ExceptT SyncNodeError (ReaderT SqlBackend m) () insertABlock syncEnv firstBlockOfEpoch blk details = do - let logCtx = initLogCtx "insertABlock" "Cardano.DbSync.Era.Byron.Insert" + severity <- liftIO $ getSeverity syncEnv + let logCtx = initLogCtx severity "insertABlock" "Cardano.DbSync.Era.Byron.Insert" pbid <- queryPrevBlockWithCache "insertABlock" cache (Byron.blockPreviousHash blk) slid <- lift . DB.insertSlotLeader $ Byron.mkSlotLeader blk let txs = Byron.blockPayload blk diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Shelley/Genesis.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Shelley/Genesis.hs index 6c9c11539..8a7be1b8a 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Shelley/Genesis.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Shelley/Genesis.hs @@ -11,11 +11,13 @@ module Cardano.DbSync.Era.Shelley.Genesis ( insertValidateGenesisDist, ) where -import Cardano.BM.Trace (Trace, logError) +import qualified Cardano.BM.Data.Severity as BM +import Cardano.BM.Trace (Trace) import qualified Cardano.Db as DB import qualified Cardano.Db.Schema.Core.TxOut as C import qualified Cardano.Db.Schema.Variant.TxOut as V import Cardano.DbSync.Api +import Cardano.DbSync.Api.Functions (getSeverity) import Cardano.DbSync.Api.Types (InsertOptions (..), SyncEnv (..), SyncOptions (..)) import Cardano.DbSync.Cache (tryUpdateCacheTx) import Cardano.DbSync.Cache.Types (CacheStatus (..), useNoCache) @@ -26,7 +28,7 @@ import Cardano.DbSync.Era.Universal.Insert.Pool (insertPoolRegister) import Cardano.DbSync.Era.Util (liftLookupFail) import Cardano.DbSync.Error import Cardano.DbSync.Util -import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logInfoCtx) +import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logErrorCtx, logInfoCtx) import Cardano.Ledger.Address (serialiseAddr) import qualified Cardano.Ledger.Coin as Ledger import qualified Cardano.Ledger.Core as Core @@ -66,15 +68,18 @@ insertValidateGenesisDist :: Bool -> ExceptT SyncNodeError IO () insertValidateGenesisDist syncEnv networkName cfg shelleyInitiation = do + severity <- liftIO $ getSeverity syncEnv let prunes = getPrunes syncEnv + logCtx = initLogCtx severity "insertValidateGenesisDist" "Cardano.DbSync.Era.Shelley.Genesis" -- Setting this to True will log all 'Persistent' operations which is great -- for debugging, but otherwise *way* too chatty. when (not shelleyInitiation && (hasInitialFunds || hasStakes)) $ do - liftIO $ logError tracer $ show SNErrIgnoreShelleyInitiation + liftIO $ logErrorCtx tracer $ logCtx {lcMessage = show SNErrIgnoreShelleyInitiation} throwError SNErrIgnoreShelleyInitiation - if False - then newExceptT $ DB.runDbIohkLogging (envBackend syncEnv) tracer (insertAction prunes) - else newExceptT $ DB.runDbIohkNoLogging (envBackend syncEnv) (insertAction prunes) + -- TODO cmdv + case severity of + BM.Debug -> newExceptT $ DB.runDbIohkLogging (envBackend syncEnv) tracer (insertAction prunes) + _otherwise -> newExceptT $ DB.runDbIohkNoLogging (envBackend syncEnv) (insertAction prunes) where tracer = getTrace syncEnv @@ -89,7 +94,8 @@ insertValidateGenesisDist syncEnv networkName cfg shelleyInitiation = do insertAction :: (MonadBaseControl IO m, MonadIO m) => Bool -> ReaderT SqlBackend m (Either SyncNodeError ()) insertAction prunes = do - let logCtx = initLogCtx "insertValidateGenesisDist" "Shelley" + severity <- liftIO $ getSeverity syncEnv + let logCtx = initLogCtx severity "insertValidateGenesisDist" "Cardano.DbSync.Era.Shelley.Genesis" ebid <- DB.queryBlockId (configGenesisHash cfg) case ebid of Right bid -> validateGenesisDistribution syncEnv prunes networkName cfg bid expectedTxCount @@ -159,7 +165,7 @@ insertValidateGenesisDist syncEnv networkName cfg shelleyInitiation = do liftIO . logInfoCtx tracer $ logCtx {lcMessage = "Initial genesis distribution populated. Hash " <> renderByteArray (configGenesisHash cfg)} when hasStakes $ - insertStaking tracer useNoCache bid cfg + insertStaking tracer severity useNoCache bid cfg -- | Validate that the initial Genesis distribution in the DB matches the Genesis data. validateGenesisDistribution :: @@ -172,7 +178,8 @@ validateGenesisDistribution :: Word64 -> ReaderT SqlBackend m (Either SyncNodeError ()) validateGenesisDistribution syncEnv prunes networkName cfg bid expectedTxCount = do - let logCtx = initLogCtx "validateGenesisDistribution" "Shelley" + severity <- liftIO $ getSeverity syncEnv + let logCtx = initLogCtx severity "validateGenesisDistribution" "Cardano.DbSync.Era.Shelley.Genesis" runExceptT $ do let tracer = getTrace syncEnv txOutTableType = getTxOutTableType syncEnv @@ -312,11 +319,12 @@ insertTxOuts syncEnv trce blkId (TxIn txInId _, txOut) = do insertStaking :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> CacheStatus -> DB.BlockId -> ShelleyGenesis StandardCrypto -> ExceptT SyncNodeError (ReaderT SqlBackend m) () -insertStaking tracer cache blkId genesis = do +insertStaking tracer severity cache blkId genesis = do -- All Genesis staking comes from an artifical transaction -- with a hash generated by hashing the address. txId <- @@ -344,7 +352,7 @@ insertStaking tracer cache blkId genesis = do forM_ stakes $ \(n, (keyStaking, keyPool)) -> do -- TODO: add initial deposits for genesis stake keys. insertStakeRegistration tracer cache (EpochNo 0) Nothing txId (2 * n) (Generic.annotateStakingCred network (KeyHashObj keyStaking)) - insertDelegation tracer cache network (EpochNo 0) 0 txId (2 * n + 1) Nothing (KeyHashObj keyStaking) keyPool + insertDelegation tracer severity cache network (EpochNo 0) 0 txId (2 * n + 1) Nothing (KeyHashObj keyStaking) keyPool -- ----------------------------------------------------------------------------- diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Adjust.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Adjust.hs index 703933baa..c2e971077 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Adjust.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Adjust.hs @@ -7,6 +7,7 @@ module Cardano.DbSync.Era.Universal.Adjust ( adjustEpochRewards, ) where +import qualified Cardano.BM.Data.Severity as DB import Cardano.BM.Trace (Trace) import qualified Cardano.Db as Db import Cardano.DbSync.Cache ( @@ -50,15 +51,16 @@ import Database.Esqueleto.Experimental ( adjustEpochRewards :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + DB.Severity -> Network -> CacheStatus -> EpochNo -> Generic.Rewards -> Set StakeCred -> ReaderT SqlBackend m () -adjustEpochRewards trce nw cache epochNo rwds creds = do +adjustEpochRewards trce severity nw cache epochNo rwds creds = do let eraIgnored = Map.toList $ Generic.unRewards rwds - logCtx = initLogCtx "adjustEpochRewards" "Cardano.DbSync.Era.Universal.Adjust" + logCtx = initLogCtx severity "adjustEpochRewards" "Cardano.DbSync.Era.Universal.Adjust" liftIO . logInfoCtx trce $ logCtx { lcEpochNo = Just (unEpochNo epochNo) diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Block.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Block.hs index af189605b..0749297d8 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Block.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Block.hs @@ -40,6 +40,7 @@ import qualified Cardano.Ledger.BaseTypes as Ledger import Cardano.Ledger.Keys import Cardano.Prelude +import Cardano.DbSync.Api.Functions (getSeverity) import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logDebugCtx, logInfoCtx) import Control.Monad.Trans.Control (MonadBaseControl) import Control.Monad.Trans.Except.Extra (newExceptT) @@ -65,7 +66,8 @@ insertBlockUniversal :: ApplyResult -> ReaderT SqlBackend m (Either SyncNodeError ()) insertBlockUniversal syncEnv isStartEventOrRollback withinTwoMins withinHalfHour blk details isMember applyResult = do - let logCtx = initLogCtx "insertBlockUniversal" "Cardano.DbSync.Era.Universal.Block" + severity <- liftIO $ getSeverity syncEnv + let logCtx = initLogCtx severity "insertBlockUniversal" "Cardano.DbSync.Era.Universal.Block" runExceptT $ do pbid <- case Generic.blkPreviousHash blk of Nothing -> liftLookupFail (renderErrorMessage (Generic.blkEra blk)) DB.queryGenesis -- this is for networks that fork from Byron on epoch 0. @@ -165,11 +167,11 @@ insertBlockUniversal syncEnv isStartEventOrRollback withinTwoMins withinHalfHour when (ioGov iopts && (withinHalfHour || unBlockNo (Generic.blkBlockNo blk) `mod` 10000 == 0)) . lift - $ insertOffChainVoteResults tracer (envOffChainVoteResultQueue syncEnv) + $ insertOffChainVoteResults tracer severity (envOffChainVoteResultQueue syncEnv) when (ioOffChainPoolData iopts && (withinHalfHour || unBlockNo (Generic.blkBlockNo blk) `mod` 10000 == 0)) . lift - $ insertOffChainPoolResults tracer (envOffChainPoolResultQueue syncEnv) + $ insertOffChainPoolResults tracer severity (envOffChainPoolResultQueue syncEnv) where iopts = getInsertOptions syncEnv diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Epoch.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Epoch.hs index cdd611a5f..9a21f3ff9 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Epoch.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Epoch.hs @@ -22,9 +22,11 @@ module Cardano.DbSync.Era.Universal.Epoch ( sumRewardTotal, ) where +import qualified Cardano.BM.Data.Severity as BM import Cardano.BM.Trace (Trace) import qualified Cardano.Db as DB import Cardano.DbSync.Api +import Cardano.DbSync.Api.Functions (getSeverity) import Cardano.DbSync.Api.Types (InsertOptions (..), SyncEnv (..)) import Cardano.DbSync.Cache (queryOrInsertStakeAddress, queryPoolKeyOrInsert) import Cardano.DbSync.Cache.Types (CacheAction (..), CacheStatus) @@ -71,6 +73,7 @@ insertOnNewEpoch :: Generic.NewEpoch -> ExceptT SyncNodeError (ReaderT SqlBackend m) () insertOnNewEpoch syncEnv blkId slotNo epochNo newEpoch = do + severity <- liftIO $ getSeverity syncEnv whenStrictJust (Generic.euProtoParams epochUpdate) $ \params -> lift $ insertEpochParam tracer blkId epochNo params (Generic.euNonce epochUpdate) whenStrictJust (Generic.neAdaPots newEpoch) $ \pots -> @@ -83,7 +86,7 @@ insertOnNewEpoch syncEnv blkId slotNo epochNo newEpoch = do pure (Ledger.psPoolDistr drepSnapshot) whenStrictJust (Generic.neEnacted newEpoch) $ \enactedSt -> do when (ioGov iopts) $ do - insertUpdateEnacted tracer cache blkId epochNo enactedSt + insertUpdateEnacted tracer severity cache blkId epochNo enactedSt whenStrictJust (Generic.nePoolDistr newEpoch) $ \(poolDistrDeleg, poolDistrNBlocks) -> when (ioPoolStats iopts) $ do let nothingMap = Map.fromList $ (,Nothing) <$> (Map.keys poolDistrNBlocks <> Map.keys spoVoting) @@ -201,6 +204,8 @@ insertStakeSlice :: ExceptT SyncNodeError (ReaderT SqlBackend m) () insertStakeSlice _ Generic.NoSlices = pure () insertStakeSlice syncEnv (Generic.Slice slice finalSlice) = do + severity <- liftIO $ getSeverity syncEnv + let logCtx = initLogCtx severity "insertStakeSlice" "Cardano.DbSync.Era.Universal.Epoch" insertEpochStake syncEnv network (Generic.sliceEpochNo slice) (Map.toList $ Generic.sliceDistr slice) when finalSlice $ do lift $ DB.updateSetComplete $ unEpochNo $ Generic.sliceEpochNo slice @@ -212,8 +217,6 @@ insertStakeSlice syncEnv (Generic.Slice slice finalSlice) = do tracer :: Trace IO Text tracer = getTrace syncEnv - logCtx = initLogCtx "insertStakeSlice" "Cardano.DbSync.Era.Universal.Epoch" - network :: Network network = getNetwork syncEnv @@ -225,21 +228,23 @@ insertEpochStake :: [(StakeCred, (Shelley.Coin, PoolKeyHash))] -> ExceptT SyncNodeError (ReaderT SqlBackend m) () insertEpochStake syncEnv nw epochNo stakeChunk = do + severity <- liftIO $ getSeverity syncEnv let cache = envCache syncEnv DB.ManualDbConstraints {..} <- liftIO $ readTVarIO $ envDbConstraints syncEnv - dbStakes <- mapM (mkStake cache) stakeChunk + dbStakes <- mapM (mkStake severity cache) stakeChunk let chunckDbStakes = splittRecordsEvery 100000 dbStakes -- minimising the bulk inserts into hundred thousand chunks to improve performance forM_ chunckDbStakes $ \dbs -> lift $ DB.insertManyEpochStakes dbConstraintEpochStake constraintNameEpochStake dbs where mkStake :: (MonadBaseControl IO m, MonadIO m) => + BM.Severity -> CacheStatus -> (StakeCred, (Shelley.Coin, PoolKeyHash)) -> ExceptT SyncNodeError (ReaderT SqlBackend m) DB.EpochStake - mkStake cache (saddr, (coin, pool)) = do + mkStake severity cache (saddr, (coin, pool)) = do saId <- lift $ queryOrInsertStakeAddress trce cache UpdateCacheStrong nw saddr - poolId <- lift $ queryPoolKeyOrInsert "insertEpochStake" trce cache UpdateCache (ioShelley iopts) pool + poolId <- lift $ queryPoolKeyOrInsert "insertEpochStake" trce severity cache UpdateCache (ioShelley iopts) pool pure $ DB.EpochStake { DB.epochStakeAddrId = saId @@ -261,27 +266,30 @@ insertRewards :: [(StakeCred, Set Generic.Reward)] -> ExceptT SyncNodeError (ReaderT SqlBackend m) () insertRewards syncEnv nw earnedEpoch spendableEpoch cache rewardsChunk = do + severity <- liftIO $ getSeverity syncEnv DB.ManualDbConstraints {..} <- liftIO $ readTVarIO $ envDbConstraints syncEnv - dbRewards <- concatMapM mkRewards rewardsChunk + dbRewards <- concatMapM (mkRewards severity) rewardsChunk let chunckDbRewards = splittRecordsEvery 100000 dbRewards -- minimising the bulk inserts into hundred thousand chunks to improve performance forM_ chunckDbRewards $ \rws -> lift $ DB.insertManyRewards dbConstraintRewards constraintNameReward rws where mkRewards :: (MonadBaseControl IO m, MonadIO m) => + BM.Severity -> (StakeCred, Set Generic.Reward) -> ExceptT SyncNodeError (ReaderT SqlBackend m) [DB.Reward] - mkRewards (saddr, rset) = do + mkRewards severity (saddr, rset) = do saId <- lift $ queryOrInsertStakeAddress trce cache UpdateCacheStrong nw saddr - mapM (prepareReward saId) (Set.toList rset) + mapM (prepareReward severity saId) (Set.toList rset) prepareReward :: (MonadBaseControl IO m, MonadIO m) => + BM.Severity -> DB.StakeAddressId -> Generic.Reward -> ExceptT SyncNodeError (ReaderT SqlBackend m) DB.Reward - prepareReward saId rwd = do - poolId <- queryPool (Generic.rewardPool rwd) + prepareReward severity saId rwd = do + poolId <- queryPool severity (Generic.rewardPool rwd) pure $ DB.Reward { DB.rewardAddrId = saId @@ -294,10 +302,11 @@ insertRewards syncEnv nw earnedEpoch spendableEpoch cache rewardsChunk = do queryPool :: (MonadBaseControl IO m, MonadIO m) => + BM.Severity -> PoolKeyHash -> ExceptT SyncNodeError (ReaderT SqlBackend m) DB.PoolHashId - queryPool poolHash = - lift (queryPoolKeyOrInsert "insertRewards" trce cache UpdateCache (ioShelley iopts) poolHash) + queryPool severity poolHash = + lift (queryPoolKeyOrInsert "insertRewards" trce severity cache UpdateCache (ioShelley iopts) poolHash) trce = getTrace syncEnv iopts = getInsertOptions syncEnv @@ -381,10 +390,11 @@ insertPoolDepositRefunds :: Generic.Rewards -> ExceptT SyncNodeError (ReaderT SqlBackend m) () insertPoolDepositRefunds syncEnv epochNo refunds = do + severity <- liftIO $ getSeverity syncEnv + let logCtx = initLogCtx severity "insertPoolDepositRefunds" "Cardano.DbSync.Era.Universal.Epoch" insertRewards syncEnv nw epochNo epochNo (envCache syncEnv) (Map.toList rwds) liftIO . logInfoCtx tracer $ logCtx {lcMessage = "Inserted " <> show (Generic.rewardsCount refunds) <> " deposit refund rewards"} where - logCtx = initLogCtx "insertPoolDepositRefunds" "Cardano.DbSync.Era.Universal.Epoch" tracer = getTrace syncEnv rwds = Generic.unRewards refunds nw = getNetwork syncEnv @@ -405,12 +415,13 @@ insertPoolStats :: Map PoolKeyHash Generic.PoolStats -> ReaderT SqlBackend m () insertPoolStats syncEnv epochNo mp = do - poolStats <- mapM preparePoolStat $ Map.toList mp + severity <- liftIO $ getSeverity syncEnv + poolStats <- mapM (preparePoolStat severity) $ Map.toList mp DB.insertManyPoolStat poolStats where - preparePoolStat :: (PoolKeyHash, Generic.PoolStats) -> ReaderT SqlBackend m DB.PoolStat - preparePoolStat (pkh, ps) = do - poolId <- queryPoolKeyOrInsert "insertPoolStats" trce cache UpdateCache True pkh + preparePoolStat :: BM.Severity -> (PoolKeyHash, Generic.PoolStats) -> ReaderT SqlBackend m DB.PoolStat + preparePoolStat severity (pkh, ps) = do + poolId <- queryPoolKeyOrInsert "insertPoolStats" trce severity cache UpdateCache True pkh pure DB.PoolStat { DB.poolStatPoolHashId = poolId diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Certificate.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Certificate.hs index b7cf7f8c9..9eb62a0fa 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Certificate.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Certificate.hs @@ -22,9 +22,11 @@ module Cardano.DbSync.Era.Universal.Insert.Certificate ( mkAdaPots, ) where +import qualified Cardano.BM.Data.Severity as BM import Cardano.BM.Trace (Trace) import qualified Cardano.Db as DB import Cardano.DbSync.Api +import Cardano.DbSync.Api.Functions (getSeverity) import Cardano.DbSync.Api.Types (InsertOptions (..), SyncEnv (..)) import Cardano.DbSync.Cache ( queryOrInsertRewardAccount, @@ -70,12 +72,14 @@ insertCertificate :: Map Word64 DB.RedeemerId -> Generic.TxCertificate -> ExceptT SyncNodeError (ReaderT SqlBackend m) () -insertCertificate syncEnv isMember mDeposits blkId txId epochNo slotNo redeemers (Generic.TxCertificate ridx idx cert) = +insertCertificate syncEnv isMember mDeposits blkId txId epochNo slotNo redeemers (Generic.TxCertificate ridx idx cert) = do + severity <- liftIO $ getSeverity syncEnv + let logCtx = initLogCtx severity "insertCertificate" "Cardano.DbSync.Era.Universal.Insert.Certificate" case cert of Left (ShelleyTxCertDelegCert deleg) -> - when (ioShelley iopts) $ insertDelegCert tracer cache mDeposits network txId idx mRedeemerId epochNo slotNo deleg + when (ioShelley iopts) $ insertDelegCert tracer severity cache mDeposits network txId idx mRedeemerId epochNo slotNo deleg Left (ShelleyTxCertPool pool) -> - when (ioShelley iopts) $ insertPoolCert tracer cache isMember mDeposits network epochNo blkId txId idx pool + when (ioShelley iopts) $ insertPoolCert tracer severity cache isMember mDeposits network epochNo blkId txId idx pool Left (ShelleyTxCertMir mir) -> when (ioShelley iopts) $ insertMirCert tracer cache network txId idx mir Left (ShelleyTxCertGenesisDeleg _gen) -> @@ -86,7 +90,7 @@ insertCertificate syncEnv isMember mDeposits blkId txId epochNo slotNo redeemers Right (ConwayTxCertDeleg deleg) -> insertConwayDelegCert syncEnv mDeposits txId idx mRedeemerId epochNo slotNo deleg Right (ConwayTxCertPool pool) -> - when (ioShelley iopts) $ insertPoolCert tracer cache isMember mDeposits network epochNo blkId txId idx pool + when (ioShelley iopts) $ insertPoolCert tracer severity cache isMember mDeposits network epochNo blkId txId idx pool Right (ConwayTxCertGov c) -> when (ioGov iopts) $ case c of ConwayRegDRep cred coin anchor -> @@ -100,7 +104,6 @@ insertCertificate syncEnv isMember mDeposits blkId txId epochNo slotNo redeemers ConwayUpdateDRep cred anchor -> lift $ insertDrepRegistration blkId txId idx cred Nothing (strictMaybeToMaybe anchor) where - logCtx = initLogCtx "insertCertificate" "Cardano.DbSync.Era.Universal.Insert.Certificate" tracer = getTrace syncEnv cache = envCache syncEnv iopts = getInsertOptions syncEnv @@ -110,6 +113,7 @@ insertCertificate syncEnv isMember mDeposits blkId txId epochNo slotNo redeemers insertDelegCert :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> CacheStatus -> Maybe Generic.Deposits -> Ledger.Network -> @@ -120,11 +124,11 @@ insertDelegCert :: SlotNo -> ShelleyDelegCert StandardCrypto -> ExceptT SyncNodeError (ReaderT SqlBackend m) () -insertDelegCert tracer cache mDeposits network txId idx mRedeemerId epochNo slotNo dCert = +insertDelegCert tracer severity cache mDeposits network txId idx mRedeemerId epochNo slotNo dCert = case dCert of ShelleyRegCert cred -> insertStakeRegistration tracer cache epochNo mDeposits txId idx $ Generic.annotateStakingCred network cred ShelleyUnRegCert cred -> insertStakeDeregistration tracer cache network epochNo txId idx mRedeemerId cred - ShelleyDelegCert cred poolkh -> insertDelegation tracer cache network epochNo slotNo txId idx mRedeemerId cred poolkh + ShelleyDelegCert cred poolkh -> insertDelegation tracer severity cache network epochNo slotNo txId idx mRedeemerId cred poolkh insertConwayDelegCert :: (MonadBaseControl IO m, MonadIO m) => @@ -137,7 +141,8 @@ insertConwayDelegCert :: SlotNo -> ConwayDelegCert StandardCrypto -> ExceptT SyncNodeError (ReaderT SqlBackend m) () -insertConwayDelegCert syncEnv mDeposits txId idx mRedeemerId epochNo slotNo dCert = +insertConwayDelegCert syncEnv mDeposits txId idx mRedeemerId epochNo slotNo dCert = do + severity <- liftIO $ getSeverity syncEnv case dCert of ConwayRegCert cred _dep -> when (ioShelley iopts) $ @@ -146,23 +151,23 @@ insertConwayDelegCert syncEnv mDeposits txId idx mRedeemerId epochNo slotNo dCer ConwayUnRegCert cred _dep -> when (ioShelley iopts) $ insertStakeDeregistration trce cache network epochNo txId idx mRedeemerId cred - ConwayDelegCert cred delegatee -> insertDeleg cred delegatee + ConwayDelegCert cred delegatee -> insertDeleg severity cred delegatee ConwayRegDelegCert cred delegatee _dep -> do when (ioShelley iopts) $ insertStakeRegistration trce cache epochNo mDeposits txId idx $ Generic.annotateStakingCred network cred - insertDeleg cred delegatee + insertDeleg severity cred delegatee where - insertDeleg cred = \case + insertDeleg severity cred = \case DelegStake poolkh -> when (ioShelley iopts) $ - insertDelegation trce cache network epochNo slotNo txId idx mRedeemerId cred poolkh + insertDelegation trce severity cache network epochNo slotNo txId idx mRedeemerId cred poolkh DelegVote drep -> when (ioGov iopts) $ insertDelegationVote trce cache network txId idx cred drep DelegStakeVote poolkh drep -> do when (ioShelley iopts) $ - insertDelegation trce cache network epochNo slotNo txId idx mRedeemerId cred poolkh + insertDelegation trce severity cache network epochNo slotNo txId idx mRedeemerId cred poolkh when (ioGov iopts) $ insertDelegationVote trce cache network txId idx cred drep @@ -405,6 +410,7 @@ mkAdaPots blockId slotNo epochNo pots = insertDelegation :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> CacheStatus -> Ledger.Network -> EpochNo -> @@ -415,9 +421,9 @@ insertDelegation :: StakeCred -> Ledger.KeyHash 'Ledger.StakePool StandardCrypto -> ExceptT SyncNodeError (ReaderT SqlBackend m) () -insertDelegation trce cache network (EpochNo epoch) slotNo txId idx mRedeemerId cred poolkh = do +insertDelegation trce severity cache network (EpochNo epoch) slotNo txId idx mRedeemerId cred poolkh = do addrId <- lift $ queryOrInsertStakeAddress trce cache UpdateCacheStrong network cred - poolHashId <- lift $ queryPoolKeyOrInsert "insertDelegation" trce cache UpdateCache True poolkh + poolHashId <- lift $ queryPoolKeyOrInsert "insertDelegation" trce severity cache UpdateCache True poolkh void . lift . DB.insertDelegation $ DB.Delegation { DB.delegationAddrId = addrId diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/GovAction.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/GovAction.hs index 8823b9a99..b0838399c 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/GovAction.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/GovAction.hs @@ -28,6 +28,7 @@ module Cardano.DbSync.Era.Universal.Insert.GovAction ( ) where +import qualified Cardano.BM.Data.Severity as BM import Cardano.BM.Trace (Trace) import qualified Cardano.Crypto as Crypto import Cardano.Db (DbWord64 (..)) @@ -71,6 +72,7 @@ insertGovActionProposal :: forall m. (MonadIO m, MonadBaseControl IO m) => Trace IO Text -> + BM.Severity -> CacheStatus -> DB.BlockId -> DB.TxId -> @@ -78,7 +80,7 @@ insertGovActionProposal :: Maybe (ConwayGovState StandardConway) -> (Word64, (GovActionId StandardCrypto, ProposalProcedure StandardConway)) -> ExceptT SyncNodeError (ReaderT SqlBackend m) () -insertGovActionProposal trce cache blkId txId govExpiresAt mcgs (index, (govId, pp)) = do +insertGovActionProposal trce severity cache blkId txId govExpiresAt mcgs (index, (govId, pp)) = do addrId <- lift $ queryOrInsertRewardAccount trce cache UpdateCache $ pProcReturnAddr pp votingAnchorId <- lift $ insertVotingAnchor blkId DB.GovActionAnchor $ pProcAnchor pp @@ -115,7 +117,7 @@ insertGovActionProposal trce cache blkId txId govExpiresAt mcgs (index, (govId, NewConstitution _ constitution -> lift $ void $ insertConstitution blkId (Just govActionProposalId) constitution _ -> pure () where - logCtx = initLogCtx "insertGovActionProposal" "Cardano.DbSync.Era.Universal.Insert.GovAction" + logCtx = initLogCtx severity "insertGovActionProposal" "Cardano.DbSync.Era.Universal.Insert.GovAction" mprevGovAction :: Maybe (GovActionId StandardCrypto) = case pProcGovAction pp of ParameterChange prv _ _ -> unGovPurposeId <$> strictMaybeToMaybe prv HardForkInitiation prv _ -> unGovPurposeId <$> strictMaybeToMaybe prv @@ -269,24 +271,26 @@ insertConstitution blockId mgapId constitution = do insertVotingProcedures :: (MonadIO m, MonadBaseControl IO m) => Trace IO Text -> + BM.Severity -> CacheStatus -> DB.BlockId -> DB.TxId -> (Voter StandardCrypto, [(GovActionId StandardCrypto, VotingProcedure StandardConway)]) -> ExceptT SyncNodeError (ReaderT SqlBackend m) () -insertVotingProcedures trce cache blkId txId (voter, actions) = - mapM_ (insertVotingProcedure trce cache blkId txId voter) (zip [0 ..] actions) +insertVotingProcedures trce severity cache blkId txId (voter, actions) = + mapM_ (insertVotingProcedure trce severity cache blkId txId voter) (zip [0 ..] actions) insertVotingProcedure :: (MonadIO m, MonadBaseControl IO m) => Trace IO Text -> + BM.Severity -> CacheStatus -> DB.BlockId -> DB.TxId -> Voter StandardCrypto -> (Word16, (GovActionId StandardCrypto, VotingProcedure StandardConway)) -> ExceptT SyncNodeError (ReaderT SqlBackend m) () -insertVotingProcedure trce cache blkId txId voter (index, (gaId, vp)) = do +insertVotingProcedure trce severity cache blkId txId voter (index, (gaId, vp)) = do govActionId <- resolveGovActionProposal cache gaId votingAnchorId <- whenMaybe (strictMaybeToMaybe $ vProcAnchor vp) $ lift . insertVotingAnchor blkId DB.VoteAnchor (mCommitteeVoterId, mDRepVoter, mStakePoolVoter) <- case voter of @@ -297,7 +301,7 @@ insertVotingProcedure trce cache blkId txId voter (index, (gaId, vp)) = do drep <- lift $ insertCredDrepHash cred pure (Nothing, Just drep, Nothing) StakePoolVoter poolkh -> do - poolHashId <- lift $ queryPoolKeyOrInsert "insertVotingProcedure" trce cache UpdateCache False poolkh + poolHashId <- lift $ queryPoolKeyOrInsert "insertVotingProcedure" trce severity cache UpdateCache False poolkh pure (Nothing, Nothing, Just poolHashId) void . lift @@ -427,12 +431,13 @@ insertUpdateEnacted :: forall m. (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> CacheStatus -> DB.BlockId -> EpochNo -> ConwayGovState StandardConway -> ExceptT SyncNodeError (ReaderT SqlBackend m) () -insertUpdateEnacted trce cache blkId epochNo enactedState = do +insertUpdateEnacted trce severity cache blkId epochNo enactedState = do (mcommitteeId, mnoConfidenceGaId) <- handleCommittee constitutionId <- handleConstitution void $ @@ -445,7 +450,7 @@ insertUpdateEnacted trce cache blkId epochNo enactedState = do , DB.epochStateEpochNo = unEpochNo epochNo } where - logCtx = initLogCtx "insertUpdateEnacted" "Cardano.DbSync.Era.Universal.Insert.GovAction" + logCtx = initLogCtx severity "insertUpdateEnacted" "Cardano.DbSync.Era.Universal.Insert.GovAction" govIds = govStatePrevGovActionIds enactedState handleCommittee = do diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Grouped.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Grouped.hs index 639331824..1a100e3d3 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Grouped.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Grouped.hs @@ -14,12 +14,14 @@ module Cardano.DbSync.Era.Universal.Insert.Grouped ( mkmaTxOuts, ) where +import qualified Cardano.BM.Data.Severity as BM import Cardano.BM.Trace (Trace) import Cardano.Db (DbLovelace (..), MinIds (..), minIdsCoreToText, minIdsVariantToText) import qualified Cardano.Db as DB import qualified Cardano.Db.Schema.Core.TxOut as C import qualified Cardano.Db.Schema.Variant.TxOut as V import Cardano.DbSync.Api +import Cardano.DbSync.Api.Functions (getSeverity) import Cardano.DbSync.Api.Types (SyncEnv (..)) import Cardano.DbSync.Cache (queryTxIdWithCache) import qualified Cardano.DbSync.Era.Shelley.Generic as Generic @@ -93,6 +95,7 @@ insertBlockGroupedData :: ExceptT SyncNodeError (ReaderT SqlBackend m) DB.MinIdsWrapper insertBlockGroupedData syncEnv grouped = do disInOut <- liftIO $ getDisableInOutState syncEnv + severity <- liftIO $ getSeverity syncEnv txOutIds <- lift . DB.insertManyTxOut disInOut $ etoTxOut . fst <$> groupedTxOut grouped let maTxOuts = concatMap (mkmaTxOuts txOutTableType) $ zip txOutIds (snd <$> groupedTxOut grouped) maTxOutIds <- lift $ DB.insertManyMaTxOut maTxOuts @@ -102,7 +105,7 @@ insertBlockGroupedData syncEnv grouped = do else lift . DB.insertManyTxIn $ etiTxIn <$> groupedTxIn grouped whenConsumeOrPruneTxOut syncEnv $ do etis <- resolveRemainingInputs (groupedTxIn grouped) $ zip txOutIds (fst <$> groupedTxOut grouped) - updateTuples <- lift $ mapM (prepareUpdates tracer) etis + updateTuples <- lift $ mapM (prepareUpdates severity tracer) etis lift $ DB.updateListTxOutConsumedByTxId $ catMaybes updateTuples void . lift . DB.insertManyTxMetadata $ groupedTxMetadata grouped void . lift . DB.insertManyTxMint $ groupedTxMint grouped @@ -152,13 +155,14 @@ mkmaTxOuts _txOutTableType (txOutId, mmtos) = mkmaTxOut <$> mmtos prepareUpdates :: (MonadBaseControl IO m, MonadIO m) => + BM.Severity -> Trace IO Text -> ExtendedTxIn -> m (Maybe (DB.TxOutIdW, DB.TxId)) -prepareUpdates trce eti = case etiTxOutId eti of +prepareUpdates severity trce eti = case etiTxOutId eti of Right txOutId -> pure $ Just (txOutId, DB.txInTxInId (etiTxIn eti)) Left _ -> do - let logCtx = initLogCtx "prepareUpdates" "Cardano.DbSync.Era.Universal.Insert.Grouped" + let logCtx = initLogCtx severity "prepareUpdates" "Cardano.DbSync.Era.Universal.Insert.Grouped" liftIO $ logErrorCtx trce $ logCtx {lcMessage = "Failed to find output for " <> Text.pack (show eti)} diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/LedgerEvent.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/LedgerEvent.hs index 6846ca36f..874608868 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/LedgerEvent.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/LedgerEvent.hs @@ -12,6 +12,7 @@ module Cardano.DbSync.Era.Universal.Insert.LedgerEvent ( import qualified Cardano.Db as DB import Cardano.DbSync.Api +import Cardano.DbSync.Api.Functions (getSeverity) import Cardano.DbSync.Api.Types (SyncEnv (..)) import Cardano.DbSync.Cache.Types (textShowStats) import Cardano.DbSync.Era.Cardano.Insert (insertEpochSyncTime) @@ -44,10 +45,9 @@ insertNewEpochLedgerEvents :: EpochNo -> [LedgerEvent] -> ExceptT SyncNodeError (ReaderT SqlBackend m) () -insertNewEpochLedgerEvents syncEnv currentEpochNo@(EpochNo curEpoch) = +insertNewEpochLedgerEvents syncEnv currentEpochNo@(EpochNo curEpoch) = do mapM_ handler where - logCtx = initLogCtx "insertNewEpochLedgerEvents" "Cardano.DbSync.Era.Universal.Insert.LedgerEvent" tracer = getTrace syncEnv cache = envCache syncEnv ntw = getNetwork syncEnv @@ -66,7 +66,9 @@ insertNewEpochLedgerEvents syncEnv currentEpochNo@(EpochNo curEpoch) = (MonadBaseControl IO m, MonadIO m) => LedgerEvent -> ExceptT SyncNodeError (ReaderT SqlBackend m) () - handler ev = + handler ev = do + severity <- liftIO $ getSeverity syncEnv + let logCtx = initLogCtx severity "insertNewEpochLedgerEvents" "Cardano.DbSync.Era.Universal.Insert.LedgerEvent" case ev of LedgerNewEpoch en ss -> do lift $ @@ -90,9 +92,9 @@ insertNewEpochLedgerEvents syncEnv currentEpochNo@(EpochNo curEpoch) = let rewards = Map.toList $ Generic.unRewards rwd insertRewards syncEnv ntw (subFromCurrentEpoch 1) (EpochNo $ curEpoch + 1) cache rewards LedgerRestrainedRewards e rwd creds -> - lift $ adjustEpochRewards tracer ntw cache e rwd creds + lift $ adjustEpochRewards tracer severity ntw cache e rwd creds LedgerTotalRewards _e rwd -> - lift $ validateEpochRewards tracer ntw (subFromCurrentEpoch 2) currentEpochNo rwd + lift $ validateEpochRewards tracer severity ntw (subFromCurrentEpoch 2) currentEpochNo rwd LedgerAdaPots _ -> pure () -- These are handled separately by insertBlock LedgerGovInfo enacted dropped expired uncl -> do diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Other.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Other.hs index 6b23ae43c..2684738c9 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Other.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Other.hs @@ -18,9 +18,11 @@ module Cardano.DbSync.Era.Universal.Insert.Other ( insertExtraKeyWitness, ) where +import qualified Cardano.BM.Data.Severity as BM import Cardano.BM.Trace (Trace) import qualified Cardano.Db as DB import Cardano.DbSync.Api (getTrace) +import Cardano.DbSync.Api.Functions (getSeverity) import Cardano.DbSync.Api.Types (SyncEnv) import Cardano.DbSync.Cache (insertDatumAndCache, queryDatum, queryMAWithCache, queryOrInsertRewardAccount, queryOrInsertStakeAddress) import Cardano.DbSync.Cache.Types (CacheAction (..), CacheStatus (..)) @@ -51,7 +53,8 @@ insertRedeemer :: (Word64, Generic.TxRedeemer) -> ExceptT SyncNodeError (ReaderT SqlBackend m) (Word64, DB.RedeemerId) insertRedeemer syncEnv disInOut groupedOutputs txId (rix, redeemer) = do - tdId <- insertRedeemerData tracer txId $ Generic.txRedeemerData redeemer + severity <- liftIO $ getSeverity syncEnv + tdId <- insertRedeemerData tracer severity txId $ Generic.txRedeemerData redeemer scriptHash <- findScriptHash rid <- lift @@ -82,15 +85,16 @@ insertRedeemer syncEnv disInOut groupedOutputs txId (rix, redeemer) = do insertRedeemerData :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> DB.TxId -> Generic.PlutusData -> ExceptT SyncNodeError (ReaderT SqlBackend m) DB.RedeemerDataId -insertRedeemerData tracer txId txd = do +insertRedeemerData tracer severity txId txd = do mRedeemerDataId <- lift $ DB.queryRedeemerData $ Generic.dataHashToBytes $ Generic.txDataHash txd case mRedeemerDataId of Just redeemerDataId -> pure redeemerDataId Nothing -> do - value <- safeDecodeToJson tracer "insertDatum: Column 'value' in table 'datum' " $ Generic.txDataValue txd + value <- safeDecodeToJson tracer severity "insertDatum: Column 'value' in table 'datum' " $ Generic.txDataValue txd lift . DB.insertRedeemerData $ DB.RedeemerData @@ -106,16 +110,17 @@ insertRedeemerData tracer txId txd = do insertDatum :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> CacheStatus -> DB.TxId -> Generic.PlutusData -> ExceptT SyncNodeError (ReaderT SqlBackend m) DB.DatumId -insertDatum tracer cache txId txd = do +insertDatum tracer severity cache txId txd = do mDatumId <- lift $ queryDatum cache $ Generic.txDataHash txd case mDatumId of Just datumId -> pure datumId Nothing -> do - value <- safeDecodeToJson tracer "insertRedeemerData: Column 'value' in table 'redeemer' " $ Generic.txDataValue txd + value <- safeDecodeToJson tracer severity "insertRedeemerData: Column 'value' in table 'redeemer' " $ Generic.txDataValue txd lift $ insertDatumAndCache cache (Generic.txDataHash txd) $ DB.Datum @@ -166,12 +171,13 @@ insertStakeAddressRefIfMissing trce cache addr = insertMultiAsset :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> CacheStatus -> PolicyID StandardCrypto -> AssetName -> ReaderT SqlBackend m DB.MultiAssetId -insertMultiAsset trce cache policy aName = do - mId <- queryMAWithCache trce cache policy aName +insertMultiAsset trce severity cache policy aName = do + mId <- queryMAWithCache trce severity cache policy aName case mId of Right maId -> pure maId Left (policyBs, assetNameBs) -> @@ -185,15 +191,16 @@ insertMultiAsset trce cache policy aName = do insertScript :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> DB.TxId -> Generic.TxScript -> ReaderT SqlBackend m DB.ScriptId -insertScript tracer txId script = do +insertScript tracer severity txId script = do mScriptId <- DB.queryScript $ Generic.txScriptHash script case mScriptId of Just scriptId -> pure scriptId Nothing -> do - json <- scriptConvert script + json <- scriptConvert DB.insertScript $ DB.Script { DB.scriptTxId = txId @@ -204,9 +211,12 @@ insertScript tracer txId script = do , DB.scriptBytes = Generic.txScriptCBOR script } where - scriptConvert :: MonadIO m => Generic.TxScript -> m (Maybe Text) - scriptConvert s = - maybe (pure Nothing) (safeDecodeToJson tracer "insertScript: Column 'json' in table 'script' ") (Generic.txScriptJson s) + scriptConvert :: MonadIO m => m (Maybe Text) + scriptConvert = + maybe + (pure Nothing) + (safeDecodeToJson tracer severity "insertScript: Column 'json' in table 'script' ") + (Generic.txScriptJson script) insertExtraKeyWitness :: (MonadBaseControl IO m, MonadIO m) => diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Pool.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Pool.hs index 2631c8a6c..7f364e840 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Pool.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Pool.hs @@ -16,6 +16,7 @@ module Cardano.DbSync.Era.Universal.Insert.Pool ( insertPoolCert, ) where +import qualified Cardano.BM.Data.Severity as BM import Cardano.BM.Trace (Trace) import Cardano.Crypto.Hash (hashToBytes) import Cardano.Db (PoolUrl (..)) @@ -109,14 +110,15 @@ insertPoolRegister trce cache isMember mdeposits network (EpochNo epoch) blkId t insertPoolRetire :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> DB.TxId -> CacheStatus -> EpochNo -> Word16 -> Ledger.KeyHash 'Ledger.StakePool StandardCrypto -> ExceptT SyncNodeError (ReaderT SqlBackend m) () -insertPoolRetire trce txId cache epochNum idx keyHash = do - poolId <- lift $ queryPoolKeyOrInsert "insertPoolRetire" trce cache UpdateCache True keyHash +insertPoolRetire trce severity txId cache epochNum idx keyHash = do + poolId <- lift $ queryPoolKeyOrInsert "insertPoolRetire" trce severity cache UpdateCache True keyHash void . lift . DB.insertPoolRetire $ DB.PoolRetire { DB.poolRetireHashId = poolId @@ -198,6 +200,7 @@ insertPoolRelay updateId relay = insertPoolCert :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> CacheStatus -> IsPoolMember -> Maybe Generic.Deposits -> @@ -208,7 +211,7 @@ insertPoolCert :: Word16 -> PoolCert StandardCrypto -> ExceptT SyncNodeError (ReaderT SqlBackend m) () -insertPoolCert tracer cache isMember mdeposits network epoch blkId txId idx pCert = +insertPoolCert tracer severity cache isMember mdeposits network epoch blkId txId idx pCert = case pCert of RegPool pParams -> insertPoolRegister tracer cache isMember mdeposits network epoch blkId txId idx pParams - RetirePool keyHash epochNum -> insertPoolRetire tracer txId cache epochNum idx keyHash + RetirePool keyHash epochNum -> insertPoolRetire tracer severity txId cache epochNum idx keyHash diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Tx.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Tx.hs index b76dbec84..90f21cbe4 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Tx.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Insert/Tx.hs @@ -13,12 +13,14 @@ module Cardano.DbSync.Era.Universal.Insert.Tx ( insertTxOut, ) where +import qualified Cardano.BM.Data.Severity as BM import Cardano.BM.Trace (Trace) import Cardano.Db (DbLovelace (..), DbWord64 (..)) import qualified Cardano.Db as DB import qualified Cardano.Db.Schema.Core.TxOut as C import qualified Cardano.Db.Schema.Variant.TxOut as V import Cardano.DbSync.Api +import Cardano.DbSync.Api.Functions (getSeverity) import Cardano.DbSync.Api.Types (InsertOptions (..), SyncEnv (..)) import Cardano.DbSync.Cache (queryTxIdWithCache, tryUpdateCacheTx) import Cardano.DbSync.Cache.Types (CacheStatus (..)) @@ -84,6 +86,7 @@ insertTx syncEnv isMember blkId epochNo slotNo applyResult blockIndex tx grouped !treasuryDonation = unCoin $ Generic.txTreasuryDonation tx hasConsumed = getHasConsumedOrPruneTxOut syncEnv txIn = Generic.txInputs tx + severity <- liftIO $ getSeverity syncEnv disInOut <- liftIO $ getDisableInOutState syncEnv -- In some txs and with specific configuration we may be able to find necessary data within the tx body. -- In these cases we can avoid expensive queries. @@ -138,7 +141,7 @@ insertTx syncEnv isMember blkId epochNo slotNo applyResult blockIndex tx grouped if not (Generic.txValidContract tx) then do - !txOutsGrouped <- mapM (insertTxOut tracer cache iopts (txId, txHash)) (Generic.txOutputs tx) + !txOutsGrouped <- mapM (insertTxOut tracer severity cache iopts (txId, txHash)) (Generic.txOutputs tx) let !txIns = map (prepareTxIn txId Map.empty) resolvedInputs -- There is a custom semigroup instance for BlockGroupedData which uses addition for the values `fees` and `outSum`. @@ -147,7 +150,7 @@ insertTx syncEnv isMember blkId epochNo slotNo applyResult blockIndex tx grouped else do -- The following operations only happen if the script passes stage 2 validation (or the tx has -- no script). - !txOutsGrouped <- mapM (insertTxOut tracer cache iopts (txId, txHash)) (Generic.txOutputs tx) + !txOutsGrouped <- mapM (insertTxOut tracer severity cache iopts (txId, txHash)) (Generic.txOutputs tx) !redeemers <- Map.fromList @@ -156,15 +159,16 @@ insertTx syncEnv isMember blkId epochNo slotNo applyResult blockIndex tx grouped (mapM (insertRedeemer syncEnv disInOut (fst <$> groupedTxOut grouped) txId) (Generic.txRedeemer tx)) when (ioPlutusExtra iopts) $ do - mapM_ (insertDatum tracer cache txId) (Generic.txData tx) + mapM_ (insertDatum tracer severity cache txId) (Generic.txData tx) mapM_ (insertCollateralTxIn syncEnv tracer txId) (Generic.txCollateralInputs tx) mapM_ (insertReferenceTxIn syncEnv tracer txId) (Generic.txReferenceInputs tx) - mapM_ (insertCollateralTxOut tracer cache iopts (txId, txHash)) (Generic.txCollateralOutputs tx) + mapM_ (insertCollateralTxOut tracer severity cache iopts (txId, txHash)) (Generic.txCollateralOutputs tx) txMetadata <- whenFalseMempty (ioMetadata iopts) $ insertTxMetadata tracer + severity txId iopts (Generic.txMetadata tx) @@ -180,11 +184,11 @@ insertTx syncEnv isMember blkId epochNo slotNo applyResult blockIndex tx grouped maTxMint <- whenFalseMempty (ioMultiAssets iopts) $ - insertMaTxMint tracer cache txId $ + insertMaTxMint tracer severity cache txId $ Generic.txMint tx when (ioPlutusExtra iopts) $ - mapM_ (lift . insertScript tracer txId) $ + mapM_ (lift . insertScript tracer severity txId) $ Generic.txScripts tx when (ioPlutusExtra iopts) $ @@ -192,8 +196,8 @@ insertTx syncEnv isMember blkId epochNo slotNo applyResult blockIndex tx grouped Generic.txExtraKeyWitnesses tx when (ioGov iopts) $ do - mapM_ (insertGovActionProposal tracer cache blkId txId (getGovExpiresAt applyResult epochNo) (apGovActionState applyResult)) $ zip [0 ..] (Generic.txProposalProcedure tx) - mapM_ (insertVotingProcedures tracer cache blkId txId) (Generic.txVotingProcedure tx) + mapM_ (insertGovActionProposal tracer severity cache blkId txId (getGovExpiresAt applyResult epochNo) (apGovActionState applyResult)) $ zip [0 ..] (Generic.txProposalProcedure tx) + mapM_ (insertVotingProcedures tracer severity cache blkId txId) (Generic.txVotingProcedure tx) let !txIns = map (prepareTxIn txId redeemers) resolvedInputs pure (grouped <> BlockGroupedData txIns txOutsGrouped txMetadata maTxMint fees outSum) @@ -209,21 +213,22 @@ insertTx syncEnv isMember blkId epochNo slotNo applyResult blockIndex tx grouped insertTxOut :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> CacheStatus -> InsertOptions -> (DB.TxId, ByteString) -> Generic.TxOut -> ExceptT SyncNodeError (ReaderT SqlBackend m) (ExtendedTxOut, [MissingMaTxOut]) -insertTxOut tracer cache iopts (txId, txHash) (Generic.TxOut index addr value maMap mScript dt) = do +insertTxOut tracer severity cache iopts (txId, txHash) (Generic.TxOut index addr value maMap mScript dt) = do mSaId <- lift $ insertStakeAddressRefIfMissing tracer cache addr mDatumId <- whenFalseEmpty (ioPlutusExtra iopts) Nothing $ Generic.whenInlineDatum dt $ - insertDatum tracer cache txId + insertDatum tracer severity cache txId mScriptId <- whenFalseEmpty (ioPlutusExtra iopts) Nothing $ whenMaybe mScript $ - lift . insertScript tracer txId + lift . insertScript tracer severity txId !txOut <- case ioTxOutTableType iopts of DB.TxOutCore -> @@ -261,7 +266,7 @@ insertTxOut tracer cache iopts (txId, txHash) (Generic.TxOut index addr value ma case ioTxOutTableType iopts of DB.TxOutCore -> ExtendedTxOut txHash txOut DB.TxOutVariantAddress -> ExtendedTxOut txHash txOut - !maTxOuts <- whenFalseMempty (ioMultiAssets iopts) $ insertMaTxOuts tracer cache maMap + !maTxOuts <- whenFalseMempty (ioMultiAssets iopts) $ insertMaTxOuts tracer severity cache maMap pure (eutxo, maTxOuts) where hasScript :: Bool @@ -300,11 +305,12 @@ insertAddress address vAddress = do insertTxMetadata :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> DB.TxId -> InsertOptions -> Maybe (Map Word64 TxMetadataValue) -> ExceptT SyncNodeError (ReaderT SqlBackend m) [DB.TxMetadata] -insertTxMetadata tracer txId inOpts mmetadata = do +insertTxMetadata tracer severity txId inOpts mmetadata = do case mmetadata of Nothing -> pure [] Just metadata -> mapMaybeM prepare $ Map.toList metadata @@ -330,7 +336,7 @@ insertTxMetadata tracer txId inOpts mmetadata = do mkDbTxMetadata (key, md) = do let jsonbs = LBS.toStrict $ Aeson.encode (metadataValueToJsonNoSchema md) singleKeyCBORMetadata = serialiseTxMetadataToCbor $ Map.singleton key md - mjson <- safeDecodeToJson tracer "prepareTxMetadata: Column 'json' in table 'metadata' " jsonbs + mjson <- safeDecodeToJson tracer severity "prepareTxMetadata: Column 'json' in table 'metadata' " jsonbs pure $ Just $ DB.TxMetadata @@ -346,11 +352,12 @@ insertTxMetadata tracer txId inOpts mmetadata = do insertMaTxMint :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> CacheStatus -> DB.TxId -> MultiAsset StandardCrypto -> ExceptT SyncNodeError (ReaderT SqlBackend m) [DB.MaTxMint] -insertMaTxMint trce cache txId (MultiAsset mintMap) = +insertMaTxMint trce severity cache txId (MultiAsset mintMap) = concatMapM (lift . prepareOuter) $ Map.toList mintMap where prepareOuter :: @@ -366,7 +373,7 @@ insertMaTxMint trce cache txId (MultiAsset mintMap) = (AssetName, Integer) -> ReaderT SqlBackend m DB.MaTxMint prepareInner policy (aname, amount) = do - maId <- insertMultiAsset trce cache policy aname + maId <- insertMultiAsset trce severity cache policy aname pure $ DB.MaTxMint { DB.maTxMintIdent = maId @@ -377,10 +384,11 @@ insertMaTxMint trce cache txId (MultiAsset mintMap) = insertMaTxOuts :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> CacheStatus -> Map (PolicyID StandardCrypto) (Map AssetName Integer) -> ExceptT SyncNodeError (ReaderT SqlBackend m) [MissingMaTxOut] -insertMaTxOuts trce cache maMap = +insertMaTxOuts trce severity cache maMap = concatMapM (lift . prepareOuter) $ Map.toList maMap where prepareOuter :: @@ -396,7 +404,7 @@ insertMaTxOuts trce cache maMap = (AssetName, Integer) -> ReaderT SqlBackend m MissingMaTxOut prepareInner policy (aname, amount) = do - maId <- insertMultiAsset trce cache policy aname + maId <- insertMultiAsset trce severity cache policy aname pure $ MissingMaTxOut { mmtoIdent = maId @@ -409,21 +417,22 @@ insertMaTxOuts trce cache maMap = insertCollateralTxOut :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> CacheStatus -> InsertOptions -> (DB.TxId, ByteString) -> Generic.TxOut -> ExceptT SyncNodeError (ReaderT SqlBackend m) () -insertCollateralTxOut tracer cache iopts (txId, _txHash) (Generic.TxOut index addr value maMap mScript dt) = do +insertCollateralTxOut tracer severity cache iopts (txId, _txHash) (Generic.TxOut index addr value maMap mScript dt) = do mSaId <- lift $ insertStakeAddressRefIfMissing tracer cache addr mDatumId <- whenFalseEmpty (ioPlutusExtra iopts) Nothing $ Generic.whenInlineDatum dt $ - insertDatum tracer cache txId + insertDatum tracer severity cache txId mScriptId <- whenFalseEmpty (ioPlutusExtra iopts) Nothing $ whenMaybe mScript $ - lift . insertScript tracer txId + lift . insertScript tracer severity txId _ <- case ioTxOutTableType iopts of DB.TxOutCore -> do diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Validate.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Validate.hs index 0ad8ab3fa..91bd12b62 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Validate.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Universal/Validate.hs @@ -10,6 +10,7 @@ module Cardano.DbSync.Era.Universal.Validate ( ) where import Cardano.BM.Trace (Trace) +import qualified Cardano.BM.Tracing as BM import Cardano.Db (DbLovelace, RewardSource) import qualified Cardano.Db as Db import qualified Cardano.DbSync.Era.Shelley.Generic as Generic @@ -52,13 +53,14 @@ import GHC.Err (error) validateEpochRewards :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> Network -> EpochNo -> EpochNo -> Map StakeCred (Set (Ledger.Reward StandardCrypto)) -> ReaderT SqlBackend m () -validateEpochRewards tracer network _earnedEpochNo spendableEpochNo rmap = do - let logCtx = initLogCtx "validateEpochRewards" "Cardano.DbSync.Era.Universal.Validate" +validateEpochRewards tracer severity network _earnedEpochNo spendableEpochNo rmap = do + let logCtx = initLogCtx severity "validateEpochRewards" "Cardano.DbSync.Era.Universal.Validate" actualCount <- Db.queryNormalEpochRewardCount (unEpochNo spendableEpochNo) if actualCount /= expectedCount then do @@ -74,7 +76,7 @@ validateEpochRewards tracer network _earnedEpochNo spendableEpochNo rmap = do , textShow actualCount ] } - logFullRewardMap tracer spendableEpochNo network (convertPoolRewards rmap) + logFullRewardMap tracer severity spendableEpochNo network (convertPoolRewards rmap) else do liftIO . logInfoCtx tracer $ logCtx @@ -93,15 +95,16 @@ validateEpochRewards tracer network _earnedEpochNo spendableEpochNo rmap = do logFullRewardMap :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> EpochNo -> Network -> Generic.Rewards -> ReaderT SqlBackend m () -logFullRewardMap tracer epochNo network ledgerMap = do +logFullRewardMap tracer severity epochNo network ledgerMap = do dbMap <- queryRewardMap epochNo when (Map.size dbMap > 0 && Map.size (Generic.unRewards ledgerMap) > 0) $ liftIO $ - diffRewardMap tracer network dbMap (Map.mapKeys (Generic.stakingCredHash network) $ Map.map convert $ Generic.unRewards ledgerMap) + diffRewardMap tracer severity network dbMap (Map.mapKeys (Generic.stakingCredHash network) $ Map.map convert $ Generic.unRewards ledgerMap) where convert :: Set Generic.Reward -> [(RewardSource, Coin)] convert = map (\rwd -> (Generic.rewardSource rwd, Generic.rewardAmount rwd)) . Set.toList @@ -139,13 +142,14 @@ queryRewardMap (EpochNo epochNo) = do diffRewardMap :: Trace IO Text -> + BM.Severity -> Network -> Map ByteString [(RewardSource, DbLovelace)] -> Map ByteString [(RewardSource, Coin)] -> IO () -diffRewardMap tracer _nw dbMap ledgerMap = do +diffRewardMap tracer severity _nw dbMap ledgerMap = do when (Map.size diffMap > 0) $ do - let logCtx = initLogCtx "diffRewardMap" "Cardano.DbSync.Era.Universal.Validate" + let logCtx = initLogCtx severity "diffRewardMap" "Cardano.DbSync.Era.Universal.Validate" logErrorCtx tracer logCtx {lcMessage = mconcat $ map render (Map.toList diffMap)} where keys :: [ByteString] diff --git a/cardano-db-sync/src/Cardano/DbSync/Era/Util.hs b/cardano-db-sync/src/Cardano/DbSync/Era/Util.hs index 76827cdd9..7b9704c88 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Era/Util.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Era/Util.hs @@ -8,6 +8,7 @@ module Cardano.DbSync.Era.Util ( safeDecodeToJson, ) where +import qualified Cardano.BM.Data.Severity as BM import Cardano.BM.Trace (Trace) import qualified Cardano.Db as DB import Cardano.DbSync.Error @@ -34,9 +35,9 @@ safeDecodeUtf8 bs containsUnicodeNul :: Text -> Bool containsUnicodeNul = Text.isInfixOf "\\u000" -safeDecodeToJson :: MonadIO m => Trace IO Text -> Text -> ByteString -> m (Maybe Text) -safeDecodeToJson tracer tracePrefix jsonBs = do - let logCtx = initLogCtx "safeDecodeToJson" "Cardano.DbSync.Era.Util" +safeDecodeToJson :: MonadIO m => Trace IO Text -> BM.Severity -> Text -> ByteString -> m (Maybe Text) +safeDecodeToJson tracer severity tracePrefix jsonBs = do + let logCtx = initLogCtx severity "safeDecodeToJson" "Cardano.DbSync.Era.Util" ejson <- liftIO $ safeDecodeUtf8 jsonBs case ejson of Left err -> do diff --git a/cardano-db-sync/src/Cardano/DbSync/Fix/ConsumedBy.hs b/cardano-db-sync/src/Cardano/DbSync/Fix/ConsumedBy.hs index dcd58f3eb..a2a38d6b5 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Fix/ConsumedBy.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Fix/ConsumedBy.hs @@ -8,6 +8,7 @@ import qualified Cardano.Chain.UTxO as Byron import qualified Cardano.Crypto as Crypto (serializeCborHash) import qualified Cardano.Db as DB import Cardano.DbSync.Api (getTrace, getTxOutTableType) +import Cardano.DbSync.Api.Functions (getSeverity) import Cardano.DbSync.Api.Types (SyncEnv) import Cardano.DbSync.Era.Byron.Insert import Cardano.DbSync.Era.Byron.Util (blockPayload, unTxHash) @@ -29,26 +30,28 @@ fixConsumedBy backend syncEnv cblk = case cblk of _ -> pure Nothing fixBlock :: SqlBackend -> SyncEnv -> ByronBlock -> IO (Maybe [FixEntry]) -fixBlock backend syncEnv bblk = case byronBlockRaw bblk of - Byron.ABOBBoundary _ -> pure $ Just [] - Byron.ABOBBlock blk -> do - mEntries <- runReaderT (runExceptT $ mapM (fixTx syncEnv) (blockPayload blk)) backend - case mEntries of - Right newEntries -> pure $ Just $ concat newEntries - Left err -> do - let logCtx = initLogCtx "fixBlock" "Cardano.DbSync.Fix.ConsumedBy" - liftIO $ - logWarningCtx (getTrace syncEnv) $ - logCtx - { lcMessage = - mconcat - [ "While fixing block " - , textShow bblk - , ", encountered error " - , textShow err - ] - } - pure Nothing +fixBlock backend syncEnv bblk = + case byronBlockRaw bblk of + Byron.ABOBBoundary _ -> pure $ Just [] + Byron.ABOBBlock blk -> do + mEntries <- runReaderT (runExceptT $ mapM (fixTx syncEnv) (blockPayload blk)) backend + case mEntries of + Right newEntries -> pure $ Just $ concat newEntries + Left err -> do + severity <- getSeverity syncEnv + let logCtx = initLogCtx severity "fixBlock" "Cardano.DbSync.Fix.ConsumedBy" + liftIO $ + logWarningCtx (getTrace syncEnv) $ + logCtx + { lcMessage = + mconcat + [ "While fixing block " + , textShow bblk + , ", encountered error " + , textShow err + ] + } + pure Nothing fixTx :: MonadIO m => SyncEnv -> Byron.TxAux -> ExceptT SyncNodeError (ReaderT SqlBackend m) [FixEntry] fixTx syncEnv tx = do diff --git a/cardano-db-sync/src/Cardano/DbSync/Fix/EpochStake.hs b/cardano-db-sync/src/Cardano/DbSync/Fix/EpochStake.hs index b793aebdc..40b31787b 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Fix/EpochStake.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Fix/EpochStake.hs @@ -5,6 +5,7 @@ module Cardano.DbSync.Fix.EpochStake where import qualified Cardano.Db as DB import Cardano.DbSync.Api +import Cardano.DbSync.Api.Functions (getSeverity) import Cardano.DbSync.Api.Types import Cardano.DbSync.Era.Shelley.Generic.StakeDist hiding (getStakeSlice) import Cardano.DbSync.Era.Universal.Epoch @@ -22,18 +23,20 @@ migrateStakeDistr :: (MonadIO m, MonadBaseControl IO m) => SyncEnv -> Strict.May migrateStakeDistr env mcls = case (envLedgerEnv env, mcls) of (HasLedger lenv, Strict.Just cls) -> do + severity <- liftIO $ getSeverity env + let logCtx = initLogCtx severity "migrateStakeDistr" "Cardano.DbSync.Fix.EpochStake" ems <- lift DB.queryAllExtraMigrations runWhen (not $ DB.isStakeDistrComplete ems) $ do liftIO $ logInfoCtx trce $ logCtx {lcMessage = "Starting Stake Distribution migration on table epoch_stake"} let stakeSlice = getStakeSlice lenv cls True case stakeSlice of NoSlices -> - liftIO $ logInsert 0 + liftIO $ logInsert logCtx 0 Slice (StakeSlice _epochNo distr) isFinal -> do - liftIO $ logInsert (Map.size distr) + liftIO $ logInsert logCtx (Map.size distr) insertStakeSlice env stakeSlice (mminEpoch, mmaxEpoch) <- lift DB.queryMinMaxEpochStake - liftIO $ logMinMax mminEpoch mmaxEpoch + liftIO $ logMinMax logCtx mminEpoch mmaxEpoch case (mminEpoch, mmaxEpoch) of (Just minEpoch, Just maxEpoch) -> do when (maxEpoch > 0) $ @@ -44,7 +47,6 @@ migrateStakeDistr env mcls = lift $ DB.insertExtraMigration DB.StakeDistrEnded _ -> pure False where - logCtx = initLogCtx "migrateStakeDistr" "Cardano.DbSync.Fix.EpochStake" trce = getTrace env mkProgress isCompleted e = DB.EpochStakeProgress @@ -52,13 +54,13 @@ migrateStakeDistr env mcls = , DB.epochStakeProgressCompleted = isCompleted } - logInsert :: Int -> IO () - logInsert n + logInsert :: LogContext -> Int -> IO () + logInsert logCtx n | n == 0 = logInfoCtx trce $ logCtx {lcMessage = "No missing epoch_stake found"} | n > 100000 = logWarningCtx trce $ logCtx {lcMessage = "Found " <> textShow n <> " epoch_stake. This may take a while"} | otherwise = logInfoCtx trce $ logCtx {lcMessage = "Found " <> textShow n <> " epoch_stake"} - logMinMax mmin mmax = + logMinMax logCtx mmin mmax = logInfoCtx trce $ logCtx { lcMessage = diff --git a/cardano-db-sync/src/Cardano/DbSync/Fix/PlutusDataBytes.hs b/cardano-db-sync/src/Cardano/DbSync/Fix/PlutusDataBytes.hs index b253435b2..0a3454d8b 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Fix/PlutusDataBytes.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Fix/PlutusDataBytes.hs @@ -11,6 +11,7 @@ module Cardano.DbSync.Fix.PlutusDataBytes where +import qualified Cardano.BM.Data.Severity as BM import Cardano.BM.Trace (Trace) import qualified Cardano.Db.Version.V13_0 as DB_V_13_0 import Cardano.DbSync.Api @@ -90,8 +91,9 @@ getNextPointList fds = case fds of getWrongPlutusData :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> ReaderT SqlBackend m FixData -getWrongPlutusData tracer = do +getWrongPlutusData tracer severity = do liftIO $ logInfoCtx tracer $ logCtx @@ -106,6 +108,7 @@ getWrongPlutusData tracer = do datumList <- findWrongPlutusData tracer + severity "Datum" DB_V_13_0.queryDatumCount DB_V_13_0.queryDatumPage @@ -116,6 +119,7 @@ getWrongPlutusData tracer = do redeemerDataList <- findWrongPlutusData tracer + severity "RedeemerData" DB_V_13_0.queryRedeemerDataCount DB_V_13_0.queryRedeemerDataPage @@ -125,7 +129,8 @@ getWrongPlutusData tracer = do (mapLeft Just . hashPlutusData . getRedeemerDataBytes) pure $ FixData datumList redeemerDataList where - logCtx = initLogCtx "getWrongPlutusData" "Cardano.DbSync.Fix.PlutusDataBytes" + logCtx = initLogCtx severity "getWrongPlutusData" "Cardano.DbSync.Fix.PlutusDataBytes" + f queryRes = do (prevBlockHsh, mPrevSlotNo) <- queryRes prevSlotNo <- mPrevSlotNo @@ -143,6 +148,7 @@ findWrongPlutusData :: forall a m. (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> Text -> m Word64 -> -- query count (Int64 -> Int64 -> m [a]) -> -- query a page @@ -151,7 +157,7 @@ findWrongPlutusData :: (a -> Maybe ByteString) -> -- get the stored bytes (a -> Either (Maybe String) ByteString) -> -- hash the stored bytes m [FixPlutusInfo] -findWrongPlutusData tracer tableName qCount qPage qGetInfo getHash getBytes hashBytes = do +findWrongPlutusData tracer severity tableName qCount qPage qGetInfo getHash getBytes hashBytes = do liftIO $ logInfoCtx tracer $ logCtx @@ -182,7 +188,7 @@ findWrongPlutusData tracer tableName qCount qPage qGetInfo getHash getBytes hash } pure datums where - logCtx = initLogCtx "findWrongPlutusData" "Cardano.DbSync.Fix.PlutusDataBytes" + logCtx = initLogCtx severity "findWrongPlutusData" "Cardano.DbSync.Fix.PlutusDataBytes" showBytes = maybe "" bsBase16Encode findRec :: Bool -> Int64 -> [[FixPlutusInfo]] -> m [FixPlutusInfo] @@ -240,12 +246,12 @@ findWrongPlutusData tracer tableName qCount qPage qGetInfo getHash getBytes hash limit = 100_000 -fixPlutusData :: MonadIO m => Trace IO Text -> CardanoBlock -> FixData -> ReaderT SqlBackend m () -fixPlutusData tracer cblk fds = do +fixPlutusData :: MonadIO m => Trace IO Text -> BM.Severity -> CardanoBlock -> FixData -> ReaderT SqlBackend m () +fixPlutusData tracer severity cblk fds = do mapM_ (fixData True) $ fdDatum fds mapM_ (fixData False) $ fdRedeemerData fds where - logCtx = initLogCtx "fixPlutusData" "Cardano.DbSync.Fix.PlutusDataBytes" + logCtx = initLogCtx severity "fixPlutusData" "Cardano.DbSync.Fix.PlutusDataBytes" fixData :: MonadIO m => Bool -> FixPlutusInfo -> ReaderT SqlBackend m () fixData isDatum fd = do diff --git a/cardano-db-sync/src/Cardano/DbSync/Fix/PlutusScripts.hs b/cardano-db-sync/src/Cardano/DbSync/Fix/PlutusScripts.hs index 773e318ce..c0dc42638 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Fix/PlutusScripts.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Fix/PlutusScripts.hs @@ -49,6 +49,7 @@ import Database.Persist.Sql (SqlBackend) import Ouroboros.Consensus.Cardano.Block (HardForkBlock (BlockAllegra, BlockAlonzo, BlockBabbage, BlockByron, BlockMary, BlockShelley)) import Ouroboros.Consensus.Shelley.Eras +import qualified Cardano.BM.Data.Severity as BM import Cardano.DbSync.Fix.PlutusDataBytes import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logInfoCtx, logWarningCtx) import Cardano.Ledger.Babbage.TxOut @@ -76,9 +77,10 @@ spanFPSOnPoint fps point = getWrongPlutusScripts :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> ReaderT SqlBackend m FixPlutusScripts -getWrongPlutusScripts tracer = do - let logCtx = initLogCtx "getWrongPlutusScripts" "Cardano.DbSync.Fix.PlutusScripts" +getWrongPlutusScripts tracer severity = do + let logCtx = initLogCtx severity "getWrongPlutusScripts" "Cardano.DbSync.Fix.PlutusScripts" liftIO $ logInfoCtx tracer $ logCtx @@ -90,16 +92,18 @@ getWrongPlutusScripts tracer = do , " This procedure makes resyncing unnecessary." ] } - FixPlutusScripts <$> findWrongPlutusScripts tracer + FixPlutusScripts <$> findWrongPlutusScripts tracer severity findWrongPlutusScripts :: forall m. (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> ReaderT SqlBackend m [FixPlutusInfo] -findWrongPlutusScripts tracer = +findWrongPlutusScripts tracer severity = findWrongPlutusData tracer + severity "Script" DB_V_13_0.queryScriptCount DB_V_13_0.queryScriptPage @@ -127,8 +131,8 @@ findWrongPlutusScripts tracer = PlutusV3 -> Left Nothing _ -> Left $ Just "Non plutus script found where it shouldn't." -fixPlutusScripts :: MonadIO m => Trace IO Text -> CardanoBlock -> FixPlutusScripts -> ReaderT SqlBackend m () -fixPlutusScripts tracer cblk fpss = do +fixPlutusScripts :: MonadIO m => Trace IO Text -> BM.Severity -> CardanoBlock -> FixPlutusScripts -> ReaderT SqlBackend m () +fixPlutusScripts tracer severity cblk fpss = do mapM_ fixData $ scriptsInfo fpss where fixData :: MonadIO m => FixPlutusInfo -> ReaderT SqlBackend m () @@ -150,7 +154,7 @@ fixPlutusScripts tracer cblk fpss = do } correctBytesMap = scrapScriptBlock cblk - logCtx = initLogCtx "fixPlutusScripts" "Cardano.DbSync.Fix.PlutusScripts" + logCtx = initLogCtx severity "fixPlutusScripts" "Cardano.DbSync.Fix.PlutusScripts" scrapScriptBlock :: CardanoBlock -> Map ByteString ByteString scrapScriptBlock cblk = case cblk of diff --git a/cardano-db-sync/src/Cardano/DbSync/Ledger/State.hs b/cardano-db-sync/src/Cardano/DbSync/Ledger/State.hs index 84e16d34c..45e26cb14 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Ledger/State.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Ledger/State.hs @@ -74,6 +74,7 @@ import qualified Control.Exception as Exception import qualified Data.ByteString.Base16 as Base16 +import qualified Cardano.BM.Tracing as BM import Cardano.DbSync.Api.Types (InsertOptions (..), LedgerEnv (..), SyncOptions (..)) import Cardano.DbSync.Error (SyncNodeError (..), fromEitherSTM) import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logInfoCtx, logWarningCtx) @@ -215,10 +216,10 @@ readStateUnsafe env = do Strict.Nothing -> throwSTM $ userError "LedgerState.readStateUnsafe: Ledger state is not found" Strict.Just st -> pure st -applyBlockAndSnapshot :: HasLedgerEnv -> CardanoBlock -> Bool -> IO (ApplyResult, Bool) -applyBlockAndSnapshot ledgerEnv blk isCons = do +applyBlockAndSnapshot :: HasLedgerEnv -> BM.Severity -> CardanoBlock -> Bool -> IO (ApplyResult, Bool) +applyBlockAndSnapshot ledgerEnv severity blk isCons = do (oldState, appResult) <- applyBlock ledgerEnv blk - tookSnapshot <- storeSnapshotAndCleanupMaybe ledgerEnv oldState appResult (blockNo blk) isCons (isSyncedWithinSeconds (apSlotDetails appResult) 600) + tookSnapshot <- storeSnapshotAndCleanupMaybe ledgerEnv severity oldState appResult (blockNo blk) isCons (isSyncedWithinSeconds (apSlotDetails appResult) 600) pure (appResult, tookSnapshot) -- The function 'tickThenReapply' does zero validation, so add minimal validation ('blockPrevHash' @@ -323,13 +324,14 @@ getSliceMeta _ = Nothing storeSnapshotAndCleanupMaybe :: HasLedgerEnv -> + BM.Severity -> CardanoLedgerState -> ApplyResult -> BlockNo -> Bool -> SyncState -> IO Bool -storeSnapshotAndCleanupMaybe env oldState appResult blkNo isCons syncState = +storeSnapshotAndCleanupMaybe env severity oldState appResult blkNo isCons syncState = case maybeFromStrict (apNewEpoch appResult) of Just newEpoch | newEpochNo <- unEpochNo (Generic.neEpoch newEpoch) @@ -337,12 +339,12 @@ storeSnapshotAndCleanupMaybe env oldState appResult blkNo isCons syncState = , isCons || (newEpochNo `mod` 10 == 0) || newEpochNo >= 503 -> do -- TODO: Instead of newEpochNo - 1, is there any way to get the epochNo from 'lssOldState'? - liftIO $ saveCleanupState env oldState (Just $ EpochNo $ newEpochNo - 1) + liftIO $ saveCleanupState env severity oldState (Just $ EpochNo $ newEpochNo - 1) pure True - _ -> + _otherwise -> if timeToSnapshot syncState blkNo && isCons then do - liftIO $ saveCleanupState env oldState Nothing + liftIO $ saveCleanupState env severity oldState Nothing pure True else pure False where @@ -352,9 +354,9 @@ storeSnapshotAndCleanupMaybe env oldState appResult blkNo isCons syncState = (SyncFollowing, bno) -> bno `mod` leSnapshotEveryFollowing env == 0 (SyncLagging, _) -> False -saveCurrentLedgerState :: HasLedgerEnv -> CardanoLedgerState -> Maybe EpochNo -> IO () -saveCurrentLedgerState env lState mEpochNo = do - let logCtx = initLogCtx "saveCurrentLedgerState" "Cardano.DbSync.Ledger.State" +saveCurrentLedgerState :: HasLedgerEnv -> BM.Severity -> CardanoLedgerState -> Maybe EpochNo -> IO () +saveCurrentLedgerState env severity lState mEpochNo = do + let logCtx = initLogCtx severity "saveCurrentLedgerState" "Cardano.DbSync.Ledger.State" case mkLedgerStateFilename (leDir env) (clsState lState) mEpochNo of Origin -> pure () -- we don't store genesis At file -> do @@ -369,17 +371,17 @@ saveCurrentLedgerState env lState mEpochNo = do } else atomically $ writeTBQueue (leStateWriteQueue env) (file, lState) -runLedgerStateWriteThread :: Trace IO Text -> LedgerEnv -> IO () -runLedgerStateWriteThread tracer lenv = +runLedgerStateWriteThread :: Trace IO Text -> BM.Severity -> LedgerEnv -> IO () +runLedgerStateWriteThread tracer severity lenv = case lenv of - HasLedger le -> ledgerStateWriteLoop tracer (leStateWriteQueue le) (configCodec $ getTopLevelconfigHasLedger le) + HasLedger le -> ledgerStateWriteLoop tracer severity (leStateWriteQueue le) (configCodec $ getTopLevelconfigHasLedger le) NoLedger _ -> forever $ threadDelay 600000000 -- 10 minutes -ledgerStateWriteLoop :: Trace IO Text -> TBQueue (FilePath, CardanoLedgerState) -> CodecConfig CardanoBlock -> IO () -ledgerStateWriteLoop tracer swQueue codecConfig = +ledgerStateWriteLoop :: Trace IO Text -> BM.Severity -> TBQueue (FilePath, CardanoLedgerState) -> CodecConfig CardanoBlock -> IO () +ledgerStateWriteLoop tracer sevirity swQueue codecConfig = loop where - logCtx = initLogCtx "ledgerStateWriteLoop" "Cardano.DbSync.Ledger.State" + logCtx = initLogCtx sevirity "ledgerStateWriteLoop" "Cardano.DbSync.Ledger.State" loop :: IO () loop = do @@ -410,11 +412,11 @@ mkLedgerStateFilename dir ledger mEpochNo = lsfFilePath . dbPointToFileName dir mEpochNo <$> getPoint (ledgerTipPoint @CardanoBlock (ledgerState ledger)) -saveCleanupState :: HasLedgerEnv -> CardanoLedgerState -> Maybe EpochNo -> IO () -saveCleanupState env ledger mEpochNo = do +saveCleanupState :: HasLedgerEnv -> BM.Severity -> CardanoLedgerState -> Maybe EpochNo -> IO () +saveCleanupState env severity ledger mEpochNo = do let st = clsState ledger - saveCurrentLedgerState env ledger mEpochNo - cleanupLedgerStateFiles env $ + saveCurrentLedgerState env severity ledger mEpochNo + cleanupLedgerStateFiles env severity $ fromWithOrigin (SlotNo 0) (ledgerTipSlot $ ledgerState st) hashToAnnotation :: ByteString -> ByteString @@ -475,16 +477,16 @@ parseLedgerStateFileName (LedgerStateDir stateDir) fp = -- ------------------------------------------------------------------------------------------------- -cleanupLedgerStateFiles :: HasLedgerEnv -> SlotNo -> IO () -cleanupLedgerStateFiles env slotNo = do +cleanupLedgerStateFiles :: HasLedgerEnv -> BM.Severity -> SlotNo -> IO () +cleanupLedgerStateFiles env severity slotNo = do files <- listLedgerStateFilesOrdered (leDir env) let (epochBoundary, valid, invalid) = foldr groupFiles ([], [], []) files -- Remove invalid (ie SlotNo >= current) ledger state files (occurs on rollback). - deleteAndLogFiles env "invalid" invalid + deleteAndLogFiles env severity "invalid" invalid -- Remove all but 6 most recent state files. - deleteAndLogStateFile env "old" (List.drop 3 valid) + deleteAndLogStateFile env severity "old" (List.drop 3 valid) -- Remove all but 6 most recent epoch boundary state files. - deleteAndLogStateFile env "old epoch boundary" (List.drop 6 epochBoundary) + deleteAndLogStateFile env severity "old epoch boundary" (List.drop 6 epochBoundary) where groupFiles :: LedgerStateFile -> @@ -498,9 +500,9 @@ cleanupLedgerStateFiles env slotNo = do | otherwise = (epochBoundary, lFile : regularFile, invalid) -loadLedgerAtPoint :: HasLedgerEnv -> CardanoPoint -> IO (Either [LedgerStateFile] CardanoLedgerState) -loadLedgerAtPoint hasLedgerEnv point = do - let logCtx = initLogCtx "loadLedgerAtPoint" "Cardano.DbSync.Ledger.State" +loadLedgerAtPoint :: HasLedgerEnv -> BM.Severity -> CardanoPoint -> IO (Either [LedgerStateFile] CardanoLedgerState) +loadLedgerAtPoint hasLedgerEnv severity point = do + let logCtx = initLogCtx severity "loadLedgerAtPoint" "Cardano.DbSync.Ledger.State" mLedgerDB <- atomically $ readTVar $ leStateVar hasLedgerEnv -- First try to find the ledger in memory let mAnchoredSeq = rollbackLedger mLedgerDB @@ -511,7 +513,7 @@ loadLedgerAtPoint hasLedgerEnv point = do -- are or can be garbage collected. writeLedgerState hasLedgerEnv Strict.Nothing performMajorGC - mst <- findStateFromPoint hasLedgerEnv point + mst <- findStateFromPoint hasLedgerEnv severity point case mst of Right st -> do writeLedgerState hasLedgerEnv (Strict.Just . LedgerDB $ AS.Empty st) @@ -524,7 +526,7 @@ loadLedgerAtPoint hasLedgerEnv point = do logCtx {lcMessage = mconcat ["Found in memory ledger snapshot at ", renderPoint point]} let ledgerDB' = LedgerDB anchoredSeq' let st = ledgerDbCurrent ledgerDB' - deleteNewerFiles hasLedgerEnv point + deleteNewerFiles hasLedgerEnv severity point writeLedgerState hasLedgerEnv $ Strict.Just ledgerDB' pure $ Right st where @@ -536,22 +538,22 @@ loadLedgerAtPoint hasLedgerEnv point = do Strict.Just ledgerDB -> AS.rollback (pointSlot point) (const True) (ledgerDbCheckpoints ledgerDB) -deleteNewerFiles :: HasLedgerEnv -> CardanoPoint -> IO () -deleteNewerFiles env point = do +deleteNewerFiles :: HasLedgerEnv -> BM.Severity -> CardanoPoint -> IO () +deleteNewerFiles env severity point = do files <- listLedgerStateFilesOrdered (leDir env) -- Genesis can be reproduced from configuration. -- TODO: We can make this a monadic action (reread config from disk) to save some memory. case getPoint point of Origin -> do - deleteAndLogStateFile env "newer" files + deleteAndLogStateFile env severity "newer" files At blk -> do let (newerFiles, _found, _olderFiles) = findLedgerStateFile files (Point.blockPointSlot blk, mkRawHash $ Point.blockPointHash blk) - deleteAndLogStateFile env "newer" newerFiles + deleteAndLogStateFile env severity "newer" newerFiles -deleteAndLogFiles :: HasLedgerEnv -> Text -> [FilePath] -> IO () -deleteAndLogFiles env descr files = do - let logCtx = initLogCtx "deleteAndLogFiles" "Cardano.DbSync.Ledger.State" +deleteAndLogFiles :: HasLedgerEnv -> BM.Severity -> Text -> [FilePath] -> IO () +deleteAndLogFiles env severity descr files = do + let logCtx = initLogCtx severity "deleteAndLogFiles" "Cardano.DbSync.Ledger.State" case files of [] -> pure () [fl] -> do @@ -561,25 +563,25 @@ deleteAndLogFiles env descr files = do logInfoCtx (leTrace env) $ logCtx {lcMessage = mconcat ["Removing ", descr, " files ", textShow files]} mapM_ safeRemoveFile files -deleteAndLogStateFile :: HasLedgerEnv -> Text -> [LedgerStateFile] -> IO () -deleteAndLogStateFile env descr lsfs = deleteAndLogFiles env descr (lsfFilePath <$> lsfs) +deleteAndLogStateFile :: HasLedgerEnv -> BM.Severity -> Text -> [LedgerStateFile] -> IO () +deleteAndLogStateFile env severity descr lsfs = deleteAndLogFiles env severity descr (lsfFilePath <$> lsfs) -findStateFromPoint :: HasLedgerEnv -> CardanoPoint -> IO (Either [LedgerStateFile] CardanoLedgerState) -findStateFromPoint env point = do +findStateFromPoint :: HasLedgerEnv -> BM.Severity -> CardanoPoint -> IO (Either [LedgerStateFile] CardanoLedgerState) +findStateFromPoint env severity point = do files <- listLedgerStateFilesOrdered (leDir env) -- Genesis can be reproduced from configuration. -- TODO: We can make this a monadic action (reread config from disk) to save some memory. case getPoint point of Origin -> do - deleteAndLogStateFile env "newer" files + deleteAndLogStateFile env severity "newer" files pure . Right $ initCardanoLedgerState (leProtocolInfo env) At blk -> do let (newerFiles, found, olderFiles) = findLedgerStateFile files (Point.blockPointSlot blk, mkRawHash $ Point.blockPointHash blk) - deleteAndLogStateFile env "newer" newerFiles + deleteAndLogStateFile env severity "newer" newerFiles case found of Just lsf -> do - mState <- loadLedgerStateFromFile (leTrace env) (getTopLevelconfigHasLedger env) False point lsf + mState <- loadLedgerStateFromFile (leTrace env) severity (getTopLevelconfigHasLedger env) False point lsf case mState of Left err -> do deleteLedgerFile err lsf @@ -590,7 +592,7 @@ findStateFromPoint env point = do logNewerFiles olderFiles pure $ Left olderFiles where - logCtx = initLogCtx "findStateFromPoint" "Cardano.DbSync.Ledger.State" + logCtx = initLogCtx severity "findStateFromPoint" "Cardano.DbSync.Ledger.State" deleteLedgerFile :: Text -> LedgerStateFile -> IO () deleteLedgerFile err lsf = do @@ -649,14 +651,14 @@ comparePointToFile lsf (blSlotNo, blHash) = else GT x -> x -loadLedgerStateFromFile :: Trace IO Text -> TopLevelConfig CardanoBlock -> Bool -> CardanoPoint -> LedgerStateFile -> IO (Either Text CardanoLedgerState) -loadLedgerStateFromFile tracer config delete point lsf = do +loadLedgerStateFromFile :: Trace IO Text -> BM.Severity -> TopLevelConfig CardanoBlock -> Bool -> CardanoPoint -> LedgerStateFile -> IO (Either Text CardanoLedgerState) +loadLedgerStateFromFile tracer severity config delete point lsf = do mst <- safeReadFile (lsfFilePath lsf) case mst of Left err -> when delete (safeRemoveFile $ lsfFilePath lsf) >> pure (Left err) Right st -> pure $ Right st where - logCtx = initLogCtx "loadLedgerStateFromFile" "Cardano.DbSync.Ledger.State" + logCtx = initLogCtx severity "loadLedgerStateFromFile" "Cardano.DbSync.Ledger.State" safeReadFile :: FilePath -> IO (Either Text CardanoLedgerState) safeReadFile fp = do diff --git a/cardano-db-sync/src/Cardano/DbSync/LocalStateQuery.hs b/cardano-db-sync/src/Cardano/DbSync/LocalStateQuery.hs index 19d69816d..70b4fa908 100644 --- a/cardano-db-sync/src/Cardano/DbSync/LocalStateQuery.hs +++ b/cardano-db-sync/src/Cardano/DbSync/LocalStateQuery.hs @@ -11,6 +11,7 @@ module Cardano.DbSync.LocalStateQuery ( ) where import Cardano.BM.Trace (Trace) +import qualified Cardano.BM.Tracing as BM import Cardano.DbSync.Error (SyncNodeError (..)) import Cardano.DbSync.StateQuery import Cardano.DbSync.Types @@ -88,15 +89,16 @@ newStateQueryTMVar = StateQueryTMVar <$> newEmptyTMVarIO -- If the history interpreter does not exist, get one. -- If the existing history interpreter returns an error, get a new one and try again. getSlotDetailsNode :: + BM.Severity -> NoLedgerEnv -> SlotNo -> IO SlotDetails -getSlotDetailsNode nlEnv slot = do - einterp1 <- maybe (getHistoryInterpreter nlEnv) pure =<< atomically (fromStrictMaybe <$> readTVar interVar) +getSlotDetailsNode sevirity nlEnv slot = do + einterp1 <- maybe (getHistoryInterpreter sevirity nlEnv) pure =<< atomically (fromStrictMaybe <$> readTVar interVar) case evalSlotDetails einterp1 of Right sd -> insertCurrentTime sd Left _ -> do - einterp2 <- getHistoryInterpreter nlEnv + einterp2 <- getHistoryInterpreter sevirity nlEnv case evalSlotDetails einterp2 of Left err -> throwIO $ SNErrLocalStateQuery $ "getSlotDetailsNode: " <> Prelude.show err Right sd -> insertCurrentTime sd @@ -117,10 +119,11 @@ getSlotDetailsNode nlEnv slot = do fromStrictMaybe Strict.Nothing = Nothing getHistoryInterpreter :: + BM.Severity -> NoLedgerEnv -> IO CardanoInterpreter -getHistoryInterpreter nlEnv = do - let logCtx = initLogCtx "getHistoryInterpreter" "DbSync.LocalStateQuery" +getHistoryInterpreter severity nlEnv = do + let logCtx = initLogCtx severity "getHistoryInterpreter" "DbSync.LocalStateQuery" respVar <- newEmptyTMVarIO atomically $ putTMVar reqVar (BlockQuery $ QueryHardFork GetInterpreter, respVar) res <- atomically $ takeTMVar respVar diff --git a/cardano-db-sync/src/Cardano/DbSync/OffChain.hs b/cardano-db-sync/src/Cardano/DbSync/OffChain.hs index bb08aca7f..6c8c75787 100644 --- a/cardano-db-sync/src/Cardano/DbSync/OffChain.hs +++ b/cardano-db-sync/src/Cardano/DbSync/OffChain.hs @@ -17,10 +17,12 @@ module Cardano.DbSync.OffChain ( fetchOffChainVoteData, ) where +import qualified Cardano.BM.Data.Severity as BM import Cardano.BM.Trace (Trace) import Cardano.Db (runIohkLogging) import qualified Cardano.Db as DB import Cardano.DbSync.Api +import Cardano.DbSync.Api.Functions (getSeverity) import Cardano.DbSync.Api.Types (InsertOptions (..), SyncEnv (..)) import Cardano.DbSync.Config.Types import Cardano.DbSync.OffChain.Http @@ -105,9 +107,10 @@ loadOffChainWorkQueue _trce offChainWorkQueue = do insertOffChainPoolResults :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> StrictTBQueue IO OffChainPoolResult -> ReaderT SqlBackend m () -insertOffChainPoolResults trce resultQueue = do +insertOffChainPoolResults trce severity resultQueue = do res <- liftIO . atomically $ flushTBQueue resultQueue unless (null res) $ do let resLength = length res @@ -115,7 +118,7 @@ insertOffChainPoolResults trce resultQueue = do liftIO . logInfoCtx trce $ logCtx {lcMessage = logInsertOffChainResults "Pool" resLength resErrorsLength} mapM_ insert res where - logCtx = initLogCtx "insertOffChainPoolResults" "Cardano.DbSync.OffChain" + logCtx = initLogCtx severity "insertOffChainPoolResults" "Cardano.DbSync.OffChain" insert :: (MonadBaseControl IO m, MonadIO m) => OffChainPoolResult -> ReaderT SqlBackend m () insert = \case OffChainPoolResultMetadata md -> void $ DB.insertCheckOffChainPoolData md @@ -129,9 +132,10 @@ insertOffChainPoolResults trce resultQueue = do insertOffChainVoteResults :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> StrictTBQueue IO OffChainVoteResult -> ReaderT SqlBackend m () -insertOffChainVoteResults trce resultQueue = do +insertOffChainVoteResults trce severity resultQueue = do res <- liftIO . atomically $ flushTBQueue resultQueue unless (null res) $ do let resLength = length res @@ -139,7 +143,7 @@ insertOffChainVoteResults trce resultQueue = do liftIO . logInfoCtx trce $ logCtx {lcMessage = logInsertOffChainResults "Voting Anchor" resLength resErrorsLength} mapM_ insert res where - logCtx = initLogCtx "insertOffChainVoteResults" "Cardano.DbSync.OffChain" + logCtx = initLogCtx severity "insertOffChainVoteResults" "Cardano.DbSync.OffChain" insert :: (MonadBaseControl IO m, MonadIO m) => OffChainVoteResult -> ReaderT SqlBackend m () insert = \case OffChainVoteResultMetadata md accessors -> do @@ -180,6 +184,8 @@ logInsertOffChainResults offChainType resLength resErrorsLength = --------------------------------------------------------------------------------------------------------------------------------- runFetchOffChainPoolThread :: SyncEnv -> IO () runFetchOffChainPoolThread syncEnv = do + severity <- liftIO $ getSeverity syncEnv + let logCtx = initLogCtx severity "runFetchOffChainPoolThread" "Cardano.DbSync.OffChain" -- if dissable gov is active then don't run voting anchor thread when (ioOffChainPoolData iopts) $ do logInfoCtx trce $ logCtx {lcMessage = "Running Offchain Pool fetch thread"} @@ -195,7 +201,6 @@ runFetchOffChainPoolThread syncEnv = do now <- liftIO Time.getPOSIXTime mapM_ (queuePoolInsert <=< fetchOffChainPoolData trce manager now) poolq where - logCtx = initLogCtx "runFetchOffChainPoolThread" "Cardano.DbSync.OffChain" trce = getTrace syncEnv iopts = getInsertOptions syncEnv @@ -204,6 +209,8 @@ runFetchOffChainPoolThread syncEnv = do runFetchOffChainVoteThread :: SyncEnv -> IO () runFetchOffChainVoteThread syncEnv = do + severity <- liftIO $ getSeverity syncEnv + let logCtx = initLogCtx severity "runFetchOffChainVoteThread" "Cardano.DbSync.OffChain" -- if dissable gov is active then don't run voting anchor thread when (ioGov iopts) $ do logInfoCtx trce $ logCtx {lcMessage = "Running Offchain Vote Anchor fetch thread"} @@ -218,7 +225,6 @@ runFetchOffChainVoteThread syncEnv = do now <- liftIO Time.getPOSIXTime mapM_ (queueVoteInsert <=< fetchOffChainVoteData gateways now) voteq where - logCtx = initLogCtx "runFetchOffChainVoteThread" "Cardano.DbSync.OffChain" trce = getTrace syncEnv iopts = getInsertOptions syncEnv gateways = dncIpfsGateway $ envSyncNodeConfig syncEnv diff --git a/cardano-db-sync/src/Cardano/DbSync/Rollback.hs b/cardano-db-sync/src/Cardano/DbSync/Rollback.hs index 216a61807..52509bcd5 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Rollback.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Rollback.hs @@ -9,9 +9,11 @@ module Cardano.DbSync.Rollback ( unsafeRollback, ) where +import qualified Cardano.BM.Data.Severity as DM import Cardano.BM.Trace (Trace) import qualified Cardano.Db as DB import Cardano.DbSync.Api +import Cardano.DbSync.Api.Functions (getSeverity) import Cardano.DbSync.Api.Types (SyncEnv (..)) import Cardano.DbSync.Cache import Cardano.DbSync.Era.Util @@ -37,7 +39,8 @@ rollbackFromBlockNo :: BlockNo -> ExceptT SyncNodeError (ReaderT SqlBackend m) () rollbackFromBlockNo syncEnv blkNo = do - let logCtx = initLogCtx "rollbackFromBlockNo" "Cardano.DbSync.Rollback" + severity <- liftIO $ getSeverity syncEnv + let logCtx = initLogCtx severity "rollbackFromBlockNo" "Cardano.DbSync.Rollback" nBlocks <- lift $ DB.queryBlockCountAfterBlockNo (unBlockNo blkNo) True mres <- lift $ DB.queryBlockNoAndEpoch (unBlockNo blkNo) whenJust mres $ \(blockId, epochNo) -> do @@ -76,14 +79,20 @@ rollbackFromBlockNo syncEnv blkNo = do txOutTableType = getTxOutTableType syncEnv prepareRollback :: SyncEnv -> CardanoPoint -> Tip CardanoBlock -> IO (Either SyncNodeError Bool) -prepareRollback syncEnv point serverTip = - DB.runDbIohkNoLogging (envBackend syncEnv) $ runExceptT action +prepareRollback syncEnv point serverTip = do + severity <- liftIO $ getSeverity syncEnv + let logCtx = initLogCtx severity "prepareRollback" "Cardano.DbSync.Rollback" + when (severity == DM.Debug) $ do + logWarningCtx trce $ + logCtx + { lcMessage = "Rollback requested" + } + DB.runDbIohkNoLogging (envBackend syncEnv) $ runExceptT $ action logCtx where - logCtx = initLogCtx "prepareRollback" "Cardano.DbSync.Rollback" trce = getTrace syncEnv - action :: MonadIO m => ExceptT SyncNodeError (ReaderT SqlBackend m) Bool - action = do + action :: MonadIO m => LogContext -> ExceptT SyncNodeError (ReaderT SqlBackend m) Bool + action logCtx = do case getPoint point of Origin -> do nBlocks <- lift DB.queryCountSlotNo @@ -127,9 +136,9 @@ prepareRollback syncEnv point serverTip = pure False -- For testing and debugging. -unsafeRollback :: Trace IO Text -> DB.TxOutTableType -> DB.PGConfig -> SlotNo -> IO (Either SyncNodeError ()) -unsafeRollback trce txOutTableType config slotNo = do - let logCtx = initLogCtx "unsafeRollback" "Cardano.DbSync.Rollback" +unsafeRollback :: Trace IO Text -> DM.Severity -> DB.TxOutTableType -> DB.PGConfig -> SlotNo -> IO (Either SyncNodeError ()) +unsafeRollback trce severity txOutTableType config slotNo = do + let logCtx = initLogCtx severity "unsafeRollback" "Cardano.DbSync.Rollback" logWarningCtx trce $ logCtx { lcSlotNo = Just $ unSlotNo slotNo diff --git a/cardano-db-sync/src/Cardano/DbSync/Sync.hs b/cardano-db-sync/src/Cardano/DbSync/Sync.hs index ec25e2f0c..58dcb362f 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Sync.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Sync.hs @@ -24,12 +24,14 @@ module Cardano.DbSync.Sync ( runSyncNodeClient, ) where +import qualified Cardano.BM.Data.Severity as BM import Cardano.BM.Data.Tracer (ToLogObject (..), ToObject) import Cardano.BM.Trace (Trace, appendName) import qualified Cardano.BM.Trace as Logging import Cardano.Client.Subscription (subscribe) import Cardano.Db (runDbIohkLogging) import Cardano.DbSync.Api +import Cardano.DbSync.Api.Functions (getSeverity) import Cardano.DbSync.Api.Types (ConsistentLevel (..), FixesRan (..), LedgerEnv (..), SyncEnv (..), SyncOptions (..), envLedgerEnv, envNetworkMagic, envOptions) import Cardano.DbSync.Config import Cardano.DbSync.Database @@ -130,6 +132,8 @@ runSyncNodeClient :: SocketPath -> IO () runSyncNodeClient metricsSetters syncEnv iomgr trce tc (SocketPath socketPath) = do + severity <- liftIO $ getSeverity syncEnv + let logCtx = initLogCtx severity "runSyncNodeClient" "Cardano.DbSync.Sync" logInfoCtx trce $ logCtx {lcMessage = "Connecting to node via " <> textShow socketPath} void $ subscribe @@ -138,9 +142,8 @@ runSyncNodeClient metricsSetters syncEnv iomgr trce tc (SocketPath socketPath) = (supportedNodeToClientVersions (Proxy @CardanoBlock)) networkSubscriptionTracers clientSubscriptionParams - (dbSyncProtocols syncEnv metricsSetters tc codecConfig) + (dbSyncProtocols syncEnv severity metricsSetters tc codecConfig) where - logCtx = initLogCtx "runSyncNodeClient" "Cardano.DbSync.Sync" codecConfig :: CodecConfig CardanoBlock codecConfig = configCodec $ getTopLevelConfig syncEnv @@ -182,13 +185,14 @@ runSyncNodeClient metricsSetters syncEnv iomgr trce tc (SocketPath socketPath) = dbSyncProtocols :: SyncEnv -> + BM.Severity -> MetricSetters -> ThreadChannels -> CodecConfig CardanoBlock -> Network.NodeToClientVersion -> BlockNodeToClientVersion CardanoBlock -> NodeToClientProtocols 'InitiatorMode LocalAddress BSL.ByteString IO () Void -dbSyncProtocols syncEnv metricsSetters tc codecConfig version bversion = +dbSyncProtocols syncEnv severity metricsSetters tc codecConfig version bversion = NodeToClientProtocols { localChainSyncProtocol = localChainSyncPtcl , localTxSubmissionProtocol = dummylocalTxSubmit @@ -200,7 +204,7 @@ dbSyncProtocols syncEnv metricsSetters tc codecConfig version bversion = (Logging.nullTracer, cTxMonitorCodec codecs, localTxMonitorPeerNull) } where - logCtx = initLogCtx "dbSyncProtocols" "Cardano.DbSync.Sync" + logCtx = initLogCtx severity "dbSyncProtocols" "Cardano.DbSync.Sync" codecs = clientCodecs codecConfig bversion version localChainSyncTracer :: Tracer IO (TraceSendRecv (ChainSync CardanoBlock (Point CardanoBlock) (Tip CardanoBlock))) @@ -227,7 +231,7 @@ dbSyncProtocols syncEnv metricsSetters tc codecConfig version bversion = (cChainSyncCodec codecs) channel ( Client.chainSyncClientPeer $ - chainSyncClientFixConsumed backend syncEnv wrongEntriesSize + chainSyncClientFixConsumed backend syncEnv severity wrongEntriesSize ) logInfoCtx tracer $ logCtx {lcMessage = mconcat ["Fixed ", textShow fixedEntries, " consumed_by_tx_id wrong entries"]} @@ -239,7 +243,7 @@ dbSyncProtocols syncEnv metricsSetters tc codecConfig version bversion = let onlyFix = soptOnlyFix $ envOptions syncEnv if noneFixed fr && (onlyFix || not skipFix) then do - fd <- runDbIohkLogging backend tracer $ getWrongPlutusData tracer + fd <- runDbIohkLogging backend tracer $ getWrongPlutusData tracer severity unless (nullData fd) $ void $ runPeer @@ -247,7 +251,7 @@ dbSyncProtocols syncEnv metricsSetters tc codecConfig version bversion = (cChainSyncCodec codecs) channel ( Client.chainSyncClientPeer $ - chainSyncClientFixData backend tracer fd + chainSyncClientFixData backend tracer severity fd ) if onlyFix then do @@ -257,7 +261,7 @@ dbSyncProtocols syncEnv metricsSetters tc codecConfig version bversion = else if isDataFixed fr && (onlyFix || not skipFix) then do - ls <- runDbIohkLogging backend tracer $ getWrongPlutusScripts tracer + ls <- runDbIohkLogging backend tracer $ getWrongPlutusScripts tracer severity unless (nullPlutusScripts ls) $ void $ runPeer @@ -265,7 +269,7 @@ dbSyncProtocols syncEnv metricsSetters tc codecConfig version bversion = (cChainSyncCodec codecs) channel ( Client.chainSyncClientPeer $ - chainSyncClientFixScripts backend tracer ls + chainSyncClientFixScripts backend tracer severity ls ) when onlyFix $ panic "All Good! This error is only thrown to exit db-sync" setIsFixed syncEnv AllFixRan @@ -277,7 +281,7 @@ dbSyncProtocols syncEnv metricsSetters tc codecConfig version bversion = localChainSyncPtcl :: RunMiniProtocolWithMinimalCtx 'InitiatorMode LocalAddress BSL.ByteString IO () Void localChainSyncPtcl = InitiatorProtocolOnly $ MiniProtocolCb $ \_ctx channel -> do - let logCtx' = initLogCtx "localChainSyncPtcl" "Cardano.DbSync.Sync" + let logCtx' = initLogCtx severity "localChainSyncPtcl" "Cardano.DbSync.Sync" liftIO . logExceptionCtx tracer logCtx' {lcMessage = "ChainSyncWithBlocksPtcl "} $ do isInitComplete <- runAndSetDone tc $ initAction channel when isInitComplete $ do @@ -302,7 +306,7 @@ dbSyncProtocols syncEnv metricsSetters tc codecConfig version bversion = (cChainSyncCodec codecs) channel ( chainSyncClientPeerPipelined $ - chainSyncClient metricsSetters tracer (fst <$> latestPoints) currentTip tc + chainSyncClient metricsSetters tracer severity (fst <$> latestPoints) currentTip tc ) atomically $ writeDbActionQueue tc DbFinish -- We should return leftover bytes returned by 'runPipelinedPeer', but @@ -357,11 +361,12 @@ dbSyncProtocols syncEnv metricsSetters tc codecConfig version bversion = chainSyncClient :: MetricSetters -> Trace IO Text -> + BM.Severity -> [Point CardanoBlock] -> WithOrigin BlockNo -> ThreadChannels -> ChainSyncClientPipelined CardanoBlock (Point CardanoBlock) (Tip CardanoBlock) IO () -chainSyncClient metricsSetters trce latestPoints currentTip tc = do +chainSyncClient metricsSetters trce severity latestPoints currentTip tc = do ChainSyncClientPipelined $ pure $ clientPipelinedStIdle currentTip latestPoints where clientPipelinedStIdle :: @@ -448,7 +453,7 @@ chainSyncClient metricsSetters trce latestPoints currentTip tc = do pure $ finish newTip tip mPoints } where - logCtx = initLogCtx "mkClientStNext" "Cardano.DbSync.Sync" + logCtx = initLogCtx severity "mkClientStNext" "Cardano.DbSync.Sync" drainThePipe :: Nat n -> @@ -471,13 +476,13 @@ drainThePipe n0 client = go n0 } chainSyncClientFixConsumed :: - SqlBackend -> SyncEnv -> Word64 -> ChainSyncClient CardanoBlock (Point CardanoBlock) (Tip CardanoBlock) IO Integer -chainSyncClientFixConsumed backend syncEnv wrongTotalSize = Client.ChainSyncClient $ do + SqlBackend -> SyncEnv -> BM.Severity -> Word64 -> ChainSyncClient CardanoBlock (Point CardanoBlock) (Tip CardanoBlock) IO Integer +chainSyncClientFixConsumed backend syncEnv severity wrongTotalSize = Client.ChainSyncClient $ do liftIO $ logInfoCtx tracer $ logCtx {lcMessage = "Starting chainsync to fix consumed_by_tx_id Byron entries. See issue https://github.com/IntersectMBO/cardano-db-sync/issues/1821. This makes resyncing unnecessary."} pure $ Client.SendMsgFindIntersect [genesisPoint] clientStIntersect where tracer = getTrace syncEnv - logCtx = initLogCtx "chainSyncClientFixConsumed" "Cardano.DbSync.Sync" + logCtx = initLogCtx severity "chainSyncClientFixConsumed" "Cardano.DbSync.Sync" clientStIntersect = Client.ClientStIntersect { Client.recvMsgIntersectFound = \_blk _tip -> @@ -524,12 +529,12 @@ chainSyncClientFixConsumed backend syncEnv wrongTotalSize = Client.ChainSyncClie logCtx {lcMessage = mconcat ["Fixed ", textShow newSize, "/", textShow wrongTotalSize, " entries"]} chainSyncClientFixData :: - SqlBackend -> Trace IO Text -> FixData -> ChainSyncClient CardanoBlock (Point CardanoBlock) (Tip CardanoBlock) IO () -chainSyncClientFixData backend tracer fixData = Client.ChainSyncClient $ do + SqlBackend -> Trace IO Text -> BM.Severity -> FixData -> ChainSyncClient CardanoBlock (Point CardanoBlock) (Tip CardanoBlock) IO () +chainSyncClientFixData backend tracer severity fixData = Client.ChainSyncClient $ do liftIO $ logInfoCtx tracer $ logCtx {lcMessage = "Starting chainsync to fix Plutus Data. This will update database values in tables datum and redeemer_data."} clientStIdle True (sizeFixData fixData) fixData where - logCtx = initLogCtx "chainSyncClientFixData" "Cardano.DbSync.Sync" + logCtx = initLogCtx severity "chainSyncClientFixData" "Cardano.DbSync.Sync" updateSizeAndLog :: Int -> Int -> IO Int updateSizeAndLog lastSize currentSize = do let diffSize = lastSize - currentSize @@ -579,7 +584,7 @@ chainSyncClientFixData backend tracer fixData = Client.ChainSyncClient $ do clientStNext lastSize fdOnPoint fdRest = Client.ClientStNext { Client.recvMsgRollForward = \blk _tip -> Client.ChainSyncClient $ do - runDbIohkLogging backend tracer $ fixPlutusData tracer blk fdOnPoint + runDbIohkLogging backend tracer $ fixPlutusData tracer severity blk fdOnPoint clientStIdle False lastSize fdRest , Client.recvMsgRollBackward = \_point _tip -> Client.ChainSyncClient $ @@ -588,12 +593,12 @@ chainSyncClientFixData backend tracer fixData = Client.ChainSyncClient $ do } chainSyncClientFixScripts :: - SqlBackend -> Trace IO Text -> FixPlutusScripts -> ChainSyncClient CardanoBlock (Point CardanoBlock) (Tip CardanoBlock) IO () -chainSyncClientFixScripts backend tracer fps = Client.ChainSyncClient $ do + SqlBackend -> Trace IO Text -> BM.Severity -> FixPlutusScripts -> ChainSyncClient CardanoBlock (Point CardanoBlock) (Tip CardanoBlock) IO () +chainSyncClientFixScripts backend tracer severity fps = Client.ChainSyncClient $ do liftIO $ logInfoCtx tracer $ logCtx {lcMessage = "Starting chainsync to fix Plutus Scripts. This will update database values in tables script."} clientStIdle True (sizeFixPlutusScripts fps) fps where - logCtx = initLogCtx "chainSyncClientFixScripts" "Cardano.DbSync.Sync" + logCtx = initLogCtx severity "chainSyncClientFixScripts" "Cardano.DbSync.Sync" updateSizeAndLog :: Int -> Int -> IO Int updateSizeAndLog lastSize currentSize = do let diffSize = lastSize - currentSize @@ -643,7 +648,7 @@ chainSyncClientFixScripts backend tracer fps = Client.ChainSyncClient $ do clientStNext lastSize fpsOnPoint fpsRest = Client.ClientStNext { Client.recvMsgRollForward = \blk _tip -> Client.ChainSyncClient $ do - runDbIohkLogging backend tracer $ fixPlutusScripts tracer blk fpsOnPoint + runDbIohkLogging backend tracer $ fixPlutusScripts tracer severity blk fpsOnPoint clientStIdle False lastSize fpsRest , Client.recvMsgRollBackward = \_point _tip -> Client.ChainSyncClient $ diff --git a/cardano-db-sync/src/Cardano/DbSync/Util/Constraint.hs b/cardano-db-sync/src/Cardano/DbSync/Util/Constraint.hs index 4659966e4..0ba594ce3 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Util/Constraint.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Util/Constraint.hs @@ -16,8 +16,10 @@ module Cardano.DbSync.Util.Constraint ( ) where import Cardano.BM.Data.Trace (Trace) +import qualified Cardano.BM.Tracing as BM import Cardano.Db (ManualDbConstraints (..)) import qualified Cardano.Db as DB +import Cardano.DbSync.Api.Functions (getSeverity) import Cardano.DbSync.Api.Types (SyncEnv (..)) import Cardano.DbSync.Util.Logging (LogContext (..), initLogCtx, logInfoCtx) import Cardano.Prelude (MonadIO (..), Proxy (..), ReaderT (runReaderT), atomically) @@ -75,7 +77,7 @@ addStakeConstraintsIfNotExist :: ReaderT SqlBackend m () addStakeConstraintsIfNotExist syncEnv trce = do mdbc <- liftIO . readTVarIO $ envDbConstraints syncEnv - unless (dbConstraintEpochStake mdbc) (addEpochStakeTableConstraint trce) + unless (dbConstraintEpochStake mdbc) (addEpochStakeTableConstraint syncEnv trce) liftIO . atomically $ writeTVar (envDbConstraints syncEnv) (mdbc {dbConstraintEpochStake = True}) @@ -88,7 +90,8 @@ addRewardConstraintsIfNotExist :: ReaderT SqlBackend m () addRewardConstraintsIfNotExist syncEnv trce = do mdbc <- liftIO . readTVarIO $ envDbConstraints syncEnv - unless (dbConstraintRewards mdbc) (addRewardTableConstraint trce) + severity <- liftIO $ getSeverity syncEnv + unless (dbConstraintRewards mdbc) (addRewardTableConstraint trce severity) liftIO . atomically $ writeTVar (envDbConstraints syncEnv) (mdbc {dbConstraintRewards = True}) @@ -97,10 +100,11 @@ addRewardTableConstraint :: forall m. (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> + BM.Severity -> ReaderT SqlBackend m () -addRewardTableConstraint trce = do +addRewardTableConstraint trce severity = do let entityD = entityDef $ Proxy @DB.Reward - logCtx = initLogCtx "addRewardTableConstraint" "Cardano.DbSync.Util" + logCtx = initLogCtx severity "addRewardTableConstraint" "Cardano.DbSync.Util" DB.alterTable entityD ( DB.AddUniqueConstraint @@ -116,11 +120,13 @@ addRewardTableConstraint trce = do addEpochStakeTableConstraint :: forall m. (MonadBaseControl IO m, MonadIO m) => + SyncEnv -> Trace IO Text -> ReaderT SqlBackend m () -addEpochStakeTableConstraint trce = do +addEpochStakeTableConstraint syncEnv trce = do + severity <- liftIO $ getSeverity syncEnv let entityD = entityDef $ Proxy @DB.EpochStake - logCtx = initLogCtx "addEpochStakeTableConstraint" "Cardano.DbSync.Util" + logCtx = initLogCtx severity "addEpochStakeTableConstraint" "Cardano.DbSync.Util" DB.alterTable entityD ( DB.AddUniqueConstraint diff --git a/cardano-db-sync/src/Cardano/DbSync/Util/Logging.hs b/cardano-db-sync/src/Cardano/DbSync/Util/Logging.hs index 51d08fd63..6be28d93d 100644 --- a/cardano-db-sync/src/Cardano/DbSync/Util/Logging.hs +++ b/cardano-db-sync/src/Cardano/DbSync/Util/Logging.hs @@ -13,6 +13,7 @@ module Cardano.DbSync.Util.Logging ( logExceptionCtx, ) where +import qualified Cardano.BM.Data.Severity as BM import Cardano.BM.Trace (Trace, logDebug, logError, logInfo, logWarning) import Cardano.Prelude hiding (catch) import Control.Exception.Lifted (catch) @@ -22,7 +23,8 @@ import qualified Data.Time.Clock as Time import Prelude hiding (show, unwords, (.)) data LogContext = LogContext - { lcFunction :: Text + { lcSeverity :: BM.Severity + , lcFunction :: Text , lcComponent :: Text , lcBlockNo :: Maybe Word64 , lcSlotNo :: Maybe Word64 @@ -30,23 +32,27 @@ data LogContext = LogContext , lcMessage :: Text } --- TODO: We could select what to show here with a debug flag! formatLogMessage :: LogContext -> Text formatLogMessage ctx = - unwords - [ lcMessage ctx - , "[Function:" - , lcFunction ctx - , "| Component:" - , lcComponent ctx - , "| Block No:" - , maybe "None" (pack . show) (lcBlockNo ctx) - , "| Slot No:" - , maybe "None" (pack . show) (lcSlotNo ctx) - , "| Epoch No:" - , maybe "None" (pack . show) (lcEpochNo ctx) - , "]" - ] + unwords $ + lcMessage ctx : debugLogs + where + debugLogs = + case lcSeverity ctx of + BM.Debug -> + [ "[Function:" + , lcFunction ctx + , "| Component:" + , lcComponent ctx + , "| Block No:" + , maybe "None" (pack . show) (lcBlockNo ctx) + , "| Slot No:" + , maybe "None" (pack . show) (lcSlotNo ctx) + , "| Epoch No:" + , maybe "None" (pack . show) (lcEpochNo ctx) + , "]" + ] + _otherwise -> [] -- Wrapper functions using LogContext logInfoCtx :: Trace IO Text -> LogContext -> IO () @@ -61,10 +67,11 @@ logErrorCtx trce ctx = logError trce (formatLogMessage ctx) logDebugCtx :: Trace IO Text -> LogContext -> IO () logDebugCtx trce ctx = logDebug trce (formatLogMessage ctx) -initLogCtx :: Text -> Text -> LogContext -initLogCtx functionName componentName = +initLogCtx :: BM.Severity -> Text -> Text -> LogContext +initLogCtx severity functionName componentName = LogContext - { lcFunction = functionName + { lcSeverity = severity + , lcFunction = functionName , lcComponent = componentName , lcBlockNo = Nothing , lcSlotNo = Nothing @@ -73,11 +80,17 @@ initLogCtx functionName componentName = } -- | Needed when debugging disappearing exceptions. -liftedLogExceptionCtx :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> Text -> m a -> m a -liftedLogExceptionCtx tracer txt action = +liftedLogExceptionCtx :: + (MonadBaseControl IO m, MonadIO m) => + Trace IO Text -> + BM.Severity -> + Text -> + m a -> + m a +liftedLogExceptionCtx tracer severity txt action = action `catch` logger where - logCtx = LogContext txt "Cardano.DbSync.Util" Nothing Nothing Nothing + logCtx = LogContext severity txt "Cardano.DbSync.Util" Nothing Nothing Nothing logger :: MonadIO m => SomeException -> m a logger e = @@ -86,7 +99,12 @@ liftedLogExceptionCtx tracer txt action = throwIO e -- | Log the runtime duration of an action. Mainly for debugging. -logActionDurationCtx :: (MonadBaseControl IO m, MonadIO m) => Trace IO Text -> LogContext -> m a -> m a +logActionDurationCtx :: + (MonadBaseControl IO m, MonadIO m) => + Trace IO Text -> + LogContext -> + m a -> + m a logActionDurationCtx tracer logCtx action = do before <- liftIO Time.getCurrentTime a <- action @@ -98,7 +116,11 @@ logActionDurationCtx tracer logCtx action = do -- code, the caught exception will not be logged. Therefore wrap all cardano-db-sync code that -- is called from network with an exception logger so at least the exception will be -- logged (instead of silently swallowed) and then rethrown. -logExceptionCtx :: Trace IO Text -> LogContext -> IO a -> IO a +logExceptionCtx :: + Trace IO Text -> + LogContext -> + IO a -> + IO a logExceptionCtx tracer logCtx action = action `catch` logger where diff --git a/cardano-db-sync/test/Cardano/DbSync/Gen.hs b/cardano-db-sync/test/Cardano/DbSync/Gen.hs index 86becae0f..b53799f0a 100644 --- a/cardano-db-sync/test/Cardano/DbSync/Gen.hs +++ b/cardano-db-sync/test/Cardano/DbSync/Gen.hs @@ -1,4 +1,3 @@ -{-# LANGUAGE OverloadedStrings #-} {-# LANGUAGE TypeApplications #-} {-# LANGUAGE NoImplicitPrelude #-} diff --git a/cardano-db-tool/cardano-db-tool.cabal b/cardano-db-tool/cardano-db-tool.cabal index d7339f0a3..3fa195ebd 100644 --- a/cardano-db-tool/cardano-db-tool.cabal +++ b/cardano-db-tool/cardano-db-tool.cabal @@ -70,6 +70,7 @@ library , contra-tracer , esqueleto , extra + , iohk-monitoring , ouroboros-consensus , ouroboros-consensus-cardano , ouroboros-network diff --git a/cardano-db-tool/src/Cardano/DbTool/Validate/Ledger.hs b/cardano-db-tool/src/Cardano/DbTool/Validate/Ledger.hs index 0572e5fdb..0193bb706 100644 --- a/cardano-db-tool/src/Cardano/DbTool/Validate/Ledger.hs +++ b/cardano-db-tool/src/Cardano/DbTool/Validate/Ledger.hs @@ -3,6 +3,7 @@ module Cardano.DbTool.Validate.Ledger ( validateLedger, ) where +import qualified Cardano.BM.Data.Severity as BM import qualified Cardano.Db as DB import Cardano.DbSync.Config import Cardano.DbSync.Config.Cardano @@ -49,7 +50,7 @@ validate params txOutTableType genCfg slotNo ledgerFiles = if ledgerSlot <= slotNo then do -- TODO fix GenesisPoint. This is only used for logging - Right state <- loadLedgerStateFromFile nullTracer (mkTopLevelConfig genCfg) False GenesisPoint ledgerFile + Right state <- loadLedgerStateFromFile nullTracer BM.Info (mkTopLevelConfig genCfg) False GenesisPoint ledgerFile validateBalance txOutTableType ledgerSlot (vpAddressUtxo params) state else do when logFailure . putStrLn $ redText "Ledger is newer than DB. Trying an older ledger."