From 8bae612b59b204dae084deaaf8a401e25202ed1b Mon Sep 17 00:00:00 2001 From: Jacob Vosmaer Date: Thu, 27 Jun 2019 18:39:25 +0200 Subject: [PATCH 01/11] Add basic http clone analyzer --- cmd/gitaly-debug/analyzehttp.go | 128 ++++++++++++++++++++++++++++++++ cmd/gitaly-debug/main.go | 20 ++++- 2 files changed, 144 insertions(+), 4 deletions(-) create mode 100644 cmd/gitaly-debug/analyzehttp.go diff --git a/cmd/gitaly-debug/analyzehttp.go b/cmd/gitaly-debug/analyzehttp.go new file mode 100644 index 0000000000..efca76463e --- /dev/null +++ b/cmd/gitaly-debug/analyzehttp.go @@ -0,0 +1,128 @@ +package main + +import ( + "bytes" + "compress/gzip" + "log" + "net/http" + "strings" + "time" + + "gitlab.com/gitlab-org/gitaly/internal/git/pktline" +) + +func analyzeHTTPClone(cloneURL string) { + wants := doBenchGet(cloneURL) + doBenchPost(cloneURL, wants) +} + +func doBenchGet(cloneURL string) []string { + req, err := http.NewRequest("GET", cloneURL+"/info/refs?service=git-upload-pack", nil) + noError(err) + + for k, v := range map[string]string{ + "User-Agent": "gitaly-debug", + "Accept": "*/*", + "Accept-Encoding": "deflate, gzip", + "Pragma": "no-cache", + } { + req.Header.Set(k, v) + } + + start := time.Now() + resp, err := http.DefaultClient.Do(req) + noError(err) + + log.Printf("GET response header: %v", resp.Header) + defer resp.Body.Close() + + var wants []string + var size int64 + scanner := pktline.NewScanner(resp.Body) + for i := 0; scanner.Scan(); i++ { + data := pktline.Data(scanner.Bytes()) + size += int64(len(data)) + if i == 0 { + log.Printf("GET first packet %v", time.Since(start)) + continue + } + + split := strings.SplitN(string(data), " ", 2) + if len(split) != 2 { + continue + } + + if strings.HasPrefix(split[1], "refs/heads/") || strings.HasPrefix(split[1], "refs/tags/") { + wants = append(wants, split[0]) + } + } + noError(scanner.Err()) + log.Printf("GET done %v", time.Since(start)) + log.Printf("GET data %d bytes", size) + + return wants +} + +func doBenchPost(cloneURL string, wants []string) { + reqBodyRaw := &bytes.Buffer{} + reqBodyGzip := gzip.NewWriter(reqBodyRaw) + for i, oid := range wants { + if i == 0 { + oid += " multi_ack_detailed no-done side-band-64k thin-pack ofs-delta deepen-since deepen-not agent=git/2.21.0" + } + _, err := pktline.WriteString(reqBodyGzip, "want "+oid+"\n") + noError(err) + } + noError(pktline.WriteFlush(reqBodyGzip)) + _, err := pktline.WriteString(reqBodyGzip, "done\n") + noError(err) + noError(reqBodyGzip.Close()) + + req, err := http.NewRequest("POST", cloneURL+"/git-upload-pack", reqBodyRaw) + noError(err) + + for k, v := range map[string]string{ + "User-Agent": "gitaly-debug", + "Accept-Encoding": "deflate, gzip", + "Content-Type": "application/x-git-upload-pack-request", + "Accept": "application/x-git-upload-pack-result", + "Content-Encoding": "gzip", + } { + req.Header.Set(k, v) + } + + start := time.Now() + resp, err := http.DefaultClient.Do(req) + noError(err) + log.Printf("POST response %v", time.Since(start)) + + log.Printf("POST response header: %v", resp.Header) + log.Printf("POST code %d", resp.StatusCode) + defer resp.Body.Close() + + packets := 0 + scanner := pktline.NewScanner(resp.Body) + var size int64 + sizeHistogram := make(map[int]int) + sideBandHistogram := make(map[byte]int) + for ; scanner.Scan(); packets++ { + if packets == 0 { + log.Printf("POST first packet %v", time.Since(start)) + } + + data := pktline.Data(scanner.Bytes()) + n := len(data) + size += int64(n) + sizeHistogram[n]++ + if len(data) > 0 { + sideBandHistogram[data[0]]++ + } + } + noError(scanner.Err()) + + log.Printf("POST: %d packets", packets) + log.Printf("POST done %v", time.Since(start)) + log.Printf("POST data %d bytes", size) + log.Printf("POST packet size histogram: %v", sizeHistogram) + log.Printf("POST packet sideband histogram: %v", sideBandHistogram) +} diff --git a/cmd/gitaly-debug/main.go b/cmd/gitaly-debug/main.go index 57d16e45db..727f9bd3cd 100644 --- a/cmd/gitaly-debug/main.go +++ b/cmd/gitaly-debug/main.go @@ -22,24 +22,36 @@ simulate-http-clone GIT_DIR HTTP. The clone data is written to /dev/null. Note that in real life the workload also depends on the transport capabilities requested by the client; this tool uses a fixed set of capabilities. + +analyze-http-clone HTTP_URL + Clones a Git repository from a public HTTP URL into /dev/null. ` ) func main() { - if len(os.Args) != 3 { + if len(os.Args) < 2 { fatal(usage) } - gitDir := os.Args[2] + extraArgs := os.Args[2:] switch os.Args[1] { case "simulate-http-clone": - testHTTPCloneSpeed(gitDir) + if len(extraArgs) != 1 { + fatal(usage) + } + simulateHTTPClone(extraArgs[0]) + case "analyze-http-clone": + if len(extraArgs) != 1 { + fatal(usage) + } + analyzeHTTPClone(extraArgs[0]) default: fatal(usage) } } -func testHTTPCloneSpeed(gitDir string) { +func simulateHTTPClone(gitDir string) { + msg("Generating server response for HTTP clone. Data goes to /dev/null.") infoRefs := exec.Command("git", "upload-pack", "--stateless-rpc", "--advertise-refs", gitDir) infoRefs.Stderr = os.Stderr -- GitLab From 087154015924964b84589a8e93597804c17a66e3 Mon Sep 17 00:00:00 2001 From: Jacob Vosmaer Date: Thu, 27 Jun 2019 18:48:06 +0200 Subject: [PATCH 02/11] remove cruft --- cmd/gitaly-debug/analyzehttp.go | 2 -- 1 file changed, 2 deletions(-) diff --git a/cmd/gitaly-debug/analyzehttp.go b/cmd/gitaly-debug/analyzehttp.go index efca76463e..a1157d1ee7 100644 --- a/cmd/gitaly-debug/analyzehttp.go +++ b/cmd/gitaly-debug/analyzehttp.go @@ -83,7 +83,6 @@ func doBenchPost(cloneURL string, wants []string) { for k, v := range map[string]string{ "User-Agent": "gitaly-debug", - "Accept-Encoding": "deflate, gzip", "Content-Type": "application/x-git-upload-pack-request", "Accept": "application/x-git-upload-pack-result", "Content-Encoding": "gzip", @@ -94,7 +93,6 @@ func doBenchPost(cloneURL string, wants []string) { start := time.Now() resp, err := http.DefaultClient.Do(req) noError(err) - log.Printf("POST response %v", time.Since(start)) log.Printf("POST response header: %v", resp.Header) log.Printf("POST code %d", resp.StatusCode) -- GitLab From 771fd2fdbd790fc9c86c975d98f7274897aaf1c1 Mon Sep 17 00:00:00 2001 From: Jacob Vosmaer Date: Thu, 27 Jun 2019 18:57:30 +0200 Subject: [PATCH 03/11] Log number of get packets --- cmd/gitaly-debug/analyzehttp.go | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/cmd/gitaly-debug/analyzehttp.go b/cmd/gitaly-debug/analyzehttp.go index a1157d1ee7..4a416a42ce 100644 --- a/cmd/gitaly-debug/analyzehttp.go +++ b/cmd/gitaly-debug/analyzehttp.go @@ -39,10 +39,11 @@ func doBenchGet(cloneURL string) []string { var wants []string var size int64 scanner := pktline.NewScanner(resp.Body) - for i := 0; scanner.Scan(); i++ { + packets := 0 + for ; scanner.Scan(); packets++ { data := pktline.Data(scanner.Bytes()) size += int64(len(data)) - if i == 0 { + if packets == 0 { log.Printf("GET first packet %v", time.Since(start)) continue } @@ -57,6 +58,7 @@ func doBenchGet(cloneURL string) []string { } } noError(scanner.Err()) + log.Printf("GET: %d packets", packets) log.Printf("GET done %v", time.Since(start)) log.Printf("GET data %d bytes", size) -- GitLab From abc6577142359b2ff4401e22b66e6db975086922 Mon Sep 17 00:00:00 2001 From: Jacob Vosmaer Date: Fri, 28 Jun 2019 11:40:08 +0200 Subject: [PATCH 04/11] Add progress --- cmd/gitaly-debug/analyzehttp.go | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/cmd/gitaly-debug/analyzehttp.go b/cmd/gitaly-debug/analyzehttp.go index 4a416a42ce..a3d5482425 100644 --- a/cmd/gitaly-debug/analyzehttp.go +++ b/cmd/gitaly-debug/analyzehttp.go @@ -3,8 +3,10 @@ package main import ( "bytes" "compress/gzip" + "fmt" "log" "net/http" + "os" "strings" "time" @@ -105,6 +107,7 @@ func doBenchPost(cloneURL string, wants []string) { var size int64 sizeHistogram := make(map[int]int) sideBandHistogram := make(map[byte]int) + progress := os.Getenv("PROGRESS") == "1" for ; scanner.Scan(); packets++ { if packets == 0 { log.Printf("POST first packet %v", time.Since(start)) @@ -117,6 +120,13 @@ func doBenchPost(cloneURL string, wants []string) { if len(data) > 0 { sideBandHistogram[data[0]]++ } + + if progress && packets%100 == 0 && packets > 0 { + fmt.Printf(".") + } + } + if progress { + fmt.Println("") } noError(scanner.Err()) -- GitLab From d194d830717b1915eda674694b672be314a59dd7 Mon Sep 17 00:00:00 2001 From: Jacob Vosmaer Date: Fri, 28 Jun 2019 12:33:54 +0200 Subject: [PATCH 05/11] More checks and information --- cmd/gitaly-debug/analyzehttp.go | 122 +++++++++++++++++++++++++------- 1 file changed, 97 insertions(+), 25 deletions(-) diff --git a/cmd/gitaly-debug/analyzehttp.go b/cmd/gitaly-debug/analyzehttp.go index a3d5482425..460a0268eb 100644 --- a/cmd/gitaly-debug/analyzehttp.go +++ b/cmd/gitaly-debug/analyzehttp.go @@ -36,30 +36,57 @@ func doBenchGet(cloneURL string) []string { noError(err) log.Printf("GET response header: %v", resp.Header) + log.Printf("GET code %d", resp.StatusCode) defer resp.Body.Close() var wants []string var size int64 + seenFlush := false scanner := pktline.NewScanner(resp.Body) packets := 0 for ; scanner.Scan(); packets++ { - data := pktline.Data(scanner.Bytes()) - size += int64(len(data)) - if packets == 0 { - log.Printf("GET first packet %v", time.Since(start)) - continue + if seenFlush { + fatal("received packet after flush") } - split := strings.SplitN(string(data), " ", 2) - if len(split) != 2 { - continue - } + data := string(pktline.Data(scanner.Bytes())) + size += int64(len(data)) - if strings.HasPrefix(split[1], "refs/heads/") || strings.HasPrefix(split[1], "refs/tags/") { - wants = append(wants, split[0]) + switch packets { + case 0: + log.Printf("GET first packet %v", time.Since(start)) + if data != "# service=git-upload-pack\n" { + fatal(fmt.Errorf("unexpected header %q", data)) + } + case 1: + if !pktline.IsFlush(scanner.Bytes()) { + fatal("missing flush after service announcement") + } + default: + if packets == 2 && !strings.Contains(data, " side-band-64k") { + fatal(fmt.Errorf("missing side-band-64k capability in %q", data)) + } + + if pktline.IsFlush(scanner.Bytes()) { + seenFlush = true + continue + } + + split := strings.SplitN(data, " ", 2) + if len(split) != 2 { + continue + } + + if strings.HasPrefix(split[1], "refs/heads/") || strings.HasPrefix(split[1], "refs/tags/") { + wants = append(wants, split[0]) + } } } noError(scanner.Err()) + if !seenFlush { + fatal("missing flush in response") + } + log.Printf("GET: %d packets", packets) log.Printf("GET done %v", time.Since(start)) log.Printf("GET data %d bytes", size) @@ -104,35 +131,80 @@ func doBenchPost(cloneURL string, wants []string) { packets := 0 scanner := pktline.NewScanner(resp.Body) - var size int64 - sizeHistogram := make(map[int]int) + totalSize := make(map[byte]int64) + payloadSizeHistogram := make(map[int]int) sideBandHistogram := make(map[byte]int) progress := os.Getenv("PROGRESS") == "1" + seenFlush := false for ; scanner.Scan(); packets++ { - if packets == 0 { - log.Printf("POST first packet %v", time.Since(start)) + if seenFlush { + fatal("received extra packet after flush") } data := pktline.Data(scanner.Bytes()) - n := len(data) - size += int64(n) - sizeHistogram[n]++ - if len(data) > 0 { - sideBandHistogram[data[0]]++ - } - if progress && packets%100 == 0 && packets > 0 { - fmt.Printf(".") + switch packets { + case 0: + if !bytes.Equal([]byte("NAK\n"), data) { + fatal(fmt.Errorf("expected NAK, got %q", data)) + } + log.Printf("NAK after %v", time.Since(start)) + default: + if pktline.IsFlush(scanner.Bytes()) { + seenFlush = true + continue + } + + if len(data) == 0 { + fatal("empty packet in PACK data") + } + + band := data[0] + if band < 1 || band > 3 { + fatal(fmt.Errorf("invalid sideband: %d", band)) + } + if sideBandHistogram[band] == 0 { + log.Printf("first %s packet after %v", bandToHuman(band), time.Since(start)) + } + + sideBandHistogram[band]++ + + n := len(data[1:]) + totalSize[band] += int64(n) + payloadSizeHistogram[n]++ + + if progress && packets%100 == 0 && packets > 0 && band == 1 { + fmt.Printf(".") + } } } if progress { fmt.Println("") } noError(scanner.Err()) + if !seenFlush { + fatal("POST response did not end in flush") + } log.Printf("POST: %d packets", packets) log.Printf("POST done %v", time.Since(start)) - log.Printf("POST data %d bytes", size) - log.Printf("POST packet size histogram: %v", sizeHistogram) + for i := byte(1); i <= 3; i++ { + log.Printf("data in %s band: %d bytes", bandToHuman(i), totalSize[i]) + } + log.Printf("POST packet payload size histogram: %v", payloadSizeHistogram) log.Printf("POST packet sideband histogram: %v", sideBandHistogram) } + +func bandToHuman(b byte) string { + switch b { + case 1: + return "pack" + case 2: + return "progress" + case 3: + return "error" + default: + fatal(fmt.Errorf("invalid band %d", b)) + return "" // never reached + } +} -- GitLab From 706a067a44b65f1ddb45c05e5cf09892e3b41298 Mon Sep 17 00:00:00 2001 From: Jacob Vosmaer Date: Fri, 28 Jun 2019 12:35:13 +0200 Subject: [PATCH 06/11] changelog --- changelogs/unreleased/jv-clone-analyzer.yml | 5 +++++ 1 file changed, 5 insertions(+) create mode 100644 changelogs/unreleased/jv-clone-analyzer.yml diff --git a/changelogs/unreleased/jv-clone-analyzer.yml b/changelogs/unreleased/jv-clone-analyzer.yml new file mode 100644 index 0000000000..d83d0a8707 --- /dev/null +++ b/changelogs/unreleased/jv-clone-analyzer.yml @@ -0,0 +1,5 @@ +--- +title: Add HTTP clone analyzer +merge_request: 1338 +author: +type: other -- GitLab From f425b4b86356aef1738b60cfd62174a37ef75eff Mon Sep 17 00:00:00 2001 From: Jacob Vosmaer Date: Fri, 28 Jun 2019 12:41:26 +0200 Subject: [PATCH 07/11] Use msg helper --- cmd/gitaly-debug/analyzehttp.go | 33 +++++++++++++++++---------------- 1 file changed, 17 insertions(+), 16 deletions(-) diff --git a/cmd/gitaly-debug/analyzehttp.go b/cmd/gitaly-debug/analyzehttp.go index 460a0268eb..7245edff72 100644 --- a/cmd/gitaly-debug/analyzehttp.go +++ b/cmd/gitaly-debug/analyzehttp.go @@ -4,7 +4,6 @@ import ( "bytes" "compress/gzip" "fmt" - "log" "net/http" "os" "strings" @@ -32,11 +31,12 @@ func doBenchGet(cloneURL string) []string { } start := time.Now() + msg("GET %v", req.URL) resp, err := http.DefaultClient.Do(req) noError(err) - log.Printf("GET response header: %v", resp.Header) - log.Printf("GET code %d", resp.StatusCode) + msg("GET response header: %v", resp.Header) + msg("GET code %d", resp.StatusCode) defer resp.Body.Close() var wants []string @@ -54,7 +54,7 @@ func doBenchGet(cloneURL string) []string { switch packets { case 0: - log.Printf("GET first packet %v", time.Since(start)) + msg("GET first packet %v", time.Since(start)) if data != "# service=git-upload-pack\n" { fatal(fmt.Errorf("unexpected header %q", data)) } @@ -87,9 +87,9 @@ func doBenchGet(cloneURL string) []string { fatal("missing flush in response") } - log.Printf("GET: %d packets", packets) - log.Printf("GET done %v", time.Since(start)) - log.Printf("GET data %d bytes", size) + msg("GET: %d packets", packets) + msg("GET done %v", time.Since(start)) + msg("GET data %d bytes", size) return wants } @@ -122,11 +122,12 @@ func doBenchPost(cloneURL string, wants []string) { } start := time.Now() + msg("POST %v", req.URL) resp, err := http.DefaultClient.Do(req) noError(err) - log.Printf("POST response header: %v", resp.Header) - log.Printf("POST code %d", resp.StatusCode) + msg("POST response header: %v", resp.Header) + msg("POST code %d", resp.StatusCode) defer resp.Body.Close() packets := 0 @@ -148,7 +149,7 @@ func doBenchPost(cloneURL string, wants []string) { if !bytes.Equal([]byte("NAK\n"), data) { fatal(fmt.Errorf("expected NAK, got %q", data)) } - log.Printf("NAK after %v", time.Since(start)) + msg("NAK after %v", time.Since(start)) default: if pktline.IsFlush(scanner.Bytes()) { seenFlush = true @@ -164,7 +165,7 @@ func doBenchPost(cloneURL string, wants []string) { fatal(fmt.Errorf("invalid sideband: %d", band)) } if sideBandHistogram[band] == 0 { - log.Printf("first %s packet after %v", bandToHuman(band), time.Since(start)) + msg("first %s packet after %v", bandToHuman(band), time.Since(start)) } sideBandHistogram[band]++ @@ -186,13 +187,13 @@ func doBenchPost(cloneURL string, wants []string) { fatal("POST response did not end in flush") } - log.Printf("POST: %d packets", packets) - log.Printf("POST done %v", time.Since(start)) + msg("POST: %d packets", packets) + msg("POST done %v", time.Since(start)) for i := byte(1); i <= 3; i++ { - log.Printf("data in %s band: %d bytes", bandToHuman(i), totalSize[i]) + msg("data in %s band: %d bytes", bandToHuman(i), totalSize[i]) } - log.Printf("POST packet payload size histogram: %v", payloadSizeHistogram) - log.Printf("POST packet sideband histogram: %v", sideBandHistogram) + msg("POST packet payload size histogram: %v", payloadSizeHistogram) + msg("POST packet sideband histogram: %v", sideBandHistogram) } func bandToHuman(b byte) string { -- GitLab From e142ad99ad4e56b835d5832c46449a776917538c Mon Sep 17 00:00:00 2001 From: Jacob Vosmaer Date: Fri, 28 Jun 2019 12:49:06 +0200 Subject: [PATCH 08/11] Use if instead of switch --- cmd/gitaly-debug/analyzehttp.go | 52 ++++++++++++++++++--------------- 1 file changed, 28 insertions(+), 24 deletions(-) diff --git a/cmd/gitaly-debug/analyzehttp.go b/cmd/gitaly-debug/analyzehttp.go index 7245edff72..15b93772e7 100644 --- a/cmd/gitaly-debug/analyzehttp.go +++ b/cmd/gitaly-debug/analyzehttp.go @@ -35,6 +35,7 @@ func doBenchGet(cloneURL string) []string { resp, err := http.DefaultClient.Do(req) noError(err) + msg("GET response after %v", time.Since(start)) msg("GET response header: %v", resp.Header) msg("GET code %d", resp.StatusCode) defer resp.Body.Close() @@ -126,6 +127,7 @@ func doBenchPost(cloneURL string, wants []string) { resp, err := http.DefaultClient.Do(req) noError(err) + msg("POST response after %v", time.Since(start)) msg("POST response header: %v", resp.Header) msg("POST code %d", resp.StatusCode) defer resp.Body.Close() @@ -144,44 +146,46 @@ func doBenchPost(cloneURL string, wants []string) { data := pktline.Data(scanner.Bytes()) - switch packets { - case 0: + if packets == 0 { if !bytes.Equal([]byte("NAK\n"), data) { fatal(fmt.Errorf("expected NAK, got %q", data)) } msg("NAK after %v", time.Since(start)) - default: - if pktline.IsFlush(scanner.Bytes()) { - seenFlush = true - continue - } + continue + } - if len(data) == 0 { - fatal("empty packet in PACK data") - } + if pktline.IsFlush(scanner.Bytes()) { + seenFlush = true + continue + } - band := data[0] - if band < 1 || band > 3 { - fatal(fmt.Errorf("invalid sideband: %d", band)) - } - if sideBandHistogram[band] == 0 { - msg("first %s packet after %v", bandToHuman(band), time.Since(start)) - } + if len(data) == 0 { + fatal("empty packet in PACK data") + } - sideBandHistogram[band]++ + band := data[0] + if band < 1 || band > 3 { + fatal(fmt.Errorf("invalid sideband: %d", band)) + } + if sideBandHistogram[band] == 0 { + msg("first %s packet after %v", bandToHuman(band), time.Since(start)) + } - n := len(data[1:]) - totalSize[band] += int64(n) - payloadSizeHistogram[n]++ + sideBandHistogram[band]++ - if progress && packets%100 == 0 && packets > 0 && band == 1 { - fmt.Printf(".") - } + n := len(data[1:]) + totalSize[band] += int64(n) + payloadSizeHistogram[n]++ + + if progress && packets%100 == 0 && packets > 0 && band == 1 { + fmt.Printf(".") } } + if progress { fmt.Println("") } + noError(scanner.Err()) if !seenFlush { fatal("POST response did not end in flush") -- GitLab From ed71160f435756db3b4ec4a884b9a638f397039b Mon Sep 17 00:00:00 2001 From: Jacob Vosmaer Date: Wed, 3 Jul 2019 13:08:53 +0200 Subject: [PATCH 09/11] Change output, add comments --- cmd/gitaly-debug/analyzehttp.go | 67 ++++++++++++++++++++------------- 1 file changed, 41 insertions(+), 26 deletions(-) diff --git a/cmd/gitaly-debug/analyzehttp.go b/cmd/gitaly-debug/analyzehttp.go index 15b93772e7..c645b7ef32 100644 --- a/cmd/gitaly-debug/analyzehttp.go +++ b/cmd/gitaly-debug/analyzehttp.go @@ -5,7 +5,6 @@ import ( "compress/gzip" "fmt" "net/http" - "os" "strings" "time" @@ -31,20 +30,31 @@ func doBenchGet(cloneURL string) []string { } start := time.Now() - msg("GET %v", req.URL) + msg("---") + msg("--- GET %v", req.URL) + msg("---") resp, err := http.DefaultClient.Do(req) noError(err) - msg("GET response after %v", time.Since(start)) - msg("GET response header: %v", resp.Header) - msg("GET code %d", resp.StatusCode) + msg("response after %v", time.Since(start)) + msg("response header: %v", resp.Header) + msg("HTTP status code %d", resp.StatusCode) defer resp.Body.Close() + // Expected response: + // - "# service=git-upload-pack\n" + // - FLUSH + // - " \n" + // - " \n" + // - ... + // - FLUSH + // var wants []string var size int64 seenFlush := false scanner := pktline.NewScanner(resp.Body) packets := 0 + refs := 0 for ; scanner.Scan(); packets++ { if seenFlush { fatal("received packet after flush") @@ -52,10 +62,9 @@ func doBenchGet(cloneURL string) []string { data := string(pktline.Data(scanner.Bytes())) size += int64(len(data)) - switch packets { case 0: - msg("GET first packet %v", time.Since(start)) + msg("first packet %v", time.Since(start)) if data != "# service=git-upload-pack\n" { fatal(fmt.Errorf("unexpected header %q", data)) } @@ -77,6 +86,7 @@ func doBenchGet(cloneURL string) []string { if len(split) != 2 { continue } + refs++ if strings.HasPrefix(split[1], "refs/heads/") || strings.HasPrefix(split[1], "refs/tags/") { wants = append(wants, split[0]) @@ -88,9 +98,10 @@ func doBenchGet(cloneURL string) []string { fatal("missing flush in response") } - msg("GET: %d packets", packets) - msg("GET done %v", time.Since(start)) - msg("GET data %d bytes", size) + msg("received %d packets", packets) + msg("done in %v", time.Since(start)) + msg("payload data: %d bytes", size) + msg("received %d refs, selected %d wants", refs, len(wants)) return wants } @@ -123,21 +134,28 @@ func doBenchPost(cloneURL string, wants []string) { } start := time.Now() - msg("POST %v", req.URL) + msg("---") + msg("--- POST %v", req.URL) + msg("---") resp, err := http.DefaultClient.Do(req) noError(err) - msg("POST response after %v", time.Since(start)) - msg("POST response header: %v", resp.Header) - msg("POST code %d", resp.StatusCode) + msg("response after %v", time.Since(start)) + msg("response header: %v", resp.Header) + msg("HTTP status code %d", resp.StatusCode) defer resp.Body.Close() + // Expected response: + // - "NAK\n" + // - " + // - ... + // - FLUSH + // packets := 0 scanner := pktline.NewScanner(resp.Body) totalSize := make(map[byte]int64) payloadSizeHistogram := make(map[int]int) sideBandHistogram := make(map[byte]int) - progress := os.Getenv("PROGRESS") == "1" seenFlush := false for ; scanner.Scan(); packets++ { if seenFlush { @@ -150,7 +168,7 @@ func doBenchPost(cloneURL string, wants []string) { if !bytes.Equal([]byte("NAK\n"), data) { fatal(fmt.Errorf("expected NAK, got %q", data)) } - msg("NAK after %v", time.Since(start)) + msg("received NAK after %v", time.Since(start)) continue } @@ -168,7 +186,7 @@ func doBenchPost(cloneURL string, wants []string) { fatal(fmt.Errorf("invalid sideband: %d", band)) } if sideBandHistogram[band] == 0 { - msg("first %s packet after %v", bandToHuman(band), time.Since(start)) + msg("received first %s packet after %v", bandToHuman(band), time.Since(start)) } sideBandHistogram[band]++ @@ -177,27 +195,24 @@ func doBenchPost(cloneURL string, wants []string) { totalSize[band] += int64(n) payloadSizeHistogram[n]++ - if progress && packets%100 == 0 && packets > 0 && band == 1 { + if packets%100 == 0 && packets > 0 && band == 1 { fmt.Printf(".") } } - if progress { - fmt.Println("") - } + fmt.Println("") // Trailing newline for progress dots. noError(scanner.Err()) if !seenFlush { fatal("POST response did not end in flush") } - msg("POST: %d packets", packets) - msg("POST done %v", time.Since(start)) + msg("received %d packets", packets) + msg("done in %v", time.Since(start)) for i := byte(1); i <= 3; i++ { - msg("data in %s band: %d bytes", bandToHuman(i), totalSize[i]) + msg("%8s band: %10d payload bytes, %6d packets", bandToHuman(i), totalSize[i], sideBandHistogram[i]) } - msg("POST packet payload size histogram: %v", payloadSizeHistogram) - msg("POST packet sideband histogram: %v", sideBandHistogram) + msg("packet payload size histogram: %v", payloadSizeHistogram) } func bandToHuman(b byte) string { -- GitLab From 5ef99f50850d9497954e03b62cf4940804d8e1b6 Mon Sep 17 00:00:00 2001 From: Jacob Vosmaer Date: Wed, 3 Jul 2019 13:10:56 +0200 Subject: [PATCH 10/11] Also put simulate in its own file --- cmd/gitaly-debug/main.go | 68 ---------------------------------------- 1 file changed, 68 deletions(-) diff --git a/cmd/gitaly-debug/main.go b/cmd/gitaly-debug/main.go index 727f9bd3cd..96361caa6c 100644 --- a/cmd/gitaly-debug/main.go +++ b/cmd/gitaly-debug/main.go @@ -1,15 +1,8 @@ package main import ( - "bufio" - "bytes" "fmt" - "io" - "io/ioutil" "os" - "os/exec" - "regexp" - "time" ) const ( @@ -50,67 +43,6 @@ func main() { } } -func simulateHTTPClone(gitDir string) { - - msg("Generating server response for HTTP clone. Data goes to /dev/null.") - infoRefs := exec.Command("git", "upload-pack", "--stateless-rpc", "--advertise-refs", gitDir) - infoRefs.Stderr = os.Stderr - out, err := infoRefs.StdoutPipe() - noError(err) - - start := time.Now() - noError(infoRefs.Start()) - - infoScanner := bufio.NewScanner(out) - var infoLines []string - for infoScanner.Scan() { - infoLines = append(infoLines, infoScanner.Text()) - } - noError(infoScanner.Err()) - - noError(infoRefs.Wait()) - - msg("simulated GET \"/info/refs?service=git-upload-pack\" returned %d lines, took %v", len(infoLines), time.Since(start)) - - if len(infoLines) == 0 { - fatal("no refs were advertised") - } - - request := &bytes.Buffer{} - refsHeads := regexp.MustCompile(`^[a-f0-9]{44} refs/heads/`) - firstLine := true - for _, line := range infoLines { - if !refsHeads.MatchString(line) { - continue - } - - commitID := line[4:44] - - if firstLine { - firstLine = false - fmt.Fprintf(request, "0098want %s multi_ack_detailed no-done side-band-64k thin-pack ofs-delta deepen-since deepen-not agent=git/2.19.1\n", commitID) - continue - } - - fmt.Fprintf(request, "0032want %s\n", commitID) - } - fmt.Fprint(request, "00000009done\n") - - uploadPack := exec.Command("git", "upload-pack", "--stateless-rpc", gitDir) - uploadPack.Stdin = request - uploadPack.Stderr = os.Stderr - out, err = uploadPack.StdoutPipe() - noError(err) - - start = time.Now() - noError(uploadPack.Start()) - - n, err := io.Copy(ioutil.Discard, out) - noError(err) - - msg("simulated POST \"/git-upload-pack\" returned %s, took %v", humanBytes(n), time.Since(start)) -} - func noError(err error) { if err != nil { fatal(err) -- GitLab From 2695bfc980ae85d1318ecfb701ed50499e43e1e3 Mon Sep 17 00:00:00 2001 From: Jacob Vosmaer Date: Wed, 3 Jul 2019 13:11:44 +0200 Subject: [PATCH 11/11] Oops missing file --- cmd/gitaly-debug/simulatehttp.go | 73 ++++++++++++++++++++++++++++++++ 1 file changed, 73 insertions(+) create mode 100644 cmd/gitaly-debug/simulatehttp.go diff --git a/cmd/gitaly-debug/simulatehttp.go b/cmd/gitaly-debug/simulatehttp.go new file mode 100644 index 0000000000..31b3766fc4 --- /dev/null +++ b/cmd/gitaly-debug/simulatehttp.go @@ -0,0 +1,73 @@ +package main + +import ( + "bufio" + "bytes" + "fmt" + "io" + "io/ioutil" + "os" + "os/exec" + "regexp" + "time" +) + +func simulateHTTPClone(gitDir string) { + msg("Generating server response for HTTP clone. Data goes to /dev/null.") + infoRefs := exec.Command("git", "upload-pack", "--stateless-rpc", "--advertise-refs", gitDir) + infoRefs.Stderr = os.Stderr + out, err := infoRefs.StdoutPipe() + noError(err) + + start := time.Now() + noError(infoRefs.Start()) + + infoScanner := bufio.NewScanner(out) + var infoLines []string + for infoScanner.Scan() { + infoLines = append(infoLines, infoScanner.Text()) + } + noError(infoScanner.Err()) + + noError(infoRefs.Wait()) + + msg("simulated GET \"/info/refs?service=git-upload-pack\" returned %d lines, took %v", len(infoLines), time.Since(start)) + + if len(infoLines) == 0 { + fatal("no refs were advertised") + } + + request := &bytes.Buffer{} + refsHeads := regexp.MustCompile(`^[a-f0-9]{44} refs/heads/`) + firstLine := true + for _, line := range infoLines { + if !refsHeads.MatchString(line) { + continue + } + + commitID := line[4:44] + + if firstLine { + firstLine = false + fmt.Fprintf(request, "0098want %s multi_ack_detailed no-done side-band-64k thin-pack ofs-delta deepen-since deepen-not agent=git/2.19.1\n", commitID) + continue + } + + fmt.Fprintf(request, "0032want %s\n", commitID) + } + fmt.Fprint(request, "00000009done\n") + + uploadPack := exec.Command("git", "upload-pack", "--stateless-rpc", gitDir) + uploadPack.Stdin = request + uploadPack.Stderr = os.Stderr + out, err = uploadPack.StdoutPipe() + noError(err) + + start = time.Now() + noError(uploadPack.Start()) + + n, err := io.Copy(ioutil.Discard, out) + noError(err) + + msg("simulated POST \"/git-upload-pack\" returned %s, took %v", humanBytes(n), time.Since(start)) +} -- GitLab