使用go的内置运行时库调试和优化程序

本文涉及的产品
服务治理 MSE Sentinel/OpenSergo,Agent数量 不受限
可观测可视化 Grafana 版,10个用户账号 1个月
简介: 【5月更文挑战第18天】在本文中,作者探讨了如何为运行时程序添加剖析支持以优化性能。他们面临的问题是一个程序需要找出平方根为整数且逆序平方等于其逆序的数字。他们首先展示了原始代码,然后使用`runtime`库进行优化,将计算和调用功能分离,同时记录CPU和内存使用情况。

简介

本文探讨了如何为运行时程序添加剖析支持以优化性能。

该例子问题是一个程序需要找出平方根为整数且逆序平方等于其逆序的数字。我们首先展示了原始代码,然后使用runtime库进行优化,将计算和调用功能分离,同时记录CPU和内存使用情况,以此作为优化的依据。

1 在执行程序中加入剖析支持

我们有一个需求,需要找到10亿以内的某些特别的数字,它们满足以下特征:

            其平方根值为整数
            其平方根值的逆序的平方,等于其逆序

例如,121 正好满足这个特点。

其平方根为 11,为整数.

平方根的逆序的平方 = 11 * 11 = 121

2 使用runtime去优化

某人实现了如下程序,可以完成千万级的计算,但是无法完成亿级别的运算。我们打算优化它,并且按照标准库runtime的指示去优化。

           func counts(n float64) {

        var ms interface{}
        for j := 1.0; j <= n; j++ {

            sj := fmt.Sprintf("%s", reverse(fmt.Sprintf("%v", j))) 
            ms = math.Sqrt(j)
            ins := fmt.Sprintf("%v", ms)  
            if strings.Count(ins, ".") > 0 {
                continue
            }

            switch ms.(type) {
            default:
                continue

            case float64: 
                sms := reverse(ins) 

                 sms str to int
                intsms, _ := strconv.ParseInt(sms, 10, 64) 

                j sj str to int
                intsj, _ := strconv.ParseInt(sj, 10, 64) 

如果逆序平方等于 原数字的逆序,输出到控制台

     if intsms*intsms == intsj {
                    fmt.Println("reverse j", intsj, "sqrt:=", intsms)
                }
            }
        }
    }

在main函数调用这个计算函数count就可以进行计算。 比如我们需要查找 十亿内的全部特征数:

    func main() {
        counts(1000000000.0)
    }

程序在执行一小会之后便停止了。 为什么?

在这里做一些简单分析。 我们不希望从 工具链的test入口查看程序性能。 因此我们选择在程序执行时嵌入代码,将性能数据输出到我们指定的文件。

  • 首先 这里把计算函数分裂为两个,

一个执行函数和一个调用函数,并且使用标准库的 strcov作为转换函数,而不是使用 fmt.Sprintf

    func reverse(s string) string {
            r := []rune(s)
            for i, j := 0, len(r)-1; i < len(r)/2; i, j = i+1, j-1 {
                    r[i], r[j] = r[j], r[i]
            }
            return string(r)
    }

    // sj 原数的逆序数
    // ins 原数的平方根的逆
    func CalcFloat(sj, ins string) {
            sms := reverse(ins)
            intsms, _ := strconv.ParseInt(sms, 10, 64)
            intsj, _ := strconv.ParseInt(sj, 10, 64)
            if intsms*intsms == intsj { 
                    println("find new:", intsj, "sqrt:=", intsms)
                    runtime.GC()
            }
    }
  • 然后我们定义两个指标,cpu使用和mem使用,并且输出到对应文件。

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

在启动调用执行函数前,输出cpu性能数据

    flag.Parse()
if *cpuprofile != "" {
    f, err := os.Create(*cpuprofile)
    if err != nil {
        log.Fatal("could not create CPU profile: ", err)
    }
    defer f.Close()
    if err := pprof.StartCPUProfile(f); err != nil {
        log.Fatal("could not start CPU profile: ", err)
    }
    defer pprof.StopCPUProfile()
}

