Repository: istio/fortio (go)

Issue:
runtime error: slice bounds out of range panic fhttp.(*BasicClient).readResponse istio.io/fortio/fhttp/http.go:718

https://k8s-gubernator.appspot.com/build/istio-prow/pull/istio_istio/1041/e2e-suite-rbac-auth/810/

```
I0215 03:13:51.270] === RUN   Test503sDuringChanges
I0215 03:13:51.270] 2018-02-15T03:13:51.268953Z	info	I httprunner.go:72> Starting http test for http://35.194.88.83/fortio/debug with 8 threads at 8.0 qps
I0215 03:13:52.329] Starting at 8 qps with 8 thread(s) [gomax 4] for 20s : 20 calls each (total 160)
I0215 03:14:00.269] 2018-02-15T03:14:00.269235Z	info	Changing rules mid run to v1/v2
I0215 03:14:00.270] 2018-02-15T03:14:00.269420Z	info	Running command /home/bootstrap/go/out/linux_amd64/release/istioctl -n simple-auth-test-bb09b462ca5b49788df8 create -f /home/bootstrap/go/src/istio.io/istio/tests/e2e/tests/simple/routingrule1.yaml
I0215 03:14:00.592] 2018-02-15T03:14:00.592542Z	info	Command output: 
I0215 03:14:00.593]  Created config route-rule/simple-auth-test-bb09b462ca5b49788df8/rule-1 at revision 3798854
I0215 03:14:00.593] , err: <nil>
W0215 03:14:02.945] panic: runtime error: slice bounds out of range
W0215 03:14:02.945] 
W0215 03:14:02.945] goroutine 71 [running]:
W0215 03:14:02.945] istio.io/istio/vendor/istio.io/fortio/fhttp.(*BasicClient).readResponse(0xc42020a2a0, 0xc42000e038)
W0215 03:14:02.945] 	/home/bootstrap/go/src/istio.io/istio/vendor/istio.io/fortio/fhttp/http.go:718 +0x210b
W0215 03:14:02.945] istio.io/istio/vendor/istio.io/fortio/fhttp.(*BasicClient).Fetch(0xc42020a2a0, 0xd, 0xc4204d1c50, 0x1, 0x1, 0xc4204d1c38)
W0215 03:14:02.945] 	/home/bootstrap/go/src/istio.io/istio/vendor/istio.io/fortio/fhttp/http.go:601 +0x460
W0215 03:14:02.946] istio.io/istio/vendor/istio.io/fortio/fhttp.(*HTTPRunnerResults).Run(0xc420091d90, 0x2)
W0215 03:14:02.946] 	/home/bootstrap/go/src/istio.io/istio/vendor/istio.io/fortio/fhttp/httprunner.go:52 +0xd7
W0215 03:14:02.946] istio.io/istio/vendor/istio.io/fortio/periodic.runOne(0x2, 0xc42001a180, 0xc42008cb40, 0xc42008cb90, 0x14, 0xbe995c9c13976f9f, 0x209644baf1, 0xdccb00, 0xc4204c6080)
W0215 03:14:02.946] 	/home/bootstrap/go/src/istio.io/istio/vendor/istio.io/fortio/periodic/periodic.go:481 +0x235
W0215 03:14:02.946] istio.io/istio/vendor/istio.io/fortio/periodic.(*periodicRunner).Run.func1(0xc42001a180, 0x14, 0xbe995c9c13976f9f, 0x209644baf1, 0xdccb00, 0xc4204c6080, 0xc420016c90, 0x2, 0xc42008cb40, 0xc42008cb90)
W0215 03:14:02.946] 	/home/bootstrap/go/src/istio.io/istio/vendor/istio.io/fortio/periodic/periodic.go:398 +0x8b
W0215 03:14:02.946] created by istio.io/istio/vendor/istio.io/fortio/periodic.(*periodicRunner).Run
W0215 03:14:02.946] 	/home/bootstrap/go/src/istio.io/istio/vendor/istio.io/fortio/periodic/periodic.go:397 +0x4e3
W0215 03:14:02.964] make: *** [e2e_simple] Error 1
```

