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

@@ -455,26 +455,35 @@ APP_ID = ; e.g. http://localhost:3000/
 ;; Use comma to separate multiple modes, e.g. "console, file"
 MODE = console
 ;;
-;; Either "Trace", "Debug", "Info", "Warn", "Error", "Critical", default is "Trace"
+;; Either "Trace", "Debug", "Info", "Warn", "Error", "Critical" or "None", default is "Info"
 LEVEL = Info
 ;;
 ;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
 ;; Router Logger
 ;;
 ;; Switch off the router log
-;DISABLE_ROUTER_LOG= ; false
+;DISABLE_ROUTER_LOG=false
 ;;
 ;; Set the log "modes" for the router log (if file is set the log file will default to router.log)
 ROUTER = console
 ;;
-;; The level at which the router logs
-;ROUTER_LOG_LEVEL = Info
+;; The router will log different things at different levels.
 ;;
+;; * started messages will be logged at TRACE level
+;; * polling/completed routers will be logged at INFO
+;; * slow routers will be logged at WARN
+;; * failed routers will be logged at WARN
+;;
+;; The routing level will default to that of the system but individual router level can be set in
+;; [log.<mode>.router] LEVEL
+;;
+
 ;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
 ;;
 ;; Access Logger (Creates log in NCSA common log format)
 ;;
 ;ENABLE_ACCESS_LOG = false
+;;
 ;; Set the log "modes" for the access log (if file is set the log file will default to access.log)
 ;ACCESS = file
 ;;

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

@@ -291,7 +291,6 @@ The following configuration set `Content-Type: application/vnd.android.package-a
 - `MINIMUM_KEY_SIZE_CHECK`: **true**: Indicate whether to check minimum key size with corresponding type.
 
 - `OFFLINE_MODE`: **false**: Disables use of CDN for static files and Gravatar for profile pictures.
-- `DISABLE_ROUTER_LOG`: **false**: Mute printing of the router log.
 - `CERT_FILE`: **https/cert.pem**: Cert file path used for HTTPS. When chaining, the server certificate must come first, then intermediate CA certificates (if any). From 1.11 paths are relative to `CUSTOM_PATH`.
 - `KEY_FILE`: **https/key.pem**: Key file path used for HTTPS. From 1.11 paths are relative to `CUSTOM_PATH`.
 - `STATIC_ROOT_PATH`: **./**: Upper level of template and static files path.
@@ -752,11 +751,16 @@ 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.)
+- `ENABLE_SSH_LOG`: **false**: save ssh log to log file
+- `ENABLE_XORM_LOG`: **true**: Set whether to perform XORM logging. Please note SQL statement logging can be disabled by setting `LOG_SQL` to false in the `[database]` section.
+
+### Router Log (`log`)
+- `DISABLE_ROUTER_LOG`: **false**: Mute printing of the router log.
 - `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\]`.
+  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\]`.
+
+### Access Log (`log`)
 - `ENABLE_ACCESS_LOG`: **false**: Creates an access.log in NCSA common log format, or as per the following template
-- `ENABLE_SSH_LOG`: **false**: save ssh log to log file
 - `ACCESS`: **file**: Logging mode for the access logger, use a comma to separate values. Configure each mode in per mode log subsections `\[log.modename.access\]`. By default the file mode will log to `$ROOT_PATH/access.log`. (If you set this to `,` it will log to the default Gitea logger.)
 - `ACCESS_LOG_TEMPLATE`: **`{{.Ctx.RemoteAddr}} - {{.Identity}} {{.Start.Format "[02/Jan/2006:15:04:05 -0700]" }} "{{.Ctx.Req.Method}} {{.Ctx.Req.URL.RequestURI}} {{.Ctx.Req.Proto}}" {{.ResponseWriter.Status}} {{.ResponseWriter.Size}} "{{.Ctx.Req.Referer}}\" \"{{.Ctx.Req.UserAgent}}"`**: Sets the template used to create the access log.
   - The following variables are available:
@@ -765,7 +769,6 @@ NB: You must have `DISABLE_ROUTER_LOG` set to `false` for this option to take ef
   - `Start`: the start time of the request.
   - `ResponseWriter`: the responseWriter from the request.
   - You must be very careful to ensure that this template does not throw errors or panics as this template runs outside of the panic/recovery script.
-- `ENABLE_XORM_LOG`: **true**: Set whether to perform XORM logging. Please note SQL statement logging can be disabled by setting `LOG_SQL` to false in the `[database]` section.
 
 ### Log subsections (`log.name`, `log.name.*`)
 

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

@@ -68,16 +68,23 @@ multiple subloggers that will log to files.
 
 ### The "Router" logger
 