然后调用计算函数,

Counts(1000000000.0)
  • 这样再输出内存使用数据,在runtime调用GC回收内存时,就获得最新的统计数据 ,

    if *memprofile != "" {

      f, err := os.Create(*memprofile)
      if err != nil {
          log.Fatal("could not create memory profile: ", err)
      }
      defer f.Close() 
      runtime.GC()   
      if err := pprof.WriteHeapProfile(f); err != nil {
          log.Fatal("could not write memory profile: ", err)
      }
    

    }

最后执行该独立程序

 go run _pprof_main.go

等待执行完成后,将获得两个性能数据文件,cpu.prof, mem.prof

3 分析性能

先看内存数据

go tool pprof .\mem.prof
File: pprof_main.test
Build ID:./pprof_main.test 2023-02-06 12:44:53.3670595 +0400 +04
Type: inuse_space
Time: Feb 6, 2023 at 12:45pm (+04)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 1.72MB, 100% of 1.72MB total
      flat  flat%   sum%        cum   cum%
    1.72MB   100%   100%     1.72MB   100%  runtime/pprof.StartCPUProfile
         0     0%   100%     1.72MB   100%  pprof_main.TestMain
         0     0%   100%     1.72MB   100%  main.main
         0     0%   100%     1.72MB   100%  runtime.main

内存占用没有太大问题。

我们再看cpu性能

top
Showing nodes accounting for 160ms, 100% of 160ms total
Showing top 10 nodes out of 62
      flat  flat%   sum%        cum   cum%
      50ms 31.25% 31.25%       50ms 31.25%  runtime.cgocall
      20ms 12.50% 43.75%       20ms 12.50%  fmt.(*pp).free
      20ms 12.50% 56.25%       30ms 18.75%  runtime.slicerunetostring
      10ms  6.25% 62.50%      150ms 93.75%  GolangTrain/41_graphs/19_pprof_main.counts
      10ms  6.25% 68.75%       30ms 18.75%  fmt.(*pp).printArg
      10ms  6.25% 75.00%       10ms  6.25%  runtime.convT64
      10ms  6.25% 81.25%       10ms  6.25%  runtime.encoderune
      10ms  6.25% 87.50%       10ms  6.25%  runtime.writeHeapBits.flush
      10ms  6.25% 93.75%       10ms  6.25%  strconv.computeBounds (inline)
      10ms  6.25%   100%       20ms 12.50%  strconv.ryuFtoaShortest

我们有三个计算函数,某些函数调用没有在这个列表中,因此,我们希望看到消耗性能最高的前10位

查看消耗cpu时间性能的最高前10的函数

     top -cum
    Showing nodes accounting for 60ms, 37.50% of 160ms total
    Showing top 10 nodes out of 62
          flat  flat%   sum%        cum   cum% 
             0     0%     0%      160ms   100%  main.main
             0     0%     0%      160ms   100%  runtime.main
          10ms  6.25%  6.25%      150ms 93.75%  _pprof_main.counts
             0     0%  6.25%       60ms 37.50%  fmt.Sprintf
          50ms 31.25% 37.50%       50ms 31.25%  runtime.cgocall
             0     0% 37.50%       50ms 31.25%  syscall.SyscallN
             0     0% 37.50%       40ms 25.00%  log.(*Logger).Output
             0     0% 37.50%       40ms 25.00%  log.(*Logger).Println
             0     0% 37.50%       30ms 18.75%  _pprof_main.reverse (inline)

可以很明显看到,我们能够控制的 主执行函数 TestMain 占比100%,

继续查,__pprof_main.counts 占比93%,其次为 fmt.Sprintf 38%,逆序函数 reverse 占比 18%。

因此可以确定重点在 count是函数和 fmt.Sprintf 转换函数。

