Golang性能调优入门
如何利用golang自带的profile工具进行应用程序的性能调优,前一段时间我做的日志分析系统在线上遇到了一个问题,就是分任务的系统down机了,日志处理延迟了10几个小时,这个时候任务分发系统重启之后开始分发任务,但是一下子就承受了十几个并发任务,导致内存消耗过快,直接吃掉了16G的内存,这可急坏了我啊。所以赶紧开始做性能优化。
性能优化我主要从以下几个方面进行了测试和调优:
- CPUProfiling
- MemProfiling
- GC&HEAP
我采用了如下的profile工具代码:
原文链接:packagemain import( "fmt" "log" "os" "runtime" "runtime/debug" "runtime/pprof" "strconv" "sync/atomic" "syscall" "time" ) varheapProfileCounterint32 varstartTime=time.Now() varpidint funcinit(){ pid=os.Getpid() } funcStartCPUProfile(){ f,err:=os.Create("cpu-"+strconv.Itoa(pid)+".pprof") iferr!=nil{ log.Fatal(err) } pprof.StartCPUProfile(f) } funcStopCPUProfile(){ pprof.StopCPUProfile() } funcStartBlockProfile(rateint){ runtime.SetBlockProfileRate(rate) } funcStopBlockProfile(){ filename:="block-"+strconv.Itoa(pid)+".pprof" f,err:=os.Create(filename) iferr!=nil{ log.Fatal(err) } iferr=pprof.Lookup("block").WriteTo(f,0);err!=nil{ log.Fatalf("can'twrite%s:%s",filename,err) } f.Close() } funcSetMemProfileRate(rateint){ runtime.MemProfileRate=rate } funcGC(){ runtime.GC() } funcDumpHeap(){ filename:="heap-"+strconv.Itoa(pid)+"-"+strconv.Itoa(int(atomic.AddInt32(&heapProfileCounter,1)))+".pprof" f,err:=os.Create(filename) iferr!=nil{ fmt.Fprintf(os.Stderr,"testing:%s",err) return } iferr=pprof.WriteHeapProfile(f);err!=nil{ fmt.Fprintf(os.Stderr,"testing:can'twrite%s:%s",filename,err) } f.Close() } funcshowSystemStat(intervaltime.Duration,countint){ usage1:=&syscall.Rusage{} varlastUtimeint64 varlastStimeint64 counter:=0 for{ //http://man7.org/linux/man-pages/man3/vtimes.3.html syscall.Getrusage(syscall.RUSAGE_SELF,usage1) utime:=usage1.Utime.Sec*1000000000+usage1.Utime.Usec stime:=usage1.Stime.Sec*1000000000+usage1.Stime.Usec userCPUUtil:=float64(utime-lastUtime)*100/float64(interval) sysCPUUtil:=float64(stime-lastStime)*100/float64(interval) memUtil:=usage1.Maxrss*1024 lastUtime=utime lastStime=stime ifcounter>0{ fmt.Printf("cpu:%3.2f%%us%3.2f%%sy,mem:%s\n",userCPUUtil,sysCPUUtil,toH(uint64(memUtil))) } counter+=1 ifcount>=1&&count<counter{ return } time.Sleep(interval) } } funcShowSystemStat(secondsint){ gofunc(){ interval:=time.Duration(seconds)*time.Second showSystemStat(interval,0) }() } funcPrintSystemStats(){ interval:=time.Duration(1)*time.Second showSystemStat(interval,1) } funcShowGCStat(){ gofunc(){ varnumGCint64 interval:=time.Duration(100)*time.Millisecond gcstats:=&debug.GCStats{PauseQuantiles:make([]time.Duration,100)} memStats:=&runtime.MemStats{} for{ debug.ReadGCStats(gcstats) ifgcstats.NumGC>numGC{ runtime.ReadMemStats(memStats) printGC(memStats,gcstats) numGC=gcstats.NumGC } time.Sleep(interval) } }() } funcPrintGCSummary(){ memStats:=&runtime.MemStats{} runtime.ReadMemStats(memStats) gcstats:=&debug.GCStats{PauseQuantiles:make([]time.Duration,100)} debug.ReadGCStats(gcstats) printGC(memStats,gcstats) } funcprintGC(memStats*runtime.MemStats,gcstats*debug.GCStats){ ifgcstats.NumGC>0{ lastPause:=gcstats.Pause[0] elapsed:=time.Now().Sub(startTime) overhead:=float64(gcstats.PauseTotal)/float64(elapsed)*100 allocatedRate:=float64(memStats.TotalAlloc)/elapsed.Seconds() fmt.Printf("NumGC:%dPause:%sPause(Avg):%sOverhead:%3.2f%%Alloc:%sSys:%sAlloc(Rate):%s/sHistogram:%s%s%s\n", gcstats.NumGC, toS(lastPause), toS(avg(gcstats.Pause)), overhead, toH(memStats.Alloc), toH(memStats.Sys), toH(uint64(allocatedRate)), toS(gcstats.PauseQuantiles[94]), toS(gcstats.PauseQuantiles[98]), toS(gcstats.PauseQuantiles[99])) }else{ //whileGChasdisabled elapsed:=time.Now().Sub(startTime) allocatedRate:=float64(memStats.TotalAlloc)/elapsed.Seconds() fmt.Printf("Alloc:%sSys:%sAlloc(Rate):%s/s\n", toH(memStats.Alloc), toH(memStats.Sys), toH(uint64(allocatedRate))) } } funcavg(items[]time.Duration)time.Duration{ varsumtime.Duration for_,item:=rangeitems{ sum+=item } returntime.Duration(int64(sum)/int64(len(items))) } //humanreadableformat functoH(bytesuint64)string{ switch{ casebytes<1024: returnfmt.Sprintf("�",bytes) casebytes<1024*1024: returnfmt.Sprintf("%.2fK",float64(bytes)/1024) casebytes<1024*1024*1024: returnfmt.Sprintf("%.2fM",float64(bytes)/1024/1024) default: returnfmt.Sprintf("%.2fG",float64(bytes)/1024/1024/1024) } } //shortstringformat functoS(dtime.Duration)string{ u:=uint64(d) ifu<uint64(time.Second){ switch{ caseu==0: return"0" caseu<uint64(time.Microsecond): returnfmt.Sprintf("%.2fns",float64(u)) caseu<uint64(time.Millisecond): returnfmt.Sprintf("%.2fus",float64(u)/1000) default: returnfmt.Sprintf("%.2fms",float64(u)/1000/1000) } }else{ switch{ caseu<uint64(time.Minute): returnfmt.Sprintf("%.2fs",float64(u)/1000/1000/1000) caseu<uint64(time.Hour): returnfmt.Sprintf("%.2fm",float64(u)/1000/1000/1000/60) default: returnfmt.Sprintf("%.2fh",float64(u)/1000/1000/1000/60/60) } } }