程序员经验分享-hwhale

pprof 性能分析

2023-11-02

pprof 是一个强大的性能分析工具,可以捕捉到多维度的运行状态的数据,在程序运行过程中可以获取cpu、heap、block、traces等执行信息

一般情况下使用下列三种pprof分析

  • runtime/pprof：采集程序（非 Server）的运行数据进行分析
  • net/http/pprof：采集 HTTP Server 的运行时数据进行分析
  • runtime/trace：采集Go程序运行中的所有的运行时事件

通常使用pprof做的事情

  • CPU 分析，按照一定的频率采集所监听的应用程序 CPU（含寄存器）的使用情况，可确定应用程序在主动消耗 CPU 周期时花费时间的位置
  • 内存分析，在应用程序进行堆分配时记录堆栈跟踪，用于监视当前和历史内存使用情况，以及检查内存泄漏
  • 阻塞分析，记录 goroutine 阻塞等待同步（包括定时器通道）的位置
  • 互斥锁分析，报告互斥锁的竞争情况

例子：

package main

import (
	"iotcomm/app"
	"log"
	"net/http"
	_"net/http/pprof"
)

func main()  {
	go func() {
		log.Println(http.ListenAndServe(":8080", nil))
	}()

	app.Run() //业务代码
}

通过浏览器查看pprof

通过打开浏览器http://localhost:8080/debug/pprof/我们可以得到

/debug/pprof/

Types of profiles available:
Count	Profile
15	allocs
0	block
0	cmdline
23	goroutine
15	heap
0	mutex
0	profile
17	threadcreate
0	trace
full goroutine stack dump
Profile Descriptions:

allocs: A sampling of all past memory allocations
block: Stack traces that led to blocking on synchronization primitives
cmdline: The command line invocation of the current program
goroutine: Stack traces of all current goroutines
heap: A sampling of memory allocations of live objects. You can specify the gc GET parameter to run GC before taking the heap sample.
mutex: Stack traces of holders of contended mutexes
profile: CPU profile. You can specify the duration in the seconds GET parameter. After you get the profile file, use the go tool pprof command to investigate the profile.
threadcreate: Stack traces that led to the creation of new OS threads
trace: A trace of execution of the current program. You can specify the duration in the seconds GET parameter. After you get the trace file, use the go tool trace command to investigate the trace.
  • allocs :过去所有内存分配的采样
    heap profile: 4: 7584 [107: 422856] @ heap/1048576
    1: 5376 [1: 5376] @ 0xec672d 0xec66ea 0xec5813 0xec5f3e 0xec5deb 0xf23dba 0xf23d6b 0xef0bb7 0xf05c30 0xf24a71 0x8645a1
#	0xec672c	math/rand.NewSource+0x12c										C:/Users/DELL/go/pkg/mod/github.com/nats-io/nats.go@v1.11.1-0.20210623165838-4b75fc59ae30/nats.go:3505
#	0xec66e9	github.com/nats-io/nats%2ego.(*Conn).initNewResp+0xe9							C:/Users/DELL/go/pkg/mod/github.com/nats-io/nats.go@v1.11.1-0.20210623165838-4b75fc59ae30/nats.go:3505
#	0xec5812	github.com/nats-io/nats%2ego.(*Conn).createNewRequestAndSend+0x492					C:/Users/DELL/go/pkg/mod/github.com/nats-io/nats.go@v1.11.1-0.20210623165838-4b75fc59ae30/nats.go:3348
#	0xec5f3d	github.com/nats-io/nats%2ego.(*Conn).newRequest+0xdd							C:/Users/DELL/go/pkg/mod/github.com/nats-io/nats.go@v1.11.1-0.20210623165838-4b75fc59ae30/nats.go:3430
#	0xec5dea	github.com/nats-io/nats%2ego.(*Conn).request+0x26a							C:/Users/DELL/go/pkg/mod/github.com/nats-io/nats.go@v1.11.1-0.20210623165838-4b75fc59ae30/nats.go:3419
#	0xf23db9	github.com/nats-io/nats%2ego.(*Conn).Request+0x419							C:/Users/DELL/go/pkg/mod/github.com/nats-io/nats.go@v1.11.1-0.20210623165838-4b75fc59ae30/nats.go:3398
#	0xf23d6a	iotcomm/app/system/admin/internal/service.(*varsSdk).JudgeIfNotifySDK+0x3ca				D:/IotComm/trunk/app/system/admin/internal/service/varsSdk.go:404
#	0xef0bb6	iotcomm/app/system/admin/internal/service.(*channelEntityVariableSubscribe).VariableChangedNotify+0xeb6	D:/IotComm/trunk/app/system/admin/internal/service/channelEntityVariableSubscribe.go:337
#	0xf05c2f	iotcomm/app/system/admin/internal/service.(*entityvarService).UpdateEntityVarValue+0x5af		D:/IotComm/trunk/app/system/admin/internal/service/entityVar.go:779
#	0xf24a70	iotcomm/app/system/admin/internal/service.NatsReport.func1.1+0x150					D:/IotComm/trunk/app/system/admin/internal/service/varsSdk.go:52

