Measure and log slow external actions

lib/Echidna.hs

@@ -54,7 +54,7 @@ prepareContract env contracts solFiles specifiedContract seed = do
                                  funs
 
   -- run processors
-  slitherInfo <- runSlither (NE.head solFiles) solConf.cryticArgs
+  slitherInfo <- runSlither (NE.head solFiles) solConf
   case find (< minSupportedSolcVersion) slitherInfo.solcVersions of
     Just outdatedVersion -> throwM $ OutdatedSolcVersion outdatedVersion
     Nothing -> pure ()

lib/Echidna/Processor.hs

@@ -19,15 +19,17 @@ import Data.Set (Set)
 import Data.Set qualified as Set
 import Data.Text (pack, isSuffixOf)
 import System.Directory (findExecutable)
-import System.Process (StdStream(..), readCreateProcessWithExitCode, proc, std_err)
 import System.Exit (ExitCode(..))
+import System.Process (StdStream(..), readCreateProcessWithExitCode, proc, std_err)
 import Text.Read (readMaybe)
 
 import EVM.ABI (AbiValue(..))
 import EVM.Types (Addr(..))
 
 import Echidna.ABI (hashSig, makeNumAbiValues, makeArrayAbiValues)
 import Echidna.Types.Signature (ContractName, FunctionName, FunctionHash)
+import Echidna.Types.Solidity (SolConf(..))
+import Echidna.Utility (measureIO)
 
 -- | Things that can go wrong trying to run a processor. Read the 'Show'
 -- instance for more detailed explanations.
@@ -122,14 +124,15 @@ instance FromJSON SlitherInfo where
           _ -> pure Nothing
 
 -- Slither processing
-runSlither :: FilePath -> [String] -> IO SlitherInfo
-runSlither fp extraArgs = if ".vy" `isSuffixOf` pack fp then return noInfo else do
+runSlither :: FilePath -> SolConf -> IO SlitherInfo
+runSlither fp solConf = if ".vy" `isSuffixOf` pack fp then return noInfo else do
   mp <- findExecutable "slither"
   case mp of
     Nothing -> throwM $ ProcessorNotFound "slither" "You should install it using 'pip3 install slither-analyzer --user'"
     Just path -> do
-      let args = ["--ignore-compile", "--print", "echidna", "--json", "-"] ++ extraArgs ++ [fp]
-      (ec, out, err) <- readCreateProcessWithExitCode (proc path args) {std_err = Inherit} ""
+      let args = ["--ignore-compile", "--print", "echidna", "--json", "-"] ++ solConf.cryticArgs ++ [fp]
+      (ec, out, err) <- measureIO solConf.quiet ("Running slither on " <> fp) $ do
+        readCreateProcessWithExitCode (proc path args) {std_err = Inherit} ""
       case ec of
         ExitSuccess ->
           case eitherDecode (BSL.pack out) of

lib/Echidna/Solidity.hs

@@ -46,6 +46,7 @@ import Echidna.Types.Solidity
 import Echidna.Types.Test (EchidnaTest(..))
 import Echidna.Types.Tx (basicTx, createTxWithValue, unlimitedGasPerBlock, initialTimestamp, initialBlockNumber)
 import Echidna.Types.World (World(..))
+import Echidna.Utility (measureIO)
 
 -- | Given a list of source caches (SourceCaches) and an optional contract name,
 -- select one that includes that contract (if possible). Otherwise, use the first source
@@ -88,8 +89,9 @@ compileContracts solConf fp = do
             stderr <- if solConf.quiet
                          then UseHandle <$> openFile nullFilePath WriteMode
                          else pure Inherit
-            (ec, out, err) <- readCreateProcessWithExitCode
-              (proc path $ (solConf.cryticArgs ++ solargs) |> x) {std_err = stderr} ""
+            (ec, out, err) <- measureIO solConf.quiet ("Compiling " <> x) $ do
+              readCreateProcessWithExitCode
+                (proc path $ (solConf.cryticArgs ++ solargs) |> x) {std_err = stderr} ""
             case ec of
               ExitSuccess -> readSolcBatch "crytic-export"
               ExitFailure _ -> throwM $ CompileFailure out err

lib/Echidna/Utility.hs

@@ -0,0 +1,14 @@
+module Echidna.Utility where
+
+import Control.Monad (unless)
+import Data.Time (diffUTCTime, getCurrentTime)
+import System.IO (hFlush, stdout)
+
+measureIO :: Bool -> String -> IO b -> IO b
+measureIO quiet message action = do
+  unless quiet $ putStr (message  <> "... ") >> hFlush stdout
+  t0 <- getCurrentTime
+  ret <- action
+  t1 <- getCurrentTime
+  unless quiet $ putStrLn $ "Done! (" <> show (diffUTCTime t1 t0) <> ")"
+  pure ret

src/Main.hs

@@ -56,6 +56,7 @@ import Echidna.UI
 import Echidna.Output.Source
 import Echidna.Output.Corpus
 import Echidna.Solidity (compileContracts, selectSourceCache)
+import Echidna.Utility (measureIO)
 import Etherscan qualified
 
 main :: IO ()
@@ -127,8 +128,10 @@ main = withUtf8 $ withCP65001 $ do
         Nothing ->
           pure ()
 
-      saveTxs (dir </> "reproducers") (filter (not . null) $ (.testReproducer) <$> campaign._tests)
-      saveTxs (dir </> "coverage") (snd <$> Set.toList campaign._corpus)
+      measureIO cfg.solConf.quiet "Saving test reproducers" $
+        saveTxs (dir </> "reproducers") (filter (not . null) $ (.testReproducer) <$> campaign._tests)
+      measureIO cfg.solConf.quiet "Saving corpus" $
+        saveTxs (dir </> "coverage") (snd <$> Set.toList campaign._corpus)
 
       -- TODO: Add another option to config for saving coverage report