我们知道go的类型转换成本,比如在string 和byte之间,直接使用强制转换成本较高。

    Showing top 10 nodes out of 36
    flat  flat%   sum%        cum   cum%
    12.14s 87.28% 87.28%     12.25s 88.07%  runtime.cgocall
     0.09s  0.65% 87.92%      0.09s  0.65%  runtime.step
     0.09s  0.65% 88.57%      0.09s  0.65%  sync.(*Mutex).Unlock
     0.08s  0.58% 89.14%      0.23s  1.65%  runtime.gentraceback
     0.07s   0.5% 89.65%      0.12s  0.86%  runtime.makeslice
     0.07s   0.5% 90.15%      0.07s   0.5%  runtime.nextFreeFast (inline)
     0.06s  0.43% 90.58%      0.34s  2.44%  runtime.systemstack
     0.04s  0.29% 90.87%      0.31s  2.23%  runtime.callers
     0.04s  0.29% 91.16%      0.08s  0.58%  runtime.writeHeapBits.flush
     0.04s  0.29% 91.45%     12.33s 88.64%  syscall.SyscallN

这一次我们查看前20个消耗cpu最高的函数

top 20 -cum
Showing nodes accounting for 12.52s, 90.01% of 13.91s total
Dropped 137 nodes (cum <= 0.07s)
Showing top 20 nodes out of 36
      flat  flat%   sum%        cum   cum% 
         0     0%     0%     13.80s 99.21%  main.main
         0     0%     0%     13.80s 99.21%  runtime.main
         0     0%     0%     13.77s 98.99%  _advice_math.counts
     0.03s  0.22%  0.22%     13.44s 96.62%  log.(*Logger).Println
     0.03s  0.22%  0.43%     13.28s 95.47%  log.(*Logger).Output
     0.01s 0.072%   0.5%     12.60s 90.58%  os.(*File).Write
         0     0%   0.5%     12.59s 90.51%  internal/poll.(*FD).Write
         0     0%   0.5%     12.59s 90.51%  os.(*File).write (inline)
     0.03s  0.22%  0.72%     12.46s 89.58%  internal/poll.(*FD).writeConsole
     0.02s  0.14%  0.86%     12.34s 88.71%  syscall.Syscall6
     0.01s 0.072%  0.93%     12.34s 88.71%  syscall.WriteConsole
     0.04s  0.29%  1.22%     12.33s 88.64%  syscall.SyscallN
    12.14s 87.28% 88.50%     12.25s 88.07%  runtime.cgocall
     0.01s 0.072% 88.57%      0.49s  3.52%  runtime.Caller
     0.06s  0.43% 89.00%      0.34s  2.44%  runtime.systemstack
     0.04s  0.29% 89.29%      0.31s  2.23%  runtime.callers
     0.02s  0.14% 89.43%      0.25s  1.80%  runtime.mallocgc
         0     0% 89.43%      0.23s  1.65%  runtime.callers.func1
     0.08s  0.58% 90.01%      0.23s  1.65%  runtime.gentraceback

现在可以完成 10亿次计算任务,采样时间 470.35s

    top 20 -cum
    Showing nodes accounting for 313.78s, 66.71% of 470.35s total
    Dropped 402 nodes (cum <= 2.35s)
    Showing top 20 nodes out of 76
          flat  flat%   sum%        cum   cum% 
             0     0%     0%    416.83s 88.62%  main.main
             0     0%     0%    416.83s 88.62%  runtime.main
         6.81s  1.45%  1.45%    416.80s 88.61%  _advice_math.counts
         4.23s   0.9%  2.35%    302.43s 64.30%  strconv.FormatFloat       
        26.35s  5.60%  7.95%    178.17s 37.88%  strconv.genericFtoa       
        17.79s  3.78% 11.73%    108.66s 23.10%  strconv.ryuFtoaShortest   
        52.53s 11.17% 22.90%    102.12s 21.71%  runtime.mallocgc
         7.24s  1.54% 24.44%     96.01s 20.41%  _advice_math.reverse (inline)
        25.67s  5.46% 29.90%     70.37s 14.96%  strconv.ryuDigits
        33.36s  7.09% 36.99%     65.56s 13.94%  runtime.slicerunetostring 
         7.56s  1.61% 38.60%     62.49s 13.29%  runtime.slicebytetostring 
         3.56s  0.76% 39.35%     56.14s 11.94%  runtime.makeslice
         5.99s  1.27% 40.63%     42.16s  8.96%  strconv.formatDigits      
        39.08s  8.31% 48.94%     39.17s  8.33%  strconv.ryuDigits32       
         0.26s 0.055% 48.99%     37.02s  7.87%  runtime.systemstack       
        31.69s  6.74% 55.73%     36.12s  7.68%  strconv.fmtF
        29.90s  6.36% 62.09%     29.90s  6.36%  runtime.encoderune        
        21.70s  4.61% 66.70%     23.21s  4.93%  runtime.stringtoslicerune 
         0.06s 0.013% 66.71%     19.25s  4.09%  runtime.gcBgMarkWorker.func2

