Merge #1754

1754: Add logging and tracing to shelley integration tests r=rvl a=rvl

### Overview

To help debug integration tests cluster issues.

- [x] Add debug tracing around cluster startup and shutdown.
- [x] Allow increasing the minimum log severity for integration tests with an environment variable.
- [x] Make sure all cluster nodes have exactly the same start time. This prevents these errors:
   ```
   [blue:cardano.node.IpSubscription:Error:46] [2020-06-15 15:34:20.86 UTC] [String "Failed to start all required subscriptions",String "[127.0.0.1:3263,127.0.0.1:32865]",String "WithIPList SubscriptionTrace",String "LocalAddresses {laIpv4 = Just 0.0.0.0:0, laIpv6 = Just [::]:0, laUnix = Nothing}"]
   ```
- [x] Re-enable stake pools in test cluster.

# Comments

To do later:
- Output debug log files for each cardano-node process to the temporary directory — requires [CAD-1247](https://jira.iohk.io/browse/CAD-1247)
- Different hostnames in cardano-node logs — requires IntersectMBO/cardano-node#1278


Co-authored-by: Rodney Lorrimar <[email protected]>

lib/cli/src/Cardano/CLI.hs

@@ -62,6 +62,7 @@ module Cardano.CLI
     , helperTracing
     , loggingOptions
     , loggingSeverities
+    , parseLoggingSeverity
     , loggingSeverityOrOffReader
     , loggingSeverityReader
 
@@ -1776,25 +1777,19 @@ forceNtpCheckOption = flag False True $ mempty
     <> help "When set, will block and force an NTP check with the server. \
             \Otherwise, uses an available cached result."
 
+-- | The lower-case names of all 'Severity' values.
 loggingSeverities :: [(String, Severity)]
-loggingSeverities =
-    [ ("debug", Debug)
-    , ("info", Info)
-    , ("notice", Notice)
-    , ("warning", Warning)
-    , ("error", Error)
-    , ("critical", Critical)
-    , ("alert", Alert)
-    , ("emergency", Emergency)
-    ]
+loggingSeverities = [(toLower <$> show s, s) | s <- [minBound .. maxBound]]
 
-loggingSeverityReader :: ReadM Severity
-loggingSeverityReader = do
-    arg <- readerAsk
+parseLoggingSeverity :: String -> Either String Severity
+parseLoggingSeverity arg =
     case lookup (map toLower arg) loggingSeverities of
         Just sev -> pure sev
         Nothing -> fail $ "unknown logging severity: " ++ arg
 
+loggingSeverityReader :: ReadM Severity
+loggingSeverityReader = eitherReader parseLoggingSeverity
+
 loggingSeverityOrOffReader :: ReadM (Maybe Severity)
 loggingSeverityOrOffReader = do
     arg <- readerAsk

lib/core/src/Cardano/Wallet/Logging.hs

@@ -19,6 +19,8 @@ module Cardano.Wallet.Logging
     , trMessageText
     , filterTraceSeverity
     , stdoutTextTracer
+    , BracketLog (..)
+    , bracketTracer
     ) where
 
 import Prelude
@@ -40,6 +42,8 @@ import Control.Monad.IO.Class
     ( MonadIO (..) )
 import Control.Tracer
     ( Tracer (..), contramap, nullTracer, traceWith )
+import Control.Tracer.Observe
+    ( ObserveIndicator (..) )
 import Data.Text
     ( Text )
 import Data.Text.Class
@@ -131,3 +135,19 @@ filterNonEmpty tr = Tracer $ \arg -> do
 -- debugging functions in the REPL, when you need a 'Tracer' object.
 stdoutTextTracer :: (MonadIO m, ToText a) => Tracer m a
 stdoutTextTracer = Tracer $ liftIO . B8.putStrLn . T.encodeUtf8 . toText
+
+data BracketLog = BracketLog Text ObserveIndicator
+   deriving (Show)
+
+instance ToText BracketLog where
+    toText (BracketLog name b) =
+        name <> ": " <> case b of
+            ObserveBefore -> "start"
+            ObserveAfter -> "finish"
+
+bracketTracer :: Monad m => Tracer m BracketLog -> Text -> m a -> m a
+bracketTracer tr name action = do
+    traceWith tr $ BracketLog name ObserveBefore
+    res <- action
+    traceWith tr $ BracketLog name ObserveAfter
+    pure res

lib/shelley/cardano-wallet-shelley.cabal

@@ -188,12 +188,14 @@ test-suite integration
     , cardano-wallet-launcher
     , cardano-wallet-shelley
     , cardano-wallet-test-utils
+    , contra-tracer
     , hspec
     , http-client
     , iohk-monitoring
     , random
     , temporary
     , text
+    , text-class
   build-tools:
       cardano-wallet-shelley
   type: