Refactor Router Logger

cmd/web.go

@@ -88,7 +88,7 @@ func runWeb(ctx *cli.Context) error {
 	}
 	defer func() {
 		if panicked := recover(); panicked != nil {
-			log.Fatal("PANIC: %v\n%s", panicked, string(log.Stack(2)))
+			log.Fatal("PANIC: %v\n%s", panicked, log.Stack(2))
 		}
 	}()
 

custom/conf/app.example.ini

@@ -469,6 +469,9 @@ ROUTER = console
 ;; The level at which the router logs
 ;ROUTER_LOG_LEVEL = Info
 ;;
+;; The handler for router logs, it controls the log format
+;ROUTER_LOG_HANDLER = v2
+;;
 ;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
 ;;
 ;; Access Logger (Creates log in NCSA common log format)

docs/content/doc/advanced/config-cheat-sheet.en-us.md

@@ -750,7 +750,8 @@ Default templates for project boards:
 - `MODE`: **console**: Logging mode. For multiple modes, use a comma to separate values. You can configure each mode in per mode log subsections `\[log.modename\]`. By default the file mode will log to `$ROOT_PATH/gitea.log`.
 - `LEVEL`: **Info**: General log level. \[Trace, Debug, Info, Warn, Error, Critical, Fatal, None\]
 - `STACKTRACE_LEVEL`: **None**: Default log level at which to log create stack traces. \[Trace, Debug, Info, Warn, Error, Critical, Fatal, None\]