4 评估fmt包的执行性能

我们使用以下简单程序,查看fmt的各个输出函数,对同一个字符串的输出性能

    var (
            benchStr = "hello, this is golang."
            sbe      = []byte(benchStr)
    )

    func FmtPrintfBytes(s []byte) {

            fmt.Printf("fmt print:%v", s)
    }

    func FmtPrintlnBytes(s []byte) {

            fmt.Println("fmt print:", s)
    }

    func PrintlnBytes(s []byte) {

            println("fmt print:", s)
    }

    func FmtSrintf(s []byte) {
            newStr := fmt.Sprintf("%v", s)
            fmt.Printf("%v", newStr)
    }

    func BenchmarkFmtPrintfBytes(b *testing.B) {

            for n := 0; n < b.N; n++ {
                    FmtPrintfBytes(sbe)
            }
    }
    func BenchmarkFmtPrintlnBytes(b *testing.B) {
            for n := 0; n < b.N; n++ {
                    FmtPrintlnBytes(sbe)
            }
    }

    func BenchmarkPrintlnBytes(b *testing.B) {
            for n := 0; n < b.N; n++ {
                    PrintlnBytes(sbe)
            }
    }

    func BenchmarkFmtSrintf(b *testing.B) {
            for n := 0; n < b.N; n++ {
                    FmtSrintf(sbe)
            }
    }

执行这个程序性能测试

    go test -cpuprofile cpu.prof -memprofile mem.prof -bench .

查看性能,内存使用几乎相同

          0     0%   100%   512.09kB 10.97%  command-line-arguments.BenchmarkFmtPrintfBytes 
     0     0%   100%   512.09kB 10.97%  command-line-arguments.BenchmarkFmtPrintlnBytes         0     0%   100%   512.09kB 10.97%  command-line-arguments.FmtPrintfBytes (inline) 
     0     0%   100%   512.09kB 10.97%  command-line-arguments.FmtPrintlnBytes (inline)

cpu使用率各有差别,但是不大

      0.01s  0.19% 75.53%      1.57s 30.49%  command-line-arguments.BenchmarkFmtPrintlnBytes         0     0% 75.53%      1.56s 30.29%  command-line-arguments.FmtPrintlnBytes (inline)         0     0% 75.53%      1.56s 30.29%  fmt.Fprintln
     0     0% 75.53%      1.55s 30.10%  fmt.Println (inline)
 0.02s  0.39% 75.92%      1.43s 27.77%  command-line-arguments.BenchmarkFmtSrintf      
     0     0% 75.92%      1.40s 27.18%  command-line-arguments.FmtSrintf
     0     0% 75.92%      1.08s 20.97%  command-line-arguments.BenchmarkFmtPrintfBytes 
     0     0% 75.92%      1.08s 20.97%  command-line-arguments.FmtPrintfBytes (inline) 
     0     0% 75.92%      0.84s 16.31%  command-line-arguments.BenchmarkPrintlnBytes   
     0     0% 75.92%      0.84s 16.31%  command-line-arguments.PrintlnBytes (inline) 

由以上性能数据可以得出简单结论,在输出同样的字节时,输出函数的性能相差不大,计算资源cpu消耗

    fmt.Println >  fmt.Sprintf + fmt.Printf  > fmt.Printf > println

