From c460f783796e5b20c69f38425deef9a541591866 Mon Sep 17 00:00:00 2001 From: Matthew Pickering Date: Sat, 6 Mar 2021 16:12:02 +0000 Subject: [PATCH 1/2] Log live_bytes and heap_size as reported by GHC.Stats A thread is spawned which at a prespecified interval will report the live bytes and heap size at the last major collection. Live bytes corresponds to how much live data a program has and should match closely the value reported during heap profiling. Heap size reports the total amount of memory the RTS is using, which corresponds more closely to OS memory usage. ``` [INFO] Live bytes: 367.45MB Heap size: 676.33MB ``` Closes #1493 --- ghcide/ghcide.cabal | 4 +- ghcide/src/Development/IDE/Main.hs | 3 +- ghcide/src/Development/IDE/Main/HeapStats.hs | 53 ++++++++++++++++++++ haskell-language-server.cabal | 3 +- 4 files changed, 60 insertions(+), 3 deletions(-) create mode 100644 ghcide/src/Development/IDE/Main/HeapStats.hs diff --git a/ghcide/ghcide.cabal b/ghcide/ghcide.cabal index 45457f6d7a..d15828d33a 100644 --- a/ghcide/ghcide.cabal +++ b/ghcide/ghcide.cabal @@ -139,6 +139,7 @@ library Control.Concurrent.Strict Development.IDE Development.IDE.Main + Development.IDE.Main.HeapStats Development.IDE.Core.Debouncer Development.IDE.Core.FileStore Development.IDE.Core.IdeConfiguration @@ -260,7 +261,8 @@ executable ghcide -rtsopts -- disable idle GC -- increase nursery size - "-with-rtsopts=-I0 -A128M" + -- Enable collection of heap statistics + "-with-rtsopts="-I0 -A128M -T" main-is: Main.hs build-depends: hiedb, diff --git a/ghcide/src/Development/IDE/Main.hs b/ghcide/src/Development/IDE/Main.hs index 2d8128e69a..66cbeae085 100644 --- a/ghcide/src/Development/IDE/Main.hs +++ b/ghcide/src/Development/IDE/Main.hs @@ -52,6 +52,7 @@ import Development.IDE.Types.Options (IdeGhcSession, clientSupportsProgress, defaultIdeOptions) import Development.IDE.Types.Shake (Key (Key)) +import Development.IDE.Main.HeapStats (withHeapStats) import Development.Shake (action) import HIE.Bios.Cradle (findCradle) import Ide.Plugin.Config (CheckParents (NeverCheck), @@ -115,7 +116,7 @@ stderrLogger = do T.hPutStrLn stderr $ "[" <> T.pack (show p) <> "] " <> m defaultMain :: Arguments -> IO () -defaultMain Arguments{..} = do +defaultMain Arguments{..} = withHeapStats argsLogger $ do pid <- T.pack . show <$> getProcessID logger <- argsLogger hSetBuffering stderr LineBuffering diff --git a/ghcide/src/Development/IDE/Main/HeapStats.hs b/ghcide/src/Development/IDE/Main/HeapStats.hs new file mode 100644 index 0000000000..de45fa6c38 --- /dev/null +++ b/ghcide/src/Development/IDE/Main/HeapStats.hs @@ -0,0 +1,53 @@ +{-# LANGUAGE NumericUnderscores #-} +-- | Logging utilities for reporting heap statistics +module Development.IDE.Main.HeapStats ( withHeapStats ) where + +import GHC.Stats +import Development.IDE.Types.Logger (Logger, logInfo) +import Control.Concurrent.Async +import qualified Data.Text as T +import Data.Word +import Control.Monad +import Control.Concurrent +import Text.Printf (printf) + +-- | Interval at which to report the latest heap statistics. +heapStatsInterval :: Int +heapStatsInterval = 60_000_000 -- 60s + +-- | Report the live bytes and heap size at the last major collection. +logHeapStats :: Logger -> IO () +logHeapStats l = do + stats <- getRTSStats + -- live_bytes is the total amount of live memory in a program + -- (corresponding to the amount on a heap profile) + let live_bytes = gcdetails_live_bytes (gc stats) + -- heap_size is the total amount of memory the RTS is using + -- this corresponds closer to OS memory usage + heap_size = gcdetails_mem_in_use_bytes (gc stats) + format :: Word64 -> T.Text + format m = T.pack (printf "%.2fMB" (fromIntegral @Word64 @Double m / 1e6)) + message = "Live bytes: " <> format live_bytes <> " " <> + "Heap size: " <> format heap_size + logInfo l message + +-- | An action which logs heap statistics at the 'heapStatsInterval' +heapStatsThread :: Logger -> IO r +heapStatsThread l = forever $ do + threadDelay heapStatsInterval + logHeapStats l + +-- | A helper function which lauches the 'heapStatsThread' and kills it +-- appropiately when the inner action finishes. It also checks to see +-- if `-T` is enabled. +withHeapStats :: Logger -> IO r -> IO r +withHeapStats l k = do + enabled <- getRTSStatsEnabled + if enabled + then do + logInfo l ("Logging heap statistics every " + <> T.pack (printf "%.2fs" (fromIntegral @Int @Double heapStatsInterval / 1e6))) + withAsync (heapStatsThread l) (const k) + else do + logInfo l "Heap statistics are not enabled (RTS option -T is needed)" + k diff --git a/haskell-language-server.cabal b/haskell-language-server.cabal index 40313da1fe..247400de54 100644 --- a/haskell-language-server.cabal +++ b/haskell-language-server.cabal @@ -294,7 +294,8 @@ executable haskell-language-server -rtsopts -- disable idle GC -- increase nursery size - "-with-rtsopts=-I0 -A128M" + -- Enable collection of heap statistics + "-with-rtsopts=-I0 -A128M -T" -Wno-unticked-promoted-constructors if flag(pedantic) ghc-options: -Werror From adcd0fdf1f8f9e4ff34de267814515d7e17b943a Mon Sep 17 00:00:00 2001 From: Matthew Pickering Date: Sun, 21 Mar 2021 21:16:34 +0000 Subject: [PATCH 2/2] Update ghcide/ghcide.cabal Co-authored-by: Jan Hrcek <2716069+jhrcek@users.noreply.github.com> --- ghcide/ghcide.cabal | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ghcide/ghcide.cabal b/ghcide/ghcide.cabal index d605dbcc29..ca6c7dfbd6 100644 --- a/ghcide/ghcide.cabal +++ b/ghcide/ghcide.cabal @@ -262,7 +262,7 @@ executable ghcide -- disable idle GC -- increase nursery size -- Enable collection of heap statistics - "-with-rtsopts="-I0 -A128M -T" + "-with-rtsopts=-I0 -A128M -T" main-is: Main.hs build-depends: hiedb,