Refactor Router Logger (#17308)

Make router logger more friendly, show the related function name/file/line.

[BREAKING]
This PR substantially changes the logging format of the router logger. If you use this logging for monitoring e.g. fail2ban you will need to update this to match the new format.

5 files changed, 32 insertions, 55 deletions

diff --git a/routers/common/logger.go b/routers/common/logger.go
deleted file mode 100644
index bc1149543c..0000000000
--- a/routers/common/logger.go
+++ /dev/null
@@ -1,33 +0,0 @@
-// Copyright 2021 The Gitea Authors. All rights reserved.
-// Use of this source code is governed by a MIT-style
-// license that can be found in the LICENSE file.
-
-package common
-
-import (
-	"net/http"
-	"time"
-
-	"code.gitea.io/gitea/modules/context"
-	"code.gitea.io/gitea/modules/log"
-)
-
-// LoggerHandler is a handler that will log the routing to the default gitea log
-func LoggerHandler(level log.Level) func(next http.Handler) http.Handler {
-	return func(next http.Handler) http.Handler {
-		return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
-			start := time.Now()
-
-			_ = log.GetLogger("router").Log(0, level, "Started %s %s for %s", log.ColoredMethod(req.Method), req.URL.RequestURI(), req.RemoteAddr)
-
-			next.ServeHTTP(w, req)
-
-			var status int
-			if v, ok := w.(context.ResponseWriter); ok {
-				status = v.Status()
-			}
-
-			_ = log.GetLogger("router").Log(0, level, "Completed %s %s %v %s in %v", log.ColoredMethod(req.Method), req.URL.RequestURI(), log.ColoredStatus(status), log.ColoredStatus(status, http.StatusText(status)), log.ColoredTime(time.Since(start)))
-		})
-	}
-}
diff --git a/routers/common/middleware.go b/routers/common/middleware.go
index 3f535628aa..2b6343b10f 100644
--- a/routers/common/middleware.go
+++ b/routers/common/middleware.go
@@ -13,6 +13,7 @@ import (
 	"code.gitea.io/gitea/modules/log"
 	"code.gitea.io/gitea/modules/process"
 	"code.gitea.io/gitea/modules/setting"
+	"code.gitea.io/gitea/modules/web/routing"
 
 	"github.com/chi-middleware/proxy"
 	"github.com/go-chi/chi/v5/middleware"
@@ -49,11 +50,10 @@ func Middlewares() []func(http.Handler) http.Handler {
 
 	handlers = append(handlers, middleware.StripSlashes)
 
-	if !setting.DisableRouterLog && setting.RouterLogLevel != log.NONE {
-		if log.GetLogger("router").GetLevel() <= setting.RouterLogLevel {
-			handlers = append(handlers, LoggerHandler(setting.RouterLogLevel))
-		}
+	if !setting.DisableRouterLog {
+		handlers = append(handlers, routing.NewLoggerHandler())
 	}
+
 	if setting.EnableAccessLog {
 		handlers = append(handlers, context.AccessLogger())
 	}
@@ -63,10 +63,11 @@ func Middlewares() []func(http.Handler) http.Handler {
 			// Why we need this? The Recovery() will try to render a beautiful
 			// error page for user, but the process can still panic again, and other
 			// middleware like session also may panic then we have to recover twice
-			// and send a simple error page that should not panic any more.
+			// and send a simple error page that should not panic anymore.
 			defer func() {
 				if err := recover(); err != nil {
-					combinedErr := fmt.Sprintf("PANIC: %v\n%s", err, string(log.Stack(2)))
+					routing.UpdatePanicError(req.Context(), err)
+					combinedErr := fmt.Sprintf("PANIC: %v\n%s", err, log.Stack(2))
 					log.Error("%v", combinedErr)
 					if setting.IsProd {
 						http.Error(resp, http.StatusText(500), 500)
diff --git a/routers/install/routes.go b/routers/install/routes.go
index ad0003a9e8..d7d8527cf5 100644
--- a/routers/install/routes.go
+++ b/routers/install/routes.go
@@ -38,8 +38,8 @@ func installRecovery() func(next http.Handler) http.Handler {
 				// should not panic any more.
 				defer func() {
 					if err := recover(); err != nil {
-						combinedErr := fmt.Sprintf("PANIC: %v\n%s", err, string(log.Stack(2)))
-						log.Error(combinedErr)
+						combinedErr := fmt.Sprintf("PANIC: %v\n%s", err, log.Stack(2))
+						log.Error("%s", combinedErr)
 						if setting.IsProd {
 							http.Error(w, http.StatusText(500), 500)
 						} else {
@@ -49,8 +49,8 @@ func installRecovery() func(next http.Handler) http.Handler {
 				}()
 
 				if err := recover(); err != nil {
-					combinedErr := fmt.Sprintf("PANIC: %v\n%s", err, string(log.Stack(2)))
-					log.Error("%v", combinedErr)
+					combinedErr := fmt.Sprintf("PANIC: %v\n%s", err, log.Stack(2))
+					log.Error("%s", combinedErr)
 
 					lc := middleware.Locale(w, req)
 					var store = dataStore{
@@ -85,10 +85,10 @@ func Routes() *web.Route {
 		r.Use(middle)
 	}
 
-	r.Use(public.AssetsHandler(&public.Options{
+	r.Use(web.WrapWithPrefix(public.AssetsURLPathPrefix, public.AssetsHandlerFunc(&public.Options{
 		Directory: path.Join(setting.StaticRootPath, "public"),
-		Prefix:    "/assets",
-	}))
+		Prefix:    public.AssetsURLPathPrefix,
+	}), "InstallAssetsHandler"))
 
 	r.Use(session.Sessioner(session.Options{
 		Provider:       setting.SessionConfig.Provider,
@@ -106,8 +106,11 @@ func Routes() *web.Route {
 	r.Use(Init)
 	r.Get("/", Install)
 	r.Post("/", web.Bind(forms.InstallForm{}), SubmitInstall)
-	r.NotFound(func(w http.ResponseWriter, req *http.Request) {
-		http.Redirect(w, req, setting.AppURL, http.StatusFound)
-	})
+
+	r.NotFound(web.Wrap(installNotFound))
 	return r
 }
+
+func installNotFound(w http.ResponseWriter, req *http.Request) {
+	http.Redirect(w, req, setting.AppURL, http.StatusFound)
+}
diff --git a/routers/web/base.go b/routers/web/base.go
index 98713bc881..fd942d3c87 100644
--- a/routers/web/base.go
+++ b/routers/web/base.go
@@ -21,12 +21,14 @@ import (
 	"code.gitea.io/gitea/modules/storage"
 	"code.gitea.io/gitea/modules/templates"
 	"code.gitea.io/gitea/modules/web/middleware"
+	"code.gitea.io/gitea/modules/web/routing"
 	"code.gitea.io/gitea/services/auth"
 
 	"gitea.com/go-chi/session"
 )
 
 func storageHandler(storageSetting setting.Storage, prefix string, objStore storage.ObjectStorage) func(next http.Handler) http.Handler {
+	funcInfo := routing.GetFuncInfo(storageHandler, prefix)
 	return func(next http.Handler) http.Handler {
 		if storageSetting.ServeDirect {
 			return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
@@ -39,6 +41,7 @@ func storageHandler(storageSetting setting.Storage, prefix string, objStore stor
 					next.ServeHTTP(w, req)
 					return
 				}
+				routing.UpdateFuncInfo(req.Context(), funcInfo)
 
 				rPath := strings.TrimPrefix(req.URL.RequestURI(), "/"+prefix)
 				u, err := objStore.URL(rPath, path.Base(rPath))
@@ -73,6 +76,7 @@ func storageHandler(storageSetting setting.Storage, prefix string, objStore stor
 				next.ServeHTTP(w, req)
 				return
 			}
+			routing.UpdateFuncInfo(req.Context(), funcInfo)
 
 			rPath := strings.TrimPrefix(req.URL.EscapedPath(), "/"+prefix+"/")
 			rPath = strings.TrimPrefix(rPath, "/")
@@ -126,8 +130,9 @@ func Recovery() func(next http.Handler) http.Handler {
 		return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
 			defer func() {
 				if err := recover(); err != nil {
-					combinedErr := fmt.Sprintf("PANIC: %v\n%s", err, string(log.Stack(2)))
-					log.Error("%v", combinedErr)
+					routing.UpdatePanicError(req.Context(), err)
+					combinedErr := fmt.Sprintf("PANIC: %v\n%s", err, log.Stack(2))
+					log.Error("%s", combinedErr)
 
 					sessionStore := session.GetSession(req)
 
diff --git a/routers/web/web.go b/routers/web/web.go
index 55a64ee7d5..e934095b79 100644
--- a/routers/web/web.go
+++ b/routers/web/web.go
@@ -21,6 +21,7 @@ import (
 	"code.gitea.io/gitea/modules/templates"
 	"code.gitea.io/gitea/modules/validation"
 	"code.gitea.io/gitea/modules/web"
+	"code.gitea.io/gitea/modules/web/routing"
 	"code.gitea.io/gitea/routers/api/v1/misc"
 	"code.gitea.io/gitea/routers/web/admin"
 	"code.gitea.io/gitea/routers/web/auth"
@@ -73,11 +74,11 @@ func CorsHandler() func(next http.Handler) http.Handler {
 func Routes(sessioner func(http.Handler) http.Handler) *web.Route {
 	routes := web.NewRoute()
 
-	routes.Use(public.AssetsHandler(&public.Options{
+	routes.Use(web.WrapWithPrefix(public.AssetsURLPathPrefix, public.AssetsHandlerFunc(&public.Options{
 		Directory:   path.Join(setting.StaticRootPath, "public"),
-		Prefix:      "/assets",
+		Prefix:      public.AssetsURLPathPrefix,
 		CorsHandler: CorsHandler(),
-	}))
+	}), "AssetsHandler"))
 
 	routes.Use(sessioner)
 
@@ -293,7 +294,7 @@ func RegisterRoutes(m *web.Route) {
 		})
 	}, reqSignOut)
 
-	m.Any("/user/events", events.Events)
+	m.Any("/user/events", routing.MarkLongPolling, events.Events)
 
 	m.Group("/login/oauth", func() {
 		m.Get("/authorize", bindIgnErr(forms.AuthorizationForm{}), auth.AuthorizeOAuth)