我正在尝试从GHC Profiler理解。有一个相当简单的应用程序,它使用werqlens-aeson库,并且在学习GHC概要分析时,我决定尝试一下它。

使用不同的选项(time工具,+RTS -p -RTS+RTS -p -h),我获得了完全不同的内存使用量。有了所有这些数字,我现在完全无法理解正在发生的事情以及该应用程序实际使用了多少内存。

这种情况使我想起了亚瑟·布洛赫(Arthur Bloch)的一句话:“一个有 watch 的人知道现在几点了。有两个 watch 的人永远不确定。”

能否请我建议我如何阅读所有这些数字,每个数字的含义是什么?

这些是数字:
time -l关于的报告19M

#/usr/bin/time -l ./simple-wreq
...
        3.02 real         0.39 user         0.17 sys
  19070976  maximum resident set size
         0  average shared memory size
         0  average unshared data size
         0  average unshared stack size
     21040  page reclaims
         0  page faults
         0  swaps
         0  block input operations
         0  block output operations
        71  messages sent
        71  messages received
      2991  signals received
        43  voluntary context switches
      6490  involuntary context switches

使用标志报告 92M 。尽管它说“total alloc”,但对我来说似乎很奇怪,像这样的简单应用程序可以分配并释放91M
# ./simple-wreq +RTS -p -RTS
# cat simple-wreq.prof
        Fri Oct 14 15:08 2016 Time and Allocation Profiling Report  (Final)

           simple-wreq +RTS -N -p -RTS

        total time  =        0.07 secs   (69 ticks @ 1000 us, 1 processor)
        total alloc =  91,905,888 bytes  (excludes profiling overheads)

COST CENTRE                             MODULE                          %time %alloc

main.g                                  Main                             60.9   88.8
MAIN                                    MAIN                             24.6    2.5
decodeLenient/look                      Data.ByteString.Base64.Internal   5.8    2.6
decodeLenientWithTable/fill             Data.ByteString.Base64.Internal   2.9    0.1
decodeLenientWithTable.\.\.fill         Data.ByteString.Base64.Internal   1.4    0.0
decodeLenientWithTable.\.\.fill.\       Data.ByteString.Base64.Internal   1.4    0.1
decodeLenientWithTable.\.\.fill.\.\.\.\ Data.ByteString.Base64.Internal   1.4    3.3
decodeLenient                           Data.ByteString.Base64.Lazy       1.4    1.4


                                                                                                             individual     inherited
COST CENTRE                                              MODULE                            no.     entries  %time %alloc   %time %alloc

MAIN                                                     MAIN                              443           0   24.6    2.5   100.0  100.0
 main                                                    Main                              887           0    0.0    0.0    75.4   97.4
  main.g                                                 Main                              889           0   60.9   88.8    75.4   97.4
   object_                                               Data.Aeson.Parser.Internal        925           0    0.0    0.0     0.0    0.2
    jstring_                                             Data.Aeson.Parser.Internal        927          50    0.0    0.2     0.0    0.2
   unstream/resize                                       Data.Text.Internal.Fusion         923         600    0.0    0.3     0.0    0.3
   decodeLenient                                         Data.ByteString.Base64.Lazy       891           0    1.4    1.4    14.5    8.1
    decodeLenient                                        Data.ByteString.Base64            897         500    0.0    0.0    13.0    6.7
....
+RTS -p -RTS+RTS -p -h向我显示了以下图片和两个数字: header 中为114K ,图中的 1.8Mb 附近。
haskell - 从GHC Profiler理解-LMLPHP

并且,以防万一,这是该应用程序:
module Main where

import Network.Wreq
import Control.Lens
import Data.Aeson.Lens
import Control.Monad

main :: IO ()
main = replicateM_ 10 g
  where
    g = do
        r <- get "http://httpbin.org/get"
        print $ r ^. responseBody
                   . key "headers"
                   . key "User-Agent"
                   . _String

更新1:谢谢大家的出色反馈。如建议的那样,我添加了hp2ps输出,因此,每一个阅读它的人都会建立起整个图片。
#./simple-wreq +RTS -s
...
     128,875,432 bytes allocated in the heap
      32,414,616 bytes copied during GC
       2,394,888 bytes maximum residency (16 sample(s))
         355,192 bytes maximum slop
               7 MB total memory in use (0 MB lost due to fragmentation)

                                     Tot time (elapsed)  Avg pause  Max pause
  Gen  0       194 colls,     0 par    0.018s   0.022s     0.0001s    0.0022s
  Gen  1        16 colls,     0 par    0.027s   0.031s     0.0019s    0.0042s

更新2 :可执行文件的大小:
#du -h simple-wreq
63M     simple-wreq

最佳答案



嗯,但是两块 watch 显示什么?两者都旨在显示UTC的当前时间吗?还是其中一个应该在UTC上显示时间,而另一个应该在火星上的某个时间显示时间?只要它们处于同步状态,第二种情况就不会有问题,对吧?

而这正是这里发生的事情。您比较不同的内存度量值:

  • 最大居住地
  • 分配的内存总量

  • 最大驻留时间是程序在给定时间使用的最大内存量。那是19MB。但是,分配的内存总量要多得多,因为这就是GHC的工作方式:它为垃圾收集的对象“分配”内存,这几乎是所有未拆包的内容。

    让我们检查一个C示例:
    int main() {
       int i;
       char * mem;
    
       for(i = 0; i < 5; ++i) {
          mem = malloc(19 * 1000 * 1000);
          free(mem);
       }
       return 0;
    }
    

    每当我们使用malloc时,我们将分配19 MB的内存。但是,之后我们立即释放内存。因此,我们在某一时刻拥有的最大内存量为19兆字节(堆栈和程序本身的内存更多)。

    但是,我们总共分配了5 * 19M,总共 95M。不过,我们可以只用20兆的RAM就可以运行我们的小程序。那是总分配内存最大驻留时间之间的差异。请注意,按时间报告的驻留时间始终至少为du <executable>,因为它也必须驻留在内存中。

    话虽如此,生成统计信息的最简单方法是-s,它将从Haskell程序的角度显示最大驻留时间。在您的情况下,它将是 1.9M ,即堆配置文件中的数字(或由于分析而增加一倍)。是的,由于库是静态链接的,Haskell可执行文件往往变得非常大。

    关于haskell - 从GHC Profiler理解,我们在Stack Overflow上找到一个类似的问题:https://stackoverflow.com/questions/40044364/

    10-11 17:59