Separate router_v1 and router

custom/conf/app.example.ini

@@ -466,14 +466,28 @@ LEVEL = Info
 ;; Set the log "modes" for the router log (if file is set the log file will default to router.log)
 ROUTER = console
 ;;
-;; 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_LEVEL = Info
+;; This router will log different things at different levels.
+;;
+;; * started messages will be logged at DEBUG level
+;; * slow routers will be logged at WARN
+;; * polling/completed routers will be logged at INFO
+;; * 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
+;;
+;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
+;; Router V1 Logger
+;;
+;; Enable the legacy router
+;ENABLE_ROUTER_V1 = false
 ;;
-;; The handler for router logs, it controls the router log format, mainly for debug purpose, two log handlers:
-;; router_logger_v1: default for before 1.16
-;; router_logger_v2: default for 1.16 and later. Developers could set both `LEVEL=Debug` to get the "started" router messages
-;ROUTER_LOG_HANDLER = router_logger_v2
+;;Set the log "modes" for the router log (if file is set the log file will default to router.log)
+;ROUTER_V1 = console
 ;;
+;; 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_V1_LOG_LEVEL = Info
+
 ;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
 ;;
 ;; Access Logger (Creates log in NCSA common log format)

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

@@ -757,8 +757,11 @@ Default templates for project boards:
 - `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\]`.
-- `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`: **router_logger_v2**: The log handler that controls the log output format. Before 1.16 the router logs are outputted by handler `router_logger_v1`. From 1.16, the default handler is `router_logger_v2` which is more meaningful and friendly.
+### Router V1 Log (`log`)
+- `ENABLE_ROUTER_V1`: **false**: Mute printing of the router log.
+- `ROUTER_V1`: **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 `ENABLE_ROUTER_V1` set to `true` for this option to take effect. Configure each mode in per mode log subsections `\[log.modename.router_v1\]`.
+- `ROUTER_V1_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.)
 
 ### Access Log (`log`)
 - `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

@@ -68,23 +68,25 @@ 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.16. The old router logger is still available as `router_v1`
+(see below) but it is deprecated and will be removed at some point.
+
+You can disable Router log by setting `DISABLE_ROUTER_LOG` or 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.
 
-Please note, setting the `LEVEL` of this logger to a level above
-`ROUTER_LOG_LEVEL` will result in no router logs.
+The router logger will log various things at different levels:
 
-You can control the output format by setting a log handler to `ROUTER_LOG_HANDLER`.
-Now Gitea has two log handlers:
-* `router_logger_v1` is the default handler for Gitea before 1.16
-* `router_logger_v2` is the default handler for Gitea from 1.16, it's more meaningful and friendly.
+- `started` messages will be logged at DEBUG level
+- `slow` routers will be logged at WARN
+- `polling`/`completed` routers will be logged at INFO
+- `failed` routers will be logged at WARN
 
-If you have applications depending on the log format (eg: fail2ban), please make sure you use the correct log handler and log format.
+The logging level for the router will default to that of the main configuration. Set `[log.<mode>.router]` `LEVEL` to change this.
+
+If you have applications depending on the log format (eg: fail2ban), please update your configuration or use the old logger.
 
 Each output sublogger for this logger is configured in
 `[log.sublogger.router]` sections. There are certain default values
@@ -99,6 +101,34 @@ which will not be inherited from the `[log]` or relevant
 NB: You can redirect the router logger to send its events to the Gitea
 log using the value: `ROUTER = ,`
 
+### The "Router_V1" logger
+
+The original router logger is still available by setting `ENABLE_ROUTER_V1`.
+
+You can configure the outputs of this
+router log by setting the `ROUTER_V1` value in the `[log]` section of the
+configuration. `ROUTER_V1` 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_V1_LOG_LEVEL` value.
+
+Please note, setting the `LEVEL` of this logger to a level above
+`ROUTER_V1_LOG_LEVEL` will result in no router logs.
+
+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_v1]` sections. There are certain default values
+which will not be inherited from the `[log]` or relevant
+`[log.sublogger]` sections:
+
+- `FILE_NAME` will default to `%(ROOT_PATH)/router.log`
+- `FLAGS` defaults to `date,time`
+- `EXPRESSION` will default to `""`
+- `PREFIX` will default to `""`
+
+NB: You can redirect the router logger to send its events to the Gitea
+log using the value: `ROUTER_V1 = ,` (but remember to enable it first using `ENABLE_ROUTER_V1`.)
+
 ### The "Access" logger
 
 The Access logger is a new logger for version 1.9. It provides a NCSA

