Sebagai antisipasi dimulainya aliran baru pada kursus "Pengembang Golang" menyiapkan terjemahan materi yang menarik.
Server DNS resmi
kami digunakan oleh puluhan ribu situs web. Kami menanggapi jutaan pertanyaan setiap hari. Saat ini, serangan DNS menjadi semakin umum, DNS adalah bagian penting dari sistem kami, dan kami perlu memastikan bahwa kami dapat bekerja dengan baik di bawah beban tinggi.dnsflood adalah alat kecil yang dapat menghasilkan sejumlah besar permintaan udp.# timeout 20s ./dnsflood example.com 127.0.0.1 -p 2053
Pemantauan sistem menunjukkan bahwa penggunaan memori layanan kami tumbuh begitu cepat sehingga kami harus menghentikannya, jika tidak, kami akan mengalami kesalahan OOM. Itu seperti masalah kebocoran memori; Ada berbagai alasan kebocoran memori "mirip" dan "nyata":- menggantung goroutine
- penyalahgunaan penangguhan dan finalizer
- substring dan sub-pemotongan
- variabel global
Posting ini memberikan penjelasan rinci tentang berbagai kebocoran.Sebelum membuat kesimpulan, pertama mari kita melakukan profil.Godebug
Berbagai alat debugging dapat diaktifkan menggunakan variabel lingkungan GODEBUG, melewati daftar pasangan yang dipisahkan koma name=value.Lacak perencana
Jejak penjadwal dapat memberikan informasi tentang perilaku goroutine saat runtime. Untuk mengaktifkan jejak penjadwal, jalankan program dengan GODEBUG=schedtrace=100, nilai menentukan periode output dalam ms.$ GODEBUG=schedtrace=100 ./redins -c config.json
SCHED 2952ms: ... runqueue=3 [26 11 7 18 13 30 6 3 24 25 11 0]
SCHED 3053ms: ... runqueue=3 [0 0 0 0 0 0 0 0 4 0 21 0]
SCHED 3154ms: ... runqueue=0 [0 6 2 4 0 30 0 5 0 11 2 5]
SCHED 3255ms: ... runqueue=1 [0 0 0 0 0 0 0 0 0 0 0 0]
SCHED 3355ms: ... runqueue=0 [1 0 0 0 0 0 0 0 0 0 0 0]
SCHED 3456ms: ... runqueue=0 [0 0 0 0 0 0 0 0 0 0 0 0]
SCHED 3557ms: ... runqueue=0 [13 0 3 0 3 33 2 0 10 8 10 14]
SCHED 3657ms: ...runqueue=3 [14 1 0 5 19 54 9 1 0 1 29 0]
SCHED 3758ms: ... runqueue=0 [67 1 5 0 0 1 0 0 87 4 0 0]
SCHED 3859ms: ... runqueue=6 [0 0 3 6 0 0 0 0 3 2 2 19]
SCHED 3960ms: ... runqueue=0 [0 0 1 0 1 0 0 1 0 1 0 0]
SCHED 4060ms: ... runqueue=5 [4 0 5 0 1 0 0 0 0 0 0 0]
SCHED 4161ms: ... runqueue=0 [0 0 0 0 0 0 0 1 0 0 0 0]
SCHED 4262ms: ... runqueue=4 [0 128 21 172 1 19 8 2 43 5 139 37]
SCHED 4362ms: ... runqueue=0 [0 0 0 0 0 0 0 0 0 0 0 0]
SCHED 4463ms: ... runqueue=6 [0 28 23 39 4 11 4 11 25 0 25 0]
SCHED 4564ms: ... runqueue=354 [51 45 33 32 15 20 8 7 5 42 6 0]
runqueue adalah panjang antrian global goroutine untuk dijalankan. Angka dalam tanda kurung adalah panjang dari proses antrian.Situasi yang ideal adalah ketika semua proses sibuk mengeksekusi goroutine, dan panjang antrian eksekusi terdistribusi secara merata di antara semua proses:SCHED 2449ms: gomaxprocs=12 idleprocs=0 threads=40 spinningthreads=1 idlethreads=1 runqueue=20 [20 20 20 20 20 20 20 20 20 20 20]
Melihat output dari schedtrace , kita dapat melihat periode waktu ketika hampir semua proses idle. Ini berarti bahwa kami tidak menggunakan prosesor pada kapasitas penuh.Jejak pengumpul sampah
Untuk mengaktifkan pelacakan pengumpulan sampah (GC), jalankan program dengan variabel lingkungan GODEBUG=gctrace=1:GODEBUG=gctrace=1 ./redins -c config1.json
.
.
.
gc 30 @3.727s 1%: 0.066+21+0.093 ms clock, 0.79+128/59/0+1.1 ms cpu, 67->71->45 MB, 76 MB goal, 12 P
gc 31 @3.784s 2%: 0.030+27+0.053 ms clock, 0.36+177/81/7.8+0.63 ms cpu, 79->84->55 MB, 90 MB goal, 12 P
gc 32 @3.858s 3%: 0.026+34+0.024 ms clock, 0.32+234/104/0+0.29 ms cpu, 96->100->65 MB, 110 MB goal, 12 P
gc 33 @3.954s 3%: 0.026+44+0.13 ms clock, 0.32+191/131/57+1.6 ms cpu, 117->123->79 MB, 131 MB goal, 12 P
gc 34 @4.077s 4%: 0.010+53+0.024 ms clock, 0.12+241/159/69+0.29 ms cpu, 142->147->91 MB, 158 MB goal, 12 P
gc 35 @4.228s 5%: 0.017+61+0.12 ms clock, 0.20+296/179/94+1.5 ms cpu, 166->174->105 MB, 182 MB goal, 12 P
gc 36 @4.391s 6%: 0.017+73+0.086 ms clock, 0.21+492/216/4.0+1.0 ms cpu, 191->198->122 MB, 210 MB goal, 12 P
gc 37 @4.590s 7%: 0.049+85+0.095 ms clock, 0.59+618/253/0+1.1 ms cpu, 222->230->140 MB, 244 MB goal, 12 P
.
.
.
Seperti yang kita lihat di sini, jumlah memori yang digunakan meningkat, dan jumlah waktu yang dibutuhkan gc untuk menyelesaikan pekerjaannya juga meningkat. Ini berarti bahwa kita mengkonsumsi lebih banyak memori daripada yang bisa ditangani.Anda GODEBUGdapat mempelajari lebih lanjut tentang dan beberapa variabel lingkungan golang lainnya di sini .Mengaktifkan Profiler
go tool pprof- Alat untuk menganalisis dan membuat profil data. Ada dua cara untuk mengonfigurasi pprof: baik langsung memanggil fungsi runtime/pprofdalam kode Anda, misalnya pprof.StartCPUProfile(), atau menginstal net/http/pprofpendengar http dan mendapatkan data dari sana, yang kami lakukan. Ini memiliki pprofkonsumsi sumber daya yang sangat kecil, sehingga dapat digunakan dengan aman dalam pembangunan, tetapi titik akhir profil tidak boleh tersedia untuk umum, karena data sensitif dapat diungkapkan.Yang perlu kita lakukan untuk opsi kedua adalah mengimpor paket "net / http / pprof" :import (
_ "net/http/pprof"
)
lalu tambahkan daftar http:go func() {
log.Println(http.ListenAndServe("localhost:6060", nil))
}()
Pprof memiliki beberapa profil default:- allocs : ambil semua alokasi memori masa lalu
- blok : tumpukan jejak yang menyebabkan pemblokiran sinkronisasi primitif
- goroutine : tumpukan jejak semua goroutine saat ini
- heap : ambil alokasi memori objek hidup.
- mutex : tumpukan jejak pemegang mutex yang bertentangan
- profil : profil prosesor.
- threadcreate : jejak stack yang mengarah pada pembuatan utas baru di OS
- trace : melacak pelaksanaan program saat ini.
Catatan: titik akhir jejak, tidak seperti semua titik akhir lainnya, adalah profil jejak , bukan pprof , Anda dapat melihatnya menggunakan penelusuran alat go sebagai gantinya go tool pprof.
Sekarang semuanya sudah siap, kita dapat melihat alat yang tersedia.Profiler prosesor
$ go tool pprof http:
Profiler prosesor secara default berfungsi selama 30 detik (kita dapat mengubahnya dengan mengatur parameter seconds) dan mengumpulkan sampel setiap 100 milidetik, setelah itu beralih ke mode interaktif. Perintah yang paling umum tersedia top, list, web.Gunakan top nuntuk melihat entri terpanas dalam format teks, ada juga dua opsi untuk menyortir output, -cumuntuk pesanan kumulatif dan -flat.(pprof) top 10 -cum
Showing nodes accounting for 1.50s, 6.19% of 24.23s total
Dropped 347 nodes (cum <= 0.12s)
Showing top 10 nodes out of 186
flat flat% sum% cum cum%
0.03s 0.12% 0.12% 16.7s 69.13% (*Server).serveUDPPacket
0.05s 0.21% 0.33% 15.6s 64.51% (*Server).serveDNS
0 0% 0.33% 14.3s 59.10% (*ServeMux).ServeDNS
0 0% 0.33% 14.2s 58.73% HandlerFunc.ServeDNS
0.01s 0.04% 0.37% 14.2s 58.73% main.handleRequest
0.07s 0.29% 0.66% 13.5s 56.00% (*DnsRequestHandler).HandleRequest
0.99s 4.09% 4.75% 7.56s 31.20% runtime.gentraceback
0.02s 0.08% 4.83% 7.02s 28.97% runtime.systemstack
0.31s 1.28% 6.11% 6.62s 27.32% runtime.mallocgc
0.02s 0.08% 6.19% 6.35s 26.21% (*DnsRequestHandler).FindANAME
(pprof)
gunakan listuntuk mengeksplorasi fungsi.(pprof) list handleRequest
Total: 24.23s
ROUTINE ======================== main.handleRequest in /home/arash/go/src/arvancloud/redins/redins.go
10ms 14.23s (flat, cum) 58.73% of Total
. . 35: l *handler.RateLimiter
. . 36: configFile string
. . 37:)
. . 38:
. . 39:func handleRequest(w dns.ResponseWriter, r *dns.Msg) {
10ms 610ms 40: context := handler.NewRequestContext(w, r)
. 50ms 41: logger.Default.Debugf("handle request: [%d] %s %s", r.Id, context.RawName(), context.Type())
. . 42:
. . 43: if l.CanHandle(context.IP()) {
. 13.57s 44: h.HandleRequest(context)
. . 45: } else {
. . 46: context.Response(dns.RcodeRefused)
. . 47: }
. . 48:}
. . 49:
(pprof)
Tim ini webmembuat grafik SVG dari area kritis dan membukanya di browser.(pprof)web handleReques
Sejumlah besar waktu yang dihabiskan dalam fungsi-fungsi GC, seperti runtime.mallocgc, sering menghasilkan alokasi memori yang signifikan, yang dapat menambah beban ke pengumpul sampah dan meningkatkan latensi.Sejumlah besar waktu yang dihabiskan untuk mekanisme sinkronisasi, seperti runtime.chansendatau runtime.lock, mungkin merupakan tanda konflik.Sejumlah besar waktu yang dihabiskan syscall.Read/Writeberarti penggunaan berlebihan operasi I / O.Profiler memori
$ go tool pprof http:
Secara default, ini menunjukkan masa pakai memori yang dialokasikan. Kita dapat melihat jumlah objek yang dipilih menggunakan -alloc_objectsopsi berguna lainnya: -iuse_objectsdan -inuse_spaceuntuk memeriksa memori langsung .Biasanya, jika Anda ingin mengurangi konsumsi memori, Anda perlu melihat -inuse_space, tetapi jika Anda ingin mengurangi latensi, lihat -alloc_objectssetelah cukup menjalankan / memuat waktu.Identifikasi kemacetan
Penting untuk terlebih dahulu menentukan jenis bottleneck (prosesor, I / O, memori) yang sedang kita hadapi. Selain profiler, ada jenis alat lain.go tool tracedapat menunjukkan apa yang dilakukan goroutine secara detail. Untuk mengumpulkan contoh jejak, kami perlu mengirim permintaan http ke titik akhir jejak:$ curl http:
File yang dihasilkan dapat dilihat menggunakan alat jejak:$ go tool trace trace.out
2019/12/25 15:30:50 Parsing trace...
2019/12/25 15:30:59 Splitting trace...
2019/12/25 15:31:10 Opening browser. Trace viewer is listening on http:
Go tool trace adalah aplikasi web yang menggunakan protokol Chrome DevTools dan hanya kompatibel dengan browser Chrome. Halaman utama terlihat seperti ini:Lihat jejak (0s-409.575266ms)Lihat jejak (411.075559ms-747.252311ms)Lihat jejak (747.252311ms-1.234968945s)Lihat jejak (1.234968945s-1.774245108ss)Lihat jejak (1.77424548414111311)Lihat jejak (2.111339514s-2.674030898s)Lihat jejak (2.674031362s-3.044145798s)Lihat jejak (3.044145798s-3.458795252s)Lihat jejak (3.43953778s-4.075080634s)Lihat jejak (4.075081098s-4.439271287s)View35 4,439 -4.814869651s)Lihat jejak (4.814869651s-5.253597835s)Analisis goroutineProfil pemblokiran jaringan ()Sinkronisasi profil pemblokiran ()Profil pemblokiran syscall ()Profil latensi penjadwal ()Tugas yang ditentukanpengguna Wilayah yang ditentukanpengguna Penggunaan mutator minimumMenelusuri membagi waktu jejak sehingga browser Anda dapat mengatasinya.
Ada sejumlah besar data di sini, yang membuatnya hampir tidak dapat dibaca jika kami tidak tahu apa yang kami cari. Mari kita tinggalkan untuk sekarang.Tautan berikut di halaman utama adalah "analisis goroutine" , yang menunjukkan berbagai jenis goroutine yang berfungsi dalam program selama periode penelusuran:Goroutines:
github.com/miekg/dns.(*Server).serveUDPPacket N=441703
runtime.gcBgMarkWorker N=12
github.com/karlseguin/ccache.(*Cache).worker N=2
main.Start.func1 N=1
runtime.bgsweep N=1
arvancloud/redins/handler.NewHandler.func2 N=1
runtime/trace.Start.func1 N=1
net/http.(*conn).serve N=1
runtime.timerproc N=3
net/http.(*connReader).backgroundRead N=1
N=40
Klik pada elemen pertama dengan N = 441703 , ini yang kita dapatkan:
analisis goroutinIni sangat menarik. Sebagian besar operasi hampir tidak membutuhkan waktu untuk diselesaikan, dan sebagian besar waktu dihabiskan di blok Sync. Mari kita lihat lebih dekat salah satunya:
pola jejak goroutine.Tampaknya program kami hampir selalu tidak aktif. Dari sini kita bisa langsung menuju ke alat kunci; profil kunci dinonaktifkan secara default, kita harus mengaktifkannya dalam kode kita terlebih dahulu:runtime.SetBlockProfileRate(1)
Sekarang kita bisa mendapatkan pilihan kunci:$ go tool pprof http:
(pprof) top
Showing nodes accounting for 16.03wks, 99.75% of 16.07wks total
Dropped 87 nodes (cum <= 0.08wks)
Showing top 10 nodes out of 27
flat flat% sum% cum cum%
10.78wks 67.08% 67.08% 10.78wks 67.08% internal/poll.(*fdMutex).rwlock
5.25wks 32.67% 99.75% 5.25wks 32.67% sync.(*Mutex).Lock
0 0% 99.75% 5.25wks 32.67% arvancloud/redins/handler.(*DnsRequestHandler).Filter
0 0% 99.75% 5.25wks 32.68% arvancloud/redins/handler.(*DnsRequestHandler).FindANAME
0 0% 99.75% 16.04wks 99.81% arvancloud/redins/handler.(*DnsRequestHandler).HandleRequest
0 0% 99.75% 10.78wks 67.08% arvancloud/redins/handler.(*DnsRequestHandler).Response
0 0% 99.75% 10.78wks 67.08% arvancloud/redins/handler.(*RequestContext).Response
0 0% 99.75% 5.25wks 32.67% arvancloud/redins/handler.ChooseIp
0 0% 99.75% 16.04wks 99.81% github.com/miekg/dns.(*ServeMux).ServeDNS
0 0% 99.75% 16.04wks 99.81% github.com/miekg/dns.(*Server).serveDNS
(pprof)
Di sini kita memiliki dua kunci berbeda ( poll.fdMutex dan sync.Mutex ), bertanggung jawab atas hampir 100% dari kunci. Ini mengkonfirmasi asumsi kami tentang konflik kunci, sekarang kami hanya perlu menemukan di mana ini terjadi:(pprof) svg lock
Perintah ini menciptakan grafik vektor dari semua node yang peka konflik dengan penekanan pada fungsi pemblokiran:
svg-grafik dari titik akhir pemblokirankita bisa mendapatkan hasil yang sama dari titik akhir goroutine:$ go tool pprof http:
lalu:(pprof) top
Showing nodes accounting for 294412, 100% of 294424 total
Dropped 84 nodes (cum <= 1472)
Showing top 10 nodes out of 32
flat flat% sum% cum cum%
294404 100% 100% 294404 100% runtime.gopark
8 0.0027% 100% 294405 100% github.com/miekg/dns.(*Server).serveUDPPacket
0 0% 100% 58257 19.79% arvancloud/redins/handler.(*DnsRequestHandler).Filter
0 0% 100% 58259 19.79% arvancloud/redins/handler.(*DnsRequestHandler).FindANAME
0 0% 100% 293852 99.81% arvancloud/redins/handler.(*DnsRequestHandler).HandleRequest
0 0% 100% 235406 79.95% arvancloud/redins/handler.(*DnsRequestHandler).Response
0 0% 100% 235406 79.95% arvancloud/redins/handler.(*RequestContext).Response
0 0% 100% 58140 19.75% arvancloud/redins/handler.ChooseIp
0 0% 100% 293852 99.81% github.com/miekg/dns.(*ServeMux).ServeDNS
0 0% 100% 293900 99.82% github.com/miekg/dns.(*Server).serveDNS
(pprof)
hampir semua program kami terletak di runtime.gopark, ini adalah penjadwal go yang tidur dengan goroutine; alasan yang sangat umum untuk ini adalah konflik kunci(pprof) svg gopark
svg-grafik dari titik akhir goroutinDi sini kita melihat dua sumber konflik:UDPConn.WriteMsg ()
Tampaknya semua jawaban akhirnya menulis ke FD yang sama (maka kuncinya), ini masuk akal, karena semuanya memiliki alamat sumber yang sama.Kami melakukan percobaan kecil dengan berbagai solusi, dan pada akhirnya kami memutuskan untuk menggunakan beberapa pendengar untuk menyeimbangkan beban. Dengan demikian, kami mengizinkan OS untuk menyeimbangkan permintaan masuk antara koneksi yang berbeda dan mengurangi konflik.Rand ()
Sepertinya ada kunci dalam fungsi matematika / rand biasa (lebih lanjut tentang ini di sini ). Ini dapat dengan mudah diperbaiki dengan bantuan Rand.New()generator angka acak yang membuat pembungkus non-blocking.rg := rand.New(rand.NewSource(int64(time.Now().Nanosecond())))
Ini sedikit lebih baik, tetapi membuat sumber baru itu mahal setiap saat. Apakah mungkin melakukan lebih baik? Dalam kasus kami, kami benar-benar tidak perlu nomor acak. Kami hanya perlu distribusi yang seragam untuk menyeimbangkan beban, dan ternyata itu Time.Nanoseconds()mungkin cocok untuk kami.Sekarang kita telah menghapus semua kunci yang tidak perlu, mari kita lihat hasilnya:
analisis goroutinTerlihat lebih baik, tapi tetap saja, sebagian besar waktu yang dibutuhkan untuk mengunci sinkronisasi. Mari kita lihat profil kunci sinkronisasi dari halaman utama antarmuka pengguna jejak:
timeline kunci sinkronisasi.Mari kita lihat fungsi boost ccachedari titik akhir kunci pprof:(pprof) list promote
ROUTINE ======================== github.com/karlseguin/ccache.(*Cache).promote in ...
0 9.66days (flat, cum) 99.70% of Total
. . 155: h.Write([]byte(key))
. . 156: return c.buckets[h.Sum32()&c.bucketMask]
. . 157:}
. . 158:
. . 159:func (c *Cache) promote(item *Item) {
. 9.66days 160: c.promotables <- item
. . 161:}
. . 162:
. . 163:func (c *Cache) worker() {
. . 164: defer close(c.donec)
. . 165:
Semua panggilan ccache.Get()berakhir dalam satu saluran c.promotables. Caching adalah bagian penting dari layanan kami, kami harus mempertimbangkan opsi lain; Dalam Dgraph memiliki artikel yang sangat baik tentang keadaan cache! Go , mereka juga memiliki modul caching yang sangat baik yang disebut ristretto . Sayangnya, ristretto belum mendukung rilis berbasis Ttl, kami dapat mengatasi masalah ini dengan menggunakan yang sangat besar MaxCostdan menjaga nilai batas waktu dalam struktur cache kami (kami ingin menyimpan data yang ketinggalan zaman dalam cache). Mari kita lihat hasilnya ketika menggunakan ristretto:
analisis goroutinHebat!Kami dapat mengurangi runtime maksimum gorutin dari 5000 ms menjadi 22 ms. Namun, sebagian besar waktu eksekusi dibagi antara "kunci sinkronisasi" dan "menunggu penjadwal". Mari kita lihat apakah kita dapat melakukan sesuatu tentang ini:
timeline kunci sinkronisasiKita hanya bisa melakukan sedikit dengan itu fdMutex.rwlock, sekarang mari kita fokus pada yang lain: gcMarkDone, yang menyumbang 53% dari waktu blokir. Fitur ini adalah bagian dari proses pengumpulan sampah. Kehadiran mereka di bagian kritis sering merupakan pertanda bahwa kami kelebihan muatan gc.optimasi alokasi
Pada titik ini, mungkin berguna untuk melihat bagaimana pengumpulan sampah bekerja; Go menggunakan pemetik mark-and-sweep. Ini melacak semua yang dipilih, dan segera setelah mencapai dua kali ukuran (atau nilai lain yang diatur GOGC) ukuran dari ukuran sebelumnya, pembersihan GC dimulai. Penilaian berlangsung dalam tiga tahap:- Pengaturan Marker (STW)
- Menandai (paralel)
- Labeling End (STW)
Fase Stop The World (STW) menghentikan seluruh proses, meskipun biasanya sangat singkat, siklus berkelanjutan dapat meningkatkan durasinya. Ini karena pada saat ini (go v1.13) goroutine digantikan hanya pada titik pemanggilan fungsi, oleh karena itu, untuk siklus kontinu, waktu jeda yang panjang dan sewenang-wenang dimungkinkan, karena GC mengharapkan semua goroutine untuk berhenti.Selama penandaan, gc menggunakan sekitar 25% GOMAXPROCS, tetapi fungsi tambahan tambahan dapat ditambahkan secara paksa untuk menandai bantuan , ini terjadi ketika goroutine yang bergerak cepat melampaui penanda latar belakang untuk mengurangi penundaan yang disebabkan oleh gc, kita perlu meminimalkan penggunaan tumpukan.Dua hal yang perlu diperhatikan:- jumlah alokasi lebih penting daripada ukuran (misalnya, alokasi memori 1000 dari struktur 20-byte membuat lebih banyak beban pada heap daripada alokasi tunggal 20.000 byte);
- tidak seperti bahasa seperti C / C ++, tidak semua alokasi memori berakhir pada heap. Go compiler memutuskan apakah variabel akan pindah ke heap atau apakah itu dapat ditempatkan di dalam frame stack. Tidak seperti variabel yang dialokasikan pada heap, variabel yang dialokasikan pada stack tidak memuat gc.
Untuk informasi lebih lanjut tentang model memori Go dan arsitektur GC, lihat presentasi ini .Untuk mengoptimalkan alokasi memori, kami menggunakan toolkit go:- profiler prosesor untuk menemukan distribusi panas;
- profiler memori untuk melacak alokasi;
- pelacak untuk pola; Gc
- analisis pelarian untuk mengetahui mengapa alokasi terjadi.
Mari kita mulai dengan profiler prosesor:$ go tool pprof http:
(pprof) top 20 -cum
Showing nodes accounting for 7.27s, 29.10% of 24.98s total
Dropped 315 nodes (cum <= 0.12s)
Showing top 20 nodes out of 201
flat flat% sum% cum cum%
0 0% 0% 16.42s 65.73% github.com/miekg/dns.(*Server).serveUDPPacket
0.02s 0.08% 0.08% 16.02s 64.13% github.com/miekg/dns.(*Server).serveDNS
0.02s 0.08% 0.16% 13.69s 54.80% github.com/miekg/dns.(*ServeMux).ServeDNS
0.01s 0.04% 0.2% 13.48s 53.96% github.com/miekg/dns.HandlerFunc.ServeDNS
0.02s 0.08% 0.28% 13.47s 53.92% main.handleRequest
0.24s 0.96% 1.24% 12.50s 50.04% arvancloud/redins/handler.(*DnsRequestHandler).HandleRequest
0.81s 3.24% 4.48% 6.91s 27.66% runtime.gentraceback
3.82s 15.29% 19.78% 5.48s 21.94% syscall.Syscall
0.02s 0.08% 19.86% 5.44s 21.78% arvancloud/redins/handler.(*DnsRequestHandler).Response
0.06s 0.24% 20.10% 5.25s 21.02% arvancloud/redins/handler.(*RequestContext).Response
0.03s 0.12% 20.22% 4.97s 19.90% arvancloud/redins/handler.(*DnsRequestHandler).FindANAME
0.56s 2.24% 22.46% 4.92s 19.70% runtime.mallocgc
0.07s 0.28% 22.74% 4.90s 19.62% github.com/miekg/dns.(*response).WriteMsg
0.04s 0.16% 22.90% 4.40s 17.61% github.com/miekg/dns.(*response).Write
0.01s 0.04% 22.94% 4.36s 17.45% github.com/miekg/dns.WriteToSessionUDP
1.43s 5.72% 28.66% 4.30s 17.21% runtime.pcvalue
0.01s 0.04% 28.70% 4.15s 16.61% runtime.newstack
0.06s 0.24% 28.94% 4.09s 16.37% runtime.copystack
0.01s 0.04% 28.98% 4.05s 16.21% net.(*UDPConn).WriteMsgUDP
0.03s 0.12% 29.10% 4.04s 16.17% net.(*UDPConn).writeMsg
Kami sangat tertarik pada fungsi terkait, mallocgcini adalah tempat bantuan dengan tag(pprof) svg mallocgc
Kita dapat melacak distribusi menggunakan titik akhir alloc, opsi alloc_objectberarti jumlah alokasi, ada opsi lain untuk menggunakan memori dan ruang alokasi.$ go tool pprof -alloc_objects http:
(pprof) top -cum
Active filters:
show=handler
Showing nodes accounting for 58464353, 59.78% of 97803168 total
Dropped 1 node (cum <= 489015)
Showing top 10 nodes out of 19
flat flat% sum% cum cum%
15401215 15.75% 15.75% 70279955 71.86% arvancloud/redins/handler.(*DnsRequestHandler).HandleRequest
2392100 2.45% 18.19% 27198697 27.81% arvancloud/redins/handler.(*DnsRequestHandler).FindANAME
711174 0.73% 18.92% 14936976 15.27% arvancloud/redins/handler.(*DnsRequestHandler).Filter
0 0% 18.92% 14161410 14.48% arvancloud/redins/handler.(*DnsRequestHandler).Response
14161410 14.48% 33.40% 14161410 14.48% arvancloud/redins/handler.(*RequestContext).Response
7284487 7.45% 40.85% 11118401 11.37% arvancloud/redins/handler.NewRequestContext
10439697 10.67% 51.52% 10439697 10.67% arvancloud/redins/handler.reverseZone
0 0% 51.52% 10371430 10.60% arvancloud/redins/handler.(*DnsRequestHandler).FindZone
2680723 2.74% 54.26% 8022046 8.20% arvancloud/redins/handler.(*GeoIp).GetSameCountry
5393547 5.51% 59.78% 5393547 5.51% arvancloud/redins/handler.(*DnsRequestHandler).LoadLocation
Mulai sekarang, kita dapat menggunakan daftar untuk setiap fungsi dan melihat apakah kita dapat mengurangi alokasi memori. Mari kita periksa:fungsi seperti printf(pprof) list handleRequest
Total: 97803168
ROUTINE ======================== main.handleRequest in /home/arash/go/src/arvancloud/redins/redins.go
2555943 83954299 (flat, cum) 85.84% of Total
. . 35: l *handler.RateLimiter
. . 36: configFile string
. . 37:)
. . 38:
. . 39:func handleRequest(w dns.ResponseWriter, r *dns.Msg) {
. 11118401 40: context := handler.NewRequestContext(w, r)
2555943 2555943 41: logger.Default.Debugf("handle request: [%d] %s %s", r.Id, context.RawName(), context.Type())
. . 42:
. . 43: if l.CanHandle(context.IP()) {
. 70279955 44: h.HandleRequest(context)
. . 45: } else {
. . 46: context.Response(dns.RcodeRefused)
. . 47: }
. . 48:}
. . 49:
Baris 41 sangat menarik, bahkan ketika debugging dimatikan, memori masih dialokasikan di sana, kita dapat menggunakan analisis pelarian untuk memeriksanya lebih detail.Go Escape Analysis Tool sebenarnya adalah flag kompiler$ go build -gcflags '-m'
Anda dapat menambahkan -m lainnya untuk informasi lebih lanjut.$ go build -gcflags '-m '
untuk antarmuka yang lebih nyaman, gunakan file view-annotated .$ go build -gcflags '-m'
.
.
.
../redins.go:39:20: leaking param: w
./redins.go:39:42: leaking param: r
./redins.go:41:55: r.MsgHdr.Id escapes to heap
./redins.go:41:75: context.RawName() escapes to heap
./redins.go:41:91: context.Request.Type() escapes to heap
./redins.go:41:23: handleRequest []interface {} literal does not escape
./redins.go:219:17: leaking param: path
.
.
.
Di sini semua parameter Debugfmenuju tumpukan. Ini karena cara penentuan Debugf:func (l *EventLogger) Debugf(format string, args ...interface{})
Semua parameter argsdikonversi ke tipe interface{}yang selalu dibuang ke heap. Kami dapat menghapus log debug, atau menggunakan perpustakaan log dengan distribusi nol, misalnya, zerolog .Untuk informasi lebih lanjut tentang analisis pelarian, lihat “alokasi efisiensi di golang” .Bekerja dengan string(pprof) list reverseZone
Total: 100817064
ROUTINE ======================== arvancloud/redins/handler.reverseZone in /home/arash/go/src/arvancloud/redins/handler/handler.go
6127746 10379086 (flat, cum) 10.29% of Total
. . 396: logger.Default.Warning("log queue is full")
. . 397: }
. . 398:}
. . 399:
. . 400:func reverseZone(zone string) string {
. 4251340 401: x := strings.Split(zone, ".")
. . 402: var y string
. . 403: for i := len(x) - 1; i >= 0; i-- {
6127746 6127746 404: y += x[i] + "."
. . 405: }
. . 406: return y
. . 407:}
. . 408:
. . 409:func (h *DnsRequestHandler) LoadZones() {
(pprof)
Karena garis di Go tidak dapat diubah, membuat garis sementara menyebabkan alokasi memori. Dimulai dengan Go 1.10, Anda dapat menggunakannya strings.Builderuntuk membuat string.(pprof) list reverseZone
Total: 93437002
ROUTINE ======================== arvancloud/redins/handler.reverseZone in /home/arash/go/src/arvancloud/redins/handler/handler.go
0 7580611 (flat, cum) 8.11% of Total
. . 396: logger.Default.Warning("log queue is full")
. . 397: }
. . 398:}
. . 399:
. . 400:func reverseZone(zone string) string {
. 3681140 401: x := strings.Split(zone, ".")
. . 402: var sb strings.Builder
. 3899471 403: sb.Grow(len(zone)+1)
. . 404: for i := len(x) - 1; i >= 0; i-- {
. . 405: sb.WriteString(x[i])
. . 406: sb.WriteByte('.')
. . 407: }
. . 408: return sb.String()
Karena kita tidak peduli dengan nilai dari garis terbalik, kita dapat menghilangkannya Split()dengan membalik seluruh baris.(pprof) list reverseZone
Total: 89094296
ROUTINE ======================== arvancloud/redins/handler.reverseZone in /home/arash/go/src/arvancloud/redins/handler/handler.go
3801168 3801168 (flat, cum) 4.27% of Total
. . 400:func reverseZone(zone string) []byte {
. . 401: runes := []rune("." + zone)
. . 402: for i, j := 0, len(runes)-1; i < j; i, j = i+1, j-1 {
. . 403: runes[i], runes[j] = runes[j], runes[i]
. . 404: }
3801168 3801168 405: return []byte(string(runes))
. . 406:}
. . 407:
. . 408:func (h *DnsRequestHandler) LoadZones() {
. . 409: h.LastZoneUpdate = time.Now()
. . 410: zones, err := h.Redis.SMembers("redins:zones")
Baca lebih lanjut tentang bekerja dengan string di sini .sinkronkan
(pprof) list GetASN
Total: 69005282
ROUTINE ======================== arvancloud/redins/handler.(*GeoIp).GetASN in /home/arash/go/src/arvancloud/redins/handler/geoip.go
1146897 1146897 (flat, cum) 1.66% of Total
. . 231:func (g *GeoIp) GetASN(ip net.IP) (uint, error) {
1146897 1146897 232: var record struct {
. . 233: AutonomousSystemNumber uint `maxminddb:"autonomous_system_number"`
. . 234: }
. . 235: err := g.ASNDB.Lookup(ip, &record)
. . 236: if err != nil {
. . 237: logger.Default.Errorf("lookup failed : %s", err)
(pprof) list GetGeoLocation
Total: 69005282
ROUTINE ======================== arvancloud/redins/handler.(*GeoIp).GetGeoLocation in /home/arash/go/src/arvancloud/redins/handler/geoip.go
1376298 3604572 (flat, cum) 5.22% of Total
. . 207:
. . 208:func (g *GeoIp) GetGeoLocation(ip net.IP) (latitude float64, longitude float64, country string, err error) {
. . 209: if !g.Enable || g.CountryDB == nil {
. . 210: return
. . 211: }
1376298 1376298 212: var record struct {
. . 213: Location struct {
. . 214: Latitude float64 `maxminddb:"latitude"`
. . 215: LongitudeOffset uintptr `maxminddb:"longitude"`
. . 216: } `maxminddb:"location"`
. . 217: Country struct {
. . 218: ISOCode string `maxminddb:"iso_code"`
. . 219: } `maxminddb:"country"`
. . 220: }
. . 221:
. . 222: if err := g.CountryDB.Lookup(ip, &record); err != nil {
. . 223: logger.Default.Errorf("lookup failed : %s", err)
. . 224: return 0, 0, "", err
. . 225: }
. 2228274 226: _ = g.CountryDB.Decode(record.Location.LongitudeOffset, &longitude)
. . 227:
. . 228: return record.Location.Latitude, longitude, record.Country.ISOCode, nil
. . 229:}
. . 230:
. . 231:func (g *GeoIp) GetASN(ip net.IP) (uint, error) {
Kami menggunakan fungsi maxmiddb untuk mendapatkan data geolokasi. Fungsi-fungsi ini diambil interface{}sebagai parameter, yang, seperti yang kita lihat sebelumnya, dapat menyebabkan tumpukan heap.kita bisa menggunakan sync.Pooluntuk caching elemen yang dipilih tetapi tidak digunakan untuk digunakan kembali berikutnya.type MMDBGeoLocation struct {
Coordinations struct {
Latitude float64 `maxminddb:"latitude"`
Longitude float64
LongitudeOffset uintptr `maxminddb:"longitude"`
} `maxminddb:"location"`
Country struct {
ISOCode string `maxminddb:"iso_code"`
} `maxminddb:"country"`
}
type MMDBASN struct {
AutonomousSystemNumber uint `maxminddb:"autonomous_system_number"`
}
func (g *GeoIp) GetGeoLocation(ip net.IP) (*MMDBGeoLocation, error) {
if !g.Enable || g.CountryDB == nil {
return nil, EMMDBNotAvailable
}
var record *MMDBGeoLocation = g.LocationPool.Get().(*MMDBGeoLocation)
logger.Default.Debugf("ip : %s", ip)
if err := g.CountryDB.Lookup(ip, &record); err != nil {
logger.Default.Errorf("lookup failed : %s", err)
return nil, err
}
_ = g.CountryDB.Decode(record.Coordinations.LongitudeOffset, &record.Coordinations.Longitude)
logger.Default.Debug("lat = ", record.Coordinations.Latitude, " lang = ", record.Coordinations.Longitude, " country = ", record.Country.ISOCode)
return record, nil
}
func (g *GeoIp) GetASN(ip net.IP) (uint, error) {
var record *MMDBASN = g.AsnPool.Get().(*MMDBASN)
err := g.ASNDB.Lookup(ip, record)
if err != nil {
logger.Default.Errorf("lookup failed : %s", err)
return 0, err
}
logger.Default.Debug("asn = ", record.AutonomousSystemNumber)
return record.AutonomousSystemNumber, nil
}
Lebih lanjut tentang sinkronisasi . Kumpulkan di sini .Ada banyak kemungkinan optimasi lain, tetapi saat ini, tampaknya kita sudah melakukan cukup. Untuk informasi lebih lanjut tentang teknik optimasi memori, Anda dapat membaca efisiensi Alokasi dalam layanan Go berkinerja tinggi .hasil
Untuk memvisualisasikan hasil pengoptimalan memori, kami menggunakan diagram dalam go tool tracejudul "Penggunaan Mutator Minimum", di sini Mutator berarti bukan gc.Sebelum optimasi:
Di sini kita memiliki jendela sekitar 500 milidetik tanpa penggunaan yang efisien (gc mengkonsumsi semua sumber daya), dan kita tidak akan pernah mendapatkan 80% penggunaan efektif dalam jangka panjang. Kami ingin jendela nol penggunaan efektif sekecil mungkin, dan secepat mungkin untuk mencapai penggunaan 100%, sesuatu seperti ini:setelah optimasi:
Kesimpulan
Dengan menggunakan alat go, kami dapat mengoptimalkan layanan kami untuk menangani sejumlah besar permintaan dan penggunaan sumber daya sistem yang lebih baik.Anda dapat melihat kode sumber kami di GitHub . Ini adalah versi yang tidak dioptimalkan dan ini yang dioptimalkan.Ini juga akan bermanfaat
Itu saja. Sampai jumpa di lapangan !