`Rprof` 的内存分析结果解读

6

我正在尝试使用性能分析来查看代码的哪一部分负责最大使用3GB内存(如gc()统计的最大使用内存所报告的,点击此处查看)。我正在这样运行内存分析:

Rprof(line.profiling = TRUE, memory.profiling = TRUE)
graf(...) # ... here I run the profiled code
Rprof(NULL)
summaryRprof(lines = "both", memory = "both")

输出结果如下:

$by.total
                       total.time total.pct mem.total self.time self.pct
"graf"                     299.12     99.69   50814.4      0.02     0.01
#2                         299.12     99.69   50814.4      0.00     0.00
"graf.fit.laplace"         299.06     99.67   50787.2      0.00     0.00
"doTryCatch"               103.42     34.47    4339.2      0.00     0.00
"chol"                     103.42     34.47    4339.2      0.00     0.00
"tryCatch"                 103.42     34.47    4339.2      0.00     0.00
"tryCatchList"             103.42     34.47    4339.2      0.00     0.00
"tryCatchOne"              103.42     34.47    4339.2      0.00     0.00
"chol.default"             101.62     33.87    1087.0    101.62    33.87
graf.fit.laplace.R#46       85.80     28.60    3633.2      0.00     0.00
"backsolve"                 78.82     26.27    1635.2     58.40    19.46

我该如何解释`mem.total`?它是什么,单位是什么?我试图查看文档,即`?Rprof`和`?summaryRprof`,但似乎没有很好的说明 :-/ 编辑:这里他们说Rprof "定期探测R的总内存使用情况"。但这不符合50GB,这远远超出了我的内存能力!(现在是8GB物理内存+12 GB页面文件)。
同样,正如R Yoda所指出的那样,`?summaryRprof`表示,使用`memory = "both"`意味着"总内存的变化"。但它到底是什么(是总内存还是总内存的变化),以及它如何与50GB数字相吻合?

编辑:profvis中进行的同样分析-当我悬停在50812上时,它显示“内存分配(MB)”,并在靠近该垂直线的黑色条上悬停“达到峰值内存分配和释放的百分比”。不确定这是什么意思...这大约是50 GB,这意味着可能是所有分配的总和(??)...绝对不是峰值内存使用:

enter image description here


是的,请参考书中的解释。 - Christoph
@Christoph 很有趣!profvis 给了我相同的数字,并标记为 MB!这可能意味着该书存在错误!但无论如何,似乎这是所有分配总和,而不是单个时间内使用的内存。请查看我的更新。 - Tomas
请参阅 https://cran.r-project.org/doc/manuals/R-exts.html#Tracking-memory-allocations 了解更多详细信息。 - R Yoda
?summaryRprof 提到:“如果 memory = “both”,则是相同的列表,但除了时间之外还会显示内存消耗,以 Mb 为单位。” 所以我认为 MB 是正确的。帮助文档也提到:“如果 memory = “both”,则除了计时数据外还报告总内存的变化(截断为零)”。 - R Yoda
@RYoda谢谢!所以,50000 MB的“总内存变化”——这是什么意思呢?我不太清楚……我的系统无法容纳50 GB的总内存。请看我的更新。 - Tomas
1个回答

3

?summaryRprof的解释如下:

如果设置memory = "both",则会显示与时间延迟相关的内存消耗(Mb)。

因此,mem.total以MB为单位。

如果也使用memory = "both",则会报告总内存的变化情况(截断为零)。

你有8 GB的RAM + 12 GB的swap但是mem.total却显示你使用了50GB的内存?

这是因为它是两个连续探测之间聚合的差异(由Rprof在固定时间间隔内拍摄的内存使用快照:如果探测发生在执行函数f时,则将与上一个探测的内存使用差异添加到f的mem.total中)。

内存使用增量可能为负数,但我从未见过负的mem.total值,因此我猜测(!)只有正值被添加到mem.total中。

这就解释了你所看到的总使用量为50 GB的原因:它并不是单个时间点的分配内存量,而是完整执行时间内的聚合内存增量。

这也解释了gc仅显示3 GB为“max used (Mb)”的事实:内存被分配和释放/回收多次,以便您不会遇到内存压力,但这会导致许多时间成本(将如此多的数据移动到RAM中使所有缓存无效并且速度变慢)在CPU应用计算逻辑之外。

这个摘要(我认为)似乎还掩盖了“垃圾收集器(gc)从非确定性时间点开始清理已释放的内存”的事实。

由于gc是懒惰(非确定性地)开始的,因此IMHO将负内存增量归因于单个刚刚测试过的函数是不公平的。

我会将mem.total解释为mem.total.used.during.runtime,这可能是该列的更好标签。

profvis具有更详细的内存使用情况总结(正如你在问题中的截图中看到的那样):它还聚合了负的内存使用增量(释放的内存),但profvis文档也警告其缺陷:

代码面板还显示内存分配和释放。解释这些信息可能有点棘手,因为它不一定反映了该行代码中分配和释放的内存量。采样分析器记录有关前一次采样和当前采样之间发生的内存分配的信息。这意味着该行上的分配/释放值实际上可能发生在先前的代码行中。

更详细的答案需要更多的研究时间(我没有) - 查看C和R源代码 - 根据Rprof创建的数据文件理解(复制)summaryRprof的聚合逻辑 Rprof数据文件(Rprof.out)如下:
:376447:6176258:30587312:152:1#2 "test" 1#1 "test2"

前四个数字(由冒号分隔)的含义如下(参见?summaryRprof): - R_SmallVallocSize:在R堆上以小块分配的向量内存[桶数] - R_LargeVallocSize:在malloc中以大块分配的向量内存[桶数] - 在R堆上的节点内存 - 时间间隔内对内部函数duplicate的调用次数(用于复制向量,例如在函数参数的copy-on-first-write语义中)

字符串是函数调用堆栈。
仅前两个数字与计算当前内存使用量(矢量)的MB有关:

TotalBuckets = R_SmallVallocSize + R_LargeVallocSize
mem.used = TotalBuckets * 8 Bytes / 1024 / 1024
# 50 MB in the above `Rprof` probe line:
# (376447 + 6176258) * 8 / 1024 / 1024

关于 Vcells 的详细信息请参见?Memory

顺便说一句:我想尝试使用summaryRProf(memory = "stats", diff = F)来获取当前的内存汇总,但是在Ubuntu上使用 R3.4.4 64位时出现了错误消息:

Error in tapply(seq_len(1L), list(index = c("1::#File", "\"test2\":1#1",  : 
  arguments must have same length

你能重现这个问题吗(似乎“统计数据”出了问题)?


非常感谢 @RYoda!!!我明天会深入研究一下!! :-) - Tomas
1
我终于做到了。非常感谢!!解密Rprof.out非常有帮助,mem.used正是我想要的,并且与gc()报告的最大内存使用读数完全相符!终于得到了我想要的东西。遗憾的是,summaryRprof()和其他工具如profvis或Rstudio没有提供这种输出。 - Tomas

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