由上可以看出，nats.go过去的一段时间内申请内存的操作最多

  • block：协程阻塞的情况，可以用来分析和查找死锁等性能瓶颈，默认不开启，可以调用runtime.SetBlockProfileRate开启来今行查看

列如：

func main()  {
	runtime.SetBlockProfileRate(1)
	go func() {
		log.Println(http.ListenAndServe(":8080", nil))
	}()

	app.Run()
}

可以得到以下block信息

--- contention:
cycles/second=3078668017
69212761621 34 @ 0x6fea9f 0xd50f7f 0x6f4641
#	0x6fea9e	sync.(*Cond).Wait+0x9e					C:/Program Files/Go/src/sync/cond.go:56
#	0xd50f7e	github.com/nats-io/nats%2ego.(*Conn).waitForMsgs+0x4de	C:/Users/DELL/go/pkg/mod/github.com/nats-io/nats.go@v1.11.1-0.20210623165838-4b75fc59ae30/nats.go:2525

38995547732 126 @ 0x6868ab 0x87cce5 0x6f4641
#	0x6868aa	runtime.chanrecv1+0x2a					C:/Program Files/Go/src/runtime/chan.go:439
#	0x87cce4	github.com/gogf/gf/os/gtimer.(*Timer).loop.func1+0x84	C:/Users/DELL/go/pkg/mod/github.com/gogf/gf@v1.16.2/os/gtimer/gtimer_timer_loop.go:21

38794859460 22 @ 0x6868eb 0xd51ff0 0x6f4641
#	0x6868ea	runtime.chanrecv2+0x2a					C:/Program Files/Go/src/runtime/chan.go:444
#	0xd51fef	github.com/nats-io/nats%2ego.(*Conn).flusher+0xef	C:/Users/DELL/go/pkg/mod/github.com/nats-io/nats.go@v1.11.1-0.20210623165838-4b75fc59ae30/nats.go:2799
  • cmdline：主要是调用os.Args，获取程序启动时的命令及参数
  • goroutine：协程相关的报告信息
  • heap：堆以及一些垃圾回收的信息
