Skip to content

Commit

Permalink
fix LOGGING specs, use a temporary file as a logging handle
Browse files Browse the repository at this point in the history
  • Loading branch information
@KtorZ
KtorZ committed Nov 14, 2019
1 parent 9185ca9 commit 72ba8d9
Show file tree
Hide file tree
Showing 2 changed files with 74 additions and 152 deletions.
78 changes: 5 additions & 73 deletions lib/core-integration/src/Test/Integration/Framework/DSL.hs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -95,9 +95,6 @@ module Test.Integration.Framework.DSL
, faucetUtxoAmt
, proc'
, waitForServer
, collectStreams
, shouldContainT
, shouldNotContainT
, for
, toQueryString
, utcIso8601ToText
Expand Down Expand Up @@ -200,13 +197,11 @@ import Cardano.Wallet.Primitive.Types
import Control.Concurrent
( threadDelay )
import Control.Concurrent.Async
( async, concurrently, race, wait )
import Control.Concurrent.MVar
( MVar, modifyMVar_, newMVar, takeMVar )
( async, race, wait )
import Control.Exception
( SomeException (..), catch, finally, try )
( SomeException (..), catch )
import Control.Monad
( forM_, join, unless, void, (>=>) )
( forM_, join, unless, void )
import Control.Monad.Catch
( MonadCatch )
import Control.Monad.Fail
Expand All @@ -225,8 +220,6 @@ import Data.Foldable
( toList )
import Data.Function
( (&) )
import Data.Functor
( (<&>) )
import Data.Generics.Internal.VL.Lens
( Lens', lens, set, view, (^.) )
import Data.Generics.Labels
Expand Down Expand Up @@ -255,8 +248,6 @@ import Data.Time.Text
( iso8601ExtendedUtc, utcTimeToText )
import Data.Word
( Word64 )
import GHC.Stack
( HasCallStack )
import GHC.TypeLits
( Symbol )
import Language.Haskell.TH.Quote
Expand All @@ -276,20 +267,18 @@ import System.Directory
import System.Exit
( ExitCode (..) )
import System.IO
( BufferMode (..), Handle, hClose, hFlush, hPutStr, hSetBuffering )
( hClose, hFlush, hPutStr )
import System.Process
( CreateProcess (..)
, ProcessHandle
, StdStream (..)
, proc
, terminateProcess
, waitForProcess
, withCreateProcess
)
import Test.Hspec
( expectationFailure )
import Test.Hspec.Expectations.Lifted
( shouldBe, shouldContain, shouldNotBe, shouldNotContain )
( shouldBe, shouldContain, shouldNotBe )
import Test.Integration.Faucet
( nextTxBuilder, nextWallet )
import Test.Integration.Framework.Request
Expand Down Expand Up @@ -1587,63 +1576,6 @@ proc' :: FilePath -> [String] -> CreateProcess
proc' cmd args = (proc cmd args)
{ std_in = CreatePipe, std_out = CreatePipe, std_err = CreatePipe }

-- | Collect lines from standard output and error streams for 65 seconds, or,
-- until a given limit is for both streams.
collectStreams :: (Int, Int) -> CreateProcess -> IO (Text, Text)
collectStreams (nOut0, nErr0) p = do
let safeP = p { std_out = CreatePipe, std_err = CreatePipe }
mvar <- newMVar (mempty, mempty)
withCreateProcess safeP $ \_ (Just o) (Just e) ph -> do
hSetBuffering o LineBuffering
hSetBuffering e LineBuffering
let io = race
(threadDelay (65 * oneSecond))
(collect mvar ((o, nOut0), (e, nErr0)) ph)
void $ io `finally` do
-- NOTE
-- Somehow, calling 'terminateProcess' isn't sufficient. We also
-- need to close the handles otherwise, the function resolves but
-- the processes remains hanging there for a while...
terminateProcess ph
flush o
flush e
takeMVar mvar
where
flush :: Handle -> IO ()
flush = try @SomeException . TIO.hGetContents >=> print

collect
:: MVar (Text, Text)
-> ((Handle, Int), (Handle, Int))
-> ProcessHandle
-> IO ()
collect mvar ((stdout, nOut), (stderr, nErr)) ph
| nOut <= 0 && nErr <= 0 = return ()
| otherwise = do
((out, nOut'), (err, nErr')) <- concurrently
(getNextLine nOut stdout)
(getNextLine nErr stderr)
modifyMVar_ mvar (\(out0, err0) ->
return (out0 <> out, err0 <> err))
collect mvar ((stdout, nOut'), (stderr, nErr')) ph

getNextLine :: Int -> Handle -> IO (Text, Int)
getNextLine n h
| n <= 0 = return (mempty, n)
| otherwise = do
threadDelay (10 * oneMillisecond)
try @SomeException (TIO.hGetLine h) <&> \case
Left _ -> (mempty, n)
Right l -> (l, n-1)

-- | Like 'shouldContain', but with 'Text'.
shouldContainT :: HasCallStack => Text -> Text -> IO ()
shouldContainT a b = T.unpack a `shouldContain` T.unpack b

-- | Like 'shouldNotContain', but with 'Text'.
shouldNotContainT :: HasCallStack => Text -> Text -> IO ()
shouldNotContainT a b = T.unpack a `shouldNotContain` T.unpack b

oneSecond :: Int
oneSecond = 1_000 * oneMillisecond

Expand Down
148 changes: 69 additions & 79 deletions lib/jormungandr/test/integration/Test/Integration/Jormungandr/Scenario/CLI/Server.hs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -9,16 +9,20 @@ module Test.Integration.Jormungandr.Scenario.CLI.Server

import Prelude

import Cardano.BM.Trace
( nullTracer )
import Cardano.CLI
( Port (..) )
import Cardano.Faucet
( getBlock0HText )
import Cardano.Launcher
( Command (..), StdStream (..), withBackendProcess )
import Control.Concurrent
( threadDelay )
import Control.Exception
( finally )
import Control.Monad
( forM_ )
( forM_, void )
import Data.Generics.Internal.VL.Lens
( (^.) )
import Data.Generics.Product.Typed
Expand All @@ -27,8 +31,12 @@ import System.Command
( Exit (..), Stderr (..), Stdout (..) )
import System.Exit
( ExitCode (..) )
import System.FilePath
( (</>) )
import System.IO
( Handle, hClose )
import System.IO.Temp
( withSystemTempDirectory )
( withSystemTempDirectory, withSystemTempFile )
import System.Process
( createProcess
, proc
Expand All @@ -39,33 +47,32 @@ import System.Process
import Test.Hspec
( SpecWith, describe, it, pendingWith, runIO )
import Test.Hspec.Expectations.Lifted
( shouldBe, shouldContain, shouldReturn )
( shouldBe, shouldContain, shouldNotContain, shouldReturn )
import Test.Integration.Framework.DSL
( Context (..)
, KnownCommand (..)
, cardanoWalletCLI
, collectStreams
, expectPathEventuallyExist
, proc'
, shouldContainT
, shouldNotContainT
)
import Test.Integration.Framework.TestData
( versionLine )
import Test.Utils.Ports
( findPort )

import qualified Data.Text as T
import qualified Data.Text.IO as TIO

spec :: forall t. KnownCommand t => SpecWith (Context t)
spec = do
block0H <- runIO $ T.unpack <$> getBlock0HText
describe "SERVER - cardano-wallet serve [SERIAL]" $ do
it "SERVER - Can start cardano-wallet serve --database" $ \_ -> do
withTempDir $ \d -> do
let db = d ++ "/db-file"
let db = d </> "db-file"
let args =
[ "serve", "--database", db, "--genesis-block-hash", block0H ]
[ "serve"
, "--database", db
, "--genesis-block-hash", block0H
]
let process = proc' (commandName @t) args
withCreateProcess process $ \_ _ _ ph -> do
expectPathEventuallyExist db
Expand All @@ -83,7 +90,7 @@ spec = do
, block0H
]

let filepath = "test/integration/js/mock-daedalus.js"
let filepath = "test" </> "integration" </> "js" </> "mock-daedalus.js"

it "Should reply with the port --random" $ \ctx -> do
pendingWith "Seems to cause some sort of race condition with --coverage"
Expand All @@ -101,79 +108,59 @@ spec = do
waitForProcess ph `shouldReturn` ExitSuccess

describe "LOGGING - cardano-wallet serve logging [SERIAL]" $ do
it "LOGGING - Launch can log --verbose" $ \ctx -> do
let args =
["serve"
, "--node-port"
, show (ctx ^. typed @(Port "node"))
, "--random-port"
, "--verbose"
, "--genesis-block-hash"
, block0H
]
let process = proc' (commandName @t) args
(out, _) <- collectStreams (20, 0) process
out `shouldContainT` versionLine
-- NOTE:
-- In theory we could also have:
--
-- out `shouldContainT` "Debug"
-- out `shouldContainT` "Notice"
--
-- but in practice, we only have INFO logs on start-up.
out `shouldContainT` "Info"

it "LOGGING - Serve --quiet logs Error only" $ \ctx -> do
let args =
["serve"
, "--node-port"
, show (ctx ^. typed @(Port "node"))
, "--random-port"
, "--quiet"
, "--genesis-block-hash"
, block0H
]
let process = proc' (commandName @t) args
(out, err) <- collectStreams (10, 10) process
out `shouldBe` mempty
err `shouldBe` mempty
withTempFile $ \logs hLogs -> do
let cmd = Command
(commandName @t)
["serve"
, "--node-port", show (ctx ^. typed @(Port "node"))
, "--random-port"
, "--quiet"
, "--genesis-block-hash", block0H
]
(pure ())
(UseHandle hLogs)
void $ withBackendProcess nullTracer cmd $ do
threadDelay (10 * oneSecond)
hClose hLogs
TIO.readFile logs `shouldReturn` mempty

it "LOGGING - Serve default logs Info" $ \ctx -> do
let args =
["serve"
, "--node-port"
, show (ctx ^. typed @(Port "node"))
, "--random-port"
, "--genesis-block-hash"
, block0H
]
let process = proc' (commandName @t) args
(out, _) <- collectStreams (5, 0) process
out `shouldNotContainT` "Debug"
out `shouldContainT` versionLine
out `shouldContainT` "Info"
-- NOTE:
-- In theory we could also have:
--
-- out `shouldContainT` "Notice"
--
-- but in practice, we only have INFO logs on start-up.
withTempFile $ \logs hLogs -> do
let cmd = Command
(commandName @t)
["serve"
, "--node-port", show (ctx ^. typed @(Port "node"))
, "--random-port"
, "--genesis-block-hash", block0H
]
(pure ())
(UseHandle hLogs)
void $ withBackendProcess nullTracer cmd $ do
threadDelay (10 * oneSecond)
hClose hLogs
logged <- T.unpack <$> TIO.readFile logs
logged `shouldNotContain` "TRACE"
logged `shouldNotContain` "DEBUG"

it "LOGGING - Serve shuts down logging correctly" $ \ctx -> do
let args =
["serve"
, "--database"
, "/does-not-exist"
, "--node-port"
, show (ctx ^. typed @(Port "node"))
, "--random-port"
, "--verbose"
, "--genesis-block-hash"
, block0H
]
let process = proc' (commandName @t) args
(out, _) <- collectStreams (2, 0) process
out `shouldContainT` "Logging shutdown."
withTempFile $ \logs hLogs -> do
let cmd = Command
(commandName @t)
["serve"
, "--database", "/does-not-exist"
, "--node-port", show (ctx ^. typed @(Port "node"))
, "--random-port"
, "--verbose"
, "--genesis-block-hash", block0H
]
(pure ())
(UseHandle hLogs)
void $ withBackendProcess nullTracer cmd $ do
threadDelay (10 * oneSecond)
hClose hLogs
logged <- T.unpack <$> TIO.readFile logs
logged `shouldContain` "Logging shutdown"

describe "LOGGING - Exits nicely on wrong genesis hash" $ do
let hashes =
Expand Down Expand Up @@ -215,3 +202,6 @@ oneSecond = 1000000

withTempDir :: (FilePath -> IO a) -> IO a
withTempDir = withSystemTempDirectory "integration-state"

withTempFile :: (FilePath -> Handle -> IO a) -> IO a
withTempFile = withSystemTempFile "temp-file"

0 comments on commit 72ba8d9

Please sign in to comment.