diff --git a/middlewares/recover.go b/middlewares/recover.go index bde96326d..88a98629d 100644 --- a/middlewares/recover.go +++ b/middlewares/recover.go @@ -2,6 +2,7 @@ package middlewares import ( "net/http" + "runtime" "github.com/containous/traefik/log" "github.com/urfave/negroni" @@ -10,7 +11,7 @@ import ( // RecoverHandler recovers from a panic in http handlers func RecoverHandler(next http.Handler) http.Handler { fn := func(w http.ResponseWriter, r *http.Request) { - defer recoverFunc(w) + defer recoverFunc(w, r) next.ServeHTTP(w, r) } return http.HandlerFunc(fn) @@ -19,23 +20,31 @@ func RecoverHandler(next http.Handler) http.Handler { // NegroniRecoverHandler recovers from a panic in negroni handlers func NegroniRecoverHandler() negroni.Handler { fn := func(w http.ResponseWriter, r *http.Request, next http.HandlerFunc) { - defer recoverFunc(w) + defer recoverFunc(w, r) next.ServeHTTP(w, r) } return negroni.HandlerFunc(fn) } -func recoverFunc(w http.ResponseWriter) { +func recoverFunc(w http.ResponseWriter, r *http.Request) { if err := recover(); err != nil { - if shouldLogPanic(err) { - log.Errorf("Recovered from panic in http handler: %+v", err) - http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError) - } else { - log.Debugf("HTTP handler has been aborted: %v", err) + if !shouldLogPanic(err) { + log.Debugf("Request has been aborted [%s - %s]: %v", r.RemoteAddr, r.URL, err) + return } + + log.Errorf("Recovered from panic in HTTP handler [%s - %s]: %+v", r.RemoteAddr, r.URL, err) + + const size = 64 << 10 + buf := make([]byte, size) + buf = buf[:runtime.Stack(buf, false)] + log.Errorf("Stack: %s", buf) + + http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError) } } +// https://github.com/golang/go/blob/a0d6420d8be2ae7164797051ec74fa2a2df466a1/src/net/http/server.go#L1761-L1775 // https://github.com/golang/go/blob/c33153f7b416c03983324b3e8f869ce1116d84bc/src/net/http/httputil/reverseproxy.go#L284 func shouldLogPanic(panicValue interface{}) bool { return panicValue != nil && panicValue != http.ErrAbortHandler diff --git a/safe/routine.go b/safe/routine.go index bb2f4fec8..9e810f621 100644 --- a/safe/routine.go +++ b/safe/routine.go @@ -145,7 +145,7 @@ func GoWithRecover(goroutine func(), customRecover func(err interface{})) { func defaultRecoverGoroutine(err interface{}) { log.Errorf("Error in Go routine: %s", err) - debug.PrintStack() + log.Errorf("Stack: %s", debug.Stack()) } // OperationWithRecover wrap a backoff operation in a Recover diff --git a/safe/routine_test.go b/safe/routine_test.go index 6d207dac3..288b9c9b0 100644 --- a/safe/routine_test.go +++ b/safe/routine_test.go @@ -13,9 +13,12 @@ import ( func TestNewPoolContext(t *testing.T) { type testKeyType string testKey := testKeyType("test") + ctx := context.WithValue(context.Background(), testKey, "test") p := NewPool(ctx) + retCtx := p.Ctx() + retCtxVal, ok := retCtx.Value(testKey).(string) if !ok || retCtxVal != "test" { t.Errorf("Pool.Ctx() did not return a derived context, got %#v, expected context with test value", retCtx) @@ -52,7 +55,8 @@ func (tr *fakeRoutine) routine(stop chan bool) { func TestPoolWithCtx(t *testing.T) { testRoutine := newFakeRoutine() - tt := []struct { + + testCases := []struct { desc string fn func(*Pool) }{ @@ -70,19 +74,20 @@ func TestPoolWithCtx(t *testing.T) { }, }, } - for _, tc := range tt { - tc := tc - t.Run(tc.desc, func(t *testing.T) { + + for _, test := range testCases { + test := test + t.Run(test.desc, func(t *testing.T) { // These subtests cannot be run in parallel, since the testRoutine // is shared across the subtests. p := NewPool(context.Background()) timer := time.NewTimer(500 * time.Millisecond) defer timer.Stop() - tc.fn(p) + test.fn(p) defer p.Cleanup() if len(p.routinesCtx) != 1 { - t.Fatalf("After %s, Pool did have %d goroutineCtxs, expected 1", tc.desc, len(p.routinesCtx)) + t.Fatalf("After %s, Pool did have %d goroutineCtxs, expected 1", test.desc, len(p.routinesCtx)) } testDone := make(chan bool, 1) @@ -91,6 +96,7 @@ func TestPoolWithCtx(t *testing.T) { p.Cleanup() testDone <- true }() + select { case <-timer.C: testRoutine.Lock() @@ -105,8 +111,9 @@ func TestPoolWithCtx(t *testing.T) { func TestPoolWithStopChan(t *testing.T) { testRoutine := newFakeRoutine() - ctx := context.Background() - p := NewPool(ctx) + + p := NewPool(context.Background()) + timer := time.NewTimer(500 * time.Millisecond) defer timer.Stop() @@ -121,6 +128,7 @@ func TestPoolWithStopChan(t *testing.T) { p.Cleanup() testDone <- true }() + select { case <-timer.C: testRoutine.Lock() @@ -133,8 +141,9 @@ func TestPoolWithStopChan(t *testing.T) { func TestPoolStartWithStopChan(t *testing.T) { testRoutine := newFakeRoutine() - ctx := context.Background() - p := NewPool(ctx) + + p := NewPool(context.Background()) + timer := time.NewTimer(500 * time.Millisecond) defer timer.Stop() diff --git a/safe/safe_test.go b/safe/safe_test.go index b5f6f30c3..242ce5509 100644 --- a/safe/safe_test.go +++ b/safe/safe_test.go @@ -5,19 +5,25 @@ import "testing" func TestSafe(t *testing.T) { const ts1 = "test1" const ts2 = "test2" + s := New(ts1) + result, ok := s.Get().(string) if !ok { t.Fatalf("Safe.Get() failed, got type '%T', expected string", s.Get()) } + if result != ts1 { t.Errorf("Safe.Get() failed, got '%s', expected '%s'", result, ts1) } + s.Set(ts2) + result, ok = s.Get().(string) if !ok { t.Fatalf("Safe.Get() after Safe.Set() failed, got type '%T', expected string", s.Get()) } + if result != ts2 { t.Errorf("Safe.Get() after Safe.Set() failed, got '%s', expected '%s'", result, ts2) }