heap profile: 6: 73120 [402: 2941872] @ heap/1048576
1: 32768 [2: 65536] @ 0x94b0a8 0x94c07e 0x94eafc 0x952c34 0x9536a5 0x960c9e 0x960db6 0xe2d7a5 0xe1b425 0xe08d68 0xe3c22a 0xe38a86 0xef002b 0xeeff33 0xf05c30 0xf24a71 0x8645a1
#	0x94b0a7	regexp.(*bitState).reset+0x227										C:/Program Files/Go/src/regexp/backtrack.go:91
#	0x94c07d	regexp.(*Regexp).backtrack+0x11d									C:/Program Files/Go/src/regexp/backtrack.go:319
#	0x94eafb	regexp.(*Regexp).doExecute+0x45b									C:/Program Files/Go/src/regexp/exec.go:535
#	0x952c33	regexp.(*Regexp).replaceAll+0x1b3									C:/Program Files/Go/src/regexp/regexp.go:617
#	0x9536a4	regexp.(*Regexp).ReplaceAllFunc+0xc4									C:/Program Files/Go/src/regexp/regexp.go:698
#	0x960c9d	github.com/gogf/gf/text/gregex.ReplaceFunc+0xbd								C:/Users/DELL/go/pkg/mod/github.com/gogf/gf@v1.16.2/text/gregex/gregex.go:97
#	0x960db5	github.com/gogf/gf/text/gregex.ReplaceStringFunc+0xb5							C:/Users/DELL/go/pkg/mod/github.com/gogf/gf@v1.16.2/text/gregex/gregex.go:121
#	0xe2d7a4	github.com/gogf/gf/database/gdb.FormatSqlWithArgs+0xc4							C:/Users/DELL/go/pkg/mod/github.com/gogf/gf@v1.16.2/database/gdb/gdb_func.go:783
#	0xe1b424	github.com/gogf/gf/database/gdb.(*Core).DoQuery+0x2e4							C:/Users/DELL/go/pkg/mod/github.com/gogf/gf@v1.16.2/database/gdb/gdb_core_underlying.go:49
#	0xe08d67	github.com/gogf/gf/database/gdb.(*Core).DoGetAll+0xe7							C:/Users/DELL/go/pkg/mod/github.com/gogf/gf@v1.16.2/database/gdb/gdb_core.go:127
#	0xe3c229	github.com/gogf/gf/database/gdb.(*Model).doGetAllBySql+0x209						C:/Users/DELL/go/pkg/mod/github.com/gogf/gf@v1.16.2/database/gdb/gdb_model_select.go:486
#	0xe38a85	github.com/gogf/gf/database/gdb.(*Model).doGetAll+0x165							C:/Users/DELL/go/pkg/mod/github.com/gogf/gf@v1.16.2/database/gdb/gdb_model_select.go:55
#	0xef002a	github.com/gogf/gf/database/gdb.(*Model).All+0x32a							C:/Users/DELL/go/pkg/mod/github.com/gogf/gf@v1.16.2/database/gdb/gdb_model_select.go:40
#	0xeeff32	iotcomm/app/system/admin/internal/service.(*channelEntityVariableSubscribe).VariableChangedNotify+0x232	D:/IotComm/trunk/app/system/admin/internal/service/channelEntityVariableSubscribe.go:330
#	0xf05c2f	iotcomm/app/system/admin/internal/service.(*entityvarService).UpdateEntityVarValue+0x5af		D:/IotComm/trunk/app/system/admin/internal/service/entityVar.go:779
#	0xf24a70	iotcomm/app/system/admin/internal/service.NatsReport.func1.1+0x150					D:/IotComm/trunk/app/system/admin/internal/service/varsSdk.go:52


# runtime.MemStats
# Alloc = 2465032
# TotalAlloc = 13052840
# Sys = 20343400
# Lookups = 0
# Mallocs = 193219
# Frees = 179358
# HeapAlloc = 2465032
# HeapSys = 11665408
# HeapIdle = 6758400
# HeapInuse = 4907008
# HeapReleased = 6471680
# HeapObjects = 13861
# Stack = 917504 / 917504
# MSpan = 165784 / 180224
# MCache = 14016 / 16384
# BuckHashSys = 1452585
# GCSys = 3215184
# OtherSys = 2896111
# NextGC = 4194304
# LastGC = 1630307387416162900
# PauseNs = [0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]
# PauseEnd = [1630307363484526700 1630307363640567200 1630307366356955300 1630307366377908700 1630307367513661900 1630307376617267500 1630307386409989000 1630307387416162900 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]
# NumGC = 8
# NumForcedGC = 0
# GCCPUFraction = 0.00015986017033100297
# DebugGC = false
  • mutex:锁互斥的使用情况，默认不开启， 需要调用需要在程序中调用runtime.SetMutexProfileFraction
    例如：
func main()  {
	runtime.SetMutexProfileFraction(1)
	go func() {
		log.Println(http.ListenAndServe(":8080", nil))
	}()
	app.Run()
}
  • threadcreate：线程的创建信息

通过终端查看pprof

  • 查看cpu在60s的使用情况
    go tool pprof http://localhost:8080/debug/pprof/profile?seconds=60 
D:\IotComm\trunk>go tool pprof http://localhost:8080/debug/pprof/profile?seconds=60
Fetching profile over HTTP from http://localhost:8080/debug/pprof/profile?seconds=60
Saved profile in C:\Users\DELL\pprof\pprof.samples.cpu.003.pb.gz
Type: cpu
Time: Aug 30, 2021 at 3:20pm (CST)
Duration: 1mins, Total samples = 450ms ( 0.75%)
Entering interactive mode (type "help" for commands, "o" for options)

