在 Go 中分析内存时看似不一致的结果

Posted 2023-03-06

【中文标题】在 Go 中分析内存时看似不一致的结果

【英文标题】：Seemingly inconsistent results when profiling memory in Go

【发布时间】：2014-11-07 19:39:19

【问题描述】：

我最近在大型数据集上运行了一些用 Go 编写的数字代码，并且遇到了内存管理问题。在尝试分析问题时，我用三种不同的方式测量了我的程序的内存使用情况：使用 Go 的 runtime/pprof 包，使用 unix time 实用程序，以及手动添加我分配的数据的大小。这三种方法没有给我一致的结果。

下面是我正在分析的代码的简化版本。它分配几个切片，将值放在每个索引处，并将它们中的每一个放在父切片中：

package main

import (
    "fmt"
    "os"

    "runtime/pprof"
    "unsafe"
    "flag"
)

var mprof = flag.String("mprof", "", "write memory profile to this file")

func main() 
    flag.Parse()

    N := 1<<15
    psSlice := make([][]int64, N)
    _ = psSlice
    size := 0

    for i := 0; i < N; i++ 
        ps := make([]int64, 1<<10)
        for i := range ps  ps[i] = int64(i) 
        psSlice[i] = ps
        size += int(unsafe.Sizeof(ps[0])) * len(ps)
    

    if *mprof != "" 
        f, err := os.Create(*mprof)
        if err != nil  panic(err) 
        pprof.WriteHeapProfile(f)
        f.Close()
    

    fmt.Printf("total allocated: %d MB\n", size >> 20)

使用命令$ time time -f "%M kB" ./mem_test -mprof=out.mprof 运行它会产生输出：

total allocated: 256 MB
1141216 kB

real    0m0.150s
user    0m0.031s
sys 0m0.113s

这里的第一个数字 256 MB 是从 unsafe.Sizeof 计算的数组的大小，第二个数字 1055 MB 是 time 报告的。运行 pprof 工具会导致

(pprof) top1
Total: 108.2 MB
   107.8  99.5%  99.5%    107.8  99.5% main.main

这些结果以您期望的方式平滑扩展，用于更小或更大长度的切片。

为什么这三个数字不排列得更紧密？

【问题讨论】：

只需在我的机器上运行您的代码并得到“总分配：1024 MB”（OS X 10.9.5）

还有你用的是什么版本的go，你用的目标架构是什么？

我的示例代码中有错误，现在我已更正。我正在为 linux/amd64 运行 Go 1.3.3

【参考方案1】：

首先，您需要提供一个没有错误的示例。让我们从基本数字开始。例如，

package main

import (
    "fmt"
    "runtime"
    "unsafe"
)

func WriteMatrix(nm [][]int64) 
    for n := range nm 
        for m := range nm[n] 
            nm[n][m]++
        
    


func NewMatrix(n, m int) [][]int64 
    a := make([]int64, n*m)
    nm := make([][]int64, n)
    lo, hi := 0, m
    for i := range nm 
        nm[i] = a[lo:hi:hi]
        lo, hi = hi, hi+m
    
    return nm


func MatrixSize(nm [][]int64) int64 
    size := int64(0)
    for i := range nm 
        size += int64(unsafe.Sizeof(nm[i]))
        for j := range nm[i] 
            size += int64(unsafe.Sizeof(nm[i][j]))
        
    
    return size


var nm [][]int64

func main() 
    n, m := 1<<15, 1<<10
    var ms1, ms2 runtime.MemStats
    runtime.ReadMemStats(&ms1)
    nm = NewMatrix(n, m)
    WriteMatrix(nm)
    runtime.ReadMemStats(&ms2)
    fmt.Println(runtime.GOARCH, runtime.GOOS)
    fmt.Println("Actual:  ", ms2.TotalAlloc-ms1.TotalAlloc)
    fmt.Println("Estimate:", n*3*8+n*m*8)
    fmt.Println("Total:   ", ms2.TotalAlloc)
    fmt.Println("Size:    ", MatrixSize(nm))

    // check top VIRT and RES for COMMAND peter
    for 
        WriteMatrix(nm)
    

输出：

$ go build peter.go && /usr/bin/time -f "%M KiB" ./peter amd64 linux 实际：269221888 估计：269221888 总计：269240592 尺寸：269221888 ^C 命令以非零状态退出 2 265220 千字节 $ $顶部 VIRT 284268 RES 265136 命令彼得

这是你所期望的吗？

有关计算内存大小的正确方法，请参阅MatrixSize。

在允许我们使用top 命令的无限循环中，通过更新将矩阵固定为驻留矩阵。

运行这个程序会得到什么结果？

---

错误：

您从/usr/bin/time 得到的结果是1056992 KiB，它太大了四倍。这是您的/usr/bin/time 版本中的一个错误，ru_maxrss 以千字节而不是页面报告。我的 Ubuntu 版本已经打​​了补丁。

参考资料：

Re: GNU time: incorrect results

time-1.7 counts rusage wrong on Linux

GNU Project Archives: time

“time” 1.7-24 source package in Ubuntu。 ru_maxrss 以千字节而不是页为单位报告。 （关闭：#649402）

#649402 - [PATCH] time overestimates max RSS by a factor of 4 - Debian Bug report logs

主题：修复 ru_maxrss 报告作者：Richard Kettlewell Bug-Debian：http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=649402

--- time-1.7.orig/time.c
+++ time-1.7/time.c
@@ -392,7 +398,7 @@
             ptok ((UL) resp->ru.ru_ixrss) / MSEC_TO_TICKS (v));
        break;
      case 'M':       /* Maximum resident set size.  */
-       fprintf (fp, "%lu", ptok ((UL) resp->ru.ru_maxrss));
+       fprintf (fp, "%lu", (UL) resp->ru.ru_maxrss);
        break;
      case 'O':       /* Outputs.  */
        fprintf (fp, "%ld", resp->ru.ru_oublock);

【讨论】：

我已经更正了示例代码中的错误。当我运行你的代码时，我得到的结果与你的一致。但是，我仍然从时间实用程序中获得了四倍的收益。

这是我运行您的代码时发生的情况： $ go build peter.go && /usr/bin/time -f "%M KiB" ./peter amd64 linux 实际：269256384 估计：269221888 总计：269355416 大小：269221888 1056992 KiB 仍然显示四倍的差异。我决定调查我的time 是否工作正常。我在你的主函数末尾放置了一个for ，在后台运行它，然后调用top。 top 表示该进程正在使用 278 MB 内存。这似乎表明time 工作不正常（不知何故）。

@mansfield：要使top 常驻值 (RES) 测量矩阵的内存，请通过在无限循环中写入来使其常驻。查看我修改后的程序。

这是一个很好的观点。但是，我得到了更新程序的VIRT 278m 和RES 258m 以及time 报告的1057008 KiB。

你的答案是正确的。我已根据您提供给我的信息联系了集群工作人员，他们确认这就是发生的事情。感谢您抽出宝贵时间帮助我追踪此事。