我正在尝试从GHC Profiler理解。有一个相当简单的应用程序,它使用werq
和lens-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 附近。并且,以防万一,这是该应用程序:
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/