注：在使用浏览器查看pprof的网址，均可以使用go tool pprof + url的方式进入pprof命令行模式
例如go tool pprof http://localhost:8080/debug/pprof/block

(pprof) top
Showing nodes accounting for 837.48MB, 100% of 837.48MB total
      flat  flat%   sum%        cum   cum%
  837.48MB   100%   100%   837.48MB   100%  main.main.func1

同样，使用top5，top10可以看到开销前5，前10占用率的函数
需要注意的是，通常情况下，占用率前5的一定是系统函数，如果发现自己写的函数占用率排在了前列，那就应该查一查时间，空间复杂度了

web可视化界面

func main()  {

	var cpuprofile = flag.String("cpuprofile", "", "write cpu profile to `file`")
	var memprofile = flag.String("memprofile", "", "write memory profile to `file`")

	flag.Parse()
	if *cpuprofile != "" {
		f, err := os.Create(*cpuprofile)
		if err != nil {
			log.Fatal("could not create CPU profile: ", err)
		}
		if err := pprof.StartCPUProfile(f); err != nil {
			log.Fatal("could not start CPU profile: ", err)
		}
		defer pprof.StopCPUProfile()
	}
	
	if *memprofile != "" {
		f, err := os.Create(*memprofile)
		if err != nil {
			log.Fatal("could not create memory profile: ", err)
		}
		runtime.GC() // get up-to-date statistics
		if err := pprof.WriteHeapProfile(f); err != nil {
			log.Fatal("could not write memory profile: ", err)
		}
		f.Close()
	}
	
	runtime.SetMutexProfileFraction(1)
	go func() {
		log.Println(http.ListenAndServe(":8080", nil))
	}()

	app.Run()
}

可以通过go run main.go --memprofile=mem.prof生成了mem.prof
可以通过go run main.go --cpuprofile=cpu.prof生成了cpu.prof

  • 启动pprof可视化界面
$ go tool pprof cpu.prof 
$ (pprof) web

或
$ go tool pprof -http=:8080 cpu.prof

在这里必须安装graphviz，移步graphviz安装教程

使用test的功能及压测生成pprof文件移步到go test文档

本文内容由网友自发贡献，版权归原作者所有，本站不承担相应法律责任。如您发现有涉嫌抄袭侵权的内容，请联系:hwhale#tublm.com(使用前将#替换为@)

go

go语言

pprof 性能分析 的相关文章

