[CBR-430] add version and configuration key to JSON logs

auxx/Main.hs

@@ -169,7 +169,7 @@ main = withCompileInfo $ do
             | otherwise = identity
         loggingParams = disableConsoleLog $
             CLI.loggingParams loggerName (aoCommonNodeArgs opts)
-    loggerBracket loggingParams . logException "auxx" $ do
+    loggerBracket "auxx" loggingParams . logException "auxx" $ do
         let runAction a = action opts a
         case aoAction opts of
             Repl    -> withAuxxRepl $ \c -> runAction (Left c)

explorer/src/explorer/Main.hs

@@ -49,7 +49,7 @@ main :: IO ()
 main = do
     args <- getExplorerNodeOptions
     let loggingParams = CLI.loggingParams loggerName (enaCommonNodeArgs args)
-    loggerBracket loggingParams . logException "node" $ do
+    loggerBracket "explorer" loggingParams . logException "node" $ do
         logInfo "[Attention] Software is built with explorer part"
         action args
 

explorer/test/Test/Pos/Explorer/Socket/MethodsSpec.hs

@@ -37,8 +37,7 @@ import           Pos.Explorer.Socket.Methods (addrSubParam, addressSetByTxs,
                      unsubscribeTxs)
 import           Pos.Explorer.TestUtil (secretKeyToAddress)
 import           Pos.Explorer.Web.ClientTypes (CAddress (..), toCAddress)
-import           Pos.Util.Log.LoggerConfig (defaultTestConfiguration)
-import           Pos.Util.Wlog (Severity (Debug), setupLogging)
+import           Pos.Util.Wlog (setupTestLogging)
 
 import           Test.Pos.Explorer.MockFactory (mkTxOut)
 
@@ -50,7 +49,7 @@ import           Test.Pos.Explorer.MockFactory (mkTxOut)
 -- stack test cardano-sl-explorer --fast --test-arguments "-m Test.Pos.Explorer.Socket"
 
 spec :: Spec
-spec = beforeAll_ (setupLogging (defaultTestConfiguration Debug)) $
+spec = beforeAll_ setupTestLogging $
     describe "Methods" $ do
         describe "fromCAddressOrThrow" $
             it "throws an exception if a given CAddress is invalid" $

generator/app/VerificationBench.hs

@@ -183,7 +183,7 @@ readBlocks path = do
 
 main :: IO ()
 main = do
-    setupLogging loggerConfig
+    setupLogging "generator" loggerConfig
     args <- Opts.execParser
         $ Opts.info
             (benchArgsParser <**> Opts.helper)

generator/test/Test/Pos/Binary/CommunicationSpec.hs

@@ -17,8 +17,7 @@ import           Pos.DB.Class (Serialized (..))
 import           Pos.Network.Block.Types (MsgBlock (..),
                      MsgSerializedBlock (..))
 import           Pos.Util.CompileInfo (withCompileInfo)
