无法从 CPU 分析中获取数据

Question

我正在尝试学习使用 Go 的分析功能。考虑到这一点，我创建了这个简单的应用程序： https: //github.com/Matias-Barrios/countWords ，它只是计算给定txt文件 的单词出现次数。问题是，创建.cpu.prof文件后我看不到任何内容。一旦我打开文件，我就会收到此错误：(0) matias #> go tool pprof .cpu.prof  File: main Type: cpu Time: Oct 9, 2019 at 12:38am (-03) Duration: 201.31ms, Total samples = 0 No samples were found with the default sample value type. Try "sample_index" command to analyze different sample values. Entering interactive mode (type "help" for commands, "o" for options) (pprof) top Showing nodes accounting for 0, 0% of 0 total       flat  flat%   sum%        cum   cum% (pprof)我在这里做错了什么？注意：我的Go版本是go版本go1.13.1 linux/amd64

Answer 1

对我来说，问题是我的代码执行得太快。我所做的是使用runtime.SetCPUProfileRate更改采样率。请注意，在runtime.pprof.StartCPUProfile中，采样率为100 Hz，建议为500 Hz。

func StartCPUProfile(w io.Writer) error {

    // The runtime routines allow a variable profiling rate,

    // but in practice operating systems cannot trigger signals

    // at more than about 500 Hz, and our processing of the

    // signal is not cheap (mostly getting the stack trace).

    // 100 Hz is a reasonable choice: it is frequent enough to

    // produce useful data, rare enough not to bog down the

    // system, and a nice round number to make it easy to

    // convert sample counts to seconds. Instead of requiring

    // each client to specify the frequency, we hard code it.

    const hz = 100

    cpu.Lock()

    defer cpu.Unlock()

    if cpu.done == nil {

         cpu.done = make(chan bool)

    }

    // Double-check.

    if cpu.profiling {

         return fmt.Errorf("cpu profiling already in use")

     }

    cpu.profiling = true

    runtime.SetCPUProfileRate(hz)

    go profileWriter(w)

    return nil

}

但就我而言，将其设置为 500 Hz 还不够快。查看runtime.SetCPUProfileRate的代码后，您似乎可以提供高达100000 Hz的频率。将其设置为足够大的值后，它解决了我的问题。

// SetCPUProfileRate sets the CPU profiling rate to hz samples per second.

// If hz <= 0, SetCPUProfileRate turns off profiling.

// If the profiler is on, the rate cannot be changed without first turning it off.

//

// Most clients should use the runtime/pprof package or

// the testing package's -test.cpuprofile flag instead of calling

// SetCPUProfileRate directly.

func SetCPUProfileRate(hz int) {

    // Clamp hz to something reasonable.

    if hz < 0 {

        hz = 0

    }

    if hz > 1000000 {

        hz = 1000000

    }

    lock(&cpuprof.lock)

    if hz > 0 {

        if cpuprof.on || cpuprof.log != nil {

            print("runtime: cannot set cpu profile rate until previous profile has finished.\n")

            unlock(&cpuprof.lock)

            return

        }

        cpuprof.on = true

        cpuprof.log = newProfBuf(1, 1<<17, 1<<14)

        hdr := [1]uint64{uint64(hz)}

        cpuprof.log.write(nil, nanotime(), hdr[:], nil)

        setcpuprofilerate(int32(hz))

    } else if cpuprof.on {

        setcpuprofilerate(0)

        cpuprof.on = false

        cpuprof.addExtra()

        cpuprof.log.close()

    }

    unlock(&cpuprof.lock)

}

Answer 2

Go 编程语言规范

推迟陈述

“defer”语句调用一个函数，该函数的执行被推迟到周围函数返回的那一刻，要么是因为周围函数执行了 return 语句，到达了其函数体的末尾，要么是因为相应的 goroutine 正在恐慌。

---

修复CPU文件过早关闭的问题：

func CPUprofiling() {

    fd, err := os.Create(".cpu.prof")

    if err != nil {

        log.Fatalln(err.Error())

    }

    defer fd.Close()

    pprof.StartCPUProfile(fd)

    defer pprof.StopCPUProfile()

}

例如，

package main

import (

    "bufio"

    "flag"

    "fmt"

    "log"

    "os"

    "runtime/pprof"

    "strings"

)

var filename string

func main() {

    cpu, err := os.Create(".cpu.prof")

    if err != nil {

        log.Fatalln(err.Error())

    }

    defer cpu.Close()

    pprof.StartCPUProfile(cpu)

    defer pprof.StopCPUProfile()

    flag.StringVar(&filename, "f", "", "Path to the input file")

    flag.Parse()

    if filename == "" {

        flag.Usage()

        log.Fatalln()

    }

    for w, c := range getResults(filename) {

        fmt.Printf("%-20s\t%d\n", w, c)

    }

    mem, err := os.Create(".mem.prof")

    if err != nil {

        log.Fatalln(err.Error())

    }

    defer mem.Close()

    pprof.WriteHeapProfile(mem)

}

func getResults(path string) map[string]int {

    results := make(map[string]int)

    file, err := os.Open(filename)

    defer file.Close()

    if err != nil {

        log.Fatalln(err.Error())

    }

    scanner := bufio.NewScanner(file)

    scanner.Split(bufio.ScanWords)

    for scanner.Scan() {

        results[removeNonWordChars(scanner.Text())]++

    }

    delete(results, "")

    return results

}

func removeNonWordChars(input string) string {

    var result strings.Builder

    result.Grow(len(input))

    for _, r := range strings.ToLower(input) {

        if r >= 'a' && r <= 'z' {

            _, err := result.WriteRune(r)

            if err != nil {

                log.Fatalln(err.Error())

            }

        }

    }

    return result.String()

}

输出：

$ go tool pprof .cpu.prof

File: main

Type: cpu

Time: Oct 9, 2019 at 5:39am (EDT)

Duration: 600.79ms, Total samples = 390ms (64.91%)

Entering interactive mode (type "help" for commands, "o" for options)

(pprof) top

Showing nodes accounting for 320ms, 82.05% of 390ms total

Showing top 10 nodes out of 43

      flat  flat%   sum%        cum   cum%

     110ms 28.21% 28.21%      110ms 28.21%  syscall.Syscall

      60ms 15.38% 43.59%       90ms 23.08%  runtime.mapassign_faststr

      40ms 10.26% 53.85%       40ms 10.26%  unicode/utf8.DecodeRune

      30ms  7.69% 61.54%       30ms  7.69%  strings.(*Builder).WriteRune

      20ms  5.13% 66.67%       20ms  5.13%  runtime.slicebytetostring

      20ms  5.13% 71.79%       20ms  5.13%  strings.ToLower

      10ms  2.56% 74.36%       60ms 15.38%  bufio.ScanWords

      10ms  2.56% 76.92%       10ms  2.56%  bufio.isSpace

      10ms  2.56% 79.49%       10ms  2.56%  fmt.(*buffer).writeString

      10ms  2.56% 82.05%       10ms  2.56%  memeqbody

(pprof) quit

$