@@ -22,15 +22,18 @@
22module Katip.Core where
22module Katip.Core where
24-------------------------------------------------------------------------------
24-------------------------------------------------------------------------------
25−import Control.Applicative as A
25+import Control.Applicative as A
26import Control.AutoUpdate
26import Control.AutoUpdate
27import Control.Concurrent
27import Control.Concurrent
28−import qualified Control.Concurrent.Async as Async
28+import qualified Control.Concurrent.Async as Async
29import Control.Concurrent.STM
29import Control.Concurrent.STM
30−import qualified Control.Concurrent.STM.TBQueue as BQ
30+import qualified Control.Concurrent.STM.TBQueue as BQ
31import Control.Exception.Safe
31import Control.Exception.Safe
32−import Control.Monad (unless, void)
32+import Control.Monad (unless, void, when)
33import Control.Monad.Base
33import Control.Monad.Base
34+#if MIN_VERSION_base(4, 9, 0)
35+import qualified Control.Monad.Fail as MF
34import Control.Monad.IO.Class
37import Control.Monad.IO.Class
35import Control.Monad.IO.Unlift
38import Control.Monad.IO.Unlift
36import Control.Monad.Trans.Class
39import Control.Monad.Trans.Class
@@ -41,28 +44,31 @@ import Control.Monad.Trans.Either
41import Control.Monad.Trans.Except
44import Control.Monad.Trans.Except
42import Control.Monad.Trans.Maybe
45import Control.Monad.Trans.Maybe
43import Control.Monad.Trans.Reader
46import Control.Monad.Trans.Reader
44−import Control.Monad.Trans.Resource (ResourceT, transResourceT)
47+import Control.Monad.Trans.Resource (MonadResource, ResourceT,
45−import Control.Monad.Trans.State.Lazy (StateT, mapStateT)
49+import Control.Monad.Trans.RWS.Lazy (RWST, mapRWST)
46−import qualified Control.Monad.Trans.State.Strict as Strict (StateT, mapStateT)
50+import qualified Control.Monad.Trans.RWS.Strict as Strict (RWST, mapRWST)
47−import Control.Monad.Trans.Writer.Lazy (WriterT, mapWriterT)
51+import Control.Monad.Trans.State.Lazy (StateT, mapStateT)
48−import qualified Control.Monad.Trans.Writer.Strict as Strict (WriterT, mapWriterT)
52+import qualified Control.Monad.Trans.State.Strict as Strict (StateT, mapStateT)
49−import Control.Monad.Trans.RWS.Lazy (RWST, mapRWST)
53+import Control.Monad.Trans.Writer.Lazy (WriterT, mapWriterT)
50−import qualified Control.Monad.Trans.RWS.Strict as Strict (RWST, mapRWST)
54+import qualified Control.Monad.Trans.Writer.Strict as Strict (WriterT,
51−import Data.Aeson (FromJSON (..), ToJSON (..),
56+import Data.Aeson (FromJSON (..), ToJSON (..),
53−import qualified Data.Aeson as A
58+import qualified Data.Aeson as A
54−import Data.Foldable as FT
59+import Data.Foldable as FT
55−import qualified Data.HashMap.Strict as HM
60+import qualified Data.HashMap.Strict as HM
56import Data.List
61import Data.List
57−import qualified Data.Map.Strict as M
62+import qualified Data.Map.Strict as M
63+import Data.Maybe (fromMaybe)
58−import Data.Semigroup as SG
64+import Data.Semigroup as SG
59import Data.String
65import Data.String
60import Data.String.Conv
66import Data.String.Conv
61−import Data.Text (Text)
67+import Data.Text (Text)
62−import qualified Data.Text as T
68+import qualified Data.Text as T
63−import qualified Data.Text.Lazy.Builder as B
69+import qualified Data.Text.Lazy.Builder as B
64import Data.Time
70import Data.Time
65−import GHC.Generics hiding (to)
71+import GHC.Generics hiding (to)
66#if MIN_VERSION_base(4, 8, 0)
72#if MIN_VERSION_base(4, 8, 0)
67#if !MIN_VERSION_base(4, 9, 0)
73#if !MIN_VERSION_base(4, 9, 0)
68import GHC.SrcLoc
74import GHC.SrcLoc
@@ -70,7 +76,7 @@ import GHC.SrcLoc
70import GHC.Stack
76import GHC.Stack
72import Language.Haskell.TH
78import Language.Haskell.TH
73−import qualified Language.Haskell.TH.Syntax as TH
79+import qualified Language.Haskell.TH.Syntax as TH
74import Lens.Micro
80import Lens.Micro
75import Lens.Micro.TH
81import Lens.Micro.TH
76import Network.HostName
82import Network.HostName
@@ -137,7 +143,7 @@ data Severity
137-- - 'V3' implies the maximum amount of payload information.
143-- - 'V3' implies the maximum amount of payload information.
138-- - Anything in between is left to the discretion of the developer.
144-- - Anything in between is left to the discretion of the developer.
139data Verbosity = V0 | V1 | V2 | V3
145data Verbosity = V0 | V1 | V2 | V3
140− deriving (Eq, Ord, Show, Read, Generic, Enum)
146+ deriving (Eq, Ord, Show, Read, Generic, Enum, Bounded)
143-------------------------------------------------------------------------------
149-------------------------------------------------------------------------------
@@ -244,7 +250,9 @@ newtype ThreadIdText = ThreadIdText {
246mkThreadIdText :: ThreadId -> ThreadIdText
252mkThreadIdText :: ThreadId -> ThreadIdText
247−mkThreadIdText = ThreadIdText . T.pack . show
253+mkThreadIdText = ThreadIdText . stripPrefix' "ThreadId " . T.pack . show
255+ stripPrefix' pfx t = fromMaybe t (T.stripPrefix pfx t)
250-------------------------------------------------------------------------------
258-------------------------------------------------------------------------------
@@ -532,52 +540,93 @@ itemJson verb a = toJSON $ a & itemPayload %~ payloadObject verb
533-- Scribes should always take a 'Severity' and 'Verbosity'.
541-- Scribes should always take a 'Severity' and 'Verbosity'.
535−-- Severity is used to *exclude log messages* that are < the provided
543+-- Severity is used to __exclude log messages__ that are lower than
536−-- Severity. For instance, if the user passes InfoS, DebugS items
544+-- the provided Severity. For instance, if the user passes InfoS,
537−-- should be ignored. Katip provides the 'permitItem' utility for this.
545+-- DebugS items should be ignored. Katip provides the 'permitItem'
546+-- utility for this. The user or the scribe may use 'permitAND' and
547+-- 'permitOR' to further customize this filtering, even dynamically if
539-- Verbosity is used to select keys from the log item's payload. Each
550-- Verbosity is used to select keys from the log item's payload. Each
540-- 'LogItem' instance describes what keys should be retained for each
551-- 'LogItem' instance describes what keys should be retained for each
541-- Verbosity level. Use the 'payloadObject' utility for extracting the keys
552-- Verbosity level. Use the 'payloadObject' utility for extracting the keys
542−-- that should be permitted.
553+-- that should be written.
544−-- There is no built-in mechanism in katip for telling a scribe that
545−-- its time to shut down. 'unregisterScribe' merely drops it from the
546−-- 'LogEnv'. This means there are 2 ways to handle resources as a scribe:
548−-- 1. Pass in the resource when the scribe is created. Handle
555+-- Scribes provide a finalizer IO action ('scribeFinalizer') that is
549−-- allocation and release of the resource elsewhere. This is what the
556+-- meant to synchronously flush any remaining writes and clean up any
550−-- Handle scribe does.
557+-- resources acquired when the scribe was created. Internally, katip
558+-- keeps a buffer for each scribe's writes. When 'closeScribe' or
559+-- 'closeScribes' is called, that buffer stops accepting new log
560+-- messages and after the last item in its buffer is sent to 'liPush',
561+-- calls the finalizer. Thus, when the finalizer returns, katip can
562+-- assume that all resources are cleaned up and all log messages are
552−-- 2. Return a finalizing function that tells the scribe to shut
565+-- While katip internally buffers messages per 'ScribeSettings', it
553−-- down. @katip-elasticsearch@'s @mkEsScribe@ returns an @IO (Scribe,
566+-- sends them one at a time to the scribe. Depending on the scribe
554−-- IO ())@. The finalizer will flush any queued log messages and shut
567+-- itself, it may make sense for that scribe to keep its own internal
555−-- down gracefully before returning. This can be hooked into your
568+-- buffer to batch-send logs if writing items one at a time is not
556−-- application's shutdown routine to ensure you never miss any log
569+-- efficient. The scribe implementer must be sure that on
557−-- messages on shutdown.
570+-- finalization, all writes are committed synchronously.
572+-- | Signature of a function passed to `Scribe` constructor and
573+-- mkScribe* functions that decides which messages to be
574+-- logged. Typically filters based on 'Severity', but can be
575+-- combined with other, custom logic with 'permitAND' and 'permitOR'
576+type PermitFunc = forall a. Item a -> IO Bool
579+-- | AND together 2 permit functions
580+permitAND :: PermitFunc -> PermitFunc -> PermitFunc
581+permitAND f1 f2 = \a -> liftA2 (&&) (f1 a) (f2 a)
583+-- | OR together 2 permit functions
584+permitOR :: PermitFunc -> PermitFunc -> PermitFunc
585+permitOR f1 f2 = \a -> liftA2 (||) (f1 a) (f2 a)
558data Scribe = Scribe {
588data Scribe = Scribe {
559− liPush :: forall a. LogItem a => Item a -> IO ()
589+ liPush :: forall a. LogItem a => Item a -> IO ()
590+ -- ^ How do we write an item to the scribe's output?
560− , scribeFinalizer :: IO ()
591+ , scribeFinalizer :: IO ()
561− -- ^ Provide a *blocking* finalizer to call when your scribe is
592+ -- ^ Provide a __blocking__ finalizer to call when your scribe is
593+ -- removed. All pending writes should be flushed synchronously. If
562− -- removed. If this is not relevant to your scribe, return () is
594+ -- this is not relevant to your scribe, return () is fine.
563− -- fine.
595+ , scribePermitItem :: PermitFunc
596+ -- ^ Provide a filtering function to allow the item to be logged,
597+ -- or not. It can check Severity or some string in item's
598+ -- body. The initial value of this is usually created from
599+ -- 'permitItem'. Scribes and users can customize this by ANDing
600+ -- or ORing onto the default with 'permitAND' or 'permitOR'
604+whenM :: Monad m => m Bool -> m () -> m ()
605+whenM mbool = (>>=) mbool . flip when
608+-- | Combine two scribes. Publishes to the left scribe if the left
609+-- would permit the item and to the right scribe if the right would
610+-- permit the item. Finalizers are called in sequence from left to
567instance Semigroup Scribe where
612instance Semigroup Scribe where
568− (Scribe pushA finA) <> (Scribe pushB finB) =
613+ (Scribe pushA finA permitA) <> (Scribe pushB finB permitB) =
614+ Scribe (\item -> whenM (permitA item) (pushA item)
615+ >> whenM (permitB item) (pushB item)
569− Scribe (\item -> pushA item >> pushB item) (finA `finally` finB)
617+ (finA `finally` finB)
618+ (permitOR permitA permitB)
572instance Monoid Scribe where
621instance Monoid Scribe where
573− mempty = Scribe (const (return ())) (return ())
622+ mempty = Scribe (const (return ())) (return ()) (permitItem DebugS)
574 mappend = (<>)
623 mappend = (<>)
577-------------------------------------------------------------------------------
626-------------------------------------------------------------------------------
578data ScribeHandle = ScribeHandle {
627data ScribeHandle = ScribeHandle {
579 shScribe :: Scribe
628 shScribe :: Scribe
580− , shChan :: BQ.TBQueue WorkerMessage
629+ , shChan :: BQ.TBQueue WorkerMessage
@@ -589,8 +638,9 @@ data WorkerMessage where
590-------------------------------------------------------------------------------
639-------------------------------------------------------------------------------
591-- | Should this item be logged given the user's maximum severity?
640-- | Should this item be logged given the user's maximum severity?
641+-- Most new scribes will use this as a base for their 'PermitFunc'
592−permitItem :: Severity -> Item a -> Bool
642+permitItem :: Monad m => Severity -> Item a -> m Bool
593−permitItem sev i = _itemSeverity i >= sev
643+permitItem sev item = return (_itemSeverity item >= sev)
596-------------------------------------------------------------------------------
646-------------------------------------------------------------------------------
@@ -615,7 +665,7 @@ makeLenses ''LogEnv
617-------------------------------------------------------------------------------
667-------------------------------------------------------------------------------
618−-- | Create a reasonable default InitLogEnv. Uses an 'AutoUdate' which
668+-- | Create a reasonable default InitLogEnv. Uses an 'AutoUpdate' which
619-- updates the timer every 1ms. If you need even more timestamp
669-- updates the timer every 1ms. If you need even more timestamp
620-- precision at the cost of performance, consider setting
670-- precision at the cost of performance, consider setting
621-- '_logEnvTimer' with 'getCurrentTime'.
671-- '_logEnvTimer' with 'getCurrentTime'.
@@ -636,7 +686,9 @@ initLogEnv an env = LogEnv
637-------------------------------------------------------------------------------
687-------------------------------------------------------------------------------
638-- | Add a scribe to the list. All future log calls will go to this
688-- | Add a scribe to the list. All future log calls will go to this
639−-- scribe in addition to the others.
689+-- scribe in addition to the others. Writes will be buffered per the
690+-- ScribeSettings to prevent slow scribes from slowing down
691+-- logging. Writes will be dropped if the buffer fills.
640registerScribe
692registerScribe
642 -- ^ Name the scribe
694 -- ^ Name the scribe
@@ -660,7 +712,7 @@ registerScribe nm scribe ScribeSettings {..} le = do
661-------------------------------------------------------------------------------
713-------------------------------------------------------------------------------
662spawnScribeWorker :: Scribe -> BQ.TBQueue WorkerMessage -> IO (Async.Async ())
714spawnScribeWorker :: Scribe -> BQ.TBQueue WorkerMessage -> IO (Async.Async ())
663−spawnScribeWorker (Scribe write _) queue = Async.async go
715+spawnScribeWorker (Scribe write _ _) queue = Async.async go
666 newCmd <- atomically (BQ.readTBQueue queue)
718 newCmd <- atomically (BQ.readTBQueue queue)
@@ -689,7 +741,7 @@ defaultScribeSettings = ScribeSettings 4096
691-------------------------------------------------------------------------------
743-------------------------------------------------------------------------------
692−-- | Remove a scribe from the environment. This does *not* finalize
744+-- | Remove a scribe from the environment. This does __not__ finalize
693-- the scribe. This mainly only makes sense to use with something like
745-- the scribe. This mainly only makes sense to use with something like
694-- MonadReader's @local@ function to temporarily disavow a single
746-- MonadReader's @local@ function to temporarily disavow a single
695-- logger for a block of code.
747-- logger for a block of code.
@@ -702,7 +754,7 @@ unregisterScribe nm = logEnvScribes %~ M.delete nm
704-------------------------------------------------------------------------------
756-------------------------------------------------------------------------------
705−-- | Unregister *all* scribes. Note that this is *not* for closing or
757+-- | Unregister __all__ scribes. Note that this is __not__ for closing or
706-- finalizing scribes, use 'closeScribes' for that. This mainly only
758-- finalizing scribes, use 'closeScribes' for that. This mainly only
707-- makes sense to use with something like MonadReader's @local@
759-- makes sense to use with something like MonadReader's @local@
708-- function to temporarily disavow any loggers for a block of code.
760-- function to temporarily disavow any loggers for a block of code.
@@ -714,9 +766,10 @@ clearScribes = logEnvScribes .~ mempty
715-------------------------------------------------------------------------------
767-------------------------------------------------------------------------------
716-- | Finalize a scribe. The scribe is removed from the environment,
768-- | Finalize a scribe. The scribe is removed from the environment,
717−-- its finalizer is called and it can never be written to again. Note
769+-- its finalizer is called so that it can never be written to again
770+-- and all pending writes are flushed. Note that this will throw any
718−-- that this will throw any exceptions yoru finalizer will throw, and
771+-- exceptions yoru finalizer will throw, and that LogEnv is immutable,
719−-- that LogEnv is immutable, so it will not be removed in that case.
772+-- so it will not be removed in that case.
720closeScribe
773closeScribe
722 -- ^ Name of the scribe
775 -- ^ Name of the scribe
@@ -827,7 +880,8 @@ instance (Katip m) => Katip (ResourceT m) where
827-- opposed to implementing 'Katip' for your monad.
880-- opposed to implementing 'Katip' for your monad.
828newtype KatipT m a = KatipT { unKatipT :: ReaderT LogEnv m a }
881newtype KatipT m a = KatipT { unKatipT :: ReaderT LogEnv m a }
829 deriving ( Functor, Applicative, Monad, MonadIO
882 deriving ( Functor, Applicative, Monad, MonadIO
830− , MonadMask, MonadCatch, MonadThrow, MonadTrans, MonadBase b)
883+ , MonadMask, MonadCatch, MonadThrow, MonadResource, MonadTrans
833instance MonadIO m => Katip (KatipT m) where
887instance MonadIO m => Katip (KatipT m) where
@@ -849,9 +903,20 @@ instance (MonadBaseControl b m) => MonadBaseControl b (KatipT m) where
849 restoreM = defaultRestoreM
903 restoreM = defaultRestoreM
851instance MonadUnliftIO m => MonadUnliftIO (KatipT m) where
905instance MonadUnliftIO m => MonadUnliftIO (KatipT m) where
906+#if MIN_VERSION_unliftio_core(0, 2, 0)
907+ withRunInIO inner = KatipT $ ReaderT $ \le -> withRunInIO $ \run ->
908+ inner (run . runKatipT le)
852 askUnliftIO = KatipT $
910 askUnliftIO = KatipT $
853− withUnliftIO $ \u ->
911+ withUnliftIO $ \u ->
854− pure (UnliftIO (unliftIO u . unKatipT))
912+ pure (UnliftIO (unliftIO u . unKatipT))
915+#if MIN_VERSION_base(4, 9, 0)
916+instance MF.MonadFail m => MF.MonadFail (KatipT m) where
917+ fail msg = lift (MF.fail msg)
856-------------------------------------------------------------------------------
921-------------------------------------------------------------------------------
857-- | Execute 'KatipT' on a log env.
922-- | Execute 'KatipT' on a log env.
@@ -883,21 +948,32 @@ logItem
884logItem a ns loc sev msg = do
949logItem a ns loc sev msg = do
885 LogEnv{..} <- getLogEnv
950 LogEnv{..} <- getLogEnv
886− liftIO $ do
951+ logKatipItem =<< liftIO
888− <$> pure _logEnvApp
952+ (Item <$> pure _logEnvApp
889− <*> pure _logEnvEnv
953+ <*> pure _logEnvEnv
890− <*> pure sev
954+ <*> pure sev
891− <*> (mkThreadIdText <$> myThreadId)
955+ <*> (mkThreadIdText <$> myThreadId)
892− <*> pure _logEnvHost
956+ <*> pure _logEnvHost
893− <*> pure _logEnvPid
957+ <*> pure _logEnvPid
894− <*> pure a
958+ <*> pure a
895− <*> pure msg
959+ <*> pure msg
896− <*> _logEnvTimer
960+ <*> _logEnvTimer
897− <*> pure (_logEnvApp <> ns)
961+ <*> pure (_logEnvApp <> ns)
898− <*> pure loc
962+ <*> pure loc)
964+-- | Log already constructed 'Item'. This is the lowest level function that other log*
966+-- It can be useful when implementing centralised logging services.
968+ :: (A.Applicative m, LogItem a, Katip m)
971+logKatipItem item = do
972+ LogEnv{..} <- getLogEnv
974+ FT.forM_ (M.elems _logEnvScribes) $ \ ScribeHandle {..} -> do
975+ whenM (scribePermitItem shScribe item) $
899− FT.forM_ (M.elems _logEnvScribes) $ \ ScribeHandle {..} -> atomically (tryWriteTBQueue shChan (NewItem item))
976+ void $ atomically (tryWriteTBQueue shChan (NewItem item))
902-------------------------------------------------------------------------------
978-------------------------------------------------------------------------------
903tryWriteTBQueue
979tryWriteTBQueue
@@ -910,6 +986,7 @@ tryWriteTBQueue q a = do
910 unless full (writeTBQueue q a)
986 unless full (writeTBQueue q a)
911 return (not full)
987 return (not full)
913-------------------------------------------------------------------------------
990-------------------------------------------------------------------------------
914-- | Log with full context, but without any code location.
991-- | Log with full context, but without any code location.
@@ -942,7 +1019,7 @@ logException
942logException a ns sev action = action `catchAny` \e -> f e >> throwM e
1019logException a ns sev action = action `catchAny` \e -> f e >> throwM e
944 f e = logF a ns sev (msg e)
1021 f e = logF a ns sev (msg e)
945− msg e = ls (T.pack "An exception has occured: ") <> showLS e
1022+ msg e = ls (T.pack "An exception has occurred: ") <> showLS e
948-------------------------------------------------------------------------------
1025-------------------------------------------------------------------------------