Skip to content

Commit a622cd2

Browse files
edmundnobleedmundnoble
committed
log: make tx failure logging into a counter
Change-Id: I9986d5c9176c3c8f3aac803794b194c801c3514e
1 parent 10b76b1 commit a622cd2

File tree

16 files changed

+93
-55
lines changed

16 files changed

+93
-55
lines changed

‎bench/Chainweb/Pact/Backend/ForkingBench.hs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -318,7 +318,7 @@ withResources rdb trunkLength logLevel compact p f = C.envWithCleanup create des
318318

319319
startPact version l bhdb pdb mempool sqlEnv = do
320320
reqQ <- newPactQueue pactQueueSize
321-
a <- async $ runPactService version cid l reqQ mempool bhdb pdb sqlEnv testPactServiceConfig
321+
a <- async $ runPactService version cid l Nothing reqQ mempool bhdb pdb sqlEnv testPactServiceConfig
322322
{ _pactBlockGasLimit = 180_000
323323
, _pactPersistIntraBlockWrites = p
324324
}

‎changes/2024-05-30T150001-0400.txt

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1 @@
1+
Failed transactions are logged at Debug rather than Info

‎src/Chainweb/Chainweb.hs

Lines changed: 33 additions & 25 deletions
Original file line numberDiff line numberDiff line change
@@ -381,32 +381,40 @@ withChainwebInternal conf logger peer serviceSock rocksDb pactDbDir backupDir re
381381
logg Info "finished pruning databases"
382382
logFunctionJson logger Info InitializingChainResources
383383

384+
txFailuresCounter <- newCounter @"txFailures"
385+
let monitorTxFailuresCounter =
386+
runForever (logFunctionText logger) "monitor txFailuresCounter" $ do
387+
approximateThreadDelay 60000000 {- 1 minute -}
388+
logFunctionCounter logger Info . (:[]) =<<
389+
roll txFailuresCounter
384390
logg Info "start initializing chain resources"
385-
concurrentWith
386-
-- initialize chains concurrently
387-
(\cid x -> do
388-
let mcfg = validatingMempoolConfig cid v (_configBlockGasLimit conf) (_configMinGasPrice conf)
389-
-- NOTE: the gas limit may be set based on block height in future, so this approach may not be valid.
390-
let maxGasLimit = fromIntegral <$> maxBlockGasLimit v maxBound
391-
case maxGasLimit of
392-
Just maxGasLimit'
393-
| _configBlockGasLimit conf > maxGasLimit' ->
394-
logg Warn $ T.unwords
395-
[ "configured block gas limit is greater than the"
396-
, "maximum for this chain; the maximum will be used instead"
397-
]
398-
_ -> return ()
399-
withChainResources
400-
v
401-
cid
402-
rocksDb
403-
(chainLogger cid)
404-
mcfg
405-
payloadDb
406-
pactDbDir
407-
(pactConfig maxGasLimit)
408-
x
409-
)
391+
withAsync monitorTxFailuresCounter $ \_ ->
392+
concurrentWith
393+
-- initialize chains concurrently
394+
(\cid x -> do
395+
let mcfg = validatingMempoolConfig cid v (_configBlockGasLimit conf) (_configMinGasPrice conf)
396+
-- NOTE: the gas limit may be set based on block height in future, so this approach may not be valid.
397+
let maxGasLimit = fromIntegral <$> maxBlockGasLimit v maxBound
398+
case maxGasLimit of
399+
Just maxGasLimit'
400+
| _configBlockGasLimit conf > maxGasLimit' ->
401+
logg Warn $ T.unwords
402+
[ "configured block gas limit is greater than the"
403+
, "maximum for this chain; the maximum will be used instead"
404+
]
405+
_ -> return ()
406+
withChainResources
407+
v
408+
cid
409+
rocksDb
410+
(chainLogger cid)
411+
mcfg
412+
payloadDb
413+
pactDbDir
414+
(pactConfig maxGasLimit)
415+
txFailuresCounter
416+
x
417+
)
410418

