【问题标题】:Seemingly inconsistent results when profiling memory in Go在 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

标签: memory time go profiling


【解决方案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 Ubunturu_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 { },在后台运行它,然后调用toptop 表示该进程正在使用 278 MB 内存。这似乎表明time 工作不正常(不知何故)。
  • @mansfield:要使top 常驻值 (RES) 测量矩阵的内存,请通过在无限循环中写入来使其常驻。查看我修改后的程序。
  • 这是一个很好的观点。但是,我得到了更新程序的VIRT 278mRES 258m 以及time 报告的1057008 KiB
  • 你的答案是正确的。我已根据您提供给我的信息联系了集群工作人员,他们确认这就是发生的事情。感谢您抽出宝贵时间帮助我追踪此事。
猜你喜欢
  • 2011-06-27
  • 1970-01-01
  • 1970-01-01
  • 2018-02-27
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 2017-11-29
  • 1970-01-01
相关资源
最近更新 更多