Setting ENABLE_GZIP=true makes swagger API URL 500 (NPE panic)

[wxiaoguang]

Steps:

1. set server.ENABLE_GZIP=true
2. visit http://localhost:3000/api/swagger
3. panic

PANIC: interface conversion: interface {} is nil, not *context.Context
/usr/local/go/src/runtime/iface.go:262 (0x400eae9)
	panicdottypeE: panic(&TypeAssertionError{iface, have, want, ""})
/Users/user/work/gitea/modules/context/context.go:622 (0x61204b1)
	GetContext: return req.Context().Value(contextKey).(*Context)
/Users/user/work/gitea/modules/web/wrap_convert.go:43 (0x6882ac4)
	convertHandler.func3: ctx := context.GetContext(req)
/Users/user/work/gitea/modules/web/wrap.go:41 (0x688068e)
	wrapInternal.func1: done, deferrable := handler(resp, req, others...)
/usr/local/go/src/net/http/server.go:2084 (0x47f7c62)
	HandlerFunc.ServeHTTP: f(w, r)
/Users/user/go/pkg/mod/github.com/!n!y!times/gziphandler@v1.1.1/gzip.go:338 (0x6bf25da)
	GzipHandlerWithOpts.func1.1: h.ServeHTTP(gw, r)
/usr/local/go/src/net/http/server.go:2084 (0x47f7c62)
	HandlerFunc.ServeHTTP: f(w, r)
/Users/user/work/gitea/modules/web/wrap_convert.go:95 (0x6882390)
	convertHandler.func9: t(next).ServeHTTP(resp, req)
/Users/user/work/gitea/modules/web/wrap.go:41 (0x688068e)
	wrapInternal.func1: done, deferrable := handler(resp, req, others...)
/usr/local/go/src/net/http/server.go:2084 (0x47f7c62)
	HandlerFunc.ServeHTTP: f(w, r)
/Users/user/go/pkg/mod/github.com/go-chi/chi/v5@v5.0.7/mux.go:442 (0x5b175fd)
	(*Mux).routeHTTP: h.ServeHTTP(w, r)
/usr/local/go/src/net/http/server.go:2084 (0x47f7c62)
	HandlerFunc.ServeHTTP: f(w, r)
/Users/user/work/gitea/routers/web/base.go:173 (0x6bf6997)
	Recovery.func1.1: next.ServeHTTP(w, req)
/usr/local/go/src/net/http/server.go:2084 (0x47f7c62)
	HandlerFunc.ServeHTTP: f(w, r)
/Users/user/go/pkg/mod/gitea.com/go-chi/session@v0.0.0-20211218221615-e3605d8b28b8/session.go:257 (0x58bb116)
	Sessioner.func1.1: next.ServeHTTP(w, req)
/usr/local/go/src/net/http/server.go:2084 (0x47f7c62)
	HandlerFunc.ServeHTTP: f(w, r)
/Users/user/work/gitea/modules/web/wrap.go:110 (0x6881827)
	WrapWithPrefix.func1.1: next.ServeHTTP(resp, req)
/usr/local/go/src/net/http/server.go:2084 (0x47f7c62)
	HandlerFunc.ServeHTTP: f(w, r)
/Users/user/go/pkg/mod/github.com/go-chi/chi/v5@v5.0.7/mux.go:71 (0x5b14799)
	(*Mux).ServeHTTP: mx.handler.ServeHTTP(w, r)
/Users/user/go/pkg/mod/github.com/go-chi/chi/v5@v5.0.7/mux.go:314 (0x5b16b23)
	(*Mux).Mount.func1: handler.ServeHTTP(w, r)
/usr/local/go/src/net/http/server.go:2084 (0x47f7c62)
	HandlerFunc.ServeHTTP: f(w, r)
/Users/user/go/pkg/mod/github.com/go-chi/chi/v5@v5.0.7/mux.go:442 (0x5b175fd)
	(*Mux).routeHTTP: h.ServeHTTP(w, r)
