接下来我们要找到耗时最多的那个部分:
go tool pprof list cpu_validator.log
显示结果如下:
D:\gopath\src\github.com\utxo\balance> go tool pprof list cpu_validator.log
list: open list: The system cannot find the file specified.
Fetched 1 source profiles out of 2
Main binary filename not available.
Type: cpu
Time: Dec 20, 2018 at 11:15pm (CST)
Duration: 625.81ms, Total samples = 420ms (67.11%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 420ms, 100% of 420ms total
Showing top 10 nodes out of 25
flat flat% sum% cum cum%
240ms 57.14% 57.14% 240ms 57.14% math/big.addMulVVW
110ms 26.19% 83.33% 380ms 90.48% math/big.nat.montgomery
30ms 7.14% 90.48% 30ms 7.14% runtime.memmove
10ms 2.38% 92.86% 10ms 2.38% math/big.(*Int).QuoRem
10ms 2.38% 95.24% 10ms 2.38% math/big.nat.add
10ms 2.38% 97.62% 10ms 2.38% runtime.lock
10ms 2.38% 100% 20ms 4.76% runtime.newstack
0 0% 100% 400ms 95.24% github.com/utxo/balance.BenchmarkTransferProofValidator
0 0% 100% 400ms 95.24% github.com/utxo/balance.TransferProofValidator
0 0% 100% 400ms 95.24% github.com/utxo/crypto/base.Exp
每一行表示一个函数的信息。前两列表示函数在 CPU 上运行的时间以及百分比;第三列是当前所有函数累加使用 CPU 的比例;第四列和第五列代表这个函数以及子函数运行所占用的时间和比例(也被称为累加值 cumulative),应该大于等于前两列的值;最后一列就是函数的名字。如果应用程序有性能问题,上面这些信息应该能告诉我们时间都花费在哪些函数的执行上了。
以上面显示的结果为例,根据cum来观察大部分的时间都花费在了Exp的执行过程中(base.Exp 函数在其他模块内被调用),我们可以通过list命令来仔细分析一下Exp函数中在那部分比较耗时:
Total: 420ms
ROUTINE ======================== github.com/utxo/crypto/base.Exp in D:\gopath\src\github.com\utxo\crypto\base\base.go
0 400ms (flat, cum) 95.24% of Total
. . 91: return E
. . 92: }
. . 93:
. . 94: if x.Sign() < 1{
. . 95: x = (&big.Int{}).Neg(x)
. 30ms 96: E = (&big.Int{}).Exp(g, x, n)
. . 97: if 1 != Gcd(E, n).Int64(){
. . 98: log.Printf("h_r is not prime with n")
. . 99: return nil
. . 100: }
. . 101:
. 20ms 102: E = (&big.Int{}).ModInverse(E, n)
. . 103: E = (&big.Int{}).Mod(E, n)
. . 104:
. . 105: }else {
. 350ms 106: E = (&big.Int{}).Exp(g, x, n)
. . 107: }
. . 108:
. . 109: return E
. . 110:}
. . 111:
如上所示,base.Exp 总计占用了 95.24% 的cpu时间, 而整个函数内最耗时的就是 big.Exp() 函数。这就给作者制造了个难题,因为在本模块中涉及到大量的指数运算,而且输入数据都较大(平均 512bit)。