modules/setting/log.go

@@ -280,6 +280,18 @@ func newRouterLogService() {
 		options.bufferLength = Cfg.Section("log").Key("BUFFER_LEN").MustInt64(10000)
 		generateNamedLogger("router", options)
 	}
+
+	Cfg.Section("log").Key("ROUTER_V1").MustString("console")
+
+	EnableRouterV1 = Cfg.Section("log").Key("ENABLE_ROUTER_V1").MustBool(false)
+	if EnableRouterV1 {
+		options := newDefaultLogOptions()
+		options.filename = filepath.Join(LogRootPath, "router.log")
+		options.flags = "date,time" // For the router we don't want any prefixed flags
+		options.bufferLength = Cfg.Section("log").Key("BUFFER_LEN").MustInt64(10000)
+		generateNamedLogger("router_v1", options)
+	}
+
 }
 
 func newLogService() {

modules/setting/setting.go

@@ -338,8 +338,8 @@ var (
 	EnableXORMLog      bool
 
 	DisableRouterLog bool
-	RouterLogLevel   log.Level
-	RouterLogHandler string
+	EnableRouterV1   bool
+	RouterV1LogLevel log.Level
 
 	EnableAccessLog   bool
 	AccessLogTemplate string
@@ -606,8 +606,7 @@ 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"))
-	RouterLogHandler = Cfg.Section("log").Key("ROUTER_LOG_HANDLER").MustString("router_logger_v2")
+	RouterV1LogLevel = log.FromString(Cfg.Section("log").Key("ROUTER_V1_LOG_LEVEL").MustString("Info"))
 
 	sec := Cfg.Section("server")
 	AppName = Cfg.Section("").Key("APP_NAME").MustString("Gitea: Git with a cup of tea")

modules/web/routing/logger_v1.go

@@ -18,7 +18,7 @@ func NewLoggerHandlerV1(level log.Level) 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)
+			_ = log.GetLogger("router_v1").Log(0, level, "Started %s %s for %s", log.ColoredMethod(req.Method), req.URL.RequestURI(), req.RemoteAddr)
 
 			next.ServeHTTP(w, req)
 
@@ -27,7 +27,7 @@ func NewLoggerHandlerV1(level log.Level) func(next http.Handler) http.Handler {
 				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)))
+			_ = log.GetLogger("router_v1").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)))
 		})
 	}
 }

modules/web/routing/logger_v2.go

@@ -11,7 +11,6 @@ import (
 
 	"code.gitea.io/gitea/modules/context"
 	"code.gitea.io/gitea/modules/log"
-	"code.gitea.io/gitea/modules/setting"
 )
 
 // NewLoggerHandlerV2 is a handler that will log routing to the router log taking account of