/usr/local/go/src/net/http/server.go:2084 (0x47f7c62)
	HandlerFunc.ServeHTTP: f(w, r)
/Users/user/work/gitea/routers/common/middleware.go:79 (0x69286d7)
	Middlewares.func2.1: next.ServeHTTP(resp, req)
/usr/local/go/src/net/http/server.go:2084 (0x47f7c62)
	HandlerFunc.ServeHTTP: f(w, r)
/Users/user/work/gitea/modules/web/routing/logger_manager.go:123 (0x687c61e)
	(*requestRecordsManager).handler.func1: next.ServeHTTP(w, req)
/usr/local/go/src/net/http/server.go:2084 (0x47f7c62)
	HandlerFunc.ServeHTTP: f(w, r)
/Users/user/go/pkg/mod/github.com/go-chi/chi/v5@v5.0.7/middleware/strip.go:30 (0x6923aa1)
	StripSlashes.func1: next.ServeHTTP(w, r)
/usr/local/go/src/net/http/server.go:2084 (0x47f7c62)
	HandlerFunc.ServeHTTP: f(w, r)
/Users/user/go/pkg/mod/github.com/chi-middleware/proxy@v1.1.1/middleware.go:37 (0x691e29b)
	ForwardedHeaders.func1.1: h.ServeHTTP(w, r)
/usr/local/go/src/net/http/server.go:2084 (0x47f7c62)
	HandlerFunc.ServeHTTP: f(w, r)
/Users/user/work/gitea/routers/common/middleware.go:32 (0x69284b1)
	Middlewares.func1.1: next.ServeHTTP(context.NewResponse(resp), req.WithContext(ctx))
/usr/local/go/src/net/http/server.go:2084 (0x47f7c62)
	HandlerFunc.ServeHTTP: f(w, r)
/Users/user/go/pkg/mod/github.com/go-chi/chi/v5@v5.0.7/mux.go:88 (0x5b14927)
	(*Mux).ServeHTTP: mx.handler.ServeHTTP(w, r)
/Users/user/work/gitea/modules/web/route.go:200 (0x687f3c5)
	(*Route).ServeHTTP: r.R.ServeHTTP(w, req)
/usr/local/go/src/net/http/server.go:2916 (0x47fca93)
	serverHandler.ServeHTTP: handler.ServeHTTP(rw, req)
/usr/local/go/src/net/http/server.go:1966 (0x47f6abb)
	(*conn).serve: serverHandler{c.server}.ServeHTTP(w, w.req)
/usr/local/go/src/runtime/asm_amd64.s:1571 (0x4074080)
	goexit: BYTE	$0x90	// NOP

[zeripath]

The next log line tells you where/which handler is causing this:

2022/05/30 21:15:17 [629525d5] router: failed    GET /api/swagger for 127.0.0.1:45120, panic in 349.6ms @ context/context.go:652(context.Auth), err=interface conversion: interface {} is nil, not *context.Context

[zeripath]

Now if I add some tracing into web wrap I see:

2022/05/30 21:45:46 .../web/wrap_convert.go:105:func9() [I] [62952cfa] gziphandler/gzip.go:320(gziphandler.GzipHandlerWithOpts)
2022/05/30 21:45:46 .../web/wrap_convert.go:105:func9() [I] [62952cfa] context/context.go:682(context.Contexter)
2022/05/30 21:45:46 .../web/wrap_convert.go:47:func3() [I] [62952cfa] context/context.go:652(context.Auth)
2022/05/30 21:45:46 .../web/wrap_convert.go:105:func9() [I] [62952cfa] middleware/get_head.go:10(middleware.GetHead)
2022/05/30 21:45:46 .../web/wrap_convert.go:47:func3() [I] [62952cfa] misc/swagger.go:18(misc.Swagger)
2022/05/30 21:45:46 ...s/context/context.go:218:HTML() [D] [62952cfa] Template: swagger/ui
2022/05/30 21:45:47 .../web/wrap_convert.go:47:func3() [I] [62952cfa] context/context.go:652(context.Auth)
PANIC