-- `ROUTER_LOG_LEVEL`: **Info**: The log level that the router should log at. (If you are setting the access log, its recommended to place this at Debug.)
+- `ROUTER_LOG_LEVEL`: **Info**: The log level that the router should log at. (If you are setting the access log, it's recommended to place this at Debug.)
+- `ROUTER_LOG_HANDLER`: **v2**: The log handler that controls the log output format. Before 1.16 the router logs are outputted by handler `v1`. From 1.16, the default handler is `v2` which is more meaningful and friendly.
 - `ROUTER`: **console**: The mode or name of the log the router should log to. (If you set this to `,` it will log to default Gitea logger.)
 NB: You must have `DISABLE_ROUTER_LOG` set to `false` for this option to take effect. Configure each mode in per mode log subsections `\[log.modename.router\]`.
 - `ENABLE_ACCESS_LOG`: **false**: Creates an access.log in NCSA common log format, or as per the following template

docs/content/doc/advanced/logging-documentation.en-us.md

@@ -79,6 +79,13 @@ changed if desired by setting the `ROUTER_LOG_LEVEL` value.
 Please note, setting the `LEVEL` of this logger to a level above
 `ROUTER_LOG_LEVEL` will result in no router logs.
 
+You can control the output format by setting a log handler to `ROUTER_LOG_HANDLER`.
+Now Gitea has two log handlers:
+* `v1` is the default handler for Gitea before 1.16
+* `v2` is the default handler for Gitea from 1.16, it's more meaningful and friendly.
+
+If you have applications depending on the log format (eg: fail2ban), please make sure you use the correct log handler and log format.
+
 Each output sublogger for this logger is configured in
 `[log.sublogger.router]` sections. There are certain default values
 which will not be inherited from the `[log]` or relevant

modules/log/colors_router.go

@@ -5,6 +5,7 @@
 package log
 
 import (
+	"fmt"
 	"time"
 )
 
@@ -72,12 +73,16 @@ var (
 	wayTooLong = ColorBytes(BgMagenta)
 )
 
-// ColoredTime adds colors for time on log
+// ColoredTime adds colors for time on log, it always formats the duration in Millisecond unit
 func ColoredTime(duration time.Duration) *ColoredValue {
+	// the output of in Millisecond is more readable:
+	// * before: "100.1ms" "100.1μs" "100.1s"
+	// * better: "100.1ms" "0.1ms"   "100100.0ms", readers can compare the values at first glance.
+	str := fmt.Sprintf("%.1fms", float64(duration.Microseconds())/1000)
 	for i, k := range durations {
 		if duration < k {
-			return NewColoredValueBytes(duration, &durationColors[i])
+			return NewColoredValueBytes(str, &durationColors[i])
 		}
 	}
-	return NewColoredValueBytes(duration, &wayTooLong)
+	return NewColoredValueBytes(str, &wayTooLong)
 }

modules/public/public.go

@@ -23,8 +23,11 @@ type Options struct {
 	CorsHandler func(http.Handler) http.Handler
 }
 
-// AssetsHandler implements the static handler for serving custom or original assets.
-func AssetsHandler(opts *Options) func(next http.Handler) http.Handler {
+// AssetsURLPathPrefix is the path prefix for static asset files
+const AssetsURLPathPrefix = "/assets/"
+
+// AssetsHandlerFunc implements the static handler for serving custom or original assets.
+func AssetsHandlerFunc(opts *Options) http.HandlerFunc {
 	var custPath = filepath.Join(setting.CustomPath, "public")
 	if !filepath.IsAbs(custPath) {
 		custPath = filepath.Join(setting.AppWorkPath, custPath)
@@ -36,52 +39,46 @@ func AssetsHandler(opts *Options) func(next http.Handler) http.Handler {
 		opts.Prefix += "/"
 	}
 
-	return func(next http.Handler) http.Handler {
-		return http.HandlerFunc(func(resp http.ResponseWriter, req *http.Request) {
-			if !strings.HasPrefix(req.URL.Path, opts.Prefix) {
-				next.ServeHTTP(resp, req)
-				return
-			}
-			if req.Method != "GET" && req.Method != "HEAD" {
-				resp.WriteHeader(http.StatusNotFound)
-				return
-			}
-
-			file := req.URL.Path
-			file = file[len(opts.Prefix):]
-			if len(file) == 0 {
-				resp.WriteHeader(http.StatusNotFound)
-				return
-			}
-			if strings.Contains(file, "\\") {
-				resp.WriteHeader(http.StatusBadRequest)
-				return
-			}
-			file = "/" + file
-
-			var written bool
-			if opts.CorsHandler != nil {
-				written = true
-				opts.CorsHandler(http.HandlerFunc(func(http.ResponseWriter, *http.Request) {
-					written = false
-				})).ServeHTTP(resp, req)
-			}
-			if written {
-				return
-			}
-
-			// custom files
-			if opts.handle(resp, req, http.Dir(custPath), file) {
-				return
-			}
-
-			// internal files
-			if opts.handle(resp, req, fileSystem(opts.Directory), file) {
-				return
-			}
+	return func(resp http.ResponseWriter, req *http.Request) {
+		if req.Method != "GET" && req.Method != "HEAD" {
+			resp.WriteHeader(http.StatusNotFound)
+			return
+		}
 
+		file := req.URL.Path
+		file = file[len(opts.Prefix):]
+		if len(file) == 0 {
 			resp.WriteHeader(http.StatusNotFound)
-		})
+			return
+		}
+		if strings.Contains(file, "\\") {
+			resp.WriteHeader(http.StatusBadRequest)
+			return
+		}
+		file = "/" + file
+
+		var written bool
+		if opts.CorsHandler != nil {
+			written = true
+			opts.CorsHandler(http.HandlerFunc(func(http.ResponseWriter, *http.Request) {
+				written = false
+			})).ServeHTTP(resp, req)
+		}
+		if written {
+			return
+		}
+
+		// custom files
+		if opts.handle(resp, req, http.Dir(custPath), file) {
+			return
+		}
+
+		// internal files
+		if opts.handle(resp, req, fileSystem(opts.Directory), file) {
+			return
+		}
+
+		resp.WriteHeader(http.StatusNotFound)
 	}
 }
 

modules/setting/log.go

@@ -126,6 +126,7 @@ func getStacktraceLogLevel(section *ini.Section, key string, defaultValue string
 
 func generateLogConfig(sec *ini.Section, name string, defaults defaultLogOptions) (mode, jsonConfig, levelName string) {
 	level := getLogLevel(sec, "LEVEL", LogLevel)
+	levelName = level.String()
 	stacktraceLevelName := getStacktraceLogLevel(sec, "STACKTRACE_LEVEL", StacktraceLogLevel)
 	stacktraceLevel := log.FromString(stacktraceLevelName)
 	mode = name

modules/setting/setting.go

@@ -336,6 +336,7 @@ var (
 	LogRootPath        string
 	DisableRouterLog   bool
 	RouterLogLevel     log.Level
+	RouterLogHandler   string
 	EnableAccessLog    bool
 	EnableSSHLog       bool
 	AccessLogTemplate  string
@@ -604,6 +605,7 @@ func loadFromConf(allowEmpty bool, extraConfig string) {
 	LogRootPath = Cfg.Section("log").Key("ROOT_PATH").MustString(path.Join(AppWorkPath, "log"))
 	forcePathSeparator(LogRootPath)
 	RouterLogLevel = log.FromString(Cfg.Section("log").Key("ROUTER_LOG_LEVEL").MustString("Info"))
+	RouterLogHandler = Cfg.Section("log").Key("ROUTER_LOG_HANDLER").MustString("v2")
 
 	sec := Cfg.Section("server")
 	AppName = Cfg.Section("").Key("APP_NAME").MustString("Gitea: Git with a cup of tea")

modules/web/route.go

@@ -13,6 +13,7 @@ import (
 
 	"code.gitea.io/gitea/modules/context"
 	"code.gitea.io/gitea/modules/web/middleware"
+	"code.gitea.io/gitea/routers/common"
 
 	"gitea.com/go-chi/binding"
 	chi "github.com/go-chi/chi/v5"
@@ -40,6 +41,7 @@ func Wrap(handlers ...interface{}) http.HandlerFunc {
 	return http.HandlerFunc(func(resp http.ResponseWriter, req *http.Request) {
 		for i := 0; i < len(handlers); i++ {
 			handler := handlers[i]
+			common.UpdateContextHandlerFuncInfo(req.Context(), handler)
 			switch t := handler.(type) {
 			case http.HandlerFunc:
 				t(resp, req)

routers/common/logger.go

@@ -12,8 +12,8 @@ import (
 	"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 {
+// NewLoggerHandlerV1 is a handler that will log the routing to the default gitea log
+func NewLoggerHandlerV1(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()