on master help sign in
Refactor logger a bit
commit547030f53c27941eae0824f2a7226dc163f54b6e authorJasper Van der Jeugt <m@jaspervdj.be> dateWed 14 Nov 2012, 11:17 (14 years ago) parent555f510
6 files changed+166−119
src/Hakyll/Core/Compiler.hs+7−19 src/Hakyll/Core/Compiler/Internal.hs+33−3 src/Hakyll/Core/Compiler/Require.hs+2−2 src/Hakyll/Core/Logger.hs+92−74 src/Hakyll/Core/Runtime.hs+29−18 src/Hakyll/Core/UnixFilter.hs+3−3
src/Hakyll/Core/Compiler.hs+7−19
@@ -16,8 +16,7 @@ module Hakyll.Core.Compiler
1616 , requireAll
1717 , cached
1818 , unsafeCompiler
19− , logCompiler
20− , timedCompiler
19+ , debugCompiler
2120 ) where
2221
2322
@@ -35,7 +34,7 @@ import Hakyll.Core.Compiler.Internal
3534import Hakyll.Core.Compiler.Require
3635import Hakyll.Core.Dependencies
3736import Hakyll.Core.Identifier
38−import Hakyll.Core.Logger
37+import Hakyll.Core.Logger as Logger
3938import Hakyll.Core.Metadata
4039import Hakyll.Core.ResourceProvider
4140import Hakyll.Core.Routes
@@ -72,7 +71,7 @@ getMetadata = getIdentifier >>= getMetadataFor
7271getMetadataFor :: Identifier -> Compiler Metadata
7372getMetadataFor identifier = do
7473 provider <- compilerProvider <$> compilerAsk
75− compilerTell [IdentifierDependency identifier]
74+ compilerTellDependencies [IdentifierDependency identifier]
7675 compilerUnsafeIO $ resourceMetadata provider identifier
7776
7877
@@ -116,19 +115,17 @@ cached :: (Binary a, Typeable a, Writable a)
116115 -> Compiler a
117116 -> Compiler a
118117cached name compiler = do
119− logger <- compilerLogger <$> compilerAsk
120118 id' <- compilerIdentifier <$> compilerAsk
121119 store <- compilerStore <$> compilerAsk
122120 provider <- compilerProvider <$> compilerAsk
123121 modified <- compilerUnsafeIO $ resourceModified provider id'
124− compilerUnsafeIO $ report logger $
125− "Checking cache: " ++ if modified then "modified" else "OK"
126122 if modified
127123 then do
128124 x <- compiler
129125 compilerUnsafeIO $ Store.set store [name, show id'] x
130126 return x
131127 else do
128+ compilerTellCacheHits 1
132129 x <- compilerUnsafeIO $ Store.get store [name, show id']
133130 progName <- compilerUnsafeIO getProgName
134131 case x of Store.Found x' -> return x'
@@ -146,16 +143,7 @@ unsafeCompiler = compilerUnsafeIO
146143
147144--------------------------------------------------------------------------------
148145-- | Compiler for debugging purposes
149−logCompiler :: String -> Compiler ()
150−logCompiler msg = do
146+debugCompiler :: String -> Compiler ()
147+debugCompiler msg = do
151148 logger <- compilerLogger <$> compilerAsk
152− compilerUnsafeIO $ report logger msg
153−
154−
155−--------------------------------------------------------------------------------
156−-- | Log and time a compiler
157−timedCompiler :: String -- ^ Message
158− -> Compiler a -- ^ Compiler to time
159− -> Compiler a -- ^ Resulting compiler
160−timedCompiler msg compiler = Compiler $ \r ->
161− timed (compilerLogger r) msg $ unCompiler compiler r
149+ compilerUnsafeIO $ Logger.debug logger msg
src/Hakyll/Core/Compiler/Internal.hs+33−3
@@ -3,16 +3,24 @@
33{-# LANGUAGE GADTs #-}
44{-# LANGUAGE GeneralizedNewtypeDeriving #-}
55module Hakyll.Core.Compiler.Internal
6− ( CompilerRead (..)
6+ ( -- * Types
7+ CompilerRead (..)
8+ , CompilerWrite (..)
79 , CompilerResult (..)
810 , Compiler (..)
911 , runCompiler
12+
13+ -- * Core operations
1014 , compilerTell
1115 , compilerAsk
1216 , compilerThrow
1317 , compilerCatch
1418 , compilerResult
1519 , compilerUnsafeIO
20+
21+ -- * Utilities
22+ , compilerTellDependencies
23+ , compilerTellCacheHits
1624 ) where
1725
1826
@@ -20,7 +28,7 @@ module Hakyll.Core.Compiler.Internal
2028import Control.Applicative (Alternative (..),
2129 Applicative (..))
2230import Control.Exception (SomeException, handle)
23−import Data.Monoid (mappend, mempty)
31+import Data.Monoid (Monoid (..))
2432
2533
2634--------------------------------------------------------------------------------
@@ -51,7 +59,17 @@ data CompilerRead = CompilerRead
5159
5260
5361--------------------------------------------------------------------------------
54−type CompilerWrite = [Dependency]
62+data CompilerWrite = CompilerWrite
63+ { compilerDependencies :: [Dependency]
64+ , compilerCacheHits :: Int
65+ } deriving (Show)
66+
67+
68+--------------------------------------------------------------------------------
69+instance Monoid CompilerWrite where
70+ mempty = CompilerWrite [] 0
71+ mappend (CompilerWrite d1 h1) (CompilerWrite d2 h2) =
72+ CompilerWrite (d1 ++ d2) (h1 + h2)
5573
5674
5775--------------------------------------------------------------------------------
@@ -165,3 +183,15 @@ compilerUnsafeIO io = Compiler $ \_ -> do
165183 x <- io
166184 return $ CompilerDone x mempty
167185{-# INLINE compilerUnsafeIO #-}
186+
187+
188+--------------------------------------------------------------------------------
189+compilerTellDependencies :: [Dependency] -> Compiler ()
190+compilerTellDependencies ds = compilerTell mempty {compilerDependencies = ds}
191+{-# INLINE compilerTellDependencies #-}
192+
193+
194+--------------------------------------------------------------------------------
195+compilerTellCacheHits :: Int -> Compiler ()
196+compilerTellCacheHits ch = compilerTell mempty {compilerCacheHits = ch}
197+{-# INLINE compilerTellCacheHits #-}
src/Hakyll/Core/Compiler/Require.hs+2−2
@@ -31,7 +31,7 @@ require :: (Binary a, Typeable a) => Identifier -> Compiler a
3131require id' = do
3232 store <- compilerStore <$> compilerAsk
3333
34− compilerTell [IdentifierDependency id']
34+ compilerTellDependencies [IdentifierDependency id']
3535 compilerResult $ CompilerRequire id' $ do
3636 result <- compilerUnsafeIO $ Store.get store (key id')
3737 case result of
@@ -54,7 +54,7 @@ requireAll :: (Binary a, Typeable a) => Pattern -> Compiler [a]
5454requireAll pattern = do
5555 universe <- compilerUniverse <$> compilerAsk
5656 let matching = filterMatches pattern universe
57− compilerTell [PatternDependency pattern matching]
57+ compilerTellDependencies [PatternDependency pattern matching]
5858 mapM require matching
5959
6060
src/Hakyll/Core/Logger.hs+92−74
@@ -1,40 +1,56 @@
1+--------------------------------------------------------------------------------
12-- | Produce pretty, thread-safe logs
2−--
3−{-# LANGUAGE BangPatterns #-}
43module Hakyll.Core.Logger
5− ( Logger
6− , makeLogger
7− , flushLogger
8− , section
9− , timed
10− , report
11− , thrown
4+ ( Verbosity (..)
5+ , Logger
6+ , new
7+ , flush
8+ , error
9+ , header
10+ , item
11+ , subitem
12+ , debug
1213 ) where
1314
14−import Control.Monad (forever)
15−import Control.Monad.Trans (MonadIO, liftIO)
16−import Control.Applicative (pure, (<$>), (<*>))
17−import Control.Concurrent (forkIO)
18−import Control.Concurrent.Chan (Chan, newChan, readChan, writeChan)
19−import Control.Concurrent.MVar (MVar, newEmptyMVar, takeMVar, putMVar)
20−import Text.Printf (printf)
2115
22−import Data.Time (getCurrentTime, diffUTCTime)
16+--------------------------------------------------------------------------------
17+import Control.Applicative (pure, (<$>), (<*>))
18+import Control.Concurrent (forkIO)
19+import Control.Concurrent.Chan (Chan, newChan, readChan, writeChan)
20+import Control.Concurrent.MVar (MVar, newEmptyMVar, putMVar, takeMVar)
21+import Control.Monad (forever)
22+import Control.Monad.Trans (MonadIO, liftIO)
23+import Data.List (intercalate)
24+import Prelude hiding (error)
2325
26+
27+--------------------------------------------------------------------------------
28+data Verbosity
29+ = Error
30+ | Header
31+ | Message
32+ | Debug
33+ deriving (Eq, Ord, Show)
34+
35+
36+--------------------------------------------------------------------------------
2437-- | Logger structure. Very complicated.
25−--
2638data Logger = Logger
27− { loggerChan :: Chan (Maybe String) -- ^ Nothing marks the end
28− , loggerSync :: MVar () -- ^ Used for sync on quit
29− , loggerSink :: String -> IO () -- ^ Out sink
39+ { loggerChan :: Chan (Maybe String) -- ^ Nothing marks the end
40+ , loggerSync :: MVar () -- ^ Used for sync on quit
41+ , loggerSink :: String -> IO () -- ^ Out sink
42+ , loggerVerbosity :: Verbosity -- ^ Verbosity
43+ , loggerColumns :: Int -- ^ Preferred number of columns
3044 }
3145
46+
47+--------------------------------------------------------------------------------
3248-- | Create a new logger
33−--
34−makeLogger :: (String -> IO ()) -> IO Logger
35−makeLogger sink = do
36− logger <- Logger <$> newChan <*> newEmptyMVar <*> pure sink
37− _ <- forkIO $ loggerThread logger
49+new :: Verbosity -> (String -> IO ()) -> IO Logger
50+new vbty sink = do
51+ logger <- Logger <$>
52+ newChan <*> newEmptyMVar <*> pure sink <*> pure vbty <*> pure 80
53+ _ <- forkIO $ loggerThread logger
3854 return logger
3955 where
4056 loggerThread logger = forever $ do
@@ -45,56 +61,58 @@ makeLogger sink = do
4561 -- Print and continue
4662 Just m -> loggerSink logger m
4763
64+
65+--------------------------------------------------------------------------------
4866-- | Flush the logger (blocks until flushed)
49−--
50−flushLogger :: Logger -> IO ()
51−flushLogger logger = do
67+flush :: Logger -> IO ()
68+flush logger = do
5269 writeChan (loggerChan logger) Nothing
5370 () <- takeMVar $ loggerSync logger
5471 return ()
5572
56−-- | Send a raw message to the logger
57−--
58−message :: Logger -> String -> IO ()
59−message logger = writeChan (loggerChan logger) . Just
60−
61−-- | Start a section in the log
62−--
63−section :: MonadIO m
64− => Logger -- ^ Logger
65− -> String -- ^ Section name
66− -> m () -- ^ No result
67−section logger = liftIO . message logger
68−
69−-- | Execute a monadic action and log the duration
70−--
71−timed :: MonadIO m
72− => Logger -- ^ Logger
73− -> String -- ^ Message
74− -> m a -- ^ Action
75− -> m a -- ^ Timed and logged action
76−timed logger msg action = do
77− start <- liftIO getCurrentTime
78− !result <- action
79− stop <- liftIO getCurrentTime
80− let diff = fromEnum $ diffUTCTime stop start
81− ms = diff `div` 10 ^ (9 :: Int)
82− formatted = printf " [%4dms] %s" ms msg
83− liftIO $ message logger formatted
84− return result
85−
86−-- | Log something at the same level as 'timed', but without the timing
87−--
88−report :: MonadIO m
89− => Logger -- ^ Logger
90− -> String -- ^ Message
91− -> m () -- ^ No result
92−report logger msg = liftIO $ message logger $ " [ ] " ++ msg
93−
94−-- | Log an error that was thrown in the compilation phase
95−--
96−thrown :: MonadIO m
97− => Logger -- ^ Logger
98− -> String -- ^ Message
99− -> m () -- ^ No result
100−thrown logger msg = liftIO $ message logger $ " [ ERROR] " ++ msg
73+
74+--------------------------------------------------------------------------------
75+string :: MonadIO m
76+ => Logger -- ^ Logger
77+ -> Verbosity -- ^ Verbosity of the string
78+ -> String -- ^ Section name
79+ -> m () -- ^ No result
80+string l v m
81+ | loggerVerbosity l >= v = liftIO $ writeChan (loggerChan l) (Just m)
82+ | otherwise = return ()
83+
84+
85+--------------------------------------------------------------------------------
86+error :: MonadIO m => Logger -> String -> m ()
87+error l m = string l Error $ "ERROR: " ++ m
88+
89+
90+--------------------------------------------------------------------------------
91+header :: MonadIO m => Logger -> String -> m ()
92+header l = string l Header
93+
94+
95+--------------------------------------------------------------------------------
96+item :: MonadIO m => Logger -> [String] -> m ()
97+item = itemWith 2
98+
99+
100+--------------------------------------------------------------------------------
101+subitem :: MonadIO m => Logger -> [String] -> m ()
102+subitem = itemWith 4
103+
104+
105+--------------------------------------------------------------------------------
106+itemWith :: MonadIO m => Int -> Logger -> [String] -> m ()
107+itemWith _ _ [] = return ()
108+itemWith i l [x] = string l Message $ replicate i ' ' ++ x
109+itemWith i l (x : ys) = string l Message $ indent ++ x ++ spaces ++ ys'
110+ where
111+ indent = replicate i ' '
112+ spaces = replicate (max 1 $ loggerColumns l - i - length x - length ys') ' '
113+ ys' = intercalate ", " ys
114+
115+
116+--------------------------------------------------------------------------------
117+debug :: MonadIO m => Logger -> String -> m ()
118+debug l m = string l Debug $ " DEBUG: " ++ m
src/Hakyll/Core/Runtime.hs+29−18
@@ -27,7 +27,8 @@ import Hakyll.Core.Compiler.Require
2727import Hakyll.Core.Configuration
2828import Hakyll.Core.Dependencies
2929import Hakyll.Core.Identifier
30−import Hakyll.Core.Logger
30+import Hakyll.Core.Logger (Logger)
31+import qualified Hakyll.Core.Logger as Logger
3132import Hakyll.Core.ResourceProvider
3233import Hakyll.Core.Routes
3334import Hakyll.Core.Rules.Internal
@@ -41,13 +42,15 @@ import Hakyll.Core.Writable
4142run :: Configuration -> Rules a -> IO RuleSet
4243run configuration rules = do
4344 -- Initialization
44− logger <- makeLogger putStrLn
45− section logger "Initialising"
46− store <- timed logger "Creating store" $
47− Store.new (inMemoryCache configuration) $ storeDirectory configuration
48− provider <- timed logger "Creating provider" $
49− newResourceProvider store (ignoreFile configuration) "."
50− ruleSet <- timed logger "Running rules" $ runRules rules provider
45+ logger <- Logger.new Logger.Debug putStrLn
46+ Logger.header logger "Initialising"
47+ Logger.item logger ["Creating store"]
48+ store <- Store.new (inMemoryCache configuration) $
49+ storeDirectory configuration
50+ Logger.item logger ["Creating provider"]
51+ provider <- newResourceProvider store (ignoreFile configuration) "."
52+ Logger.item logger ["Running rules"]
53+ ruleSet <- runRules rules provider
5154
5255 -- Get old facts
5356 mOldFacts <- Store.get store factsKey
@@ -73,11 +76,11 @@ run configuration rules = do
7376 -- Run the program and fetch the resulting state
7477 result <- runErrorT $ runRWST build read' state
7578 case result of
76− Left e -> thrown logger e
79+ Left e -> Logger.error logger e
7780 Right (_, s, _) -> Store.set store factsKey $ runtimeFacts s
7881
7982 -- Flush and return
80− flushLogger logger
83+ Logger.flush logger
8184 return ruleSet
8285 where
8386 factsKey = ["Hakyll.Core.Runtime.run", "facts"]
@@ -109,23 +112,25 @@ type Runtime a = RWST RuntimeRead () RuntimeState (ErrorT String IO) a
109112--------------------------------------------------------------------------------
110113build :: Runtime ()
111114build = do
115+ logger <- runtimeLogger <$> ask
116+ Logger.header logger "Checking for out-of-date items"
112117 scheduleOutOfDate
118+ Logger.header logger "Compiling"
113119 pickAndChase
120+ Logger.header logger "Success"
114121
115122
116123--------------------------------------------------------------------------------
117124scheduleOutOfDate :: Runtime ()
118125scheduleOutOfDate = do
119− logger <- runtimeLogger <$> ask
120126 provider <- runtimeProvider <$> ask
121127 universe <- runtimeUniverse <$> ask
122128 facts <- runtimeFacts <$> get
123129 todo <- runtimeTodo <$> get
124130
125131 let identifiers = map fst universe
126− modified <- timed logger "Checking for modified items" $
127− fmap S.fromList $ flip filterM identifiers $
128− liftIO . resourceModified provider
132+ modified <- fmap S.fromList $ flip filterM identifiers $
133+ liftIO . resourceModified provider
129134 let (ood, facts', _) = outOfDate identifiers modified facts
130135 todo' = M.fromList
131136 [(id', c) | (id', c) <- universe, id' `S.member` ood]
@@ -163,7 +168,6 @@ chase trail id'
163168 store <- runtimeStore <$> ask
164169 config <- runtimeConfiguration <$> ask
165170
166− section logger $ "Processing " ++ show id'
167171 let compiler = todo M.! id'
168172 read' = CompilerRead
169173 { compilerIdentifier = id'
@@ -174,18 +178,25 @@ chase trail id'
174178 , compilerLogger = logger
175179 }
176180
177− result <- timed logger "Compiling" $ liftIO $ runCompiler compiler read'
181+ result <- liftIO $ runCompiler compiler read'
178182 case result of
179183 -- Rethrow error
180184 CompilerError e -> throwError e
181185
182186 -- Huge success
183− CompilerDone (CompiledItem compiled) facts -> do
187+ CompilerDone (CompiledItem compiled) cwrite -> do
188+ let facts = compilerDependencies cwrite
189+ cacheHits
190+ | compilerCacheHits cwrite <= 0 = "modified"
191+ | otherwise = "cache hit"
192+ Logger.item logger [show id', cacheHits]
193+
184194 -- Write if necessary
185195 case runRoutes routes id' of
186196 Nothing -> return ()
187− Just url -> timed logger ("Routing to " ++ url) $ do
197+ Just url -> do
188198 let path = destinationDirectory config </> url
199+ Logger.subitem logger ["-> " ++ path]
189200 liftIO $ makeDirectories path
190201 liftIO $ write path compiled
191202
src/Hakyll/Core/UnixFilter.hs+3−3
@@ -75,9 +75,9 @@ unixFilterWith :: (Handle -> i -> IO ()) -- ^ Writer
7575 -> [String] -- ^ Program args
7676 -> i -- ^ Program input
7777 -> Compiler o -- ^ Program output
78−unixFilterWith writer reader programName args input =
79− timedCompiler ("Executing external program " ++ programName) $
80− unsafeCompiler $ unixFilterIO writer reader programName args input
78+unixFilterWith writer reader programName args input = do
79+ debugCompiler ("Executing external program " ++ programName)
80+ unsafeCompiler $ unixFilterIO writer reader programName args input
8181
8282
8383--------------------------------------------------------------------------------