go程序调试、分析与优化

1、Go程序调试、分析与优化八月 25, 20159条评论Brad Fitzpatrick在YAPC Asia 2015（Yet Anotherl Conference）上做了一次技术，题为：GoDebugging, Profiling, and Optimization。个人感觉这篇中价值最大的是BradFitz现场演示的一个有关如何对Go程序进行调试、分析和优化的 Demo，将上传到了他个人在的repo中，但)。于 是打算在这不知为何，repo中的代码似乎与repo里talk.md中的说明不甚一致(btw，我并没有看里按照Brad的思路重新走一遍demo的演示流程(所有演示代码在这里可以到)。

2、一、实验环境$uname -aLinux pc-tony 3.13.0-61-generic #100precise1-Ubuntu SMP Wed Jul 2015 x86_64 x86_64 x86_64 GNU/Linux29 12:06:40注意:在Darwin或Windows下，profile的结果可能与这里有很大不同(甚至完全不一样的输出和瓶颈热点)。$erergo1.5 linux/amd64$ go env GOARCH=amd64GOBIN=/home1/tonybai/.bin/go15/bin GOEXE=GOHOSTARCH=amd64GOHOSTOS=linux GO

3、OS=linuxGOPATH=/home1/tonybai/proj/GoProjects GORACE=GOROOT=/home1/tonybai/.bin/go15 GOTOOLDIR=/home1/tonybai/.bin/go15/pkg/tool/linux_amd64 GO15VENDOREXPERIMENT=1CC=gccGOGCCFLAGS=-fPIC -m64 -pthread -fmessage-length=0 CXX=g+CGO_ENABLED=1代码基于的/bradfitz/talk-yapc-asia-2015。二、待优化程序(step0)待优化程序，也就是原始程序

4、，放在step0中：/go-debug-profile-optimization/step0/demo.gopackage mainimport (fmtlog net/http regexp)varvisitorsfunc handleHi(w http.ResponseWriter, r *http.Request)if match, _ := regexp.MatchString(w*$, r.FormValue(color) !match http.Error(w, Optional color is invalid, http.SreturnusBadRequest)visitors

5、+w.Header().Set(Content-Type, text/html charset=utf-8) w.Write(byte(e!You are visitor number + fmt.Spr(visitors)+!)func main()log.Prf(Starting on port 8080)http.HandleFunc(/hi, handleHi)log.Fatal(http.ListenAndServe(:8080,nil)$gorun demo.go2015/08/25 09:42:35 Starting on port 8080在浏览器输入：一切顺利的话，页面会显示

6、：e!You are visitor number 1!三、添加测试代码按照talk.md中的说明，brad repo中demo中根本没有测试代码(commit2427d0faa12ed1fb05f1e6a1e69307c11259c2b2)。于是我根据作者的意图，新增了demo_test.go，采用TesndleHi_Recorder和TesndleHi_TestServer对HandleHi进试：/go-debug-profile-optimization/step0/demo_test.gopackage mainimport (bufio net/httpnet/http/httpte

7、st stringstesting)func TesndleHi_Recorder(t *testing.T) rw := httptest.NewRecorder()handleHi(rw, req(t, GET / HTTP/1.0rnrn) if !strings.Contains(rw.Body.String(), visitort.Errorf(Unexpected output: %s, rw.Body)number) func req(t *testing.T, v string) *http.Request req, err := http.ReadRequest(bufi i

8、f err != nil t.Fatal(err)return reqReader(strings.NewReader(v)func Tests := deferndleHi_TestServer(t *testing.T) httptest.NewServer(http.HandlerFunc(handleHi) ts.Close()res, err := http.Get(ts.URL) if err != nil t.Error(err) returnif g, w := res.Header.Get(Content-Type), text/html charset=utf-8g !=

9、wt.Errorf(Content-Type = %q want %q,g,w)slurp, err := ioutil.ReadAll(res.Body) defer res.Body.Close()if err != nil t.Error(err) returnt.Logf(Got: %s, slurp)$ go test -v= RUNPASS:= RUNPASS:Tes TesTesTesndleHi_Recorder ndleHi_Recorder (0.00s)ndleHi_TestServerndleHi_TestServer (0.00s)demo_test.go:45: G

10、ot: e!You are visitor number2! PASSok_/home1/tonybai/proj/opensource/experiments/go-debug-profile-optimization/step00.007s测试通过！至此，step0使命结束。四、Race Detector(竞态分析）并发设计使得程序可以更好更有效的利用现代处理器的多。但并发设计很容易引入竞态，导致严重bug。Go程序中竞态就是当多个goroutine并发某共享数据且未使用同步机制时，且至少一个goroutine进行了写操作。不过go工具自带race分析功能。在分析优化step0中demo代

11、码 前，先要保证demo代码中不存在竞态。工具的使用方法就是在go test后加上-race标志，在step0目录下：$ go test -v -race= RUNPASS:= RUNPASS:Tes TesTesTesndleHi_Recorder ndleHi_Recorder (0.00s)ndleHi_TestServerndleHi_TestServer (0.00s)demo_test.go:45: Got: e!You are visitor number2! PASSok_/home1/tonybai/proj/opensource/experiments/go-debug-p

12、rofile-optimization/step01.012s-race通过做运行时分析做竞态分析，虽然不存在误报，但却存在实际有竞态，但工具没发现的情况。接下来改造一下测试代码，让test并发起来：向step1(copy自step0)中demo_test.go中添加一个test method:/go-debug-profile-optimization/step1/demo_test.go func Tests := deferndleHi_TestServer_Parallel(t *testing.T) httptest.NewServer(http.HandlerFunc(handle

13、Hi) ts.Close()var wg sync.WaitGroupfor i := 0 iwg.Add(1) 2 i+ gofunc()deferwg.Done()res, err := http.Get(ts.URL) if err != nil t.Error(err) returnif g, w := res.Header.Get(Content-Type),text/htmlcharset=utf-8g!= w t.Errorf(Content-Type = %q want %q,g, w)slurp, err := ioutil.ReadAll(res.Body) defer r

14、es.Body.Close()if err != nil t.Error(err) returnt.Logf(Got: %s, slurp)()wg.Wait()执行竞态test：$ go test -v -race= RUNPASS:= RUNPASS:Tes TesTesTesndleHi_Recorder ndleHi_Recorder (0.00s)ndleHi_TestServerndleHi_TestServer (0.00s)demo_test.go:46: Got: e!You are visitornumber2!= RUNTesndleHi_TestServer_Paral

15、lel= WARNING: DATA RACERead by goroutine 22:_/home1/tonybai/proj/opensource/ optimization/step1.handleHi()/home1/tonybai/proj/opensource/ optimization/step1/demo.go:17 +0 xf5net/http.HandlerFunc.ServeHTTP()/experiments/go-debug-profile-/experiments/go-debug-profile-/tmp/workdir/go/src/net/http/serve

16、r.go:1422 +047 net/http/httptest.(*waitGroupHandler).ServeHTTP()/tmp/workdir/go/src/net/http/httptest/server.go:200 +0 xfe net/http.serverHandler.ServeHTTP()/tmp/workdir/go/src/net/http/server.go:1862 +0206 net/http.(*conn).serve()/tmp/workdir/go/src/net/http/server.go:1361 +0 x117cPrevious write by

17、 goroutine 25:_/home1/tonybai/proj/opensource/ optimization/step1.handleHi()/home1/tonybai/proj/opensource/ optimization/step1/demo.go:17 +0111net/http.HandlerFunc.ServeHTTP()/experiments/go-debug-profile-/experiments/go-debug-profile-/tmp/workdir/go/src/net/http/server.go:1422 +047 net/http/httptes

18、t.(*waitGroupHandler).ServeHTTP()/tmp/workdir/go/src/net/http/httptest/server.go:200 +0 xfe net/http.serverHandler.ServeHTTP()/tmp/workdir/go/src/net/http/server.go:1862 +0206 net/http.(*conn).serve()/tmp/workdir/go/src/net/http/server.go:1361 +0 x117cGoroutine 22 (running) created at:net/http.(*Ser

19、ver).Serve()/tmp/workdir/go/src/net/http/server.go:1910+0464Goroutine 25 (running) created at: net/http.(*Server).Serve()/tmp/workdir/go/src/net/http/server.go:1910=+0464 PASS: TesndleHi_TestServer_Parallel (0.00s)demo_test.go:71: Got: e!You are visitor number3!demo_test.go:71: Got: e!You are visito

20、r number4! PASSFound 1 exit sFAILdata raus 66)_/home1/tonybai/proj/opensource/experiments/go-debug-profile-optimization/step11.023s工具发现demo.go第17行：visitors+是一处潜在的竞态条件。visitors被多个goroutine但未采用同步机制。既然发现了竞态条件，就需要fix it。有多种fix方法可选：1、使用channel 2、使用Mutex3、使用atomicBrad使用了atomic：/go-debug-profile-optimizati

21、on/step1/demo.go var visitors64 / must be acsed atomicallyfunc handleHi(wif match, _http.ResponseWriter, r *http.Request):= regexp.MatchString(w*$, r.FormValue(color) !matchhttp.Error(w, Optional color is invalid, http.SreturnusBadRequest)visitNum := atomic.Add64(&visitors, 1)w.Header().Set(Content-

22、Type, text/html charset=utf-8)w.Write(byte(e!You are visitor number +fmt.Spr(visitNum) + !) 再做一次测试：$ go test -v -race= RUNPASS:= RUNPASS:Tes TesTesTesndleHi_Recorder ndleHi_Recorder (0.00s)ndleHi_TestServerndleHi_TestServer (0.00s)demo_test.go:46: Got: e!Youarevisitornumber2!= RUNTesndleHi_TestServe

23、r_Parallel PASS: TesndleHi_TestServer_Parallel (0.00s)demo_test.go:71: Got: e!Youarevisitornumber3!demo_test.go:71: Got: e!Youarevisitornumber4! PASSok_/home1/tonybai/proj/opensource/experiments/go-debug-profile-optimization/step11.020s竞态条件被消除了！至此，step1结束了使命！五、CPU Profiling要做CPU Profilling，需要benark数

24、据，Go test提供benark test功能，只要写对应的Benark测试方法即可：/go-debug-profile-optimization/step2/demo_test.go func BenarkHi(b *testing.B) b.ReportAllocs()req, err := http.ReadRequest(bufi HTTP/1.0rnrn)if err != nil b.Fatal(err)Reader(strings.NewReader(GET /for i := 0 i b.N i+ rw := httptest.NewRecorder() handleHi(r

25、w, req) $ go test -v -run=$ -bench=.PASSBenarkHi-410000014808 ns/op4961 B/op81allocs/opok_/home1/tonybai/proj/opensource/experiments/go-debug-profile-optimization/step21.648s开始CPU Profiling：$ go test -v -run=$ -bench=BenPASSarkHi$ -benchtime=2s -cpuprofile=prof.cpuBenarkHi-420000014679 ns/op4961 B/o

26、p81allocs/opok_/home1/tonybai/proj/opensource/experiments/go-debug-profile-optimization/step23.096s执行完benark test后，step2目录下出现两个新文件prof.cpu和step2.test，这两个文件将作为后续go tool pprof的输入：$lsdemo.godemo_test.goprof.cpustep2.test*使用go profile viewer工具：$ go tool pprof step2.test prof.cpuEntering(pprof) toperacti

27、ve mode (type help fords)1830ms of 3560ms total (51.40%)Dropped 53 nodes (cum = 1290ms)flat 480ms 360ms 170ms 170ms120msflat% 13.48%10.11%4.78%4.78%3.37%sum% 13.48%23.60%28.37%33.15%36.52%cum 980ms 700ms 170ms 200ms1100mscum% 27.53%19.66%4.78%5.62%30.90%runtime.growslice runtime.mallocgc runtime.hea

28、pBitsSetType runtime.scanblockregexp.makeOnePass.func2120ms 110ms 110ms 100ms90ms3.37%3.09%3.09%2.81%2.53%39.89%42.98%46.07%48.88%51.40%550ms 300ms 220ms 100ms1290ms15.45%8.43%6.18%2.81%36.24%runtime.newarrayruntime.makesliceruntime.mruntime.futexsign1regexp.makeOnePass(pprof) topcum0.18s of 3.56s t

29、otal ( 5.06%)Dropped 53 nodes (cum = 1.29s)flat%0%0.56%0%0%0.84%0.28%0%0%0.84%2.53%sum%0%0.56%0.56%0.56%1.40%1.69%1.69%1.69%2.53%5.06%cum 3.26s2.87s2.87s2.87s2.80s2.46s2.24s2.24s1.56s1.29scum% 91.57%80.62%80.62%80.62%78.65%69.10%62.92%62.92%43.82%36.24%runtime.goexitBenarkHitesting.(*B).launch testi

30、ng.(*B).runN step2.handleHi regexp.MatchStringpile pilepileOnePassregexp.makeOnePass(pprof) lisTotal: 3.56sndleHiROUTINE = handleHi in go-debug-profile-optimization/step2/demo.go30ms.2.80s.(flat, cum) 78.65% of 9:)10:11:var visitors 12:13:func handleHi(wTotal64 / must be acsedatomicallyhttp.Response

31、Writer, r*http.Request).2.47s14:!match15:ifmatch, _:= regexp.MatchString(w*$,r.FormValue(color).http.Error(w, Optional color is invalid,http.SusBadRequest).10ms 10ms.20ms 90ms16:17:18:19:returnvisitNum := atomic.Add64(&visitors, 1)w.Header().Set(Content-Type, text/htmlcharset=utf-8)10ms20ms20:w.Writ

32、e(byte(e!You are visitor number+fmt.Spr(visitNum) +.24:func main()f(Starting on port 8080)25:26:log.Prhttp.HandleFunc(/hi, handleHi)(pprof)从top cum来看，handleHi消耗cpu较大，而handleHi中，又是MatchString耗时最长。六、第一次优化前面已经发现MatchString较为耗时，优化：让正则式仅编译一次(step3)：/ go-debug-profile-optimization/step3/demo.go var visito

33、rs64 / must be acsed atomicallyvar rxOptionalID =pile(d*$)func handleHi(w http.ResponseWriter, r *http.Request) if !rxOptionalID.MatchString(r.FormValue(color) http.Error(w, Optional color is invalid, http.S returnusBadRequest)visitNum := atomic.Add64(&visitors, 1)w.Header().Set(Content-Type, text/h

34、tml charset=utf-8)w.Write(byte(e!You are visitornumber + fmt.Spr(visitNum) +!) 运行一下bench：$ go test -bench=.PASSBenarkHi-410000001678ns/op720 B/op9allocs/opok_/home1/tonybai/proj/opensource/experiments/go-debug-profile-optimization/step31.710s对比之前在step2中运行的bench结果：$ go test -v -run=$ -bench=.PASSBena

35、rkHi-410000014808 ns/op4961 B/op81allocs/opok_/home1/tonybai/proj/opensource/experiments/go-debug-profile-optimization/step21.648s耗时相同，但优化后的bench运行了100w次，而之前的Bench运行10w次，相当于性能提高10倍。再看看cpu prof结果：$ go test -v -run=$ -bench=BenPASSarkHi$ -benchtime=3s -cpuprofile=prof.cpuBenarkHi-430000001640 ns/op720

36、 B/op9allocs/opok_/home1/tonybai/proj/opensource/experiments/go-debug-profile-optimization/step36.540s$ go tool pprof step3.test prof.cpuEnteringeractive mode (typehelp fords)(pprof) top cum 302.74s of 8.07s total (33.95%)Dropped 72 nodes (cum = 0.56s)flat%0%0.62%0%0%0.74%sum%0%0.62%0.62%0.62%1.36%1

37、5.61%15.86%15.86%16.60%17.72%18.34%cum 7.17s6.21s6.21s6.21s4.96s2.35s1.63s1.53s1.53s1.22s1.09scum% 88.85%76.95%76.95%76.95%61.46%29.12%20.20%18.96%18.96%15.12%13.51%runtime.goexitstep3.BenarkHitesting.(*B).launch testing.(*B).runN step3.handleHi runtime.mallocgc runtime.systemstack net/http.Header.S

38、et net/textproto.MIMEHeader.Set runtime.newobjectfmt.Spr14.25%0.25%0%0.74%1.12%0.62%0.20s00.01s0.05s0.09s0.01s0.20s00.05s00.04s0.01s0.01s00.01s0.28s0.17s0.02s0.11s2.48%0%0.12%0.62%1.12%0.12%2.48%0%0.62%0%0.5%0.12%0.12%0%0.12%3.47%2.11%0.25%1.36%20.82%20.82%20.94%21.56%22.68%22.80%25.28%25.28%25.90%2

39、5.90%26.39%26.52%26.64%26.64%26.77%30.24%32.34%32.59%33.95%1s 0.81s0.79s0.76s0.71s0.71s0.70s0.69s0.69s0.68s0.68s0.67s0.65s0.65s0.65s0.62s0.59s0.58s0.56s12.39%10.04%9.79%9.42%8.80%8.80%8.67%8.55%8.55%8.43%8.43%8.30%8.05%8.05%8.05%7.68%7.31%7.19%6.94%runtime.mruntime.mcallsign1runtime.schedule regexp.

40、(*Regexp).MatchString regexp.(*Regexp).doExecute runtime.concatstring5runtime.concatstringsruntime.gosponeruntime.mSpan_Spruntime.bgspruntime.newarray runtime.goschedImpl runtime.gosched_mruntime.gospone.func1runtime.sponeruntime.makemap runtime.heapBitsSfmt.(*pp).doPrpSpanfmt.(*pp).prArghandleHi耗时有

41、一定下降。七、Mem Profiling在step3目录下执行bench，获取mem分配数据：$ go test -v -run=$ -bench=BenPASSarkHi$ -benchtime=2s -memprofile=prof.memBenarkHi-420000001657 ns/op720 B/op9allocs/opok_/home1/tonybai/proj/opensource/experiments/go-debug-profile-optimization/step35.002s使用pprof工具分析mem：$ go tool pprof alloc_spatep3.t

42、est prof.memEntering(pprof) toperactive mode (type help fords)2065.91MB of 2067.41MB total (99.93%)Dropped 14flat 1076.35MBnodes (cum =flat%sum% 52.06% 52.06%10.34MB)cumcum% 1076.35MB 52.06%net/textproto.MIMEHeader.Set535.54MB406.52MB47.50MB000025.90%19.66%2.30%0%0%0%0%77.97%97.63%99.93%99.93%99.93%

43、99.93%99.93%2066.91MB1531.37MB48.50MB1076.35MB2066.91MB2066.91MB2066.91MB100%74.07%2.35%52.06%100%100%100%step3.BenarkHistep3.handleHi fmt.Spr net/http.Header.Set runtime.goexit testing.(*B).launchtesting.(*B).runN(pprof) top-cum2065.91MB of 2067.41MB total (99.93%)Dropped 14flat 535.54MB000406.52MB

44、01076.35MB47.50MBnodes (cum =10.34MB)cum 2066.91MB2066.91MB2066.91MB2066.91MB1531.37MB1076.35MB1076.35MB48.50MBflat% 25.90%0%0%0%19.66%0%52.06%2.30%sum% 25.90%25.90%25.90%25.90%45.57%45.57%97.63%99.93%cum% 100%100%100%100%74.07%52.06%52.06%2.35%step3.BenarkHiruntime.goexit testing.(*B).launch testin

45、g.(*B).runN step3.handleHi net/http.Header.Set net/textproto.MIMEHeader.Setfmt.Spr(pprof) lis Total: 2.02GBROUTINE 406.52MB.ndleHi=step3.handleHi in step3/demo.go1.50GB (flat, cum)74.07% of Totalhttp.Error(w, Optional color is invalid,.17:http.SusBadRequest).charset=utf-8).18:19:20:21:22:returnvisit

46、Num := atomic.Add64(&visitors, 1)1.05GBw.Header().Set(Content-Type, text/html.23:w.Write(byte(e!You are visitor number +(visitNum) +.27:func main()f(Starting on port 8080)28:log.Pr.29:http.HandleFunc(/hi, handleHi)(pprof)可以看到handleHi22、23两行占用了较多内存。八、第二次优化第二次优化的方法：1、删除w.Header().Set这行2、用fmt.Fprf替代w.W

47、rite第二次优化的代码在step4目录中：/ go-debug-profile-optimization/step4/demo.go func handleHi(w http.ResponseWriter, r *http.Request) if !rxOptionalID.MatchString(r.FormValue(color) http.Error(w, Optional color is invalid, http.SusBadRequest) returnvisitNum fmt.Fprnumber %d!, := atomic.Add64(&visitors, 1)f(w, e

48、!You are visitorr.FormValue(color),visitNum)执行一遍pprof:$ go test -v -run=$ -bench=BenPASSarkHi$ -benchtime=2s -memprofile=prof.memBenarkHi-420000001428 ns/op304 B/op6allocs/opok_/home1/tonybai/proj/opensource/experiments/go-debug-profile-optimization/step44.343s$ go tool pprof alloc_spatep4.test prof

49、.memEntering(pprof) toperactivemode (type help fords)868.06MB of 868.56MBDropped 5 nodes (cumtotal (99.94%)= 4.34MB)flat flat%sum%559.54MB 64.42% 64.42%cumcum%868.06MB 99.94%step4.BenarkHi219.52MB89MB000025.27%10.25%0%0%0%0%89.70%99.94%99.94%99.94%99.94%99.94%219.52MB308.52MB219.52MB219.52MB219.52MB

50、219.52MB25.27%35.52%25.27%25.27%25.27%25.27%bytes.makeSlice step4.handleHi bytes.(*Buffer).Writebytes.(*Buffer).growfmt.Fprfnet/http/httptest.(*ResponseRecorder).Write000(pprof) top 868.06MB of0%0%0%cum99.94%99.94%99.94%868.06MB868.06MB868.06MB99.94%99.94%99.94%runtime.goexittesting.(*B).launch test

51、ing.(*B).runN868.56MB total(99.94%)Dropped 5 nodes (cum . 308.52MBe!You.18:19:20:21:22:returnvisitNum := atomic.Add64(&visitors, 1)fmt.Fprf(w, h1 stype=color:are visitor number %d!, r.FormValue(color), visitNum) 23:24:25:func main() .26:27:log.Prf(Starting on port 8080)http.HandleFunc(/hi, handleHi)

52、(pprof)可以看出内存占用大幅减少。九、Benchcmpgolang./x/tools中有一个工具：benchcmp，可以给出两次bench的结果对比。/golang/tools是golang./x/tools的一个镜像。安enchcmp步骤：1、go get -u/golang/tools2、mkdir -p $GOPATH/src/golang./x3、mv $GOP4、go install golang./golang/tools $GOPATH/src/golang./x/tools/cmd/benchcmp/x分别在step2、step3和step4下执行如下命令：$ go-de

53、bug-profile-optimization/step2$ go test -bench=. -memprofile=prof.mem mem.2PASS| teeBenarkHi-410000014786 ns/op4961 B/op81allocs/opok_/home1/tonybai/proj/opensource/experiments/go-debug-profile-optimization/step21.644sgo-debug-profile-optimization/step3$ go test -bench=. -memprofile=prof.mem | mem.3

54、PASSteeBenarkHi-410000001662 ns/op720 B/op9allocs/opok_/home1/tonybai/proj/opensource/experiments/go-debug-profile-optimization/step31.694sgo-debug-profile-optimization/step4$ go test -bench=. -memprofile=prof.mem | mem.4PASSteeBenarkHi-410000001428 ns/op304 B/op6allocs/opok_/home1/tonybai/proj/open

55、source/experiments/go-debug-profile-optimization/step41.456s利用benchcmp工具对比结果（benchcmp old new）：$ benchcmp step3/mem.3 step4/mem.4benBenarkarkHi-4old ns/op1662new ns/op1428delta-14.08%benBenarkarkHi-4old9allocsnew6allocsdelta-33.33%benBenarkarkHi-4old720bytesnew304bytesdelta-57.78%$ benchcmp step2/me

56、m.2 step4/mem.4benBenarkarkHi-4old ns/op14786new1428ns/opdelta-90.34%benBenarkarkHi-4old81allocsnew6allocsdelta-92.59%benBenarkarkHi-4old4961bytesnew304bytesdelta-93.87%可以看出优化后，内存分配大幅减少，gc的时间也随之减少。十、内存来自哪在BenarkHi中每次handleHi执行后的内存：/step5/demo_test.go func BenarkHi(b *testing.B) b.ReportAllocs()req,

57、err := http.ReadRequest(bufi HTTP/1.0rnrn)if err != nil b.Fatal(err)Reader(strings.NewReader(GET/for i := 0 i b.N i+ rw := httptest.NewRecorder() handleHi(rw, req)reset(rw)func reset(rw *httptest.ResponseRecorder) m := rw.HeaderMapfor k := range m delete(m, k)body := rw.Body body.Reset()*rw = httpte

58、st.ResponseRecorderBody:body,HeaderMap: m, $ go test -v -run=$ -bench=Ben PASSarkHi$-benchtime=2s-memprofile=prof.memBenarkHi-420000001518 ns/op304 B/op6allocs/opok_/home1/tonybai/proj/opensource/experiments/go-debug-profile-optimization/step54.577s$ go tool pprof alloc_spatep5.test prof.memEntering

59、eractive mode (type help fords)(pprof) top cum 10290.52MB of 291.52MB total (99.66%)Dropped 14flat0179.01MB0026.50MB0085.01MB00nodes (cum .(pprof). 111.51MBe!You.18:19:20:21:22:returnvisitNum := atomic.Add64(&visitors, 1)fmt.Fprf(w, h1 stype=color:are visitor number %d!, r.FormValue(color), visitNum

60、) 23:24:25:func main() 26:27:log.Prf(Starting on port 8080)http.HandleFunc(/hi, handleHi)内存从300MB降到111MB。内存来自哪？看到lisndleHi，fmt.Fprf分配了111.51MB。来看这一行代码：fmt.Fprf(w, r.FormValue(color), num)e!You are visitor number %d!,fmt.Fprf的manual：$ go docfunc Fprfmt.Fprff(w io.Writer, format string, aerface) (n, e