on master help sign in
Add Process logging

Obelisk.CLI.Process exposes two functions that replace our use of callProcess and readProcess. They automatically send process output to logging. Like any other logging message, - Use severity level to control whether to show the (verbose) process output by default in console or not. - Logging won't interfer with a running spinner.

commit0040eeae5a77b0ec9ed5b0dd698b0c8e538749a1 authorSridhar Ratnakumar <srid@srid.ca> dateSun 13 May 2018, 13:24 (8 years ago) parent342ccab
7 files changed+134−51
lib/command/obelisk-command.cabal+2−1 lib/command/src/Obelisk/CLI/Logging.hs+27−14 lib/command/src/Obelisk/CLI/Process.hs+80 lib/command/src/Obelisk/CLI/Spinner.hs+4−2 lib/command/src/Obelisk/Command.hs+10−2 lib/command/src/Obelisk/Command/Nix.hs+5−21 lib/command/src/Obelisk/Command/Thunk.hs+6−11
lib/command/obelisk-command.cabal+2−1
@@ -20,7 +20,7 @@ library
2020 , filepath
2121 , github
2222 , hit
23− , questioner
23+ , io-streams
2424 , exceptions
2525 , logging-effect
2626 , mtl
@@ -38,6 +38,7 @@ library
3838 exposed-modules:
3939 Obelisk.App
4040 Obelisk.CLI.Logging
41+ Obelisk.CLI.Process
4142 Obelisk.CLI.Spinner
4243 Obelisk.Command
4344 Obelisk.Command.Deploy
lib/command/src/Obelisk/CLI/Logging.hs+27−14
@@ -9,6 +9,7 @@ module Obelisk.CLI.Logging
99 , Output (..)
1010 , failWith
1111 , putLog
12+ , putLogRaw
1213 , handleLog
1314 ) where
1415
@@ -26,14 +27,14 @@ import System.IO (hFlush, stdout)
2627
2728import Control.Monad.Log (MonadLog, Severity (..), WithSeverity (..), logMessage)
2829
29−
3030data LoggingConfig = LoggingConfig
31− { _loggingConfig_level :: Severity -- TODO: Start using this.
31+ { _loggingConfig_level :: Severity
3232 , _loggingConfig_lock :: MVar Bool -- Whether the last message was an Overwrite output
3333 }
3434
3535data Output
3636 = Output_Log (WithSeverity Text) -- Regular logging message (with colors and newlines)
37+ | Output_LogRaw (WithSeverity Text) -- Like `Output_Log` but without the implicit newline added.
3738 | Output_Overwrite [String] -- Overwrites the current line (i.e. \r followed by `putStr`)
3839 | Output_ClearLine -- Clears the line
3940 deriving (Eq, Show, Ord)
@@ -43,25 +44,33 @@ isOverwrite = \case
4344 Output_Overwrite _ -> True
4445 _ -> False
4546
47+getSeverity :: Output -> Maybe Severity
48+getSeverity = \case
49+ Output_Log (WithSeverity sev _) -> Just sev
50+ Output_LogRaw (WithSeverity sev _) -> Just sev
51+ _ -> Nothing
52+
4653handleLog :: MonadIO m => LoggingConfig -> Output -> m ()
47−handleLog c current = do
54+handleLog c output = do
4855 let lock = _loggingConfig_lock c
4956 liftIO $ modifyMVar_ lock $ \wasOverwriting -> do
50− case current of
51− Output_Log (WithSeverity sev _) -> do
57+ case getSeverity output of
58+ Nothing -> handleLog' output
59+ Just sev -> do
5260 -- Discard unless severity is above configured log level
5361 unless (sev > _loggingConfig_level c) $ do
5462 -- If the last output was an overwrite (with cursor on same line), first clear it,
5563 when wasOverwriting $ handleLog' Output_ClearLine
5664 -- ... then actually write the log.
57− handleLog' current
58− _ ->
59− handleLog' current
60− return $ isOverwrite current
65+ handleLog' output
66+ return $ isOverwrite output
6167
6268handleLog' :: MonadIO m => Output -> m ()
6369handleLog' = \case
64− Output_Log m -> liftIO $ writeLog m
70+ Output_Log m -> liftIO $ writeLogWith T.putStrLn m
71+ Output_LogRaw m -> liftIO $ do
72+ writeLogWith T.putStr m
73+ hFlush stdout
6574 Output_Overwrite xs -> liftIO $ putStrs $ "\r" : xs
6675 Output_ClearLine -> liftIO $ do
6776 -- Go to the first column and clear the whole line
@@ -76,6 +85,10 @@ handleLog' = \case
7685putLog :: MonadLog Output m => Severity -> Text -> m ()
7786putLog sev = logMessage . Output_Log . WithSeverity sev
7887
88+-- | Like `putLog` but without the implicit newline added.
89+putLogRaw :: MonadLog Output m => Severity -> Text -> m ()
90+putLogRaw sev = logMessage . Output_LogRaw . WithSeverity sev
91+
7992-- | Like `putLog Error` but also abrupts the program.
8093failWith :: (MonadIO m, MonadLog Output m) => Text -> m a
8194failWith s = do
@@ -84,13 +97,13 @@ failWith s = do
8497
8598-- | Write log to stdout with colors
8699-- TODO: Disable colours when not on interactive terminal
87−writeLog :: (MonadIO m, MonadMask m) => WithSeverity Text -> m ()
88−writeLog (WithSeverity severity s) = case sevColor severity of
100+writeLogWith :: (MonadIO m, MonadMask m) => (Text -> IO ()) -> WithSeverity Text -> m ()
101+writeLogWith f (WithSeverity severity s) = case sevColor severity of
89102 Just setColor -> bracket_ setColor reset $ liftIO (T.putStr s)
90− Nothing -> liftIO $ T.putStrLn s
103+ Nothing -> liftIO $ f s
91104 where
92105 -- We must reset *before* the newline, else the cursor won't be reset.
93− reset = liftIO $ setSGR [Reset] >> T.putStrLn ""
106+ reset = liftIO $ setSGR [Reset] >> f ""
94107 sevColor sev = if
95108 | sev <= Error -> Just $ liftIO $ setSGR [SetColor Foreground Vivid Red]
96109 | sev <= Warning -> Just $ liftIO $ setSGR [SetColor Foreground Vivid Yellow]
lib/command/src/Obelisk/CLI/Process.hsnew file+80
@@ -0,0 +1,80 @@
1+{-# LANGUAGE FlexibleContexts #-}
2+{-# LANGUAGE LambdaCase #-}
3+{-# LANGUAGE MultiParamTypeClasses #-}
4+{-# LANGUAGE MultiWayIf #-}
5+{-# LANGUAGE ScopedTypeVariables #-}
6+
7+-- | An extension of `System.Process` that integrates with logging (`Obelisk.CLI.Logging`)
8+-- and is thus spinner friendly.
9+module Obelisk.CLI.Process
10+ ( readProcessAndLogStderr
11+ , callProcessAndLogOutput
12+ ) where
13+
14+import Control.Applicative (liftA2)
15+import Control.Monad (void)
16+import Control.Monad.Catch (MonadMask)
17+import Control.Monad.Fix (fix)
18+import Control.Monad.IO.Class (liftIO)
19+import Control.Monad.Log (MonadLog)
20+import Control.Monad.Reader (MonadIO)
21+import qualified Data.ByteString.Char8 as BSC
22+import Data.Monoid ((<>))
23+import qualified Data.Text as T
24+import Data.Text.Encoding (decodeUtf8)
25+import qualified Data.Text.IO as T
26+import System.Exit (ExitCode (..))
27+import System.IO (Handle)
28+import System.IO.Streams (InputStream, handleToInputStream)
29+import qualified System.IO.Streams as Streams
30+import System.IO.Streams.Concurrent (concurrentMerge)
31+import System.Process
32+
33+import Obelisk.CLI.Logging (Output, Severity (..), failWith, putLogRaw)
34+
35+-- | Like `System.Process.readProcess` but logs the stderr instead of letting the external process inherit it.
36+readProcessAndLogStderr
37+ :: (MonadIO m, MonadMask m, MonadLog Output m)
38+ => Severity -> CreateProcess -> m String
39+readProcessAndLogStderr sev process = do
40+ (out, _err) <- withProcess process $ \_out err -> do
41+ streamToLog sev =<< liftIO (handleToInputStream err)
42+ -- TODO: Why are we using Text here?
43+ liftIO $ T.unpack . T.strip <$> T.hGetContents out
44+
45+-- | Like `System.Process.callProcess` but logs the combined output (stdout and stderr)
46+callProcessAndLogOutput
47+ :: (MonadIO m, MonadMask m, MonadLog Output m)
48+ => Severity -> CreateProcess -> m ()
49+callProcessAndLogOutput sev process = do
50+ void $ withProcess process $ \out err -> do
51+ stream <- liftIO $ do
52+ uncurry combineStream =<< liftA2 (,) (handleToInputStream out) (handleToInputStream err)
53+ streamToLog sev stream
54+ where
55+ combineStream s1 s2 = concurrentMerge [s1, s2]
56+
57+withProcess
58+ :: (MonadIO m, MonadMask m, MonadLog Output m)
59+ => CreateProcess -> (Handle -> Handle -> m ()) -> m (Handle, Handle)
60+withProcess process action = do
61+ (_, Just out, Just err, p) <- liftIO $ createProcess $ process
62+ { std_out = CreatePipe
63+ , std_err = CreatePipe
64+ }
65+ action out err -- Pass the handles to the custom action
66+ liftIO (waitForProcess p) >>= \case
67+ ExitSuccess -> return ()
68+ ExitFailure code -> do
69+ -- Log an error. We also fail immediately; however we should probably let the caller control that.
70+ failWith $ T.pack $ "Process " <> show process <> " failed with exit code: " <> show code
71+ return (out, err) -- Return the handles
72+
73+-- | Read from an input stream and log its contents
74+streamToLog
75+ :: (MonadIO m, MonadMask m, MonadLog Output m)
76+ => Severity -> InputStream BSC.ByteString -> m ()
77+streamToLog sev stream = fix $ \loop -> do
78+ liftIO (Streams.read stream) >>= \case
79+ Nothing -> return ()
80+ Just line -> putLogRaw sev (decodeUtf8 line) >> loop
lib/command/src/Obelisk/CLI/Spinner.hs+4−2
@@ -21,10 +21,10 @@ import Obelisk.CLI.Logging (LoggingConfig, Output (..), handleLog)
2121withSpinner'
2222 :: (MonadIO m, MonadMask m, MonadLog Output m)
2323 => LoggingConfig -> Text -> m a -> m a
24−withSpinner' c s = bracket' run cleanup . const
24+withSpinner' conf s = bracket' run cleanup . const
2525 where
2626 -- TODO: Can we obviate passing LoggingConfig just to use forkIO?
27− run = liftIO $ forkIO $ flip runLoggingT (handleLog c) $ do
27+ run = liftIO $ forkIO $ flip runLoggingT (handleLog conf) $ do
2828 forM_ spin $ \e -> do
2929 logMessage $ Output_Overwrite [e, " ", T.unpack s]
3030 delay
@@ -36,6 +36,8 @@ withSpinner' c s = bracket' run cleanup . const
3636 delay = liftIO $ threadDelay 100000 -- A shorter delay ensures that we update promptly.
3737 spin = coloredSpinner spinnerCircleHalves
3838
39+-- Spinner types
40+
3941type Spinner = [String]
4042
4143spinner :: SpinnerTheme -> Spinner
lib/command/src/Obelisk/Command.hs+10−2
@@ -24,10 +24,12 @@ import System.Environment
2424import System.FilePath
2525import System.IO (hIsTerminalDevice, stdout)
2626import System.Posix.Process (executeFile)
27+import System.Process (proc)
2728
2829import Obelisk.App
2930import Obelisk.CLI.Logging (LoggingConfig (LoggingConfig, _loggingConfig_level), Severity (..), failWith,
3031 putLog)
32+import Obelisk.CLI.Process (readProcessAndLogStderr)
3133import Obelisk.Command.Deploy
3234import Obelisk.Command.Project
3335import Obelisk.Command.Repl
@@ -258,6 +260,7 @@ ob = \case
258260 Nothing -> failWith $ "ObInternal_RunStaticIO: no such StaticKey: " <> T.pack (show k)
259261 Just p -> liftIO $ deRefStaticPtr p
260262 ObInternal_TestLogging -> do -- TODO: Remove this command once thoroughly satisfied with logging/spinner.
263+ -- Or move it to CLI.hs
261264 putLog Notice "We will now log a warning, and then start a spinner"
262265 withSpinner "Running some long-running task" $ do
263266 liftIO $ threadDelay 1000000
@@ -266,8 +269,13 @@ ob = \case
266269 putLog Notice "This is some info mesage"
267270 putLog Warning "And now a warning as well"
268271 liftIO $ threadDelay 1000000
269− putLog Notice "Now we start a 2nd spinner and fail inside of that:"
270− withSpinner "Doing something dangerous" $ do
272+ putLog Notice "Now we start a 2nd spinner, run a couple of process, the last of which fails:"
273+ withSpinner "Looking around" $ do
274+ liftIO $ threadDelay 1000000
275+ output <- readProcessAndLogStderr Notice $ proc "ls" ["-l", "/"]
276+ putLog Notice $ "Output was: " <> T.pack output
277+ liftIO $ threadDelay 1000000
278+ _ <- readProcessAndLogStderr Notice $ proc "ls" ["-l", "/does-not-exist"]
271279 liftIO $ threadDelay 1000000
272280 failWith "Something dangerous happened"
273281
lib/command/src/Obelisk/Command/Nix.hs+5−21
@@ -1,5 +1,4 @@
11{-# LANGUAGE FlexibleContexts #-}
2−{-# LANGUAGE LambdaCase #-}
32{-# LANGUAGE MultiParamTypeClasses #-}
43{-# LANGUAGE OverloadedStrings #-}
54{-# LANGUAGE ScopedTypeVariables #-}
@@ -11,17 +10,14 @@ module Obelisk.Command.Nix
1110 , Arg (..)
1211 ) where
1312
14−import Control.Monad.IO.Class (liftIO)
15−import qualified Data.ByteString.Lazy as LBS
1613import Data.Default
1714import Data.Monoid ((<>))
1815import qualified Data.Text as T
19−import qualified Data.Text.IO as T
20−import System.Exit (ExitCode (ExitSuccess))
21−import System.Process (StdStream (CreatePipe), createProcess, proc, std_err, std_out, waitForProcess)
16+import System.Process (proc)
2217
2318import Obelisk.App (MonadObelisk)
24−import Obelisk.CLI.Logging (failWith)
19+import Obelisk.CLI.Logging (Severity (..))
20+import Obelisk.CLI.Process (readProcessAndLogStderr)
2521import Obelisk.Command.Utils (withSpinner)
2622
2723-- | Where to put nix-build output
@@ -72,18 +68,6 @@ nixBuild cfg = do
7268 OutLink_None -> ["--no-out-link"]
7369 OutLink_IndirectRoot outLink -> ["--out-link", outLink]
7470 ]
75− (_, Just out, Just err, p) <- liftIO $ createProcess (proc "nix-build" args)
76− { std_out = CreatePipe
77− , std_err = CreatePipe
78− }
79− let msg = T.pack $ "Running nix-build [" <> _target_path (_nixBuildConfig_target cfg) <> "]"
71+ let msg = T.pack $ "Running nix-build (" <> _target_path (_nixBuildConfig_target cfg) <> ")"
8072 withSpinner msg $ do
81− liftIO (waitForProcess p) >>= \case
82− ExitSuccess -> return ()
83− _ -> do
84− -- FIXME: We should interleave `out` and `err` in their original order?
85− -- TODO: Replace this with logging functions for coordinating cleanly with spinner.
86− liftIO $ LBS.putStr =<< LBS.hGetContents out
87− liftIO $ LBS.putStr =<< LBS.hGetContents err
88− failWith "nix-build failed"
89− liftIO $ T.unpack . T.strip <$> T.hGetContents out
73+ readProcessAndLogStderr Debug (proc "nix-build" args)
lib/command/src/Obelisk/Command/Thunk.hs+6−11
@@ -71,6 +71,7 @@ import System.Process (StdStream (CreatePipe), callProcess, createProcess, proc,
7171import Development.Placeholders
7272import Obelisk.App (MonadObelisk)
7373import Obelisk.CLI.Logging (Severity (..), failWith, putLog)
74+import Obelisk.CLI.Process (callProcessAndLogOutput)
7475import Obelisk.Command.Utils (callProcessNixShell, checkGitCleanStatus, cp, withSpinner)
7576
7677--TODO: Support symlinked thunk data
@@ -471,17 +472,12 @@ unpackThunk thunkDir = readThunk thunkDir >>= \case
471472 githubURI <- liftIO $ either throwIO (return . repoSshUrl) repoResult >>= \case
472473 Nothing -> fail "Cannot determine clone URI for thunk source"
473474 Just c -> return $ T.unpack $ getUrl c
474− withSpinner ("Cloning " <> T.pack thunkName <> " from GitHub") $ do
475− liftIO $ callProcess "hub" --TODO: Depend on hub explicitly
476− [ "clone"
477− , "-n"
478− , githubURI
479− , tmpRepo
480− ]
475+ withSpinner ("Retrieving thunk " <> T.pack thunkName <> " from GitHub") $ do
476+ callProcessAndLogOutput Notice (proc "hub" ["clone", "-n", githubURI, tmpRepo])
481477 let obGitDir = tmpRepo </> ".git" </> "obelisk"
482478 --If this directory already exists then something is weird and we should fail
483479 liftIO $ createDirectory obGitDir
484− withSpinner "Copying thunk" $ do
480+ withSpinner ("Copying thunk " <> T.pack thunkName <> " to " <> T.pack thunkDir) $ do
485481 liftIO $ cp
486482 [ "-r"
487483 , "-T"
@@ -507,7 +503,6 @@ unpackThunk thunkDir = readThunk thunkDir >>= \case
507503 , tmpRepo
508504 , thunkDir
509505 ]
510− return ()
511506 ThunkSource_Git _s -> do
512507 $notImplemented
513508
@@ -527,8 +522,8 @@ packThunk thunkDir upstream = readThunk thunkDir >>= \case
527522 [ "-rf"
528523 , thunkDir
529524 ]
530− liftIO $ createThunk thunkDir thunkPtr
531− return ()
525+ withSpinner ("Packing thunk " <> T.pack thunkDir) $
526+ liftIO $ createThunk thunkDir thunkPtr
532527
533528getThunkPtr :: MonadObelisk m => FilePath -> String -> m ThunkPtr
534529getThunkPtr thunkDir upstream = do