随机推荐

  • Window 窗口属性及嵌入窗口到D3D渲染窗口顶层

    Window窗口有很多属性 可以通过设定window的style和ex style中知道 这些属性有时候在实现某些效果的时候 是非常非常重要 以前都没有怎么详细了解 只是在用到对应的API时看一下 根本没有详细深入 这里想记录一下最近工作上

  • Python 创建Windows窗口(GUI)

    创建Windows窗口 GUI py 基本的四要素 import tkinter 导入tkinter模块 root tkinter Tk 创建Window窗口对象 root title 我的第一个GUI程序 窗口标题 root mainlo

  • 屏幕截图的实现和源代码

    最近打算写一些入门相关的小应用程序开发实例 个人感觉学习程序开发 其关键的一步就是阅读源代码 RTFSC 呵呵 然后尝试自己动手编写 这里所谓的自己动手编写并不是让你照着源代码一句话一句的敲 也不是复制粘贴 而是阅读了源代码以后 学习其中的

  • 使用vscode 连接服务器 进行深度学习代码调试

    博主本来在Win上已经配好环境了 但是在跑代码的过程中 因为tensor拼接得太大了 导致笔记本内存不足 因此需要到服务器上跑 为什么选择vscode 如果直接用xshell连接服务器 在命令行运行py文件 不是很直观 也不能debug 还

  • Linux HugePage

    1 闲聊 有一段时间 数据库上出现过CPU消耗非常高的问题 最后分析到了Linux HugePage 发现自己对这一块都没什么了解 于是做了 些了解 Linux 下的大页分为两种类型 标准大页 Huge Pages 和透明大页 Transp

  • ZK实现SASL认证+Kafka连接ZK

    ZK实现SASL认证 Kafka连接ZK 关键词 zk sasl kfaka 未授权认证 参考文档 搭建Kafka集群时 对ZooKeeper认证与权限控制 http ohmycat me 2019 05 08 kafka with zoo

  • VUE element-ui之table表格中嵌套输入框，且输入框失焦自动勾选当前行

    步骤 表格中直接插槽法

  • linux tasklet 的分析与使用

    linux tasklet 的分析与使用 目录 linux tasklet 的分析与使用 tasklet 源码分析 tasklet shedule 调度的分析 tasklet 执行 tasklet 使用简单示例 结论 tasklet 是利用

  • HTTP协议深度剖析及其在各个阶段的作用

    作者 禅与计算机程序设计艺术 1 简介 HTTP HyperText Transfer Protocol 即超文本传输协议 是互联网中使用的基于TCP IP通信协议 HTTP是一个属于应用层的协议 由于其简洁 灵活 易用 快速的方式 越来越

  • three.js简介 —— 3D框架

    随着HTML5的普及 网页的表现能力越来越强大 浏览器提供了WebGL接口 可以通过调用对应API进行3D图形的绘制 Three js在这些基础接口之上又做了一层封装 原文链接 特点 Three js特点 掩盖了3D渲染细节 面向对象 功能

  • 大数据之数据仓库与信息采集平台实战

    一 Kylin前置概念 1 Kylin术语 1 Data Warehouse 数据仓库 数据仓库是一个各种数据 包括历史数据和当前数据 的中心存储系统 是BI business intelligence 商业智能 的核心部件 这里所谈的数据

  • Fegin的GET请求传对象

    学习笔记 Fegin的GET请求如何传递对象 近期做项目发现使用Fegin的GET请求时 如果使用了对象进行传输 会被当做POST请求处理 解决方法如下 1 接口使用 ModelAttribute注解 GetMapping getTest

  • Rose 画序列图

    转载请标明是引用于 http blog csdn net chenyujing1234 欢迎大家拍砖 一 1 序列图的定义 在 UML 的表示中 序列图将交互关系表示为一个二维图 其中 纵向是时间轴 时间沿竖线向下延伸 横向代表了在协作中各

  • 在这里，读懂中国人工智能发展史

    2022年末 由OpenAI开发的大数据模型ChatGPT横空出世 激发了社会各界对于人工智能的极大兴趣 支持者有之 反对者亦不乏 我国的百度 华为 阿里巴巴等科技企业都已向人工智能领域投入了大量资源 并已取得初步成果 由于人工智能的新发展

  • 设置路由器显示检查代理服务器连接失败,路由器设置成功了可检测认证连接失败是为什？...

    希望我的回答对你有用 拨号的时候有没有出现错误代码 提示错误的代码是什么 ADSL拨号错误代码详解 错误 602 The port is already open 问题 拨号网络网络由于设备安装错误或正在使用 不能进行连接 原因 RasPP

  • openCV上图片显示中文c++

    准备材料 1 中文汉字库 2 中文显示扩展类 cvxFont h ifndef OPENCVUNICODE CVXFONT H define OPENCVUNICODE CVXFONT H include

  • FPN(Feature Pyramid Networks) 网络

    FPN 网络 1 前言 通常在神经网络中 浅层特征图 feature maps 的感受野比较小 包含语义信息比较少 但是其空间位置信息准确 而深层网络 感受野大 语义信息强 但是由于 pooling 等造成了像素位置信息丢失等 所以空间位置

  • Python - 字节byte数组与int之间的转换

    将byte数组转int 方式一 b b x00 x00 x03 xE8 或使用 0x0 0x0 0x3 0xE8 亦可 需将列表转为字节b bytes b i1 struct unpack gt i b 0 print i1 1000 方式

  • 【Qt学习】02：信号和槽机制

    信号和槽机制 OVERVIEW 信号和槽机制 一 系统自带信号与槽 二 自定义信号与槽 1 基本使用 student cpp teacher cpp widget cpp main cpp 2 信号与槽重载 student cpp teac

  • pprof 性能分析

    pprof 是一个强大的性能分析工具 可以捕捉到多维度的运行状态的数据 在程序运行过程中可以获取cpu heap block traces等执行信息 一般情况下使用下列三种pprof分析 runtime pprof 采集程序 非 Serve

热门标签