Haskell: 如何检测“惰性内存泄漏”

35
经过几个小时的调试,我意识到一个非常简单的玩具例子由于表达式 return $ 1 + x 中缺少一个 ! 是不高效的(感谢duplode!但是为什么ghc不优化它?)。我之所以意识到这一点,是因为我正在将其与一个更快的Python代码进行比较,但我不会总是编写Python代码来测试我的代码...
那么我的问题是:是否有一种自动检测这些“懒惰内存泄漏”的方法,这些泄漏没有真正原因而导致程序变慢?我还不太擅长优化Haskell代码,即使你很有经验,在忘记了 ! 的情况下,很可能出现这种情况。
我知道:
- +RTS -s 命令,但我不确定如何解释它:例如对于一个简单的程序,看到79MB的内存似乎对我来说太大了,但也许它正是我的当前程序所需要的。 对于更大的程序来说,只是通过这种方式检测“懒惰泄漏”是不可能的,因为我不知道程序应该占用多少内存。 - cabal v2-run --enable-profiling mysatsolvers -- +RTS -p 命令,但似乎启用分析器会破坏GHC做的一些优化,因此很难将这些值用于实际基准测试。而且,对我来说仍然不清楚如何从输出中找到泄漏。
例如,您能否向我解释一下如何在像这个例子这样的玩具程序中找到“懒惰泄漏”?
{-# LANGUAGE DerivingVia, FlexibleInstances, ScopedTypeVariables #-}
module Main where

--- It depends on the transformers, containers, and base packages.
--- Optimisation seems to be important or the NoLog case will be way to long.
--- $ ghc -O Main.hs

import qualified Data.Map.Strict as MapStrict
import Data.Functor.Identity

import qualified Control.Monad as CM
import qualified Control.Monad.State.Strict as State
import qualified Data.Time as Time

-- Create a class that allows me to use the function "myTell"
-- that adds a number in the writer (either the LogEntry
-- or StupidLogEntry one)
class Monad m => LogFunctionCalls m where
  myTell :: String -> Int -> m ()

---------- Logging disabled ----------
--- (No logging at all gives the same time so I don't put here)
newtype NoLog a = NoLog { unNoLog :: a }
  deriving (Functor, Applicative, Monad) via Identity

instance LogFunctionCalls NoLog where
  myTell _ _ = pure ()

---------- Logging with Map ----------
-- When logging, associate a number to each name.
newtype LogEntryMap = LogEntryMap (MapStrict.Map String Int)
  deriving (Eq, Show)

instance LogFunctionCalls (State.State LogEntryMap) where
  myTell namefunction n = State.modify' $
    \(LogEntryMap m) ->
      LogEntryMap $ MapStrict.insertWith (+) namefunction n m

---------- Logging with Int ----------
-- Don't use any Map to avoid inefficiency of Map
newtype LogEntryInt = LogEntryInt Int
  deriving (Eq, Show)

instance LogFunctionCalls (State.State LogEntryInt) where
  myTell namefunction n = State.modify' $
    \(LogEntryInt m) -> LogEntryInt $! m + n

---------- Function to compute ----------
countNumberCalls :: (LogFunctionCalls m) => Int -> m Int
countNumberCalls 0 = return 0
countNumberCalls n = do
  myTell "countNumberCalls" 1
  x <- countNumberCalls $! n - 1
  return $ 1 + x

main :: IO ()
main = do
  let www = 15000000
  putStrLn $ "Let's start!"
  --- Logging disabled
  t0 <- Time.getCurrentTime
  let n = unNoLog $ countNumberCalls www
  putStrLn $ "Logging disabled: " ++ (show n)
  t1 <- Time.getCurrentTime
  print (Time.diffUTCTime t1 t0)
  -- Logging with Map
  let (n, LogEntryMap log) = State.runState (countNumberCalls www) (LogEntryMap MapStrict.empty)
  putStrLn $ "Logging with Map: " ++ (show n)
  putStrLn $ (show $ log)
  t2 <- Time.getCurrentTime
  print (Time.diffUTCTime t2 t1)
  -- Logging with Int
  let (n, LogEntryInt log) = State.runState (countNumberCalls www) (LogEntryInt 0)
  putStrLn $ "Logging with Int: " ++ (show n)
  putStrLn $ (show $ log)
  t3 <- Time.getCurrentTime
  print (Time.diffUTCTime t3 t2)

请考虑在此处打开一个 GHC 票证来说明您的情况。也许需求分析器无法在这里得到改进,但谁知道呢。 GHC 总部可能会感激这个自包含的示例。 - jberryman
3个回答

45
检测内存泄漏的主要方法是堆分析。具体来说,您需要查找{{常驻}}(大部分为堆)内存量的意外增长,可以在+RTS -s统计输出中找到最大常驻量,或者更可靠的是,在使用+RTS -h<x>标志和hp2ps工具生成的堆分析输出中,随着时间的推移呈现出特征的“金字塔”形状。
如果我使用+RTS -s运行您的玩具程序,我会看到:
   3,281,896,520 bytes allocated in the heap
   3,383,195,568 bytes copied during GC
     599,346,304 bytes maximum residency (17 sample(s))
       5,706,584 bytes maximum slop
             571 MB total memory in use (0 MB lost due to fragmentation)

第一行通常可以忽略。Haskell程序通常每秒运行分配大约恒定数量的内存,而这种分配速率要么接近零(对于某些不寻常的程序),要么是每秒0.5-2.0 GB。该程序运行了4秒并分配了3.8 GB,这并不罕见。
然而,在垃圾回收期间复制的字节和最大驻留内存是令人担忧的。假设您有一个预计在常量空间中运行的程序(即,没有需要整个内容的不断增长的数据结构),则正确运行的Haskell程序通常不需要在垃圾回收期间复制太多数据,并且往往会具有最大驻留内存,该内存占用总分配字节数的一小部分(例如,100 KB而不是半GB),并且这不会随着您测试的“迭代”次数而显著增加。
您可以在不打开正式剖析的情况下随时间生成快速堆剖析。如果使用GHC标志-rtsopts编译,则可以使用:
./Toy +RTS -hT

然后使用hp2ps工具以图形方式显示结果:

hp2ps -c -e8in Toy.hp
evince Toy.ps &

这种金字塔形式是一个警示信号:

enter image description here

请注意,堆的快速线性增长每秒数百兆字节,然后迅速线性崩溃。这种模式出现在整个计算被强制执行之前无需构建巨大的惰性数据结构时。您在这里看到两个金字塔,因为您的第二个和第三个测试都显示了内存泄漏。
另外,x轴以"MUT seconds"(mutator运行的时间,不包括垃圾收集)为单位,因此这比实际的4秒运行时间要少。这实际上是另一个红旗。花费一半时间进行垃圾收集的Haskell程序可能没有正确运行。
要获取有关导致此堆金字塔的详细信息,您需要启用分析编译。分析可能会使程序运行得稍慢,但通常不会更改已经存在的优化。但是,标志-fprof-auto(和相关标志)自动插入成本中心,可能会导致性能发生大变化(通过干扰内联等)。不幸的是,cabal --enable-profiling标志打开了分析(编译器标志-prof)和标志-fprof-auto-top,该标志自动生成顶级函数的成本中心,因此对于您的玩具示例,即使没有+RTS标志,它也会显着改变第一个测试用例的行为(将运行时间从0.4秒增加到5秒)。这可能是您在分析影响结果的问题。您不需要任何成本中心来获取其他几种堆配置文件,因此您可以添加cabal标志--profiling-detail = none以关闭它,然后您的分析程序应该会稍微慢一些,但通常具有与未分析版本类似的性能。
我不使用Cabal,但使用以下编译(应该相当于--enable-profiling --profiling-detail = none):
ghc -O2 -rtsopts -prof Toy.hs    # no -fprof-auto...

我可以按数据类型对您的程序进行性能分析:

./Toy +RTS -hy

如果我查看堆剖析图:

enter image description here

这个属性将大部分堆分配给Int类型--这缩小了我的问题范围,转而集中于一堆未计算的惰性Int计算,这可能指引我正确的方向。

如果我真的难以缩小问题范围并且感觉需要进行技术深入挖掘,我还可以通过closure运行堆剖面(标志-hd)。这告诉我罪魁祸首是两个金字塔的Main.sat_s7mQMain.sat_s7kP。这看起来非常神秘,但它们是由编译器生成的程序的低级中间表示形式“STG”中的函数名称。

如果我使用相同的标志重新编译,但添加-fforce-recomp -ddump-stg -dsuppress-all

ghc -O2 -rtsopts -prof -fforce-recomp -ddump-stg -dsuppress-all Toy.hs

这将转储包含这两个函数定义的STG。 (生成的标识符可能因代码和/或编译器标志的小改变而不同,因此最好重新编译并转储STG,然后重新对该可执行文件进行剖析,以确保标识符匹配。)

如果我在STG中搜索第一个罪犯,我会找到定义:

sat_s7mQ =
    CCCS \u []
        case ww2_s7mL of {
          I# y_s7mO ->
              case +# [1# y_s7mO] of sat_s7mP {
                __DEFAULT -> I# [sat_s7mP];
              };
        };

是的,这些都非常技术化,但这是STG术语中表达1 + y的方式,它可以帮助我锁定罪魁祸首。
如果您不懂STG,可以尝试引入一些成本中心。例如,我尝试使用-fprof-auto(Cabal标志--profiling-detail=all-functions)仅对第二个测试用例进行分析。 Toy.prof中的分析输出对于内存泄漏并不那么有用,因为它处理的是总分配量而不是随时间活动(即驻留且未垃圾回收)的分配量,但您可以通过运行以下命令按成本中心创建堆剖面:
./Toy +RTS -hc

在这种情况下,它将所有内容归因于一个成本中心,即(315)countNumberCalls。 "315"是成本中心号码,您可以在Toy.prof输入中查找确切的源代码行,如果名称不清楚的话。无论如何,这至少有助于将问题缩小到countNumberCalls
对于更复杂的函数,有时可以通过手动指定成本中心来进一步缩小问题范围,例如:
countNumberCalls :: (LogFunctionCalls m) => Int -> m Int
countNumberCalls 0 = return 0
countNumberCalls n = do
  {-# SCC "mytell_call" #-} myTell "countNumberCalls" 1
  x <- {-# SCC "recursive_call" #-} countNumberCalls $! n - 1
  {-# SCC "return_statment" #-} return $ {-# SCC "one_plus_x" #-} 1 + x

这实际上将所有内容归因于“recursive_call”,所以并没有太大帮助。
虽然不是错误。你实际上有两个内存泄漏——x <- countNumberCalls $! n - 1会泄漏堆,因为x没有被强制执行,而1 + x则会泄漏栈。你可以启用BangPatterns扩展并编写:
!x <- countNumebrCalls $1 n - 1

而这实际上会消除一个内存泄漏,将第二种情况的速度从2.5秒加快到1.0秒,并将最大驻留内存从460兆字节降至95兆字节(GC期间复制的字节数从1.5吉字节降至73千字节!)。然而,堆剖面将显示线性增长的堆栈占用了几乎所有常驻内存。由于堆栈跟踪不如堆跟踪得好,因此更难追踪。

一些额外的注释:

尽管+RTS -h<x>标志主要用于堆剖析(在GHC文档中被称为“堆剖析”选项),但它们技术上可以报告除堆之外的驻留内存的其他用途,包括每个线程状态,其中包括线程状态对象和堆栈。默认情况下,当运行已进行剖析的二进制文件(使用-prof编译)时,+RTS -h<x>标志不会报告包括堆栈在内的每个线程状态,但是您可以添加-xt标志,例如+RTS -hc -xt。由于可能是无意中的疏忽,对于未进行剖析的二进制文件,+RTS -hT标志(唯一可用的-h<x>标志)即使没有-xt标志也包括堆栈。由于编译器bug-hT标志在GHC 8.6.x及更早版本的已剖析二进制文件上无效,但在GHC 8.8.x上有效,并且对于该版本,+RTS -hT在未进行剖析的二进制文件上包括堆栈,但在进行剖析的二进制文件上排除它,除非您也指定-xt。这就是为什么在上面的示例中,“STACK”仅出现在运行非剖析二进制文件的堆剖析时。您可以添加-xt标志以在所有其他堆剖面中查看它。请注意,此“STACK”实际上是堆栈使用,而不是与堆栈有关的堆上的对象。

黑洞主要用于支持并发。当一个线程开始评估一个thunk时,它会将其“黑化”(即标记为黑洞),因此如果另一个线程想要评估相同的thunk,则等待评估而不是尝试并行重新评估它(这将重复正在运行的线程的工作)。在非线程运行时也使用它,部分原因是因为它可以检测无限循环(如果一个线程遇到自己的黑洞),但还有一些更重要的原因我记不清了。对于-hT-hd-hy堆分析,像这样被黑化的堆对象将被标记为“BLACKHOLE”。上述配置文件中的有限采样率可能会使情况有些不清楚,但在您的程序中正在发生的是建立了一长串Int thunks链,当值最终强制执行时,它们会变成一长串BLACKHOLE,每个都代表已启动并正在等待链中的下一个计算的计算。

非常感谢您的回答,它非常有用且完整!我只有一些问题,例如,在图表中“黑洞”的含义是什么(在我的情况下,“黑洞”比thunk更小,而在您的情况下,thunk更大,不知道为什么)?第一张图片中的“堆栈”是指指向堆栈的堆中的元素,还是其他什么东西?(我有点迷失方向,因为我认为我们正在进行堆分析) - tobiasBora
2
我在结尾处添加了一些关于“BLACKHOLE”和“STACK”的注释。我不知道你的黑洞使用方式与我的不同。这可能是 GHC 版本的差异,也可能是偶然的——分析是通过采样完成的,样本的时间可以改变表面模式。 - K. A. Buhr
是否有可能增加采样率?显然这会使程序运行变慢,但采样精度会提高。在完美的世界中,人们可以通过发送信号到程序来打开和关闭高频采样。 - Mikko Rantalainen
是的,堆剖分采样率由 +RTS -i<xx> 选项设置,它表示每秒采样数。默认值为 +RTS -i0.01。但据我所知,在运行程序时无法更改它。 - K. A. Buhr
在堆中分配了3,281,896,520字节。需要解释的是,为什么应该忽略这一行。如果实际上已经分配了这么多空间,那么这就是一个问题吗?如果是这样,为什么还要查看通常较低的其他数字?这一行应该被忽略,因为它只是报告了堆中分配的总字节数。这个数字本身并没有什么意义,因为它不会告诉你有多少内存正在使用或者可用。相反,你应该关注其他数字,比如堆中当前正在使用的字节数和堆的最大容量。如果这些数字接近堆的最大容量,那么你可能需要考虑优化你的代码或增加系统内存。 - Nawaz

6
你问:

return $ 1 + x [...] 但是为什么ghc不会优化它呢?

答案是严格求值和惰性求值在语义上略有不同,因此让 GHC 进行优化可能会破坏你的程序。
区别在于未定义值的处理。任何试图评估一个 undefined 的尝试都会引发异常。在 GHCi 中:
Prelude> undefined
*** Exception: Prelude.undefined
CallStack (from HasCallStack):
  error, called at libraries/base/GHC/Err.hs:79:14 in base:GHC.Err
  undefined, called at <interactive>:1:1 in interactive:Ghci1

如果我有一个包含未定义的表达式,那么同样的事情也会发生:

Prelude> 2 + undefined
*** Exception: Prelude.undefined [...]

然而,如果评估过程没有到达未定义状态,那么一切都很好:
Prelude> True || undefined
True

Haskell使用"非严格语义"和"惰性求值"。在技术上,非严格语义是Haskell的定义的一部分,而惰性求值是GHC中的实现机制,但你可以把它们看作是同义词。当你定义变量时,其值不会立即计算,因此如果你从未使用该变量,那么就没有问题:

Prelude> let b = undefined
Prelude> b
*** Exception: Prelude.undefined

let可以正常工作,但是评估它定义的变量会抛出异常。

现在考虑您未评估的一系列1+调用。 GHC 事先无法知道您是否会使用结果(见下文),也无法知道其中是否潜藏着异常。作为程序员,您可能知道存在异常并小心不查看结果,依赖于 Haskell 的非严格语义。如果 GHC 过早地评估并得到异常,则您的程序将在不应该失败的情况下失败。

实际上,GHC 编译器包括一种名为Demand Analyser(曾称为 Strictness Analyser)的优化部分,它寻找需要进行优化的机会,就像您想要的那样。然而,它有限制,因为只有在它能够证明结果将被评估时才能优化计算。

另一个问题是您使用了State monad。它实际上有两个变体;Lazy 和 Strict。Strict 变体在写入状态时强制执行该状态,但是 Lazy 变体(默认值)不会。


我明白,但是在这里似乎很容易看到状态实际上会被显示出来(它被打印出来,而且函数也不可能更简单),并且当整数大于0时它不会产生错误。我确实理解monad可能是个问题,但考虑到我正在使用一个严格的state monad...我认为这仍然是可行的。但无论如何,感谢您的评论! - tobiasBora
@tobiasBora 啊,抱歉,我错过了你的导入中的“Strict”。我知道这很痛苦,因为我曾经在我写的一个程序中花了一周时间追踪这个确切的问题。 - Paul Johnson

3

有一类特定的空间泄漏可以通过检测它们在回收过度堆使用时使用了过多的堆栈来进行检测。 以下网站列出了具体的方法,以及大量的案例研究,但大体上:

  • 使用+RTS -K10K将堆栈限制为10Kb,在有限大小的堆栈下编译和运行代码。
  • 使用+RTS -xc获取堆栈跟踪,查看突破堆栈限制的代码。

这并不是一种完美的方法,因为有时你会有内存泄漏而没有过度堆栈使用,有时你会有过度堆栈使用而没有内存泄漏,但对应关系相当好,并且工具可以部署在 CI 上以阻止引入新的泄漏。


网页内容由stack overflow 提供, 点击上面的
可以查看英文原文,
原文链接