Je vous propose une traduction de cette page où il est question de profilage et d’optimisation du code Go.
Présentation faite par Brad Fitzpatrick
YAPC::Asia 2015
Tokyo Big Sight, 2015-08-22
Voir le diaporama d’introduction
Regarder la vidéo de cette présentation
Les exigences
Si vous le faites de chez vous, vous aurez besoin des éléments suivants:
Programme de départ
Débuggons et optimisons un simple serveur http
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
|
package main
import (
"fmt"
"log"
"net/http"
"regexp"
)
var visitors int
func handleHi(w http.ResponseWriter, r *http.Request) {
if match, _ := regexp.MatchString(`^\w*$`, r.FormValue("color")); !match {
http.Error(w, "Optional color is invalid", http.StatusBadRequest)
return
}
visitors++
w.Header().Set("Content-Type", "text/html; charset=utf-8")
w.Write([]byte("<h1 style='color: " + r.FormValue("color") +
"'>Welcome!</h1>You are visitor number " + fmt.Sprint(visitors) + "!"))
}
func main() {
log.Printf("Starting on port 8080")
http.HandleFunc("/hi", handleHi)
log.Fatal(http.ListenAndServe("127.0.0.1:8080", nil))
}
|
Exécutons le:
1
2
3
4
5
6
|
$ cd $GOPATH/src/github.com/bradfitz/talk-yapc-asia-2015/demo
$ go run demo.go
ou
$ go build && ./demo
ou
$ go install && demo
|
Testons:
1
2
|
$ go test
? yapc/demo [no test files]
|
Oula. Pas de test. Écrivons-en un peu.
Dans le fichier demo_test.go:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
|
package demo
import (
"bufio"
"net/http"
"net/http/httptest"
"strings"
"testing"
)
func TestHandleRoot_Recorder(t *testing.T) {
rw := httptest.NewRecorder()
handleHi(rw, req(t, "GET / HTTP/1.0\r\n\r\n"))
if !strings.Contains(rw.Body.String(), "visitor number") {
t.Errorf("Unexpected output: %s", rw.Body)
}
}
func req(t *testing.T, v string) *http.Request {
req, err := http.ReadRequest(bufio.NewReader(strings.NewReader(v)))
if err != nil {
t.Fatal(err)
}
return req
}
|
Maintenant:
1
2
3
4
5
|
$ go test -v
=== RUN TestHandleHi_Recorder
--- PASS: TestHandleHi_Recorder (0.00s)
PASS
ok yapc/demo 0.053s
|
Ceci teste le gestionnaire HTTP avec une simple implémentation en mémoire de
l’interface ResponseWriter.
Une autre façon d’écrire un test HTTP consiste à utiliser le client et le
serveur HTTP actuel mais avec des adresses localhost automatiquement crées, en
utilisant le paquet httptest:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
|
func TestHandleHi_TestServer(t *testing.T) {
ts := httptest.NewServer(http.HandlerFunc(handleHi))
defer ts.Close()
res, err := http.Get(ts.URL)
if err != nil {
t.Error(err)
return
}
if g, w := res.Header.Get("Content-Type"), "text/html; charset=utf-8"; g != w {
t.Errorf("Content-Type = %q; want %q", g, w)
}
slurp, err := ioutil.ReadAll(res.Body)
defer res.Body.Close()
if err != nil {
t.Error(err)
return
}
t.Logf("Got: %s", slurp)
}
|
Race detector
La simultanéité est intégrée au langage Go et il parallélise automatiquement le
code selon les besoins sur les CPU disponibles. Contrairement à Rust, en Go,
vous pouvez écrire un code avec une
race condition si
vous n’êtes pas prudent. Une race condition arrive quand de multiple goroutines
accèdent à une donnée partagée sans synchronisation et quand une des gouroutines
fait de l’écriture.
Avant d’optimiser notre code, assurons-nous de ne pas avoir de race condition.
Lançons juste les tests avec le drapeau -race:
1
2
3
|
$ go test -race
PASS
ok yapc/demo 1.047s
|
Tout est bon, non ?
Hé bien non !
Le détecteur de race conditions de Go utilise l’analyse d’exécution. Il n’a pas
de faux positifs mais il a des faux négatifs. S’il ne voit pas vraiment de race
condition, il ne peut pas les signaler.
Changeons notre test pour faire deux choses à la fois:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
|
func TestHandleHi_TestServer_Parallel(t *testing.T) {
ts := httptest.NewServer(http.HandlerFunc(handleHi))
defer ts.Close()
var wg sync.WaitGroup
for i := 0; i < 2; i++ {
wg.Add(1)
go func() {
defer wg.Done()
res, err := http.Get(ts.URL)
if err != nil {
t.Error(err)
return
}
if g, w := res.Header.Get("Content-Type"), "text/html; charset=utf-8"; g != w {
t.Errorf("Content-Type = %q; want %q", g, w)
}
slurp, err := ioutil.ReadAll(res.Body)
defer res.Body.Close()
if err != nil {
t.Error(err)
return
}
t.Logf("Got: %s", slurp)
}()
}
wg.Wait()
}
|
Maintenant nous pouvons relancer le test et regarder ce qui se passe:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
|
$ go test -v -race
=== RUN TestHandleHi_Recorder
--- PASS: TestHandleHi_Recorder (0.00s)
=== RUN TestHandleHi_TestServer
--- PASS: TestHandleHi_TestServer (0.00s)
demo_test.go:46: Got: <h1 style='color: '>Welcome!</h1>You are visitor number 2!
=== RUN TestHandleHi_TestServer_Parallel
==================
WARNING: DATA RACE
Read by goroutine 21:
yapc/demo.handleHi()
/Users/bradfitz/src/yapc/demo/demo.go:17 +0xf5
net/http.HandlerFunc.ServeHTTP()
/Users/bradfitz/go/src/net/http/server.go:1422 +0x47
net/http/httptest.(*waitGroupHandler).ServeHTTP()
/Users/bradfitz/go/src/net/http/httptest/server.go:200 +0xfe
net/http.serverHandler.ServeHTTP()
/Users/bradfitz/go/src/net/http/server.go:1862 +0x206
net/http.(*conn).serve()
/Users/bradfitz/go/src/net/http/server.go:1361 +0x117c
Previous write by goroutine 23:
yapc/demo.handleHi()
/Users/bradfitz/src/yapc/demo/demo.go:17 +0x111
net/http.HandlerFunc.ServeHTTP()
/Users/bradfitz/go/src/net/http/server.go:1422 +0x47
net/http/httptest.(*waitGroupHandler).ServeHTTP()
/Users/bradfitz/go/src/net/http/httptest/server.go:200 +0xfe
net/http.serverHandler.ServeHTTP()
/Users/bradfitz/go/src/net/http/server.go:1862 +0x206
net/http.(*conn).serve()
/Users/bradfitz/go/src/net/http/server.go:1361 +0x117c
Goroutine 21 (running) created at:
net/http.(*Server).Serve()
/Users/bradfitz/go/src/net/http/server.go:1912 +0x464
Goroutine 23 (running) created at:
net/http.(*Server).Serve()
/Users/bradfitz/go/src/net/http/server.go:1912 +0x464
==================
--- PASS: TestHandleHi_TestServer_Parallel (0.00s)
demo_test.go:68: Got: <h1 style='color: '>Welcome!</h1>You are visitor number 3!
demo_test.go:68: Got: <h1 style='color: '>Welcome!</h1>You are visitor number 4!
PASS
Found 1 data race(s)
exit status 66
FAIL yapc/demo 1.056s
|
Maintenant, nous pouvons voir que l’écriture sur la ligne 17 (la variable
visitors) est en conflit avec la lecture de la ligne 17 (sur la même variable).
Pour le rendre plus évident, modifiez le code comme suit:
1
2
|
now := visitors + 1
visitors = now
|
… et il affichera des numéros de lignes différents pour chaque erreur.
Corrigeons la race condition
Si votre code comporte des races conditions, tous les paries sont perdus et
attendez vous à un plantage de l’application.
Il y a plusieurs solutions pour résoudre le problème:
- Utiliser les canaux (“Ne pas communiquer en partageant la mémoire; à la place,
partagez la mémoire en communiquant”)
- Utiliser un Mutex
- Utiliser un atomic
Les mutex
1
2
3
4
5
6
7
8
9
10
11
12
|
var visitors struct {
sync.Mutex
n int
}
...
func foo() {
...
visitors.Lock()
visitors.n++
yourVisitorNumber := visitors.n
visitors.Unlock()
}
|
atomic
1
2
3
4
5
6
|
var visitors int64 // must be accessed atomically
...
func foo() {
...
visitNum := atomic.AddInt64(&visitors, 1)
}
|
À quelle vitesse peut-il aller ? Profilage CPU !
Pour utiliser le profileur de CPU Go, il est préférable d’écrire une fonction de
référence qui est très similaire à une fonction de test:
1
2
3
4
5
6
7
8
|
func BenchmarkHi(b *testing.B) {
b.ReportAllocs()
r := req(b, "GET / HTTP/1.0\r\n\r\n")
for i := 0; i < b.N; i++ {
rw := httptest.NewRecorder()
handleHi(rw, r)
}
}
|
(et changez func req en une interface testing.TB à la place. Elle prendra un
argument *testing.T ou *testing.B)
Nous pouvons maintenant lancer le test de performances:
1
2
3
4
|
$ go test -v -run=^$ -bench=.
PASS
BenchmarkHi-4 100000 12843 ns/op
ok yapc/demo 1.472s
|
Jouez avec les drapeaux comme -benchtime.
Est-ce que c’est rapide ? lent ?
Mais regardons où va le CPU maintenant …
Profilage du CPU
1
|
$ go test -v -run=^$ -bench=^BenchmarkHi$ -benchtime=2s -cpuprofile=prof.cpu
|
(Laissons le binaire de demo.test de coté)
Maintetant, utilisons le visualiseur de profil Go:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
|
$ go tool pprof demo.test prof.cpu
Entering interactive mode (type "help" for commands)
(pprof) top
3070ms of 3850ms total (79.74%)
Dropped 62 nodes (cum <= 19.25ms)
Showing top 10 nodes out of 92 (cum >= 290ms)
flat flat% sum% cum cum%
1710ms 44.42% 44.42% 1710ms 44.42% runtime.mach_semaphore_signal
290ms 7.53% 51.95% 1970ms 51.17% runtime.growslice
230ms 5.97% 57.92% 230ms 5.97% runtime.mach_semaphore_wait
200ms 5.19% 63.12% 2270ms 58.96% runtime.mallocgc
160ms 4.16% 67.27% 160ms 4.16% runtime.heapBitsSetType
110ms 2.86% 70.13% 210ms 5.45% runtime.mapassign1
110ms 2.86% 72.99% 110ms 2.86% runtime.memclr
100ms 2.60% 75.58% 640ms 16.62% regexp.makeOnePass.func2
100ms 2.60% 78.18% 100ms 2.60% runtime.memmove
60ms 1.56% 79.74% 290ms 7.53% runtime.makeslice
(pprof) top --cum
0.26s of 3.85s total ( 6.75%)
Dropped 62 nodes (cum <= 0.02s)
Showing top 10 nodes out of 92 (cum >= 2.22s)
flat flat% sum% cum cum%
0 0% 0% 3.55s 92.21% runtime.goexit
0 0% 0% 3.48s 90.39% testing.(*B).launch
0 0% 0% 3.48s 90.39% testing.(*B).runN
0.01s 0.26% 0.26% 3.47s 90.13% yapc/demo.BenchmarkHi
0.01s 0.26% 0.52% 3.44s 89.35% yapc/demo.handleHi
0 0% 0.52% 3.30s 85.71% regexp.MatchString
0.01s 0.26% 0.78% 3s 77.92% regexp.Compile
0 0% 0.78% 2.99s 77.66% regexp.compile
0.20s 5.19% 5.97% 2.27s 58.96% runtime.mallocgc
0.03s 0.78% 6.75% 2.22s 57.66% regexp.compileOnePass
(pprof) list handleHi
Total: 3.85s
ROUTINE ======================== yapc/demo.handleHi in /Users/bradfitz/src/yapc/demo/demo.go
10ms 3.44s (flat, cum) 89.35% of Total
. . 8:)
. . 9:
. . 10:var visitors int
. . 11:
. . 12:func handleHi(w http.ResponseWriter, r *http.Request) {
. 3.30s 13: if match, _ := regexp.MatchString(\w*$r.FormValue("color")); !match {
. . 14: http.Error(w, "Optional color is invalid", http.StatusBadRequest)
. . 15: return
. . 16: }
10ms 10ms 17: visitors++
. 50ms 18: w.Header().Set("Content-Type", "text/html; charset=utf-8")
. 80ms 19: w.Write([]byte("<h1 style='color: " + r.FormValue("color") + "'>Welcome!</h1>You are visitor number " + fmt.Sprint(visitors) + "!"))
. . 20:}
. . 21:
. . 22:func main() {
. . 23: log.Printf("Starting on port 8080")
. . 24: http.HandleFunc("/hi", handleHi)
(pprof) web
|
3 secondes dans regexp.MatchString ? \
Le profilage de la CPU affiche 85,71% du temps cumulatif dans MatchString,
77,92% dans la compilation regexp et 58,96% dans le garbage collector
(qui est déclenchée via les allocations).
Moins d’allocation => moins d’utilisation du garbage collector (GC)
Pourquoi allouons-nous ?
Profilage de mémoire
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
|
$ go tool pprof --alloc_space demo.test prof.mem
(pprof) top
1159.72MB of 1485.25MB total (78.08%)
Dropped 12 nodes (cum <= 7.43MB)
Showing top 10 nodes out of 33 (cum >= 1484.75MB)
flat flat% sum% cum cum%
294.10MB 19.80% 19.80% 294.10MB 19.80% regexp.onePassCopy
174.53MB 11.75% 31.55% 174.53MB 11.75% regexp.progMachine
119.03MB 8.01% 39.57% 170.54MB 11.48% regexp/syntax.(*compiler).compile
106.53MB 7.17% 46.74% 106.53MB 7.17% net/textproto.MIMEHeader.Set
100.51MB 6.77% 53.51% 308.51MB 20.77% regexp.makeOnePass
99MB 6.67% 60.17% 208.01MB 14.00% regexp.makeOnePass.func2
84.50MB 5.69% 65.86% 84.50MB 5.69% regexp.mergeRuneSets.func2
69.51MB 4.68% 70.54% 80.01MB 5.39% regexp/syntax.(*parser).op
58.51MB 3.94% 74.48% 242.02MB 16.30% regexp/syntax.Parse
53.50MB 3.60% 78.08% 1484.75MB 100% yapc/demo.BenchmarkHi
(pprof) top --cum
249.02MB of 1485.25MB total (16.77%)
Dropped 12 nodes (cum <= 7.43MB)
Showing top 10 nodes out of 33 (cum >= 308.51MB)
flat flat% sum% cum cum%
0 0% 0% 1484.75MB 100% runtime.goexit
0 0% 0% 1484.75MB 100% testing.(*B).launch
0 0% 0% 1484.75MB 100% testing.(*B).runN
53.50MB 3.60% 3.60% 1484.75MB 100% yapc/demo.BenchmarkHi
52.50MB 3.53% 7.14% 1431.25MB 96.36% yapc/demo.handleHi
0 0% 7.14% 1265.21MB 85.18% regexp.MatchString
0 0% 7.14% 1087.18MB 73.20% regexp.Compile
42.51MB 2.86% 10.00% 1087.18MB 73.20% regexp.compile
0 0% 10.00% 602.61MB 40.57% regexp.compileOnePass
100.51MB 6.77% 16.77% 308.51MB 20.77% regexp.makeOnePass
(pprof) list BenchmarkHi
Total: 1.45GB
ROUTINE ======================== yapc/demo.BenchmarkHi in /Users/bradfitz/src/yapc/demo/demo_test.go
53.50MB 1.45GB (flat, cum) 100% of Total
. . 72:}
. . 73:
. . 74:func BenchmarkHi(b *testing.B) {
. . 75: r := req(b, "GET / HTTP/1.0\r\n\r\n")
. . 76: for i := 0; i < b.N; i++ {
53.50MB 53.50MB 77: rw := httptest.NewRecorder()
. 1.40GB 78: handleHi(rw, r)
. . 79: }
. . 80:}
(pprof) list handleHi
Total: 1.45GB
ROUTINE ======================== yapc/demo.handleHi in /Users/bradfitz/src/yapc/demo/demo.go
52.50MB 1.40GB (flat, cum) 96.36% of Total
. . 8:)
. . 9:
. . 10:var visitors int
. . 11:
. . 12:func handleHi(w http.ResponseWriter, r *http.Request) {
. 1.24GB 13: if match, _ := regexp.MatchString(\w*$r.FormValue("color")); !match {
. . 14: http.Error(w, "Optional color is invalid", http.StatusBadRequest)
. . 15: return
. . 16: }
. . 17: visitors++
. 106.53MB 18: w.Header().Set("Content-Type", "text/html; charset=utf-8")
52.50MB 59.50MB 19: w.Write([]byte("<h1 style='color: " + r.FormValue("color") + "'>Welcome!</h1>You are visitor number " + fmt.Sprint(visitors) + "!"))
. . 20:}
. . 21:
. . 22:func main() {
. . 23: log.Printf("Starting on port 8080")
. . 24: http.HandleFunc("/hi", handleHi)
|
Compilons cette regexp juste une fois
1
2
3
|
var colorRx = regexp.MustCompile(`\w*$`)
...
if !colorRx.MatchString(r.FormValue("color")) {
|
Et maintenant:
1
2
3
4
|
$ go test -bench=.
PASS
BenchmarkHi-4 1000000 1451 ns/op
ok yapc/demo 1.517s
|
10x plus vite !
Comparons avec le CPU maintenant:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
|
bradfitz@laptop demo$ go test -v -run=^$ -bench=. -benchtime=3s -memprofile=prof.mem -cpuprofile=prof.cpu
PASS
BenchmarkHi-4 3000000 1420 ns/op
ok yapc/demo 5.768s
bradfitz@laptop demo$ profcpu
Entering interactive mode (type "help" for commands)
(pprof) top --cum 30
2.78s of 6.24s total (44.55%)
Dropped 75 nodes (cum <= 0.03s)
Showing top 30 nodes out of 114 (cum >= 0.67s)
flat flat% sum% cum cum%
0 0% 0% 4.84s 77.56% runtime.goexit
0 0% 0% 3.72s 59.62% testing.(*B).launch
0 0% 0% 3.72s 59.62% testing.(*B).runN
0.02s 0.32% 0.32% 3.71s 59.46% yapc/demo.BenchmarkHi
0 0% 0.32% 3.04s 48.72% yapc/demo.handleHi
0.37s 5.93% 6.25% 2.55s 40.87% runtime.mallocgc
2.16s 34.62% 40.87% 2.16s 34.62% runtime.mach_semaphore_signal
0 0% 40.87% 2.16s 34.62% runtime.mach_semrelease
0 0% 40.87% 2.16s 34.62% runtime.notewakeup
0 0% 40.87% 2.16s 34.62% runtime.semawakeup
0 0% 40.87% 2.03s 32.53% runtime.startm
0 0% 40.87% 2.02s 32.37% runtime.wakep
0 0% 40.87% 1.83s 29.33% runtime.systemstack
0 0% 40.87% 1.54s 24.68% runtime.ready
0 0% 40.87% 1.54s 24.68% runtime.startGC
0 0% 40.87% 1.32s 21.15% runtime.schedule
0.02s 0.32% 41.19% 1.21s 19.39% runtime.mcall
0.01s 0.16% 41.35% 1.06s 16.99% runtime.semasleep.func1
0 0% 41.35% 1.05s 16.83% runtime.semasleep1
0 0% 41.35% 1.01s 16.19% runtime.concatstring5
0.11s 1.76% 43.11% 1.01s 16.19% runtime.concatstrings
0.01s 0.16% 43.27% 0.94s 15.06% runtime.rawstringtmp
0.03s 0.48% 43.75% 0.93s 14.90% runtime.rawstring
0.01s 0.16% 43.91% 0.75s 12.02% runtime.stringtoslicebyte
0.02s 0.32% 44.23% 0.74s 11.86% runtime.rawbyteslice
0 0% 44.23% 0.73s 11.70% runtime.stopm
0.02s 0.32% 44.55% 0.70s 11.22% runtime.newobject
0 0% 44.55% 0.69s 11.06% runtime.semasleep
0 0% 44.55% 0.67s 10.74% runtime.findrunnable
0 0% 44.55% 0.67s 10.74% runtime.goschedImpl
(pprof) bradfitz@laptop demo$ profmem
Entering interactive mode (type "help" for commands)
(pprof) top --cum
2739.53MB of 2740.53MB total ( 100%)
Dropped 9 nodes (cum <= 13.70MB)
flat flat% sum% cum cum%
0 0% 0% 2740.03MB 100% runtime.goexit
0 0% 0% 2740.03MB 100% testing.(*B).launch
0 0% 0% 2740.03MB 100% testing.(*B).runN
728.06MB 26.57% 26.57% 2740.03MB 100% yapc/demo.BenchmarkHi
561.03MB 20.47% 47.04% 2011.98MB 73.42% yapc/demo.handleHi
0 0% 47.04% 1382.94MB 50.46% net/http.Header.Set
1382.94MB 50.46% 97.50% 1382.94MB 50.46% net/textproto.MIMEHeader.Set
67.50MB 2.46% 100% 68MB 2.48% fmt.Sprint
(pprof)
(pprof) list handleHi
Total: 2.68GB
ROUTINE ======================== yapc/demo.handleHi in /Users/bradfitz/src/yapc/demo/demo.go
561.03MB 1.96GB (flat, cum) 73.42% of Total
. . 15: if !colorRx.MatchString(r.FormValue("color")) {
. . 16: http.Error(w, "Optional color is invalid", http.StatusBadRequest)
. . 17: return
. . 18: }
. . 19: visitors++
. 1.35GB 20: w.Header().Set("Content-Type", "text/html; charset=utf-8")
561.03MB 629.03MB 21: w.Write([]byte("<h1 style='color: " + r.FormValue("color") + "'>Welcome!</h1>You are visitor number " + fmt.Sprint(visitors) + "!"))
. . 22:}
. . 23:
. . 24:func main() {
. . 25: log.Printf("Starting on port 8080")
. . 26: http.HandleFunc("/hi", handleHi)
|
Optimisation de la mémoire
- Supprimer la ligne d’en tête Content-Type (le serveur net/http le fera pour
nous)
- Utiliser fmt.Fprintf(w, … à la place de la concaténation
Benchcmp
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
|
$ go test -bench=. -memprofile=prof.mem | tee mem.0
... (fix)
$ go test -bench=. -memprofile=prof.mem | tee mem.1
... (fix)
$ go test -bench=. -memprofile=prof.mem | tee mem.2
$ benchcmp mem.0 mem.2
benchmark old ns/op new ns/op delta
BenchmarkHi-4 1180 964 -18.31%
benchmark old allocs new allocs delta
BenchmarkHi-4 9 5 -44.44%
benchmark old bytes new bytes delta
BenchmarkHi-4 720 224 -68.89%
|
Une nette amélioration. Maintenant d’où vient cette mémoire ?
profmem, voir et fixer ResponseRecorder:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
|
func BenchmarkHi(b *testing.B) {
b.ReportAllocs()
r := req(b, "GET / HTTP/1.0\r\n\r\n")
rw := httptest.NewRecorder()
for i := 0; i < b.N; i++ {
handleHi(rw, r)
reset(rw)
}
}
func reset(rw *httptest.ResponseRecorder) {
m := rw.HeaderMap
for k := range m {
delete(m, k)
}
body := rw.Body
body.Reset()
*rw = httptest.ResponseRecorder{
Body: body,
HeaderMap: m,
}
}
|
Maintenant:
1
2
3
|
$ go test -bench=. -memprofile=prof.mem | tee mem.3
PASS
BenchmarkHi-4 2000000 649 ns/op 32 B/op 2 allocs/op
|
Où est-ce ?
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
|
(pprof) top --cum 10
88MB of 88MB total ( 100%)
flat flat% sum% cum cum%
0 0% 0% 87.50MB 99.43% runtime.goexit
0 0% 0% 87.50MB 99.43% testing.(*B).launch
0 0% 0% 87.50MB 99.43% testing.(*B).runN
0 0% 0% 87.50MB 99.43% yapc/demo.BenchmarkHi
87.50MB 99.43% 99.43% 87.50MB 99.43% yapc/demo.handleHi
0.50MB 0.57% 100% 0.50MB 0.57% runtime.malg
0 0% 100% 0.50MB 0.57% runtime.mcommoninit
0 0% 100% 0.50MB 0.57% runtime.mpreinit
0 0% 100% 0.50MB 0.57% runtime.rt0_go
0 0% 100% 0.50MB 0.57% runtime.schedinit
(pprof) list handleHi
Total: 88MB
ROUTINE ======================== yapc/demo.handleHi in /Users/bradfitz/src/yapc/demo/demo.go
87.50MB 87.50MB (flat, cum) 99.43% of Total
. . 24: visitors.n++
. . 25: num := visitors.n
. . 26: visitors.Unlock()
. . 27: // w.Header().Set("Content-Type", "text/html; charset=utf-8")
. . 28:
87.50MB 87.50MB 29: fmt.Fprintf(w, "<h1 style='color: %s'>Welcome!</h1>You are visitor number %d!", r.FormValue("color"), num)
. . 30:}
. . 31:
. . 32:func main() {
. . 33: log.Printf("Starting on port 8080")
. . 34: http.HandleFunc("/hi", handleHi)
(pprof) disasm handleHi
...
. . 831f7: LEAQ 0x70(SP), BX
. . 831fc: MOVQ BX, 0x8(SP)
. . 83201: MOVQ $0x0, 0x10(SP)
43MB 43MB 8320a: CALL runtime.convT2E(SB)
. . 8320f: MOVQ 0x18(SP), CX
. . 83214: MOVQ 0x20(SP), AX
...
|
Représentation en temps réel des structures de données Go
Regardez ce diaporama: accéder aux structures de données intégrées
- Une interface Go représente 2 mots en mémoire: (type, pointer)
- Une chaîne en Go représente 2 mots en mémoire: (pointeur de base, longueur)
- Une liste en Go représente 3 mots en mémoire: (pointeur de base, taille,
capacité)
En sachant cela, regardons ces 32 octets / op.
La ligne en Go est:
1
2
|
fmt.Fprintf(w, "<h1 style='color: %s'>Welcome!</h1>You are visitor number %d!",
r.FormValue("color"), num)
|
La signature de la fonction fmt.Fprintf est:
1
2
3
4
5
|
$ go doc fmt.Fprintf
func Fprintf(w io.Writer, format string, a ...interface{}) (n int, err error)
Fprintf formats according to a format specifier and writes to w. It returns
the number of bytes written and any write error encountered.
|
Ces valeurs d’interface sont de 16 octets chacune. Elles sont passées par
valeur, mais le mot de données d’une interface doit être un pointeur et parce
que la chaîne est une valeur composée de 2 mots (plus grand que le 1 mot de
données) et int n’est pas un pointeur, la conversion d’un type vers une
interface vide (runtime.convT2E) alloue 16 octets pour chacune (la plus petite
taille d’allocation sur 64 bits) et met un pointeur sur l’allocation dans le mot
de données de la valeur de l’interface.
Allez à cette partie dans les diapositives maintenant:
accéder aux structures de données intégrées
Supprimer toutes les allocations
Vous ne voulez probablement pas écrire de code comme celui-ci, mais quand cela
arrive, vous pouvez faire quelque chose comme:
1
2
3
4
5
|
var bufPool = sync.Pool{
New: func() interface{} {
return new(bytes.Buffer)
},
}
|
… pour créer un pool de mémoire tampon par processeur à portée globale, puis
dans le gestionnaire:
1
2
3
4
5
6
7
8
9
|
buf := bufPool.Get().(*bytes.Buffer)
defer bufPool.Put(buf)
buf.Reset()
buf.WriteString("<h1 style='color: ")
buf.WriteString(r.FormValue("color"))
buf.WriteString(">Welcome!</h1>You are visitor number ")
b := strconv.AppendInt(buf.Bytes(), int64(num), 10)
b = append(b, '!')
w.Write(b)
|
Profile de contestation
Premièrement, écrivons un benchmark parallère:
1
2
3
4
5
6
7
8
9
10
|
func BenchmarkHiParallel(b *testing.B) {
r := req(b, "GET / HTTP/1.0\r\n\r\n")
b.RunParallel(func(pb *testing.PB) {
rw := httptest.NewRecorder()
for pb.Next() {
handleHi(rw, r)
reset(rw)
}
})
}
|
et faisons des mesures:
1
|
$ go test -bench=Parallel -blockprofile=prof.block
|
“Fixons” ça:
1
2
3
4
5
6
7
8
9
|
var colorRxPool = sync.Pool{
New: func() interface{} { return regexp.MustCompile(`\w*$`) },
}
...
func handleHi(w http.ResponseWriter, r *http.Request) {
if !colorRxPool.Get().(*regexp.Regexp).MatchString(r.FormValue("color")) {
http.Error(w, "Optional color is invalid", http.StatusBadRequest)
return
}
|
Qu’en est-il de ce mutex de visiteurs ?
Sortez-le dans une fonction:
1
2
3
4
5
6
7
8
|
num := nextVisitorNum()
...
func nextVisitorNum() int {
visitors.Lock()
defer visitors.Unlock()
visitors.n++
return visitors.n
}
|
puis, écrivons quelques benchmark:
1
2
3
4
5
6
7
|
func BenchmarkVisitCount(b *testing.B) {
b.RunParallel(func(pb *testing.PB) {
for pb.Next() {
incrementVisitorNum()
}
})
}
|
Essayez:
- sans defer
- avec int(atomic.AddInt64(&atomicVisitors, 1))
Couverture
1
2
3
4
5
6
|
$ go test -cover -coverprofile=cover
PASS
coverage: 54.8% of statements
ok yapc/demo 0.066s
$ go tool cover -html=cover
(opens web browser)
|
