Go Pprof 学习记录

1,066 阅读3分钟

什么是Pprof

pprof是go的性能工具,在程序运行的过程中可以记录程序运行信息,CPU,内存使用情况。以及坑比较多的 goroutine运行情况,当需要性能调优或者定位bug的时候这些记录就很重要了(最下面记一次解决go 程序运行内存占用过大问题)

基本使用

使用pprof有多种方式,我使用的就是大家都使用的 net/http/pprof

下面是我在beego中的配置

beego.Router("/debug/pprof", &controllers.PprofController{})
beego.Router("/debug/pprof/:app([\\w]+)", &controllers.PprofController{})
package controllers

import (
	"net/http/pprof"

	"github.com/astaxie/beego"
)

type PprofController struct {
	beego.Controller
}

func (this *PprofController) Get() {
	switch this.Ctx.Input.Param(":app") {
	default:
		pprof.Index(this.Ctx.ResponseWriter, this.Ctx.Request)
	case "":
		pprof.Index(this.Ctx.ResponseWriter, this.Ctx.Request)
	case "cmdline":
		pprof.Cmdline(this.Ctx.ResponseWriter, this.Ctx.Request)
	case "profile":
		pprof.Profile(this.Ctx.ResponseWriter, this.Ctx.Request)
	case "symbol":
		pprof.Symbol(this.Ctx.ResponseWriter, this.Ctx.Request)
	}
	this.Ctx.ResponseWriter.WriteHeader(200)
}

开始使用

基本上我这次使用都只是为了看内存的占用,所以围绕着实际出发把我实践过的写一下

先看如下代码

func (c *MainController) Get() {

	timer := time.NewTimer(time.Second * (30 + 1))
	clearDone := make(chan bool)
	go func() {
		fmt.Println("开启定时器")
		<-timer.C
		fmt.Println("定时结束")
		clearDone <- true
		fmt.Println("定时器结束,往管道输出内容")
	}()
	c.serverData("定时器启动了") //这段代码就是下面的封装的
	// self.ServeJSON()
	// self.StopRun()

	<-clearDone

}

熟悉beego的朋友应该知道 StopRun() 这个方法会中断执行(其实就是return)下面的代码不会执行了。

先说好上面这段代码就是有问题的代码

接下来使用pprof去排查一下 启动服务器中输入 localhost:8080/debug/pprof 可以看到很多选项 下面是最下面有英语的解释 但是这里我用中文描述一下

image.png

  • block : goroutine的阻塞信息,但是我这里是0,之后再探讨一下这个block是怎么看的。
  • allocs : 所有过去内存分配的抽样
  • heap : 堆内存的信息
  • mutex : 锁的信息
  • threadcreate : 线程信息

我主要是通过goroutine 和 heap 这两个都会打印调用栈信息,然后在goroutine还可以看到开了多少个协程在使用,heap就是内存的分配信息。

当我打开如下url时候可以看到如下信息

localhost:8080/debug/pprof/goroutine?debug=1

image.png

第一行就显示了我目前程序开了多少个goroutine,我等待了很久还是这么多基本可以判断阻塞住了.毕竟我也没写什么死循环

打开

localhost:8080/debug/pprof/goroutine?debug=2

image.png 可以看到一堆信息.全都是这一个方法阻塞了 看了下图中的描述 chan send, 10 minutes 按照我的理解就是这个chan已经阻塞了10分钟了..... 并且是在代码的20行 回到最上面看第20行

clearDone <- true

就是这么一句阻塞了,按照我自己的理解就是 这个方法已经执行完了 所以定义 clearDone已经被回收掉了。但是在goroutine中还在往里面发数据(其实这里我也有一个疑惑就是为什么往被回收了的chan里面写数据不是panic 而是阻塞)

命令行方式

这个是我最喜欢的方式 可以使用命令行的方式去查看

go tool pprof localhost:8080/debug/pprof/goroutine

可以看到如下信息

image.png

进入了命令行的交互模式 以此类推 举一反三 想获取其他的改改url就行了

help可以查看使用说明

top 可以查看前10个的内存分配情况

tree 以树状显示

png 以图片格式输出

svg 生成浏览器可以识别的svg文件

注意 如果没有Graphviz记得安装 !!

再来一个demo

func (c *MainController) Get() {

	tick := time.Tick(time.Second / 100)
	var buf []byte
	for range tick {
		buf = append(buf, make([]byte, 1024*1024)...)
	}

}

启动这个例子会一直吃内存

go tool pprof http://localhost:8080/debug/pprof/heap

执行如上命令获取堆栈内存

使用top 查看消耗最多内存的程序

image.png

可以看出是Get方法消耗的最多

深入查看是哪一段代码吧 使用 list MainController 可以看到如下信息

image.png

也可以使用 weblist MainController

image.png

可以看到是初始化数组的时候消耗的内存(测试的时候我电脑风扇都响了)

也可以使用如上说的 svg png 生成图片观看