-import           Pos.Util.Log.LoggerConfig (defaultTestConfiguration)
-import           Pos.Util.Wlog (Severity (Debug), setupLogging)
+import           Pos.Util.Wlog (setupTestLogging)
 
 import           Test.Pos.Block.Logic.Mode (blockPropertyTestable)
 import           Test.Pos.Block.Logic.Util (EnableTxPayload (..),
@@ -72,7 +71,7 @@ deserializeSerilizedMsgSerializedBlockSpec = do
     descNoBlock = "deserialization of a serialized MsgNoSerializedBlock message should give back corresponding MsgNoBlock"
 
 spec :: Spec
-spec = beforeAll_ (setupLogging (defaultTestConfiguration Debug)) $
+spec = beforeAll_ setupTestLogging $
     withStaticConfigurations $ \_ _ -> withCompileInfo $
         describe "Pos.Binary.Communication" $ do
             describe "serializeMsgSerializedBlock" serializeMsgSerializedBlockSpec

generator/test/Test/Pos/Block/Logic/VarSpec.hs

@@ -41,8 +41,7 @@ import           Pos.Generator.BlockEvent.DSL (BlockApplyResult (..),
                      runBlockEventGenT)
 import qualified Pos.GState as GS
 import           Pos.Launcher (HasConfigurations)
-import           Pos.Util.Log.LoggerConfig (defaultTestConfiguration)
-import           Pos.Util.Wlog (Severity (Debug), setupLogging)
+import           Pos.Util.Wlog (setupTestLogging)
 
 import           Test.Pos.Block.Logic.Event (BlockScenarioResult (..),
                      DbNotEquivalentToSnapshot (..), runBlockScenario)
@@ -61,7 +60,7 @@ import           Test.Pos.Util.QuickCheck.Property (splitIntoChunks,
 spec :: Spec
 -- Unfortunatelly, blocks generation is quite slow nowdays.
 -- See CSL-1382.
-spec = beforeAll_ (setupLogging (defaultTestConfiguration Debug)) $ withStaticConfigurations $ \txpConfig _ ->
+spec = beforeAll_ setupTestLogging $ withStaticConfigurations $ \txpConfig _ ->
     describe "Block.Logic.VAR" $ modifyMaxSuccess (min 4) $ do
         describe "verifyBlocksPrefix" $ verifyBlocksPrefixSpec txpConfig
         describe "verifyAndApplyBlocks" $ verifyAndApplyBlocksSpec txpConfig

lib/src/Pos/Launcher/Launcher.hs

@@ -20,7 +20,7 @@ import           Pos.Client.CLI.Params (getNodeParams)
 import           Pos.DB.DB (initNodeDBs)
 import           Pos.DB.Txp.Logic (txpGlobalSettings)
 import           Pos.Launcher.Configuration (AssetLockPath (..),
-                     HasConfigurations, WalletConfiguration,
+                     HasConfigurations, WalletConfiguration, cfoKey,
                      withConfigurations)
 import           Pos.Launcher.Param (LoggingParams (..), NodeParams (..))
 import           Pos.Launcher.Resource (NodeResources, bracketNodeResources,
@@ -48,12 +48,14 @@ launchNode
        )
     -> IO ()
 launchNode nArgs cArgs lArgs action = do
-    let withLogger' = loggerBracket lArgs . logException (lpDefaultName lArgs)
+    let confOpts = configurationOptions (commonArgs cArgs)
+    let confKey = cfoKey confOpts
+    let withLogger' = loggerBracket confKey lArgs . logException (lpDefaultName lArgs)
     let withConfigurations' = withConfigurations
             (AssetLockPath <$> cnaAssetLockPath cArgs)
             (cnaDumpGenesisDataPath cArgs)
             (cnaDumpConfiguration cArgs)
-            (configurationOptions (commonArgs cArgs))
+            confOpts
 
     withLogger' $ withConfigurations' $ \genesisConfig walletConfig txpConfig ntpConfig -> do
         (nodeParams, Just sscParams) <- getNodeParams

lib/src/Pos/Launcher/Resource.hs

@@ -247,12 +247,12 @@ getRealLoggerConfig LoggingParams{..} = do
                       -- add output to the console with severity filter >= Info
         Just False -> identity
 
-setupLoggers :: MonadIO m => LoggingParams -> m ()
-setupLoggers params = setupLogging =<< getRealLoggerConfig params
+setupLoggers :: MonadIO m => Text -> LoggingParams -> m ()
+setupLoggers cfoKey params = setupLogging cfoKey =<< getRealLoggerConfig params
 
 -- | RAII for Logging.
-loggerBracket :: LoggingParams -> IO a -> IO a
-loggerBracket lp = bracket_ (setupLoggers lp) removeAllHandlers
+loggerBracket :: Text -> LoggingParams -> IO a -> IO a
+loggerBracket cfoKey lp = bracket_ (setupLoggers cfoKey lp) removeAllHandlers
 
 ----------------------------------------------------------------------------
 -- NodeContext

lib/test/Test/Pos/Diffusion/BlockSpec.hs

@@ -45,9 +45,7 @@ import           Pos.Infra.Network.Types (Bucket (..))
 import           Pos.Infra.Reporting.Health.Types (HealthStatus (..))
 import           Pos.Logic.Pure (pureLogic)
 import           Pos.Logic.Types as Logic (Logic (..))
-import           Pos.Util.Log.LoggerConfig (defaultTestConfiguration)
-import           Pos.Util.Trace (wlogTrace, wsetupLogging)
-import           Pos.Util.Wlog (Severity (Debug))
+import           Pos.Util.Trace (setupTestTrace, wlogTrace)
 
 import           Test.Pos.Chain.Block.Arbitrary.Generate (generateMainBlock)
 
@@ -122,7 +120,7 @@ clientLogic = pureLogic
 
 withServer :: Transport -> Logic IO -> (NodeId -> IO t) -> IO t
 withServer transport logic k = do
-    logTrace <- liftIO $ wsetupLogging (defaultTestConfiguration Debug) ("server.outboundqueue")
+    logTrace <- liftIO $ setupTestTrace
     -- Morally, the server shouldn't need an outbound queue, but we have to
     -- give one.
     oq <- liftIO $ OQ.new

lib/test/Test/Pos/Launcher/ConfigurationSpec.hs

@@ -11,14 +11,13 @@ import           Pos.Core.Slotting (Timestamp (..))
 import           Pos.Launcher.Configuration (ConfigurationOptions (..),
                      defaultConfigurationOptions, withConfigurationsM)
 import           Pos.Util.Config (ConfigurationException)
-import           Pos.Util.Log.LoggerConfig (defaultTestConfiguration)
-import           Pos.Util.Wlog (Severity (Debug), setupLogging)
+import           Pos.Util.Wlog (setupTestLogging)
 
 spec :: Spec
 spec = describe "Pos.Launcher.Configuration" $ do
     describe "withConfigurationsM" $ do
         it "should parse `lib/configuration.yaml` file" $ do
-            liftIO $ setupLogging (defaultTestConfiguration Debug)
+            liftIO $ setupTestLogging
             startTime <- Timestamp . round . (* 1000000) <$> liftIO getPOSIXTime
             let cfo = defaultConfigurationOptions
                         { cfoFilePath = "./configuration.yaml"

networking/src/Bench/Network/Commons.hs

@@ -106,7 +106,7 @@ loadLogConfig logsPrefix configFile = do
         Nothing  -> return defaultLogConfig
         Just lc0 -> parseLoggerConfig lc0
     lc <- liftIO $ setLogPrefix logsPrefix lc1
-    setupLogging lc
+    setupLogging "bench" lc
 
 
 -- * Logging & parsing

networking/test/Test/NodeSpec.hs

@@ -35,9 +35,7 @@ import           Test.QuickCheck.Modifiers (NonEmptyList (..), getNonEmpty)
 
 import           Node
 import           Node.Message.Binary (binaryPacking)
-import           Pos.Util.Log.LoggerConfig (defaultTestConfiguration)
-import           Pos.Util.Trace (wsetupLogging)
-import           Pos.Util.Wlog (Severity (Debug))
+import           Pos.Util.Trace (setupTestTrace)
 import           Test.Util (HeavyParcel (..), Parcel (..), Payload (..),
                      TestState, deliveryTest, expected, makeInMemoryTransport,
                      makeTCPTransport, mkTestState, modifyTestState,
@@ -46,7 +44,7 @@ import           Test.Util (HeavyParcel (..), Parcel (..), Payload (..),
 spec :: Spec
 spec = describe "Node" $ modifyMaxSuccess (const 50) $ do
 
-    logTrace <- runIO $ wsetupLogging (defaultTestConfiguration Debug) "nodespec"
+    logTrace <- runIO $ setupTestTrace
 
         -- Take at most 25000 bytes for each Received message.
         -- We want to ensure that the MTU works, but not make the tests too

tools/src/keygen/Main.hs

@@ -156,7 +156,7 @@ genVssCert genesisConfig path = do
 main :: IO ()
 main = do
     KeygenOptions {..} <- getKeygenOptions
-    setupLogging $ defaultInteractiveConfiguration Debug
+    setupLogging "keygen" $ defaultInteractiveConfiguration Debug
     usingLoggerName "keygen"
         $ withConfigurations Nothing Nothing False koConfigurationOptions
         $ \genesisConfig _ _ _ -> do

tools/src/launcher/Main.hs

@@ -306,7 +306,7 @@ main =
             case loNodeLogConfig of
                 Nothing -> loNodeArgs
                 Just lc -> loNodeArgs ++ ["--log-config", toText lc]
-    setupLogging $
+    setupLogging (cfoKey loConfiguration) $
         defaultInteractiveConfiguration Info
             & lcBasePath .~ launcherLogsPrefix
             & lcLoggerTree %~ case launcherLogsPrefix of

util/cardano-sl-util.cabal

@@ -55,6 +55,7 @@ library
                        Pos.Util.Wlog
 
   other-modules:
+                       Paths_cardano_sl_util
                        Pos.Util.CompileInfoGit
                        Pos.Util.Log.Scribes
                        Pos.Util.Log.Rotator

util/src/Pos/Util/Log.hs

@@ -109,11 +109,11 @@ addLoggerName t f =
 
 -- | setup logging according to configuration @LoggerConfig@
 --   the backends (scribes) will be registered with katip
-setupLogging :: MonadIO m => LoggerConfig -> m LoggingHandler
-setupLogging lc = do
+setupLogging :: MonadIO m => Text -> LoggerConfig -> m LoggingHandler
+setupLogging cfoKey lc = do
     lh <- liftIO $ Internal.newConfig lc
     scribes <- liftIO $ meta lh lc
-    liftIO $ Internal.registerBackends lh scribes
+    liftIO $ Internal.registerBackends cfoKey lh scribes
     return lh
       where
         -- returns a list of: (name, Scribe, finalizer)
@@ -130,7 +130,7 @@ setupLogging lc = do
                                      (_lc ^. lcRotation)
             forM lhs (\lh -> case (lh ^. lhBackend) of
                     FileJsonBE -> do
-                        let bp = fromMaybe "." basepath
+                        let bp = fromMaybe "./" basepath
                             fp = fromMaybe "node.json" $ lh ^. lhFpath
                             fdesc = Internal.mkFileDescription bp fp
                             nm = lh ^. lhName
@@ -142,8 +142,8 @@ setupLogging lc = do
                                       K.V0
                         return (nm, scribe)
                     FileTextBE -> do
-                        let bp = fromMaybe "." basepath
-                            fp = (fromMaybe "node.log" $ lh ^. lhFpath)
+                        let bp = fromMaybe "./" basepath
+                            fp = fromMaybe "node.log" $ lh ^. lhFpath
                             fdesc = Internal.mkFileDescription bp fp
                             nm = lh ^. lhName
                         scribe <- mkTextFileScribe
@@ -179,7 +179,7 @@ setupLogging lc = do
 * example
 
     @
-      lh <- setupLogging logconf
+      lh <- setupLogging "test" logconf
       usingLoggerName lh "processXYZ" $
           logInfo "entering"
           complexWork "42"
@@ -208,7 +208,7 @@ usingLoggerNames lh names action = do
 * example
 
     @
-      lh <- setupLogging logconf
+      lh <- setupLogging "test" logconf
       loggerBracket lh "processXYZ" $
           logInfo "entering"
           complexWork "42"
@@ -236,22 +236,22 @@ loggerBracket lh name action = do
 {- |
    * interactive tests
 
-   >>> lh <- setupLogging $ defaultInteractiveConfiguration Info
+   >>> lh <- setupLogging "test" $ defaultInteractiveConfiguration Info
    >>> loggerBracket lh "testtest" $ do { logInfo "This is a message" }
 
-   >>> lh <- setupLogging $ defaultInteractiveConfiguration Info
+   >>> lh <- setupLogging "test" $ defaultInteractiveConfiguration Info
    >>> loggerBracket lh "testtest" $ do { logDebug "You won't see this message" }
 
-   >>> lh <- setupLogging $ defaultInteractiveConfiguration Info
+   >>> lh <- setupLogging "test" $ defaultInteractiveConfiguration Info
    >>> loggerBracket lh "testtest" $ do { logWarning "Attention!"; addLoggerName "levelUp" $ do { logError "..now it happened" } }
 
-   >>> lh <- setupLogging $ defaultInteractiveConfiguration Info
+   >>> lh <- setupLogging "test" $ defaultInteractiveConfiguration Info
    >>> usingLoggerName lh "testmore" $ do { logInfo "hello..." }
 
    >>> lc0 <- return $ defaultInteractiveConfiguration Info
    >>> newlt <- return $ lc0 ^. lcLoggerTree & ltNamedSeverity .~ Data.HashMap.Strict.fromList [("cardano-sl.silent", Error)]
    >>> lc <- return $ lc0 & lcLoggerTree .~ newlt
-   >>> lh <- setupLogging lc
+   >>> lh <- setupLogging "test" lc
    >>> usingLoggerName lh "silent" $ do { logWarning "you won't see this!" }
    >>> usingLoggerName lh "verbose" $ do { logWarning "now you read this!" }
 -}

util/src/Pos/Util/Log/Internal.hs

@@ -26,6 +26,8 @@ import           Control.Concurrent.MVar (modifyMVar_, newMVar, withMVar)
 
 import qualified Data.Text as T
 import           Data.Time (UTCTime, getCurrentTime)
+import           Data.Version (showVersion)
+import           Paths_cardano_sl_util (version)
 import           System.FilePath (splitFileName, (</>))
 import           Universum hiding (newMVar)
 
@@ -112,10 +114,10 @@ newConfig lc = do
     return $ LoggingHandler mv
 
 -- | register scribes in `katip`
-registerBackends :: LoggingHandler -> [(T.Text, K.Scribe)] -> IO ()
-registerBackends lh scribes = do
+registerBackends :: Text -> LoggingHandler -> [(T.Text, K.Scribe)] -> IO ()
+registerBackends cfoKey lh scribes = do
     LoggingHandlerInternal cfg _ ctx counter <- takeMVar (getLSI lh)
-    le0 <- K.initLogEnv (s2kname "cardano-sl") "production"
+    le0 <- K.initLogEnv (s2kname "cardano-sl") $ fromString $ (T.unpack cfoKey) <> ":" <> showVersion version
     -- use 'getCurrentTime' to get a more precise timestamp
     -- as katip uses per default some internal buffered time variable
     timer <- mkAutoUpdate defaultUpdateSettings { updateAction = getCurrentTime, updateFreq = 10000 }

util/src/Pos/Util/Trace.hs

@@ -13,7 +13,7 @@ module Pos.Util.Trace
     , Wlog.Severity (..)
     -- * trace setup
     , setupLogging
-    , wsetupLogging
+    , setupTestTrace
     , logTrace
     -- * log messages
     , logDebug
@@ -26,6 +26,7 @@ module Pos.Util.Trace
 import           Data.Functor.Contravariant (Contravariant (..), Op (..))
 import qualified Data.Text.IO as TIO
 import qualified Pos.Util.Log as Log
+import           Pos.Util.Log.LoggerConfig (defaultTestConfiguration)
 import qualified Pos.Util.Wlog as Wlog
 import           Universum hiding (trace)
 
@@ -44,20 +45,26 @@ natTrace nat (Trace (Op tr)) = Trace $ Op $ nat . tr
 
 -- | setup logging and return a Trace
 setupLogging :: MonadIO m
-             => Log.LoggerConfig
+             => Text
+             -> Log.LoggerConfig
              -> Log.LoggerName
              -> IO (Trace m (Log.Severity, Text))
-setupLogging lc ln = do
-    lh <- Log.setupLogging lc
+setupLogging cfoKey lc ln = do
+    lh <- Log.setupLogging cfoKey lc
     return $ logTrace lh ln
 
-wsetupLogging :: Wlog.LoggerConfig
+wsetupLogging :: Text
+              -> Wlog.LoggerConfig
               -> Wlog.LoggerName
               -> IO (Trace IO (Wlog.Severity, Text))
-wsetupLogging lc ln = do
-    Wlog.setupLogging lc
+wsetupLogging cfoKey lc ln = do
+    Wlog.setupLogging cfoKey lc
     return $ wlogTrace ln
 
+setupTestTrace :: IO (Trace IO (Wlog.Severity, Text))
+setupTestTrace =
+    wsetupLogging "test" (defaultTestConfiguration Wlog.Debug) "testing"
+
 trace :: Trace m s -> s -> m ()
 trace = getOp . runTrace