411419
-- initialize global resources after all chain resources are initialized
412420
(\cs -> do

‎src/Chainweb/Chainweb/ChainResources.hs

Lines changed: 5 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@
88
{-# LANGUAGE TemplateHaskell #-}
99
{-# LANGUAGE TypeApplications #-}
1010
{-# LANGUAGE TypeFamilies #-}
11+
{-# LANGUAGE DataKinds #-}
1112

1213
-- |
1314
-- Module: Chainweb.Chainweb.ChainResources
@@ -53,6 +54,7 @@ import Chainweb.Version
5354
import Chainweb.WebPactExecutionService
5455

5556
import Chainweb.Storage.Table.RocksDB
57+
import Chainweb.Counter
5658

5759
-- -------------------------------------------------------------------------- --
5860
-- Single Chain Resources
@@ -88,16 +90,17 @@ withChainResources
8890
-> FilePath
8991
-- ^ database directory for checkpointer
9092
-> PactServiceConfig
93+
-> Counter "txFailures"
9194
-> (ChainResources logger -> IO a)
9295
-> IO a
9396
withChainResources
94-
v cid rdb logger mempoolCfg0 payloadDb pactDbDir pactConfig inner =
97+
v cid rdb logger mempoolCfg0 payloadDb pactDbDir pactConfig txFailuresCounter inner =
9598
withBlockHeaderDb rdb v cid $ \cdb -> do
9699
pexMv <- newEmptyMVar
97100
let mempoolCfg = mempoolCfg0 pexMv
98101
Mempool.withInMemoryMempool_ (setComponent "mempool" logger) mempoolCfg v $ \mempool -> do
99102
mpc <- MPCon.mkMempoolConsensus mempool cdb $ Just payloadDb
100-
withPactService v cid logger mpc cdb
103+
withPactService v cid logger (Just txFailuresCounter) mpc cdb
101104
payloadDb pactDbDir pactConfig $ \requestQ -> do
102105
let pex = pes requestQ
103106
putMVar pexMv pex

‎src/Chainweb/Pact/PactService.hs

Lines changed: 10 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@
1313
{-# LANGUAGE TypeApplications #-}
1414
{-# LANGUAGE TypeFamilies #-}
1515
{-# LANGUAGE ViewPatterns #-}
16+
{-# LANGUAGE DataKinds #-}
1617

1718
-- |
1819
-- Module: Chainweb.Pact.PactService
@@ -117,22 +118,24 @@ import Chainweb.Utils hiding (check)
117118
import Chainweb.Version
118119
import Chainweb.Version.Guards
119120
import Utils.Logging.Trace
121+
import Chainweb.Counter
120122

121123
runPactService
122124
:: Logger logger
123125
=> CanReadablePayloadCas tbl
124126
=> ChainwebVersion
125127
-> ChainId
126128
-> logger
129+
-> Maybe (Counter "txFailures")
127130
-> PactQueue
128131
-> MemPoolAccess
129132
-> BlockHeaderDb
130133
-> PayloadDb tbl
131134
-> SQLiteEnv
132135
-> PactServiceConfig
133136
-> IO ()
134-
runPactService ver cid chainwebLogger reqQ mempoolAccess bhDb pdb sqlenv config =
135-
void $ withPactService ver cid chainwebLogger bhDb pdb sqlenv config $ do
137+
runPactService ver cid chainwebLogger txFailuresCounter reqQ mempoolAccess bhDb pdb sqlenv config =
138+
void $ withPactService ver cid chainwebLogger txFailuresCounter bhDb pdb sqlenv config $ do
136139
initialPayloadState mempoolAccess ver cid
137140
serviceRequests mempoolAccess reqQ
138141

@@ -141,13 +144,14 @@ withPactService
141144
=> ChainwebVersion
142145
-> ChainId
143146
-> logger
147+
-> Maybe (Counter "txFailures")
144148
-> BlockHeaderDb
145149
-> PayloadDb tbl
146150
-> SQLiteEnv
147151
-> PactServiceConfig
148152
-> PactServiceM logger tbl a
149153
-> IO (T2 a PactServiceState)
150-
withPactService ver cid chainwebLogger bhDb pdb sqlenv config act =
154+
withPactService ver cid chainwebLogger txFailuresCounter bhDb pdb sqlenv config act =
151155
withProdRelationalCheckpointer checkpointerLogger (_pactModuleCacheLimit config) sqlenv (_pactPersistIntraBlockWrites config) ver cid $ \checkpointer -> do
152156
let !rs = readRewards
153157
let !pse = PactServiceEnv
@@ -166,6 +170,7 @@ withPactService ver cid chainwebLogger bhDb pdb sqlenv config act =
166170
, _psGasLogger = gasLogger <$ guard (_pactLogGas config)
167171
, _psBlockGasLimit = _pactBlockGasLimit config
168172
, _psEnableLocalTimeout = _pactEnableLocalTimeout config
173+
, _psTxFailuresCounter = txFailuresCounter
169174
}
170175
!pst = PactServiceState mempty
171176

@@ -763,7 +768,7 @@ execLocal cwtx preflight sigVerify rdepth = pactLabel "execLocal" $ do
763768
Right{} -> do
764769
let initialGas = initialGasOf $ P._cmdPayload cwtx
765770
T3 cr _mc warns <- liftIO $ applyCmd
766-
_psVersion _psLogger _psGasLogger (_cpPactDbEnv dbEnv)
771+
_psVersion _psLogger _psGasLogger Nothing (_cpPactDbEnv dbEnv)
767772
noMiner gasModel ctx spv cmd
768773
initialGas mc ApplyLocal
769774

@@ -1015,7 +1020,7 @@ execPreInsertCheckReq txs = pactLabel "execPreInsertCheckReq" $ do
10151020
, P.FlagDisableHistoryInTransactionalMode ] ++
10161021
disableReturnRTC (ctxVersion pd) (ctxChainId pd) (ctxCurrentBlockHeight pd)
10171022

1018-
let buyGasEnv = TransactionEnv P.Transactional (_cpPactDbEnv dbEnv) l Nothing (ctxToPublicData pd) spv nid gasPrice rk gasLimit ec Nothing
1023+
let buyGasEnv = TransactionEnv P.Transactional (_cpPactDbEnv dbEnv) l Nothing (ctxToPublicData pd) spv nid gasPrice rk gasLimit ec Nothing Nothing
10191024

10201025
cr <- liftIO
10211026
$! catchesPactError l CensorsUnexpectedError

‎src/Chainweb/Pact/PactService/ExecBlock.hs

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -423,6 +423,7 @@ applyPactCmd isGenesis miner txTimeLimit cmd = StateT $ \(T2 mcache maybeBlockGa
423423
logger <- view (psServiceEnv . psLogger)
424424
gasLogger <- view (psServiceEnv . psGasLogger)
425425
gasModel <- view (psServiceEnv . psGasModel)
426+
txFailuresCounter <- view (psServiceEnv . psTxFailuresCounter)
426427
v <- view chainwebVersion
427428
let
428429
-- for errors so fatal that the tx doesn't make it in the block
@@ -471,7 +472,8 @@ applyPactCmd isGenesis miner txTimeLimit cmd = StateT $ \(T2 mcache maybeBlockGa
471472
let txGas (T3 r _ _) = fromIntegral $ P._crGas r
472473
T3 r c _warns <-
473474
tracePactBlockM' "applyCmd" (J.toJsonViaEncode hsh) txGas $ do
474-
liftIO $ txTimeout $ applyCmd v logger gasLogger (_cpPactDbEnv dbEnv) miner (gasModel txCtx) txCtx spv gasLimitedCmd initialGas mcache ApplySend
475+
liftIO $ txTimeout $
476+
applyCmd v logger gasLogger txFailuresCounter (_cpPactDbEnv dbEnv) miner (gasModel txCtx) txCtx spv gasLimitedCmd initialGas mcache ApplySend
475477
pure $ T2 r c
476478

477479
if isGenesis

‎src/Chainweb/Pact/Service/PactInProcApi.hs

Lines changed: 8 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@
88
{-# LANGUAGE RankNTypes #-}
99
{-# LANGUAGE ScopedTypeVariables #-}
1010
{-# LANGUAGE TypeFamilies #-}
11+
{-# LANGUAGE TypeApplications #-}
1112

1213
-- |
1314
-- Module: Chainweb.Pact.Service.PactInProcApi
@@ -51,6 +52,7 @@ import Chainweb.Version
5152
import Data.LogMessage
5253

5354
import GHC.Stack (HasCallStack)
55+
import Chainweb.Counter (Counter)
5456

5557
-- | Initialization for Pact (in process) Api
5658
withPactService
@@ -59,16 +61,17 @@ withPactService
5961
=> ChainwebVersion
6062
-> ChainId
6163
-> logger
64+
-> Maybe (Counter "txFailures")
6265
-> MempoolConsensus
6366
-> BlockHeaderDb
6467
-> PayloadDb tbl
6568
-> FilePath
6669
-> PactServiceConfig
6770
-> (PactQueue -> IO a)
6871
-> IO a
69-
withPactService ver cid logger mpc bhdb pdb pactDbDir config action =
72+
withPactService ver cid logger txFailuresCounter mpc bhdb pdb pactDbDir config action =
7073
withSqliteDb cid logger pactDbDir (_pactResetDb config) $ \sqlenv ->
71-
withPactService' ver cid logger mpa bhdb pdb sqlenv config action
74+
withPactService' ver cid logger txFailuresCounter mpa bhdb pdb sqlenv config action
7275
where
7376
mpa = pactMemPoolAccess mpc $ addLabel ("sub-component", "MempoolAccess") logger
7477

@@ -81,21 +84,22 @@ withPactService'
8184
=> ChainwebVersion
8285
-> ChainId
8386
-> logger
87+
-> Maybe (Counter "txFailures")
8488
-> MemPoolAccess
8589
-> BlockHeaderDb
8690
-> PayloadDb tbl
8791
-> SQLiteEnv
8892
-> PactServiceConfig
8993
-> (PactQueue -> IO a)
9094
-> IO a
91-
withPactService' ver cid logger memPoolAccess bhDb pdb sqlenv config action = do
95+
withPactService' ver cid logger txFailuresCounter memPoolAccess bhDb pdb sqlenv config action = do
9296
reqQ <- newPactQueue (_pactQueueSize config)
9397
race (concurrently_ (monitor reqQ) (server reqQ)) (action reqQ) >>= \case
9498
Left () -> error "Chainweb.Pact.Service.PactInProcApi: pact service terminated unexpectedly"
9599
Right a -> return a
96100
where
97101
server reqQ = runForever logg "pact-service"
98-
$ PS.runPactService ver cid logger reqQ memPoolAccess bhDb pdb sqlenv config
102+
$ PS.runPactService ver cid logger txFailuresCounter reqQ memPoolAccess bhDb pdb sqlenv config
99103
logg = logFunction logger
100104
monitor = runPactServiceQueueMonitor $ addLabel ("sub-component", "PactQueue") logger
101105

‎src/Chainweb/Pact/TransactionExec.hs

Lines changed: 13 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,5 @@
11
{-# LANGUAGE AllowAmbiguousTypes #-}
2+
{-# LANGUAGE DataKinds #-}
23
{-# LANGUAGE BangPatterns #-}
34
{-# LANGUAGE DerivingStrategies #-}
45
{-# LANGUAGE FlexibleContexts #-}
@@ -68,7 +69,7 @@ import qualified Data.ByteString as B
6869
import qualified Data.ByteString.Short as SB
6970
import Data.Decimal (Decimal, roundTo)
7071
import Data.Default (def)
71-
import Data.Foldable (fold, for_)
72+
import Data.Foldable (fold, for_, traverse_)
7273
import Data.IORef
7374
import qualified Data.HashMap.Strict as HM
7475
import qualified Data.List as List
@@ -81,6 +82,7 @@ import qualified System.LogLevel as L
8182

8283
-- internal Pact modules
8384

85+
import Chainweb.Counter
8486
import Chainweb.Pact.Backend.Types (_cpPactDbEnv)
8587
import Pact.Eval (eval, liftTerm)
8688
import Pact.Gas (freeGasEnv)
@@ -172,6 +174,7 @@ applyCmd
172174
-- ^ Pact logger
173175
-> Maybe logger
174176
-- ^ Pact gas logger
177+
-> Maybe (Counter "txFailures")
175178
-> PactDbEnv p
176179
-- ^ Pact db environment
177180
-> Miner
@@ -191,7 +194,7 @@ applyCmd
191194
-> ApplyCmdExecutionContext
192195
-- ^ is this a local or send execution context?
193196
-> IO (T3 (CommandResult [TxLogJson]) ModuleCache (S.Set PactWarning))
194-
applyCmd v logger gasLogger pdbenv miner gasModel txCtx spv cmd initialGas mcache0 callCtx = do
197+
applyCmd v logger gasLogger txFailuresCounter pdbenv miner gasModel txCtx spv cmd initialGas mcache0 callCtx = do
195198
T2 cr st <- runTransactionM cenv txst applyBuyGas
196199

197200
let cache = _txCache st
@@ -214,7 +217,7 @@ applyCmd v logger gasLogger pdbenv miner gasModel txCtx spv cmd initialGas mcach
214217
<> flagsFor v (ctxChainId txCtx) (ctxCurrentBlockHeight txCtx)
215218

216219
cenv = TransactionEnv Transactional pdbenv logger gasLogger (ctxToPublicData txCtx) spv nid gasPrice
217-
requestKey (fromIntegral gasLimit) executionConfigNoHistory quirkGasFee
220+
requestKey (fromIntegral gasLimit) executionConfigNoHistory quirkGasFee txFailuresCounter
218221

219222
!requestKey = cmdToRequestKey cmd
220223
!gasPrice = view cmdGasPrice cmd
@@ -358,6 +361,7 @@ applyGenesisCmd logger dbEnv spv txCtx cmd =
358361
-- after the block height where pact4.4 is on.
359362
<> S.fromList [ FlagDisableInlineMemCheck, FlagDisablePact44 ]
360363
, _txQuirkGasFee = Nothing
364+
, _txTxFailuresCounter = Nothing
361365
}
362366
txst = TransactionState
363367
{ _txCache = mempty
@@ -444,7 +448,7 @@ applyCoinbase v logger dbEnv (Miner mid mks@(MinerKeys mk)) reward@(ParsedDecima
444448
, flagsFor v (ctxChainId txCtx) (ctxCurrentBlockHeight txCtx)
445449
]
446450
tenv = TransactionEnv Transactional dbEnv logger Nothing (ctxToPublicData txCtx) noSPVSupport
447-
Nothing 0.0 rk 0 ec Nothing
451+
Nothing 0.0 rk 0 ec Nothing Nothing
448452
txst = TransactionState mc mempty 0 Nothing (_geGasModel freeGasEnv) mempty
449453
initState = setModuleCache mc $ initCapabilities [magic_COINBASE]
450454
rk = RequestKey chash
@@ -519,7 +523,7 @@ applyLocal logger gasLogger dbEnv gasModel txCtx spv cmdIn mc execConfig =
519523
!gasPrice = view cmdGasPrice cmd
520524
!gasLimit = view cmdGasLimit cmd
521525
tenv = TransactionEnv Local dbEnv logger gasLogger (ctxToPublicData txCtx) spv nid gasPrice
522-
rk (fromIntegral gasLimit) execConfig Nothing
526+
rk (fromIntegral gasLimit) execConfig Nothing Nothing
523527
txst = TransactionState mc mempty 0 Nothing gasModel mempty
524528
gas0 = initialGasOf (_cmdPayload cmdIn)
525529
currHeight = ctxCurrentBlockHeight txCtx
@@ -581,7 +585,7 @@ readInitModules = do
581585
nid = Nothing
582586
chash = pactInitialHash
583587
tenv = TransactionEnv Local dbEnv logger Nothing (ctxToPublicData txCtx) noSPVSupport nid 0.0
584-
rk 0 def Nothing
588+
rk 0 def Nothing Nothing
585589
txst = TransactionState mempty mempty 0 Nothing (_geGasModel freeGasEnv) mempty
586590
interp = defaultInterpreter
587591
die msg = throwM $ PactInternalError $ "readInitModules: " <> msg
@@ -709,8 +713,10 @@ failTxWith err msg = do
709713
rk <- view txRequestKey
710714
l <- view txLogger
711715

712-
liftIO $ logFunction l L.Info
716+
liftIO $ logFunction l L.Debug
713717
(TxFailureLog rk err msg)
718+
liftIO . traverse_ inc
719+
=<< view txTxFailuresCounter
714720

715721
return $! CommandResult rk Nothing (PactResult (Left err))
716722
gas (Just logs) Nothing Nothing []

0 commit comments

Comments
 (0)