tsweb: add stack trace to panic error msg

Updates #12784

Signed-off-by: Paul Scott <paul@tailscale.com>

tsweb/tsweb.go

@@ -20,6 +20,7 @@ import (
 	"os"
 	"path/filepath"
 	"regexp"
+	"runtime"
 	"strconv"
 	"strings"
 	"sync"
@@ -356,6 +357,13 @@ func (h retHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 	)
 	defer func() {
 		if didPanic {
+			// TODO(icio): When the panic below is eventually caught by
+			// http.Server, it cancels the inlight request and the "500 Internal
+			// Server Error" response we wrote to the client below is never
+			// received, even if we flush it.
+			if f, ok := w.(http.Flusher); ok {
+				f.Flush()
+			}
 			panic(panicRes)
 		}
 	}()
@@ -364,10 +372,16 @@ func (h retHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 			if r := recover(); r != nil {
 				didPanic = true
 				panicRes = r
-				// Even if r is an error, do not wrap it as an error here as
-				// that would allow things like panic(vizerror.New("foo")) which
-				// is really hard to define the behavior of.
-				err = fmt.Errorf("panic: %v", r)
+				if r == http.ErrAbortHandler {
+					err = http.ErrAbortHandler
+				} else {
+					// Even if r is an error, do not wrap it as an error here as
+					// that would allow things like panic(vizerror.New("foo")) which
+					// is really hard to define the behavior of.
+					var stack [10000]byte
+					n := runtime.Stack(stack[:], false)
+					err = fmt.Errorf("panic: %v\n\n%s", r, stack[:n])
+				}
 			}
 		}()
 		return h.rh.ServeHTTPReturn(lw, r)

tsweb/tsweb_test.go

@@ -8,11 +8,13 @@ import (
 	"context"
 	"errors"
 	"fmt"
+	"io"
 	"net"
 	"net/http"
 	"net/http/httptest"
 	"net/url"
 	"strings"
+	"sync/atomic"
 	"testing"
 	"time"
 
@@ -527,6 +529,82 @@ func TestStdHandler(t *testing.T) {
 	}
 }
 
+func TestStdHandler_Panic(t *testing.T) {
+	var r AccessLogRecord
+	h := StdHandler(
+		ReturnHandlerFunc(func(w http.ResponseWriter, r *http.Request) error {
+			panicElsewhere()
+			return nil
+		}),
+		HandlerOptions{
+			Logf: t.Logf,
+			OnCompletion: func(_ *http.Request, alr AccessLogRecord) {
+				r = alr
+			},
+		},
+	)
+
+	// Run our panicking handler in a http.Server which catches and rethrows
+	// any panics.
+	var recovered atomic.Value
+	s := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		defer func() {
+			if r := recovered.Load(); r != nil {
+				panic(r)
+			}
+		}()
+		defer func() {
+			recovered.Store(recover())
+		}()
+		h.ServeHTTP(w, r)
+	}))
+	t.Cleanup(s.Close)
+
+	// Send a request to our server.
+	res, err := http.Get(s.URL)
+	if err != nil {
+		t.Fatal(err)
+	}
+	if recovered.Load() == nil {
+		t.Fatal("expected panic but saw none")
+	}
+
+	// Check that the log message contained the stack trace in the error.
+	var logerr bool
+	if p := "panic: panicked elsewhere\n\ngoroutine "; !strings.HasPrefix(r.Err, p) {
+		t.Errorf("got error prefix %q, want %q", r.Err[:min(len(r.Err), len(p))], p)
+		logerr = true
+	}
+	if s := "\ntailscale.com/tsweb.panicElsewhere("; !strings.Contains(r.Err, s) {
+		t.Errorf("want substr %q, not found", s)
+		logerr = true
+	}
+	if logerr {
+		t.Logf("logger got error: (quoted) %q\n\n(verbatim)\n%s", r.Err, r.Err)
+	}
+
+	t.Run("check_response", func(t *testing.T) {
+		// TODO(icio): Swallow panics? tailscale/tailscale#12784
+		t.SkipNow()
+
+		// Check that the server sent an error response.
+		if res.StatusCode != 500 {
+			t.Errorf("got status code %d, want %d", res.StatusCode, 500)
+		}
+		body, err := io.ReadAll(res.Body)
+		if err != nil {
+			t.Errorf("error reading body: %s", err)
+		} else if want := "internal server error\n"; string(body) != want {
+			t.Errorf("got body %q, want %q", body, want)
+		}
+		res.Body.Close()
+	})
+}
+
+func panicElsewhere() {
+	panic("panicked elsewhere")
+}
+
 func BenchmarkLogNot200(b *testing.B) {
 	b.ReportAllocs()
 	rh := handlerFunc(func(w http.ResponseWriter, r *http.Request) error {