diff --git a/src/sut/dumblog/bench/journal/Main.hs b/src/sut/dumblog/bench/journal/Main.hs index 776e2a22..8b3e1e0c 100644 --- a/src/sut/dumblog/bench/journal/Main.hs +++ b/src/sut/dumblog/bench/journal/Main.hs @@ -1,10 +1,15 @@ module Main where -import Dumblog.Journal.Main (DumblogConfig(Run), journalDumblog) +import System.Directory (removePathForcibly) + +import Dumblog.Journal.Main import Common ------------------------------------------------------------------------ main :: IO () -main = commonMain "Journal" (journalDumblog Run bUFFER_CAPACITY pORT . Just) +main = do + removePathForcibly dUMBLOG_JOURNAL + removePathForcibly dUMBLOG_SNAPSHOT + commonMain "Journal" (journalDumblog Run bUFFER_CAPACITY pORT . Just) diff --git a/src/sut/dumblog/src/Dumblog/Journal/FrontEnd.hs b/src/sut/dumblog/src/Dumblog/Journal/FrontEnd.hs index 2c23138b..fde46a3e 100644 --- a/src/sut/dumblog/src/Dumblog/Journal/FrontEnd.hs +++ b/src/sut/dumblog/src/Dumblog/Journal/FrontEnd.hs @@ -53,7 +53,7 @@ httpFrontend journal metrics (FrontEndInfo blocker) req respond = do respond $ Wai.responseLBS status400 [] err Right cmd -> do key <- newKey blocker - now <- return 0 -- getCurrentNanosSinceEpoch + now <- getCurrentNanosSinceEpoch let env = encode (Envelope (sequenceNumber key) cmd now) res <- Journal.appendBS journal env res' <- case res of diff --git a/src/sut/dumblog/src/Dumblog/Journal/Main.hs b/src/sut/dumblog/src/Dumblog/Journal/Main.hs index ca0859b1..70946421 100644 --- a/src/sut/dumblog/src/Dumblog/Journal/Main.hs +++ b/src/sut/dumblog/src/Dumblog/Journal/Main.hs @@ -148,11 +148,14 @@ dUMBLOG_JOURNAL = "/tmp/dumblog.journal" dUMBLOG_METRICS :: FilePath dUMBLOG_METRICS = "/tmp/dumblog.metrics" +dUMBLOG_SNAPSHOT :: FilePath +dUMBLOG_SNAPSHOT = "/tmp/dumblog.snapshot" + journalDumblog :: DumblogConfig -> Int -> Int -> Maybe (MVar ()) -> IO () journalDumblog cfg _capacity port mReady = do let fpj = dUMBLOG_JOURNAL fpm = dUMBLOG_METRICS - fps = "/tmp/dumblog.snapshot" + fps = dUMBLOG_SNAPSHOT untilSnapshot = 1000 case cfg of Run -> do diff --git a/src/sut/dumblog/src/Dumblog/Journal/Worker.hs b/src/sut/dumblog/src/Dumblog/Journal/Worker.hs index 3d2dcbda..83ca5d87 100644 --- a/src/sut/dumblog/src/Dumblog/Journal/Worker.hs +++ b/src/sut/dumblog/src/Dumblog/Journal/Worker.hs @@ -63,9 +63,9 @@ worker journal metrics (WorkerInfo blocker snapshotFile eventCount untilSnapshot ; Just entry -> do Metrics.decrCounter_ metrics QueueDepth 1 let Envelope key cmd arrivalTime = decode entry - -- now <- getCurrentNanosSinceEpoch - -- Convert from nano s to µs with `* 10^3`. - -- Metrics.measure metrics Latency (realToFrac ((now - arrivalTime) * 1000)) + now <- getCurrentNanosSinceEpoch + -- Convert from nano s to µs with `* 10^-3`. + Metrics.measure metrics Latency (realToFrac ((now - arrivalTime)) * 0.001) timeIt metrics cmd $ do {- // in case of decode error Metrics.incrCounter metrics ErrorsEncountered 1 diff --git a/src/sut/dumblog/src/Dumblog/Metrics/Main.hs b/src/sut/dumblog/src/Dumblog/Metrics/Main.hs index fd64f0a5..9dbd3809 100644 --- a/src/sut/dumblog/src/Dumblog/Metrics/Main.hs +++ b/src/sut/dumblog/src/Dumblog/Metrics/Main.hs @@ -51,8 +51,7 @@ metricsMain = do either (const (return ())) msyncMetadata eMeta putStr (ansiClearScreen ++ ansiGoto 1 1) - -- displayLatency metrics - displayServiceTime metrics + displayLatencyAndServiceTime metrics displayQueueDepth metrics ts' <- displayThroughput metrics ts displayUtilisation metrics ts' @@ -69,26 +68,15 @@ ansiClearScreen = "\ESC[2J" ansiGoto :: Int -> Int -> String ansiGoto x y = "\ESC[" ++ show y ++ ";" ++ show x ++ "H" -displayLatency :: DumblogMetrics -> IO () -displayLatency metrics = do - mMin <- percentile metrics Latency 0 - mMed <- percentile metrics Latency 50 - m90 <- percentile metrics Latency 90 - m99 <- percentile metrics Latency 99 - m999 <- percentile metrics Latency 99.9 - m9999 <- percentile metrics Latency 99.99 - mMax <- percentile metrics Latency 100 - printf "%-25.25s\n" "Latency" - printf " min %10.2f µs\n" (fromMaybe 0 mMin) - printf " med %10.2f µs\n" (fromMaybe 0 mMed) - printf " 90 %10.2f µs\n" (fromMaybe 0 m90) - printf " 99 %10.2f µs\n" (fromMaybe 0 m99) - printf " 99.9 %10.2f µs\n" (fromMaybe 0 m999) - printf " 99.99 %10.2f µs\n" (fromMaybe 0 m9999) - printf " max %10.2f µs\n" (fromMaybe 0 mMax) - -displayServiceTime :: DumblogMetrics -> IO () -displayServiceTime metrics = do +displayLatencyAndServiceTime :: DumblogMetrics -> IO () +displayLatencyAndServiceTime metrics = do + mMinL <- percentile metrics Latency 0 + mMedL <- percentile metrics Latency 50 + m90L <- percentile metrics Latency 90 + m99L <- percentile metrics Latency 99 + m999L <- percentile metrics Latency 99.9 + m9999L <- percentile metrics Latency 99.99 + mMaxL <- percentile metrics Latency 100 mMin <- percentile metrics ServiceTimeWrites 0 mMed <- percentile metrics ServiceTimeWrites 50 m90 <- percentile metrics ServiceTimeWrites 90 @@ -103,22 +91,35 @@ displayServiceTime metrics = do m999' <- percentile metrics ServiceTimeReads 99.9 m9999' <- percentile metrics ServiceTimeReads 99.99 mMax' <- percentile metrics ServiceTimeReads 100 - printf "%-25.25s%-70.25s\n" "Service time (writes):" "Service time (reads):" - printf " min %10.2f µs%15.2fµs\n" (fromMaybe 0 mMin) (fromMaybe 0 mMin') - printf " med %10.2f µs%15.2fµs\n" (fromMaybe 0 mMed) (fromMaybe 0 mMed') - printf " 90 %10.2f µs%15.2fµs\n" (fromMaybe 0 m90) (fromMaybe 0 m90') - printf " 99 %10.2f µs%15.2fµs\n" (fromMaybe 0 m99) (fromMaybe 0 m99') - printf " 99.9 %10.2f µs%15.2fµs\n" (fromMaybe 0 m999) (fromMaybe 0 m999') - printf " 99.99 %10.2f µs%15.2fµs\n" (fromMaybe 0 m9999) (fromMaybe 0 m9999') - printf " max %10.2f µs%15.2fµs\n" (fromMaybe 0 mMax) (fromMaybe 0 mMax') + printf "%-25.25s%-25.25s%-25.25s\n" "\nLatency:" + "Service time (writes):" + "Service time (reads):" + printf " min %10.2f µs%15.2f µs%20.2f µs\n" + (fromMaybe 0 mMinL) (fromMaybe 0 mMin) (fromMaybe 0 mMin') + printf " med %10.2f µs%15.2f µs%20.2f µs\n" + (fromMaybe 0 mMedL) (fromMaybe 0 mMed) (fromMaybe 0 mMed') + printf " 90 %10.2f µs%15.2f µs%20.2f µs\n" + (fromMaybe 0 m90L) (fromMaybe 0 m90) (fromMaybe 0 m90') + printf " 99 %10.2f µs%15.2f µs%20.2f µs\n" + (fromMaybe 0 m99L) (fromMaybe 0 m99) (fromMaybe 0 m99') + printf " 99.9 %10.2f µs%15.2f µs%20.2f µs\n" + (fromMaybe 0 m999L) (fromMaybe 0 m999) (fromMaybe 0 m999') + printf " 99.99 %10.2f µs%15.2f µs%20.2f µs\n" + (fromMaybe 0 m9999L) (fromMaybe 0 m9999) (fromMaybe 0 m9999') + printf " max %10.2f µs%15.2f µs%20.2f µs\n" + (fromMaybe 0 mMaxL) (fromMaybe 0 mMax) (fromMaybe 0 mMax') + latencySum <- realToFrac <$> metricsSum metrics Latency :: IO Double writeSum <- realToFrac <$> metricsSum metrics ServiceTimeWrites :: IO Double readSum <- realToFrac <$> metricsSum metrics ServiceTimeReads :: IO Double + latencyCnt <- count metrics Latency writeCnt <- count metrics ServiceTimeWrites readCnt <- count metrics ServiceTimeReads - printf " sum %10.2f s %15.2fs\n" (writeSum / 1e6) (readSum / 1e6) + printf " sum %10.2f s %15.2f s %20.2f s\n" + (latencySum / 1e6) (writeSum / 1e6) (readSum / 1e6) let totalCnt :: Double totalCnt = realToFrac (writeCnt + readCnt) - printf " count %7d (%2.0f%%) %10d (%2.0f%%)\n" + printf " count %7d %17d (%2.0f%%) %15d (%2.0f%%)\n" + latencyCnt writeCnt (realToFrac writeCnt / totalCnt * 100) readCnt (realToFrac readCnt / totalCnt * 100)