tree 0a2ac22b9c173cb2cad54693c233746d38976f01
parent 3fab47e9999e5198d2ecdeeb5dddcfda859edbc2
author Fumitoshi Ukai <fumitoshi.ukai@gmail.com> 1428500676 +0900
committer Fumitoshi Ukai <fumitoshi.ukai@gmail.com> 1428500676 +0900

add -kati_cpuprofile option.

for dump-products in repo/android

$ go tool pprof ../../kati ../kati.prof
(pprof) top30
15.82s of 18.05s total (87.65%)
Dropped 141 nodes (cum <= 0.09s)
Showing top 30 nodes out of 77 (cum >= 0.88s)
      flat  flat%   sum%        cum   cum%
     4.06s 22.49% 22.49%      4.06s 22.49%  scanblock
     3.52s 19.50% 41.99%      3.52s 19.50%  runtime.aeshashbody
     1.65s  9.14% 51.14%      1.65s  9.14%  runtime.MSpan_Sweep
     1.09s  6.04% 57.17%      1.23s  6.81%  runtime.mallocgc
     0.84s  4.65% 61.83%      0.84s  4.65%  runtime.memclr
     0.68s  3.77% 65.60%      3.72s 20.61%  runtime.evacuate
     0.44s  2.44% 68.03%      0.44s  2.44%  runtime.memmove
     0.43s  2.38% 70.42%      5.53s 30.64%  runtime.mapassign1
     0.28s  1.55% 71.97%      0.28s  1.55%  runtime.writebarrierptr
     0.26s  1.44% 73.41%      0.53s  2.94%  regexp.(*machine).step
     0.25s  1.39% 74.79%      0.25s  1.39%  runtime.xchg
     0.22s  1.22% 76.01%      0.22s  1.22%  regexp/syntax.(*Inst).MatchRunePos
     0.21s  1.16% 77.17%      1.11s  6.15%  main.parseExpr
     0.21s  1.16% 78.34%      0.34s  1.88%  regexp.(*machine).add
     0.19s  1.05% 79.39%      0.29s  1.61%  runtime.mapiternext
     0.18s     1% 80.39%     10.04s 55.62%  main.(*Evaluator).evalExprSlice
     0.17s  0.94% 81.33%      0.29s  1.61%  bytes.(*Buffer).grow
     0.15s  0.83% 82.16%      1.15s  6.37%  regexp.(*machine).match
     0.14s  0.78% 82.94%      0.14s  0.78%  runtime.readvarint
     0.13s  0.72% 83.66%      0.45s  2.49%  runtime.mapaccess1
     0.12s  0.66% 84.32%      0.24s  1.33%  runtime.mapaccess2_faststr
     0.11s  0.61% 84.93%      0.36s  1.99%  bytes.(*Buffer).WriteByte
     0.10s  0.55% 85.48%      0.10s  0.55%  runtime.(*bmap).overflow
     0.10s  0.55% 86.04%      0.10s  0.55%  runtime.mprof_GC
     0.06s  0.33% 86.37%      0.10s  0.55%  runtime.makemap
     0.06s  0.33% 86.70%      0.42s  2.33%  runtime.newobject
     0.05s  0.28% 86.98%      0.35s  1.94%  main.(*VarTab).Lookup
     0.04s  0.22% 87.20%      0.13s  0.72%  runtime.growslice
     0.04s  0.22% 87.42%      0.15s  0.83%  runtime.makeslice
     0.04s  0.22% 87.65%      0.88s  4.88%  runtime.newarray
(pprof) top35 -cum
12.96s of 18.05s total (71.80%)
Dropped 141 nodes (cum <= 0.09s)
Showing top 35 nodes out of 77 (cum >= 0.71s)
      flat  flat%   sum%        cum   cum%
         0     0%     0%     10.04s 55.62%  main.(*Evaluator).evalExpr
     0.18s     1%     1%     10.04s 55.62%  main.(*Evaluator).evalExprSlice
     0.03s  0.17%  1.16%     10.04s 55.62%  main.(*Evaluator).evalFunction
         0     0%  1.16%     10.04s 55.62%  main.funcCall
         0     0%  1.16%     10.04s 55.62%  main.funcForeach
         0     0%  1.16%     10.04s 55.62%  main.funcIf
     0.01s 0.055%  1.22%      8.96s 49.64%  main.funcEval
         0     0%  1.22%      6.49s 35.96%  main.(*Evaluator).eval
         0     0%  1.22%      6.21s 34.40%  main.(*Evaluator).evalInclude
         0     0%  1.22%      6.19s 34.29%  main.(*IncludeAST).eval
     0.01s 0.055%  1.27%      5.88s 32.58%  main.(*Evaluator).VarTab
     0.43s  2.38%  3.66%      5.53s 30.64%  runtime.mapassign1
         0     0%  3.66%      4.43s 24.54%  GC
     4.06s 22.49% 26.15%      4.06s 22.49%  scanblock
     0.68s  3.77% 29.92%      3.72s 20.61%  runtime.evacuate
         0     0% 29.92%      3.72s 20.61%  runtime.growWork
         0     0% 29.92%      3.58s 19.83%  System
     3.52s 19.50% 49.42%      3.52s 19.50%  runtime.aeshashbody
         0     0% 49.42%      3.03s 16.79%  main.(*VarTab).Assign
     0.03s  0.17% 49.58%      2.78s 15.40%  main.(*VarTab).Vars
     1.65s  9.14% 58.73%      1.65s  9.14%  runtime.MSpan_Sweep
         0     0% 58.73%      1.30s  7.20%  main.splitSpaces
     0.02s  0.11% 58.84%      1.30s  7.20%  regexp.(*Regexp).Split
         0     0% 58.84%      1.25s  6.93%  regexp.(*Regexp).FindAllStringIndex
     0.01s 0.055% 58.89%      1.25s  6.93%  regexp.(*Regexp).allMatches
     1.09s  6.04% 64.93%      1.23s  6.81%  runtime.mallocgc
         0     0% 64.93%      1.22s  6.76%  regexp.(*Regexp).doExecute
         0     0% 64.93%      1.19s  6.59%  main.Eval
     0.15s  0.83% 65.76%      1.15s  6.37%  regexp.(*machine).match
     0.21s  1.16% 66.93%      1.11s  6.15%  main.parseExpr
         0     0% 66.93%      1.08s  5.98%  main.funcStrip
         0     0% 66.93%      0.95s  5.26%  main.funcFilter
     0.04s  0.22% 67.15%      0.88s  4.88%  runtime.newarray
     0.84s  4.65% 71.80%      0.84s  4.65%  runtime.memclr
         0     0% 71.80%      0.71s  3.93%  main.(*Evaluator).evalMaybeRule