Pull request:
Fixing panic bug when first chunk size is not in read buffer
Fixes #127
Fixes https://github.com/istio/istio/issues/3585

Manual tested by cutting a http response just after headers in o1 and
rest in o2:
(cat /tmp/o1; sleep 10; cat /tmp/o2) | nc -v -l 8085

fortio curl -loglevel debug http://127.0.0.1:8085/ > /tmp/f

Without fix == crash, with fix
08:31:27 D http.go:486> ParseChunkSize()
08:31:27 V http.go:718> chunk mode but no chunk length yet, reading more

Patch:
diff --git a/Gopkg.toml b/Gopkg.toml
index b901a8c..e28fdf6 100644
--- a/Gopkg.toml
+++ b/Gopkg.toml
@@ -4,6 +4,8 @@
 # for detailed Gopkg.toml documentation.
 #
 
+# DO NOT ADD MORE DEPENDENCIES TO FORTIO
+
 [[constraint]]
   name = "github.com/golang/protobuf"
   version = "1.0.0"
diff --git a/fhttp/http.go b/fhttp/http.go
index 1806382..0988d90 100644
--- a/fhttp/http.go
+++ b/fhttp/http.go
@@ -713,6 +713,12 @@ func (c *BasicClient) readResponse(conn *net.TCPConn) {
 							chunkedMode = true
 							var dataStart int
 							dataStart, contentLength = ParseChunkSize(c.buffer[c.headerLen:c.size])
+							if contentLength == -1 {
+								// chunk length not available yet
+								log.LogVf("chunk mode but no first chunk length yet, reading more")
+								max = c.headerLen
+								continue
+							}
 							max = c.headerLen + dataStart + contentLength + 2 // extra CR LF
 							log.Debugf("chunk-length is %d (%s) setting max to %d",
 								contentLength, c.buffer[c.headerLen:c.headerLen+dataStart-2],


Test patch:
diff --git a/fhttp/http_loglevel_test.go b/fhttp/http_loglevel_test.go
index 5217d80..306b7d7 100644
--- a/fhttp/http_loglevel_test.go
+++ b/fhttp/http_loglevel_test.go
@@ -28,4 +28,5 @@ import (
 func TestDebugMode(t *testing.T) {
 	log.SetLogLevel(log.Debug)
 	TestHTTPRunner(t)
+	TestNoFirstChunkSizeInitially(t)
 }
diff --git a/fhttp/http_test.go b/fhttp/http_test.go
index ecfeb6e..b9bfff9 100644
--- a/fhttp/http_test.go
+++ b/fhttp/http_test.go
@@ -482,6 +482,36 @@ func TestEchoBack(t *testing.T) {
 	}
 }
 
+// Test for bug #127
+
+var testBody = "delayedChunkedSize-body"
+
+func delayedChunkedSize(w http.ResponseWriter, r *http.Request) {
+	log.LogVf("delayedChunkedSize %v %v %v %v", r.Method, r.URL, r.Proto, r.RemoteAddr)
+	w.WriteHeader(http.StatusOK)
+	flusher, _ := w.(http.Flusher)
+	flusher.Flush()
+	time.Sleep(1 * time.Second)
+	w.Write([]byte(testBody))
+}
+
+func TestNoFirstChunkSizeInitially(t *testing.T) {
+	p, m := DynamicHTTPServer(false)
+	m.HandleFunc("/", delayedChunkedSize)
+	url := fmt.Sprintf("http://localhost:%d/delayedChunkedSize", p)
+	o := HTTPOptions{URL: url}
+	client := NewClient(&o)
+	code, data, header := client.Fetch() // used to panic/bug #127
+	log.LogVf("delayedChunkedSize result code %d, data len %d, headerlen %d", code, len(data), header)
+	if code != 200 {
+		t.Errorf("Got %d instead of 200", code)
+	}
+	expected := "17\r\n" + testBody + "\r\n0\r\n\r\n" // 17 is hex size of testBody
+	if string(data[header:]) != expected {
+		t.Errorf("Got %s not as expected %q at offset %d", DebugSummary(data, 256), expected, header)
+	}
+}
+
 func TestInvalidRequest(t *testing.T) {
 	o := HTTPOptions{
 		URL: "http://www.google.com/", // valid url