http: make tests quiet, fixing a test race

R=golang-dev, r
CC=golang-dev
https://golang.org/cl/4754044

src/pkg/http/serve_test.go

@@ -110,7 +110,6 @@ func TestConsumingBodyOnNextConn(t *testing.T) {
 	listener := &oneConnListener{conn}
 	handler := func(res ResponseWriter, req *Request) {
 		reqNum++
-		t.Logf("Got request #%d: %v", reqNum, req)
 		ch <- req
 	}
 
@@ -119,7 +118,6 @@ func TestConsumingBodyOnNextConn(t *testing.T) {
 	}()
 
 	var req *Request
-	t.Log("Waiting for first request.")
 	req = <-ch
 	if req == nil {
 		t.Fatal("Got nil first request.")
@@ -129,7 +127,6 @@ func TestConsumingBodyOnNextConn(t *testing.T) {
 			req.Method, "POST")
 	}
 
-	t.Log("Waiting for second request.")
 	req = <-ch
 	if req == nil {
 		t.Fatal("Got nil first request.")
@@ -139,7 +136,6 @@ func TestConsumingBodyOnNextConn(t *testing.T) {
 			req.Method, "POST")
 	}
 
-	t.Log("Waiting for EOF.")
 	if serveerr := <-servech; serveerr != os.EOF {
 		t.Errorf("Serve returned %q; expected EOF", serveerr)
 	}
@@ -788,7 +784,24 @@ func TestZeroLengthPostAndResponse(t *testing.T) {
 }
 
 func TestHandlerPanic(t *testing.T) {
-	log.SetOutput(ioutil.Discard) // is noisy otherwise
+	// Unlike the other tests that set the log output to ioutil.Discard
+	// to quiet the output, this test uses a pipe.  The pipe serves three
+	// purposes:
+	//
+	//   1) The log.Print from the http server (generated by the caught
+	//      panic) will go to the pipe instead of stderr, making the
+	//      output quiet.
+	//
+	//   2) We read from the pipe to verify that the handler
+	//      actually caught the panic and logged something.
+	//
+	//   3) The blocking Read call prevents this TestHandlerPanic
+	//      function from exiting before the HTTP server handler
+	//      finishes crashing. If this text function exited too
+	//      early (and its defer log.SetOutput(os.Stderr) ran),
+	//      then the crash output could spill into the next test.
+	pr, pw := io.Pipe()
+	log.SetOutput(pw)
 	defer log.SetOutput(os.Stderr)
 
 	ts := httptest.NewServer(HandlerFunc(func(ResponseWriter, *Request) {
@@ -799,6 +812,25 @@ func TestHandlerPanic(t *testing.T) {
 	if err == nil {
 		t.Logf("expected an error")
 	}
+
+	// Do a blocking read on the log output pipe so its logging
+	// doesn't bleed into the next test.  But wait only 5 seconds
+	// for it.
+	done := make(chan bool)
+	go func() {
+		buf := make([]byte, 1024)
+		_, err := pr.Read(buf)
+		if err != nil {
+			t.Fatal(err)
+		}
+		done <- true
+	}()
+	select {
+	case <-done:
+		return
+	case <-time.After(5e9):
+		t.Error("expected server handler to log an error")
+	}
 }
 
 func TestNoDate(t *testing.T) {