@@ -29,15 +28,16 @@ func NewLoggerHandlerV2() func(next http.Handler) http.Handler {
 
 func logPrinter(logger log.Logger) func(trigger Event, record *requestRecord) {
 	return func(trigger Event, record *requestRecord) {
-		if trigger == StartEvent && setting.LogLevel > log.DEBUG {
+		if trigger == StartEvent && !logger.IsDebug() {
 			// for performance, if the "started" message shouldn't be logged, we just return as early as possible
-			// developers could set both `log.LEVEL=Debug` to get the "started" request messages.
+			// developers can set the router log level to DEBUG to get the "started" request messages.
 			return
 		}
 
 		shortFilename := ""
 		line := 0
 		shortName := ""
+		isError := false
 
 		record.lock.RLock()
 		isLongPolling := record.isLongPolling
@@ -47,34 +47,36 @@ func logPrinter(logger log.Logger) func(trigger Event, record *requestRecord) {
 			// we might not find all handlers, so if a handler has not called `UpdateFuncInfo`, we won't know its information
 			// in such case, we should debug to find what handler it is and use `UpdateFuncInfo` to report its information
 			shortFilename = "unknown-handler"
+			isError = true
 		}
 		record.lock.RUnlock()
 
 		req := record.request
 
 		if trigger == StartEvent {
 			// when a request starts, we have no information about the handler function information, we only have the request path
-			logger.Debug("router: started %v %s for %s", log.ColoredMethod(req.Method), req.RequestURI, req.RemoteAddr)
+			logger.Debug("router: %s %v %s for %s", log.NewColoredValueBytes("started  ", log.DEBUG.Color()), log.ColoredMethod(req.Method), req.RequestURI, req.RemoteAddr)
 			return
 		}
 
 		handlerFuncInfo := fmt.Sprintf("%s:%d(%s)", shortFilename, line, shortName)
 		if trigger == StillExecutingEvent {
-			message := "still-executing"
+			message := "slow      "
 			level := log.WARN
 			if isLongPolling {
 				level = log.INFO
-				message = "long-polling"
+				message = "polling  "
 			}
 			_ = logger.Log(0, level, "router: %s %v %s for %s, elapsed %v @ %s",
-				message,
+				log.NewColoredValueBytes(message, level.Color()),
 				log.ColoredMethod(req.Method), req.RequestURI, req.RemoteAddr,
 				log.ColoredTime(time.Since(record.startTime)),
 				handlerFuncInfo,
 			)
 		} else {
 			if record.panicError != nil {
-				_ = logger.Log(0, log.WARN, "router: failed %v %s for %s, panic in %v @ %s, err=%v",
+				_ = logger.Log(0, log.WARN, "router: %s %v %s for %s, panic in %v @ %s, err=%v",
+					log.NewColoredValueBytes("failed   ", log.WARN.Color()),
 					shortFilename, line, shortName,
 					log.ColoredMethod(req.Method), req.RequestURI, req.RemoteAddr,
 					log.ColoredTime(time.Since(record.startTime)),
@@ -86,7 +88,13 @@ func logPrinter(logger log.Logger) func(trigger Event, record *requestRecord) {
 				if v, ok := record.responseWriter.(context.ResponseWriter); ok {
 					status = v.Status()
 				}
-				_ = logger.Log(0, setting.RouterLogLevel, "router: completed %v %s for %s, %v %v in %v @ %s",
+				level := log.INFO
+				if isError {
+					level = log.ERROR
+				}
+
+				_ = logger.Log(0, level, "router: %s %v %s for %s, %v %v in %v @ %s",
+					log.NewColoredValueBytes("completed", level.Color()),
 					log.ColoredMethod(req.Method), req.RequestURI, req.RemoteAddr,
 					log.ColoredStatus(status), log.ColoredStatus(status, http.StatusText(status)), log.ColoredTime(time.Since(record.startTime)),
 					handlerFuncInfo,

routers/common/middleware.go

@@ -51,18 +51,13 @@ func Middlewares() []func(http.Handler) http.Handler {
 	handlers = append(handlers, middleware.StripSlashes)
 
 	if !setting.DisableRouterLog {
-		var routerLogHandler func(http.Handler) http.Handler
-		if setting.RouterLogHandler == "router_logger_v1" {
-			routerLogHandler = routing.NewLoggerHandlerV1(setting.RouterLogLevel)
-		} else if setting.RouterLogHandler == "router_logger_v2" {
-			routerLogHandler = routing.NewLoggerHandlerV2()
-		}
-		if routerLogHandler == nil {
-			log.Warn("unknown router log handler '%s', fall back to router_logger_v2")
-			routerLogHandler = routing.NewLoggerHandlerV2()
-		}
-		handlers = append(handlers, routerLogHandler)
+		handlers = append(handlers, routing.NewLoggerHandlerV2())
 	}
+
+	if setting.EnableRouterV1 {
+		handlers = append(handlers, routing.NewLoggerHandlerV1(setting.RouterV1LogLevel))
+	}
+
 	if setting.EnableAccessLog {
 		handlers = append(handlers, context.AccessLogger())
 	}