-You can disable Router log by setting `DISABLE_ROUTER_LOG`.
+The Router logger has been substantially changed in v1.17. If you are using the router logger for fail2ban or other monitoring
+you will need to update this configuration.
+
+You can disable Router log by setting `DISABLE_ROUTER_LOG` or by setting all of its sublogger configurations to `none`.
 
 You can configure the outputs of this
 router log by setting the `ROUTER` value in the `[log]` section of the
-configuration. `ROUTER` will default to `console` if unset. The Gitea
-Router logs at the `Info` level by default, but this can be
-changed if desired by setting the `ROUTER_LOG_LEVEL` value.
+configuration. `ROUTER` will default to `console` if unset and will default to same level as main logger.
+
+The Router logger logs the following:
+
+- `started` messages will be logged at TRACE level
+- `polling`/`completed` routers will be logged at INFO
+- `slow` routers will be logged at WARN
+- `failed` routers will be logged at WARN
 
-Please note, setting the `LEVEL` of this logger to a level above
-`ROUTER_LOG_LEVEL` will result in no router logs.
+The logging level for the router will default to that of the main configuration. Set `[log.<mode>.router]` `LEVEL` to change this.
 
 Each output sublogger for this logger is configured in
 `[log.sublogger.router]` sections. There are certain default values

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 converts the provided time to a ColoredValue for logging. The duration is always formatted in milliseconds.
 func ColoredTime(duration time.Duration) *ColoredValue {
+	// the output of duration 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/log/log.go

@@ -288,4 +288,8 @@ func (l *LoggerAsWriter) Log(msg string) {
 func init() {
 	_, filename, _, _ := runtime.Caller(0)
 	prefix = strings.TrimSuffix(filename, "modules/log/log.go")
+	if prefix == filename {
+		// in case the source code file is moved, we can not trim the suffix, the code above should also be updated.
+		panic("unable to detect correct package prefix, please update file: " + filename)
+	}
 }

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, defaultValue string) strin
 
 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
@@ -254,8 +255,10 @@ func generateNamedLogger(key string, options defaultLogOptions) *LogDescription
 func newAccessLogService() {
 	EnableAccessLog = Cfg.Section("log").Key("ENABLE_ACCESS_LOG").MustBool(false)
 	AccessLogTemplate = Cfg.Section("log").Key("ACCESS_LOG_TEMPLATE").MustString(
-		`{{.Ctx.RemoteAddr}} - {{.Identity}} {{.Start.Format "[02/Jan/2006:15:04:05 -0700]" }} "{{.Ctx.Req.Method}} {{.Ctx.Req.URL.RequestURI}} {{.Ctx.Req.Proto}}" {{.ResponseWriter.Status}} {{.ResponseWriter.Size}} "{{.Ctx.Req.Referer}}\" \"{{.Ctx.Req.UserAgent}}"`)
-	Cfg.Section("log").Key("ACCESS").MustString("file")
+		`{{.Ctx.RemoteAddr}} - {{.Identity}} {{.Start.Format "[02/Jan/2006:15:04:05 -0700]" }} "{{.Ctx.Req.Method}} {{.Ctx.Req.URL.RequestURI}} {{.Ctx.Req.Proto}}" {{.ResponseWriter.Status}} {{.ResponseWriter.Size}} "{{.Ctx.Req.Referer}}\" \"{{.Ctx.Req.UserAgent}}"`,
+	)
+	// the `MustString` updates the default value, and `log.ACCESS` is used by `generateNamedLogger("access")` later
+	_ = Cfg.Section("log").Key("ACCESS").MustString("file")
 	if EnableAccessLog {
 		options := newDefaultLogOptions()
 		options.filename = filepath.Join(LogRootPath, "access.log")

modules/setting/setting.go

@@ -333,13 +333,14 @@ var (
 	LogLevel           log.Level
 	StacktraceLogLevel string
 	LogRootPath        string
-	DisableRouterLog   bool
-	RouterLogLevel     log.Level
-	EnableAccessLog    bool
 	EnableSSHLog       bool
-	AccessLogTemplate  string
 	EnableXORMLog      bool
 
+	DisableRouterLog bool
+
+	EnableAccessLog   bool
+	AccessLogTemplate string
+
 	// Time settings
 	TimeFormat string
 	// UILocation is the location on the UI, so that we can display the time on UI.
@@ -601,7 +602,6 @@ func loadFromConf(allowEmpty bool, extraConfig string) {
 	StacktraceLogLevel = getStacktraceLogLevel(Cfg.Section("log"), "STACKTRACE_LEVEL", "None")
 	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"))
 
 	sec := Cfg.Section("server")
 	AppName = Cfg.Section("").Key("APP_NAME").MustString("Gitea: Git with a cup of tea")