Merge pull request kubernetes#82588 from liggitt/abort-handler-panic

Propagate and honor http.ErrAbortHandler

Author: k8s-ci-robot

staging/src/k8s.io/apimachinery/pkg/util/runtime/runtime.go

@@ -18,6 +18,7 @@ package runtime
 
 import (
 	"fmt"
+	"net/http"
 	"runtime"
 	"sync"
 	"time"
@@ -56,8 +57,16 @@ func HandleCrash(additionalHandlers ...func(interface{})) {
 	}
 }
 
-// logPanic logs the caller tree when a panic occurs.
+// logPanic logs the caller tree when a panic occurs (except in the special case of http.ErrAbortHandler).
 func logPanic(r interface{}) {
+	if r == http.ErrAbortHandler {
+		// honor the http.ErrAbortHandler sentinel panic value:
+		//   ErrAbortHandler is a sentinel panic value to abort a handler.
+		//   While any panic from ServeHTTP aborts the response to the client,
+		//   panicking with ErrAbortHandler also suppresses logging of a stack trace to the server's error log.
+		return
+	}
+
 	// Same as stdlib http server code. Manually allocate stack trace buffer size
 	// to prevent excessively large logs
 	const size = 64 << 10

staging/src/k8s.io/apimachinery/pkg/util/runtime/runtime_test.go

@@ -20,6 +20,7 @@ import (
 	"bytes"
 	"fmt"
 	"io"
+	"net/http"
 	"os"
 	"regexp"
 	"strings"
@@ -114,6 +115,24 @@ func TestHandleCrashLog(t *testing.T) {
 	}
 }
 
+func TestHandleCrashLogSilenceHTTPErrAbortHandler(t *testing.T) {
+	log, err := captureStderr(func() {
+		defer func() {
+			if r := recover(); r != http.ErrAbortHandler {
+				t.Fatalf("expected to recover from http.ErrAbortHandler")
+			}
+		}()
+		defer HandleCrash()
+		panic(http.ErrAbortHandler)
+	})
+	if err != nil {
+		t.Fatalf("%v", err)
+	}
+	if len(log) > 0 {
+		t.Fatalf("expected no stderr log, got: %s", log)
+	}
+}
+
 // captureStderr redirects stderr to result string, and then restore stderr from backup
 func captureStderr(f func()) (string, error) {
 	r, w, err := os.Pipe()

staging/src/k8s.io/apiserver/pkg/endpoints/handlers/rest.go

@@ -220,12 +220,15 @@ func finishRequest(timeout time.Duration, fn resultFunc) (result runtime.Object,
 		defer func() {
 			panicReason := recover()
 			if panicReason != nil {
-				// Same as stdlib http server code. Manually allocate stack
-				// trace buffer size to prevent excessively large logs
-				const size = 64 << 10
-				buf := make([]byte, size)
-				buf = buf[:goruntime.Stack(buf, false)]
-				panicReason = fmt.Sprintf("%v\n%s", panicReason, buf)
+				// do not wrap the sentinel ErrAbortHandler panic value
+				if panicReason != http.ErrAbortHandler {
+					// Same as stdlib http server code. Manually allocate stack
+					// trace buffer size to prevent excessively large logs
+					const size = 64 << 10
+					buf := make([]byte, size)
+					buf = buf[:goruntime.Stack(buf, false)]
+					panicReason = fmt.Sprintf("%v\n%s", panicReason, buf)
+				}
 				// Propagate to parent goroutine
 				panicCh <- panicReason
 			}

staging/src/k8s.io/apiserver/pkg/endpoints/handlers/rest_test.go

@@ -849,6 +849,8 @@ func TestFinishRequest(t *testing.T) {
 		expectedObj   runtime.Object
 		expectedErr   error
 		expectedPanic string
+
+		expectedPanicObj interface{}
 	}{
 		{
 			name:    "Expected obj is returned",
@@ -906,6 +908,17 @@ func TestFinishRequest(t *testing.T) {
 			expectedErr:   nil,
 			expectedPanic: "rest_test.go",
 		},
+		{
+			name:    "http.ErrAbortHandler panic is propagated without wrapping with stack",
+			timeout: time.Second,
+			fn: func() (runtime.Object, error) {
+				panic(http.ErrAbortHandler)
+			},
+			expectedObj:      nil,
+			expectedErr:      nil,
+			expectedPanic:    http.ErrAbortHandler.Error(),
+			expectedPanicObj: http.ErrAbortHandler,
+		},
 	}
 	for i, tc := range testcases {
 		t.Run(tc.name, func(t *testing.T) {
@@ -919,6 +932,10 @@ func TestFinishRequest(t *testing.T) {
 				case r != nil && len(tc.expectedPanic) > 0 && !strings.Contains(fmt.Sprintf("%v", r), tc.expectedPanic):
 					t.Errorf("expected panic containing '%s', got '%v'", tc.expectedPanic, r)
 				}
+
+				if tc.expectedPanicObj != nil && !reflect.DeepEqual(tc.expectedPanicObj, r) {
+					t.Errorf("expected panic obj %#v, got %#v", tc.expectedPanicObj, r)
+				}
 			}()
 			obj, err := finishRequest(tc.timeout, tc.fn)
 			if (err == nil && tc.expectedErr != nil) || (err != nil && tc.expectedErr == nil) || (err != nil && tc.expectedErr != nil && err.Error() != tc.expectedErr.Error()) {

staging/src/k8s.io/apiserver/pkg/server/filters/timeout.go

@@ -98,7 +98,8 @@ func (t *timeoutHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 	go func() {
 		defer func() {
 			err := recover()
-			if err != nil {
+			// do not wrap the sentinel ErrAbortHandler panic value
+			if err != nil && err != http.ErrAbortHandler {
 				// Same as stdlib http server code. Manually allocate stack
 				// trace buffer size to prevent excessively large logs
 				const size = 64 << 10

staging/src/k8s.io/apiserver/pkg/server/filters/timeout_test.go

@@ -52,14 +52,14 @@ func (r *recorder) Count() int {
 	return r.count
 }
 
-func newHandler(responseCh <-chan string, panicCh <-chan struct{}, writeErrCh chan<- error) http.HandlerFunc {
+func newHandler(responseCh <-chan string, panicCh <-chan interface{}, writeErrCh chan<- error) http.HandlerFunc {
 	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
 		select {
 		case resp := <-responseCh:
 			_, err := w.Write([]byte(resp))
 			writeErrCh <- err
-		case <-panicCh:
-			panic("inner handler panics")
+		case panicReason := <-panicCh:
+			panic(panicReason)
 		}
 	})
 }
@@ -72,7 +72,7 @@ func TestTimeout(t *testing.T) {
 	}()
 
 	sendResponse := make(chan string, 1)
-	doPanic := make(chan struct{}, 1)
+	doPanic := make(chan interface{}, 1)
 	writeErrors := make(chan error, 1)
 	gotPanic := make(chan interface{}, 1)
 	timeout := make(chan time.Time, 1)
@@ -139,7 +139,7 @@ func TestTimeout(t *testing.T) {
 	}
 
 	// Panics
-	doPanic <- struct{}{}
+	doPanic <- "inner handler panics"
 	res, err = http.Get(ts.URL)
 	if err != nil {
 		t.Fatal(err)
@@ -156,4 +156,22 @@ func TestTimeout(t *testing.T) {
 	case <-time.After(30 * time.Second):
 		t.Fatalf("expected to see a handler panic, but didn't")
 	}
+
+	// Panics with http.ErrAbortHandler
+	doPanic <- http.ErrAbortHandler
+	res, err = http.Get(ts.URL)
+	if err != nil {
+		t.Fatal(err)
+	}
+	if res.StatusCode != http.StatusInternalServerError {
+		t.Errorf("got res.StatusCode %d; expected %d due to panic", res.StatusCode, http.StatusInternalServerError)
+	}
+	select {
+	case err := <-gotPanic:
+		if err != http.ErrAbortHandler {
+			t.Errorf("expected unwrapped http.ErrAbortHandler, got %#v", err)
+		}
+	case <-time.After(30 * time.Second):
+		t.Fatalf("expected to see a handler panic, but didn't")
+	}
 }

staging/src/k8s.io/apiserver/pkg/server/filters/wrap.go

@@ -25,9 +25,16 @@ import (
 	"k8s.io/apiserver/pkg/server/httplog"
 )
 
-// WithPanicRecovery wraps an http Handler to recover and log panics.
+// WithPanicRecovery wraps an http Handler to recover and log panics (except in the special case of http.ErrAbortHandler panics, which suppress logging).
 func WithPanicRecovery(handler http.Handler) http.Handler {
 	return withPanicRecovery(handler, func(w http.ResponseWriter, req *http.Request, err interface{}) {
+		if err == http.ErrAbortHandler {
+			// honor the http.ErrAbortHandler sentinel panic value:
+			//   ErrAbortHandler is a sentinel panic value to abort a handler.
+			//   While any panic from ServeHTTP aborts the response to the client,
+			//   panicking with ErrAbortHandler also suppresses logging of a stack trace to the server's error log.
+			return
+		}
 		http.Error(w, "This request caused apiserver to panic. Look in the logs for details.", http.StatusInternalServerError)
 		klog.Errorf("apiserver panic'd on %v %v", req.Method, req.RequestURI)
 	})