on master help sign in
Adding support for custom LogItem formatters.
commit0809f5a1fccbf636ade337bef3230a084db6f648 authortmbull <tristan.bull@goilluminate.com> dateTue 18 Sep 2018, 13:43 (8 years ago) parent6751eb3
4 files changed+109−15
katip/src/Katip.hs+4 katip/src/Katip/Scribes/Handle.hs+54−12 katip/test/Katip/Tests/Scribes/Handle-json.golden+38 katip/test/Katip/Tests/Scribes/Handle.hs+13−3
katip/src/Katip.hs+4
@@ -177,8 +177,12 @@ module Katip
177177
178178 -- * Included Scribes
179179 , mkHandleScribe
180+ , mkHandleScribeWithFormatter
180181 , mkFileScribe
181182 , ColorStrategy (..)
183+ , ItemFormatter
184+ , bracketFormat
185+ , jsonFormat
182186
183187 -- * Tools for implementing Scribes
184188 , permitItem
katip/src/Katip/Scribes/Handle.hs+54−12
@@ -1,5 +1,3 @@
1−{-# LANGUAGE RecordWildCards #-}
2−
31module Katip.Scribes.Handle where
42
53-------------------------------------------------------------------------------
@@ -8,6 +6,8 @@ import Control.Concurrent
86import Control.Exception (bracket_, finally)
97import Control.Monad
108import Data.Aeson
9+import Data.Text.Lazy (toStrict)
10+import Data.Text.Lazy.Encoding (decodeUtf8)
1111import qualified Data.HashMap.Strict as HM
1212import Data.Monoid as M
1313import Data.Scientific as S
@@ -64,7 +64,15 @@ data ColorStrategy
6464-- Returns the newly-created `Scribe`. The finalizer flushes the
6565-- handle. Handle mode is set to 'LineBuffering' automatically.
6666mkHandleScribe :: ColorStrategy -> Handle -> Severity -> Verbosity -> IO Scribe
67−mkHandleScribe cs h sev verb = do
67+mkHandleScribe = mkHandleScribeWithFormatter bracketFormat
68+
69+-- | Logs to a file handle such as stdout, stderr, or a file. Takes a custom
70+-- `ItemFormatter` that can be used to format `Item` as needed.
71+--
72+-- Returns the newly-created `Scribe`. The finalizer flushes the
73+-- handle. Handle mode is set to 'LineBuffering' automatically.
74+mkHandleScribeWithFormatter :: (forall a . LogItem a => ItemFormatter a) -> ColorStrategy -> Handle -> Severity -> Verbosity -> IO Scribe
75+mkHandleScribeWithFormatter formatItem cs h sev verb = do
6876 hSetBuffering h LineBuffering
6977 colorize <- case cs of
7078 ColorIfTerminal -> hIsTerminalDevice h
@@ -90,8 +98,21 @@ mkFileScribe f sev verb = do
9098
9199
92100-------------------------------------------------------------------------------
93−formatItem :: LogItem a => Bool -> Verbosity -> Item a -> Builder
94−formatItem withColor verb Item{..} =
101+-- | A custom ItemFormatter for logging `Item`s. Takes a `Bool` indicating
102+-- whether to colorize the output, `Verbosity` of output, and an `Item` to
103+-- format.
104+--
105+-- See `bracketFormat` and `jsonFormat` for examples.
106+type ItemFormatter a = Bool -> Verbosity -> Item a -> Builder
107+
108+-- | A traditional 'bracketed' log format. Contexts and other information will
109+-- be flattened out into bracketed fields. For example:
110+--
111+-- > [2016-05-11 21:01:15][MyApp][Info][myhost.example.com][1724][ThreadId 1154][main:Helpers.Logging Helpers/Logging.hs:32:7] Started
112+-- > [2016-05-11 21:01:15][MyApp.confrabulation][Debug][myhost.example.com][1724][ThreadId 1154][confrab_factor:42.0][main:Helpers.Logging Helpers/Logging.hs:41:9] Confrabulating widgets, with extra namespace and context
113+-- > [2016-05-11 21:01:15][MyApp][Info][myhost.example.com][1724][ThreadId 1154][main:Helpers.Logging Helpers/Logging.hs:43:7] Namespace and context are back to normal
114+bracketFormat :: LogItem a => ItemFormatter a
115+bracketFormat withColor verb Item{..} =
95116 brackets nowStr <>
96117 brackets (mconcat $ map fromText $ intercalateNs _itemNamespace) <>
97118 brackets (fromText (renderSeverity' _itemSeverity)) <>
@@ -104,13 +125,34 @@ formatItem withColor verb Item{..} =
104125 where
105126 nowStr = fromText (formatAsLogTime _itemTime)
106127 ks = map brackets $ getKeys verb _itemPayload
107− renderSeverity' s = case s of
108− EmergencyS -> red $ renderSeverity s
109− AlertS -> red $ renderSeverity s
110− CriticalS -> red $ renderSeverity s
111− ErrorS -> red $ renderSeverity s
112− WarningS -> yellow $ renderSeverity s
113− _ -> renderSeverity s
128+ renderSeverity' severity =
129+ colorBySeverity withColor severity (renderSeverity severity)
130+
131+-- | Logs items as JSON. This can be useful in circumstances where you already
132+-- have infrastructure that is expecting JSON to be logged to a standard stream
133+-- or file. For example:
134+
135+-- > {"at":"2018-10-02T21:50:30.4523848Z","env":"production","ns":["MyApp"],"data":{},"app":["MyApp"],"msg":"Started","pid":"10456","loc":{"loc_col":9,"loc_pkg":"main","loc_mod":"Helpers.Logging","loc_fn":"Helpers\\Logging.hs","loc_ln":44},"host":"myhost.example.com","sev":"Info","thread":"ThreadId 139"}
136+-- > {"at":"2018-10-02T21:50:30.4523848Z","env":"production","ns":["MyApp","confrabulation"],"data":{"confrab_factor":42},"app":["MyApp"],"msg":"Confrabulating widgets, with extra namespace and context","pid":"10456","loc":{"loc_col":11,"loc_pkg":"main","loc_mod":"Helpers.Logging","loc_fn":"Helpers\\Logging.hs","loc_ln":53},"host":"myhost.example.com","sev":"Debug","thread":"ThreadId 139"}
137+-- > {"at":"2018-10-02T21:50:30.4523848Z","env":"production","ns":["MyApp"],"data":{},"app":["MyApp"],"msg":"Namespace and context are back to normal","pid":"10456","loc":{"loc_col":9,"loc_pkg":"main","loc_mod":"Helpers.Logging","loc_fn":"Helpers\\Logging.hs","loc_ln":55},"host":"myhost.example.com","sev":"Info","thread":"ThreadId 139"}
138+jsonFormat :: LogItem a => ItemFormatter a
139+jsonFormat withColor verb i =
140+ fromText $
141+ colorBySeverity withColor (_itemSeverity i) $
142+ toStrict $ decodeUtf8 $ encode $ itemJson verb i
143+
144+-- | Color a text message based on `Severity`. `ErrorS` and more severe errors
145+-- are colored red, `WarningS` is colored yellow, and all other messages are
146+-- rendered in the default color.
147+colorBySeverity :: Bool -> Severity -> Text -> Text
148+colorBySeverity withColor severity msg = case severity of
149+ EmergencyS -> red msg
150+ AlertS -> red msg
151+ CriticalS -> red msg
152+ ErrorS -> red msg
153+ WarningS -> yellow msg
154+ _ -> msg
155+ where
114156 red = colorize "31"
115157 yellow = colorize "33"
116158 colorize c s
katip/test/Katip/Tests/Scribes/Handle-json.goldennew file+38
@@ -0,0 +1,38 @@
1+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Debug","thread":"1337"}
2+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"1337"}
3+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Notice","thread":"1337"}
4+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Warning","thread":"1337"}
5+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Error","thread":"1337"}
6+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Critical","thread":"1337"}
7+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Alert","thread":"1337"}
8+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Emergency","thread":"1337"}
9+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"0"}
10+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"1"}
11+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"1337"}
12+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"2147483647"}
13+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"1337"}
14+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"www.example.com","sev":"Info","thread":"1337"}
15+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"127.0.0.1","sev":"Info","thread":"1337"}
16+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"0","loc":null,"host":"example","sev":"Info","thread":"1337"}
17+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"1","loc":null,"host":"example","sev":"Info","thread":"1337"}
18+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"1337","loc":null,"host":"example","sev":"Info","thread":"1337"}
19+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"2147483647","loc":null,"host":"example","sev":"Info","thread":"1337"}
20+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"1337"}
21+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message\nwith newline","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"1337"}
22+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":" a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message a really long message","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"1337"}
23+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"сообщение","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"1337"}
24+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"哈囉世界","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"1337"}
25+{"at":"2000-01-01T00:00:00Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"1337"}
26+{"at":"2123-12-31T23:59:59.999999999999Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"1337"}
27+{"at":"2016-10-10T01:01:05Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"1337"}
28+{"at":"2100-12-31T12:59:10.1Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"1337"}
29+{"at":"1982-01-01T12:30:00.000000000001Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"1337"}
30+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"1337"}
31+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo","bar"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"1337"}
32+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["фу","бар"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"1337"}
33+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["with\nnewline"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"1337"}
34+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"1337"}
35+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":{"loc_col":1,"loc_pkg":"main","loc_mod":"Some.Module","loc_fn":"path/Some/Module.hs","loc_ln":30},"host":"example","sev":"Info","thread":"1337"}
36+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"note":{"deep":"some note"}},"app":["app"],"msg":"message","pid":"7331","loc":{"loc_col":9000,"loc_pkg":"main","loc_mod":"Some.Module","loc_fn":"путь/Some/Module.hs","loc_ln":3000},"host":"example","sev":"Info","thread":"1337"}
37+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"sub":null,"list":[],"text":"","num":0,"float":0},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"1337"}
38+{"at":"2016-06-12T12:34:56Z","env":"production","ns":["foo"],"data":{"sub":{"note":{"deep":"some note"}},"list":["one","two","three"],"text":"note","num":10,"float":5.5},"app":["app"],"msg":"message","pid":"7331","loc":null,"host":"example","sev":"Info","thread":"1337"}
katip/test/Katip/Tests/Scribes/Handle.hs+13−3
@@ -1,4 +1,5 @@
11{-# LANGUAGE OverloadedStrings #-}
2+{-# LANGUAGE RankNTypes #-}
23module Katip.Tests.Scribes.Handle
34 ( tests
45 ) where
@@ -25,7 +26,6 @@ import Test.Tasty.HUnit
2526import Text.Regex.TDFA
2627-------------------------------------------------------------------------------
2728import Katip
28−import Katip.Scribes.Handle
2929-------------------------------------------------------------------------------
3030
3131
@@ -55,6 +55,10 @@ tests = testGroup "Katip.Scribes.Handle"
5555 goldenVsString "Text-golden"
5656 "test/Katip/Tests/Scribes/Handle-text.golden"
5757 (setupFn >>= writeTextLog)
58+ , withResource setupTempFile teardownTempFile $ \setupFn ->
59+ goldenVsString "Json-golden"
60+ "test/Katip/Tests/Scribes/Handle-json.golden"
61+ (setupFn >>= writeJsonLog)
5862 ]
5963
6064
@@ -234,14 +238,20 @@ mkUTCTime y mt d h mn s = UTCTime day dt
234238
235239-------------------------------------------------------------------------------
236240writeTextLog :: (FilePath, Handle) -> IO (BL.ByteString)
237−writeTextLog (path, h) = do
241+writeTextLog = writeFormattedLog bracketFormat
242+
243+writeJsonLog :: (FilePath, Handle) -> IO (BL.ByteString)
244+writeJsonLog = writeFormattedLog jsonFormat
245+
246+writeFormattedLog :: (forall a . LogItem a => ItemFormatter a) -> (FilePath, Handle) -> IO (BL.ByteString)
247+writeFormattedLog format (path, h) = do
238248 mapM_ (put . formatOne) genItems
239249 mapM_ (put . formatOne) genTypedItems
240250 hClose h
241251 BL.readFile path
242252 where
243253 formatOne :: LogItem a => Item a -> Text
244− formatOne = LT.toStrict . LT.toLazyText . formatItem False V3
254+ formatOne = LT.toStrict . LT.toLazyText . format False V3
245255 put = B.hPutStrLn h . T.encodeUtf8
246256
247257setupTempFile :: IO (FilePath, Handle)