This double context.Auth check is interesting...

[zeripath]

In fact it gets more interesting if we add some logging in to check the done status within that function

Patch

diff --git a/modules/context/context.go b/modules/context/context.go
index dcc43973c..d851ac875 100644
--- a/modules/context/context.go
+++ b/modules/context/context.go
@@ -230,6 +230,7 @@ func (ctx *Context) HTML(status int, name base.TplName) {
 		}
 		ctx.ServerError("Render failed", err)
 	}
+	ctx.Resp.Flush()
 }
 
 // RenderToString renders the template content to a string
diff --git a/modules/web/wrap_convert.go b/modules/web/wrap_convert.go
index 8dc4e6d62..42e203263 100644
--- a/modules/web/wrap_convert.go
+++ b/modules/web/wrap_convert.go
@@ -10,6 +10,7 @@ import (
 	"net/http"
 
 	"code.gitea.io/gitea/modules/context"
+	"code.gitea.io/gitea/modules/log"
 	"code.gitea.io/gitea/modules/web/routing"
 )
 
@@ -17,72 +18,90 @@ type wrappedHandlerFunc func(resp http.ResponseWriter, req *http.Request, others
 
 func convertHandler(handler interface{}) wrappedHandlerFunc {
 	funcInfo := routing.GetFuncInfo(handler)
+
 	switch t := handler.(type) {
 	case http.HandlerFunc:
 		return func(resp http.ResponseWriter, req *http.Request, others ...wrappedHandlerFunc) (done bool, deferrable func()) {
 			routing.UpdateFuncInfo(req.Context(), funcInfo)
+			log.Info("%v", funcInfo)
 			t(resp, req)
 			if r, ok := resp.(context.ResponseWriter); ok && r.Status() > 0 {
 				done = true
 			}
+			log.Info("%v:%t", funcInfo, done)
 			return
 		}
 	case func(http.ResponseWriter, *http.Request):
 		return func(resp http.ResponseWriter, req *http.Request, others ...wrappedHandlerFunc) (done bool, deferrable func()) {
 			routing.UpdateFuncInfo(req.Context(), funcInfo)
+			log.Info("%v", funcInfo)
 			t(resp, req)
 			if r, ok := resp.(context.ResponseWriter); ok && r.Status() > 0 {
 				done = true
 			}
+			log.Info("%v:%t", funcInfo, done)
 			return
 		}
 
 	case func(ctx *context.Context):
 		return func(resp http.ResponseWriter, req *http.Request, others ...wrappedHandlerFunc) (done bool, deferrable func()) {
 			routing.UpdateFuncInfo(req.Context(), funcInfo)
+			log.Info("%v", funcInfo)
 			ctx := context.GetContext(req)
 			t(ctx)
 			done = ctx.Written()
+			log.Info("%v:%t", funcInfo, done)
 			return
 		}
 	case func(ctx *context.Context) goctx.CancelFunc:
 		return func(resp http.ResponseWriter, req *http.Request, others ...wrappedHandlerFunc) (done bool, deferrable func()) {
 			routing.UpdateFuncInfo(req.Context(), funcInfo)
+			log.Info("%v", funcInfo)
 			ctx := context.GetContext(req)
 			deferrable = t(ctx)
 			done = ctx.Written()
+			log.Info("%v:%t", funcInfo, done)
 			return
 		}
 	case func(*context.APIContext):
 		return func(resp http.ResponseWriter, req *http.Request, others ...wrappedHandlerFunc) (done bool, deferrable func()) {
 			routing.UpdateFuncInfo(req.Context(), funcInfo)
+			log.Info("%v", funcInfo)
 			ctx := context.GetAPIContext(req)
 			t(ctx)
 			done = ctx.Written()
+			log.Info("%v:%t", funcInfo, done)
 			return
 		}
 	case func(*context.APIContext) goctx.CancelFunc:
 		return func(resp http.ResponseWriter, req *http.Request, others ...wrappedHandlerFunc) (done bool, deferrable func()) {
 			routing.UpdateFuncInfo(req.Context(), funcInfo)
+			log.Info("%v", funcInfo)
 			ctx := context.GetAPIContext(req)
 			deferrable = t(ctx)
 			done = ctx.Written()
+			log.Info("%v:%t", funcInfo, done)
 			return
 		}
 	case func(*context.PrivateContext):
 		return func(resp http.ResponseWriter, req *http.Request, others ...wrappedHandlerFunc) (done bool, deferrable func()) {
 			routing.UpdateFuncInfo(req.Context(), funcInfo)
+			log.Info("%v", funcInfo)
 			ctx := context.GetPrivateContext(req)
 			t(ctx)
 			done = ctx.Written()
+			log.Info("%v:%t", funcInfo, done)
 			return
 		}
 	case func(*context.PrivateContext) goctx.CancelFunc:
 		return func(resp http.ResponseWriter, req *http.Request, others ...wrappedHandlerFunc) (done bool, deferrable func()) {
 			routing.UpdateFuncInfo(req.Context(), funcInfo)
+			log.Info("%v", funcInfo)
 			ctx := context.GetPrivateContext(req)
 			deferrable = t(ctx)
 			done = ctx.Written()
+			log.Info("%v:%t", funcInfo, done)
+
 			return
 		}
 	case func(http.Handler) http.Handler:
@@ -92,10 +111,13 @@ func convertHandler(handler interface{}) wrappedHandlerFunc {
 				next = wrapInternal(others)
 			}
 			routing.UpdateFuncInfo(req.Context(), funcInfo)
+			log.Info("%v", funcInfo)
 			t(next).ServeHTTP(resp, req)
 			if r, ok := resp.(context.ResponseWriter); ok && r.Status() > 0 {
 				done = true
 			}
+			log.Info("%v:%t", funcInfo, done)
+
 			return
 		}
 	default:

Produces logs like this:

2022/05/30 22:15:20 .../web/wrap_convert.go:114:func9() [I] [629533e8] gziphandler/gzip.go:320(gziphandler.GzipHandlerWithOpts)
2022/05/30 22:15:20 .../web/wrap_convert.go:114:func9() [I] [629533e8] context/context.go:683(context.Contexter)
2022/05/30 22:15:20 .../web/wrap_convert.go:49:func3() [I] [629533e8] context/context.go:653(context.Auth)
2022/05/30 22:15:20 .../web/wrap_convert.go:53:func3() [I] [629533e8] context/context.go:653(context.Auth):false
2022/05/30 22:15:20 .../web/wrap_convert.go:114:func9() [I] [629533e8] middleware/get_head.go:10(middleware.GetHead)
2022/05/30 22:15:20 .../web/wrap_convert.go:49:func3() [I] [629533e8] misc/swagger.go:18(misc.Swagger)
2022/05/30 22:15:20 ...s/context/context.go:218:HTML() [D] [629533e8] Template: swagger/ui
2022/05/30 22:15:20 .../web/wrap_convert.go:53:func3() [I] [629533e8] misc/swagger.go:18(misc.Swagger):true
2022/05/30 22:15:20 .../web/wrap_convert.go:119:func9() [I] [629533e8] middleware/get_head.go:10(middleware.GetHead):true
2022/05/30 22:15:20 .../web/wrap_convert.go:119:func9() [I] [629533e8] context/context.go:683(context.Contexter):false
2022/05/30 22:15:20 .../web/wrap_convert.go:49:func3() [I] [629533e8] context/context.go:653(context.Auth)
PANIC

Now the interesting thing lines is context/context.go:683(context.Contexter):false

Here this is saying that the response wasn't written to.

But it should have been ...

And if we look a bit higher we see:

			if r, ok := resp.(context.ResponseWriter); ok && r.Status() > 0 {
				done = true
			}

But the resp that we are passed here is a GzipResponseWriter which doesn't have the requisite function.

So this done never gets set.

We need to wrap the resp if it's not a ResponseWriter