有一些简单的cpu资源使用率区别,但是区别不大。

5 小结

我们在这里介绍了如何不通过工具链的 test 入口,对独立程序嵌入性能数据提取。

并做了一个简单的对比,知道格式化输出的成本 Println 的接口转换有一定的成本,但是区别不大。

目录
相关文章
|
3天前
|
存储 安全 测试技术
【Go语言精进之路】构建高效Go程序:了解map实现原理并高效使用
【Go语言精进之路】构建高效Go程序:了解map实现原理并高效使用
17 3
|
3天前
|
存储 监控 Go
【Go语言精进之路】构建高效Go程序:了解切片实现原理并高效使用
【Go语言精进之路】构建高效Go程序:了解切片实现原理并高效使用
16 3
|
3天前
|
设计模式 安全 Go
【Go语言精进之路】构建高效Go程序:零值可用、使用复合字面值作为初值构造器
【Go语言精进之路】构建高效Go程序:零值可用、使用复合字面值作为初值构造器
8 2
|
3天前
|
存储 安全 Go
【Go语言精进之路】构建高效Go程序:掌握变量、常量声明法则与iota在枚举中的奥秘
【Go语言精进之路】构建高效Go程序:掌握变量、常量声明法则与iota在枚举中的奥秘
13 2
|
8天前
|
负载均衡 算法 Java
【面试宝藏】Go语言运行时机制面试题
探索Go语言运行时,了解goroutine的轻量级并发及GMP模型,包括G(协程)、M(线程)和P(处理器)。GMP调度涉及Work Stealing和Hand Off机制,实现负载均衡。文章还讨论了从协作到基于信号的抢占式调度,以及GC的三色标记算法和写屏障技术。理解这些概念有助于优化Go程序性能。
24 4
|
15天前
|
NoSQL 安全 Go
Go 语言 mongox 库:简化操作、安全、高效、可扩展、BSON 构建
go mongox 是一个基于泛型的库,扩展了 MongoDB 的官方库。通过泛型技术,它实现了结构体与 MongoDB 集合的绑定,旨在提供类型安全和简化的数据操作。 go mongox 还引入链式调用,让文档操作更流畅,并且提供了丰富的 BSON 构建器和内置函数,简化了 BSON 数据的构建。 此外,它还支持插件化编程和内置多种钩子函数,为数据库操作前后的自定义逻辑提供灵活性,增强了应用的可扩展性和可维护性。
50 6
|
20天前
|
JSON Java Go
使用go语言中的内置库调试性能
【5月更文挑战第21天】本文介绍Go 语言提供了内置的 expvar 模块来输出度量数据,帮助定位性能瓶颈。与 pprof 不同,expvar 专注于应用的宏观状态,通过 HTTP 接口 `/debug/vars` 提供标准的 JSON 格式数据,包括自定义度量和内存统计等。通过 expvar,开发者可以轻松监控应用状态,如消息处理速率、内存使用等,而无需像 C++ 或 Java 那样手动实现。
30 0
使用go语言中的内置库调试性能
|
25天前
|
数据可视化 算法 Java
了解go语言运行时工具的作用
【5月更文挑战第16天】本文简介`runtime`库提供系统调用包装、执行跟踪、内存分配统计、运行时指标和剖析支持。`internal/syscall`封装系统调用,保证uintptr参数有效。`trace`用于执行跟踪,捕获各种事件,如goroutine活动、系统调用和GC事件。`ReadMemStats`提供内存分配器统计。`metrics`接口访问运行时定义的度量,包括CPU使用、GC和内存信息。`coverage`支持代码覆盖率分析,`cgo`处理C语言交互,`pprof`提供性能剖析工具集成。这些功能帮助优化和理解Go程序的运行行为。
38 6
|
27天前
|
Go
第一个 Go 程序
第一个 Go 程序
23 2
|
1月前
|
SQL 开发框架 .NET
你确定不学?Go标准库之 text/template
你确定不学?Go标准库之 text/template
20 2