summaryrefslogtreecommitdiffstats
path: root/modules
diff options
context:
space:
mode:
Diffstat (limited to 'modules')
-rw-r--r--modules/log/colors_router.go11
-rw-r--r--modules/log/log.go4
-rw-r--r--modules/public/public.go89
-rw-r--r--modules/setting/log.go7
-rw-r--r--modules/setting/setting.go10
-rw-r--r--modules/web/route.go138
-rw-r--r--modules/web/routing/context.go51
-rw-r--r--modules/web/routing/funcinfo.go171
-rw-r--r--modules/web/routing/funcinfo_test.go81
-rw-r--r--modules/web/routing/logger.go106
-rw-r--r--modules/web/routing/logger_manager.go122
-rw-r--r--modules/web/routing/requestrecord.go29
-rw-r--r--modules/web/wrap.go117
-rw-r--r--modules/web/wrap_convert.go101
14 files changed, 843 insertions, 194 deletions
diff --git a/modules/log/colors_router.go b/modules/log/colors_router.go
index 3064e005cf..888198d4e9 100644
--- a/modules/log/colors_router.go
+++ b/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)
}
diff --git a/modules/log/log.go b/modules/log/log.go
index cae24f53d8..f805a36231 100644
--- a/modules/log/log.go
+++ b/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)
+ }
}
diff --git a/modules/public/public.go b/modules/public/public.go
index a58709d86f..f4a769f27a 100644
--- a/modules/public/public.go
+++ b/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)
}
}
diff --git a/modules/setting/log.go b/modules/setting/log.go
index b0ae5fb646..a53b431196 100644
--- a/modules/setting/log.go
+++ b/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")
diff --git a/modules/setting/setting.go b/modules/setting/setting.go
index abd6716c74..26eeda525f 100644
--- a/modules/setting/setting.go
+++ b/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")
diff --git a/modules/web/route.go b/modules/web/route.go
index 19193773d5..86e407701c 100644
--- a/modules/web/route.go
+++ b/modules/web/route.go
@@ -18,144 +18,6 @@ import (
chi "github.com/go-chi/chi/v5"
)
-// Wrap converts all kinds of routes to standard library one
-func Wrap(handlers ...interface{}) http.HandlerFunc {
- if len(handlers) == 0 {
- panic("No handlers found")
- }
-
- for _, handler := range handlers {
- switch t := handler.(type) {
- case http.HandlerFunc, func(http.ResponseWriter, *http.Request),
- func(ctx *context.Context),
- func(ctx *context.Context) goctx.CancelFunc,
- func(*context.APIContext),
- func(*context.APIContext) goctx.CancelFunc,
- func(*context.PrivateContext),
- func(*context.PrivateContext) goctx.CancelFunc,
- func(http.Handler) http.Handler:
- default:
- panic(fmt.Sprintf("Unsupported handler type: %#v", t))
- }
- }
- return http.HandlerFunc(func(resp http.ResponseWriter, req *http.Request) {
- for i := 0; i < len(handlers); i++ {
- handler := handlers[i]
- switch t := handler.(type) {
- case http.HandlerFunc:
- t(resp, req)
- if r, ok := resp.(context.ResponseWriter); ok && r.Status() > 0 {
- return
- }
- case func(http.ResponseWriter, *http.Request):
- t(resp, req)
- if r, ok := resp.(context.ResponseWriter); ok && r.Status() > 0 {
- return
- }
- case func(ctx *context.Context) goctx.CancelFunc:
- ctx := context.GetContext(req)
- cancel := t(ctx)
- if cancel != nil {
- defer cancel()
- }
- if ctx.Written() {
- return
- }
- case func(*context.APIContext) goctx.CancelFunc:
- ctx := context.GetAPIContext(req)
- cancel := t(ctx)
- if cancel != nil {
- defer cancel()
- }
- if ctx.Written() {
- return
- }
- case func(*context.PrivateContext) goctx.CancelFunc:
- ctx := context.GetPrivateContext(req)
- cancel := t(ctx)
- if cancel != nil {
- defer cancel()
- }
- if ctx.Written() {
- return
- }
- case func(ctx *context.Context):
- ctx := context.GetContext(req)
- t(ctx)
- if ctx.Written() {
- return
- }
- case func(*context.APIContext):
- ctx := context.GetAPIContext(req)
- t(ctx)
- if ctx.Written() {
- return
- }
- case func(*context.PrivateContext):
- ctx := context.GetPrivateContext(req)
- t(ctx)
- if ctx.Written() {
- return
- }
- case func(http.Handler) http.Handler:
- var next = http.HandlerFunc(func(http.ResponseWriter, *http.Request) {})
- if len(handlers) > i+1 {
- next = Wrap(handlers[i+1:]...)
- }
- t(next).ServeHTTP(resp, req)
- return
- default:
- panic(fmt.Sprintf("Unsupported handler type: %#v", t))
- }
- }
- })
-}
-
-// Middle wrap a context function as a chi middleware
-func Middle(f func(ctx *context.Context)) func(netx http.Handler) http.Handler {
- return func(next http.Handler) http.Handler {
- return http.HandlerFunc(func(resp http.ResponseWriter, req *http.Request) {
- ctx := context.GetContext(req)
- f(ctx)
- if ctx.Written() {
- return
- }
- next.ServeHTTP(ctx.Resp, ctx.Req)
- })
- }
-}
-
-// MiddleCancel wrap a context function as a chi middleware
-func MiddleCancel(f func(ctx *context.Context) goctx.CancelFunc) func(netx http.Handler) http.Handler {
- return func(next http.Handler) http.Handler {
- return http.HandlerFunc(func(resp http.ResponseWriter, req *http.Request) {
- ctx := context.GetContext(req)
- cancel := f(ctx)
- if cancel != nil {
- defer cancel()
- }
- if ctx.Written() {
- return
- }
- next.ServeHTTP(ctx.Resp, ctx.Req)
- })
- }
-}
-
-// MiddleAPI wrap a context function as a chi middleware
-func MiddleAPI(f func(ctx *context.APIContext)) func(netx http.Handler) http.Handler {
- return func(next http.Handler) http.Handler {
- return http.HandlerFunc(func(resp http.ResponseWriter, req *http.Request) {
- ctx := context.GetAPIContext(req)
- f(ctx)
- if ctx.Written() {
- return
- }
- next.ServeHTTP(ctx.Resp, ctx.Req)
- })
- }
-}
-
// Bind binding an obj to a handler
func Bind(obj interface{}) http.HandlerFunc {
var tp = reflect.TypeOf(obj)
diff --git a/modules/web/routing/context.go b/modules/web/routing/context.go
new file mode 100644
index 0000000000..f57b2e9026
--- /dev/null
+++ b/modules/web/routing/context.go
@@ -0,0 +1,51 @@
+// 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 routing
+
+import (
+ "context"
+ "net/http"
+)
+
+type contextKeyType struct{}
+
+var contextKey contextKeyType
+
+//UpdateFuncInfo updates a context's func info
+func UpdateFuncInfo(ctx context.Context, funcInfo *FuncInfo) {
+ record, ok := ctx.Value(contextKey).(*requestRecord)
+ if !ok {
+ return
+ }
+
+ record.lock.Lock()
+ record.funcInfo = funcInfo
+ record.lock.Unlock()
+
+}
+
+// MarkLongPolling marks the reuqest is a long-polling request, and the logger may output different message for it
+func MarkLongPolling(resp http.ResponseWriter, req *http.Request) {
+ record, ok := req.Context().Value(contextKey).(*requestRecord)
+ if !ok {
+ return
+ }
+
+ record.lock.Lock()
+ record.isLongPolling = true
+ record.lock.Unlock()
+}
+
+//UpdatePanicError updates a context's error info, a panic may be recovered by other middlewares, but we still need to know that.
+func UpdatePanicError(ctx context.Context, err interface{}) {
+ record, ok := ctx.Value(contextKey).(*requestRecord)
+ if !ok {
+ return
+ }
+
+ record.lock.Lock()
+ record.panicError = err
+ record.lock.Unlock()
+}
diff --git a/modules/web/routing/funcinfo.go b/modules/web/routing/funcinfo.go
new file mode 100644
index 0000000000..6d3986e364
--- /dev/null
+++ b/modules/web/routing/funcinfo.go
@@ -0,0 +1,171 @@
+// 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 routing
+
+import (
+ "fmt"
+ "reflect"
+ "runtime"
+ "strings"
+ "sync"
+)
+
+var funcInfoMap = map[uintptr]*FuncInfo{}
+var funcInfoNameMap = map[string]*FuncInfo{}
+var funcInfoMapMu sync.RWMutex
+
+// FuncInfo contains information about the function to be logged by the router log
+type FuncInfo struct {
+ file string
+ shortFile string
+ line int
+ name string
+ shortName string
+}
+
+// String returns a string form of the FuncInfo for logging
+func (info *FuncInfo) String() string {
+ if info == nil {
+ return "unknown-handler"
+ }
+ return fmt.Sprintf("%s:%d(%s)", info.shortFile, info.line, info.shortName)
+}
+
+// GetFuncInfo returns the FuncInfo for a provided function and friendlyname
+func GetFuncInfo(fn interface{}, friendlyName ...string) *FuncInfo {
+ // ptr represents the memory position of the function passed in as v.
+ // This will be used as program counter in FuncForPC below
+ ptr := reflect.ValueOf(fn).Pointer()
+
+ // if we have been provided with a friendlyName look for the named funcs
+ if len(friendlyName) == 1 {
+ name := friendlyName[0]
+ funcInfoMapMu.RLock()
+ info, ok := funcInfoNameMap[name]
+ funcInfoMapMu.RUnlock()
+ if ok {
+ return info
+ }
+ }
+
+ // Otherwise attempt to get pre-cached information for this function pointer
+ funcInfoMapMu.RLock()
+ info, ok := funcInfoMap[ptr]
+ funcInfoMapMu.RUnlock()
+
+ if ok {
+ if len(friendlyName) == 1 {
+ name := friendlyName[0]
+ info = copyFuncInfo(info)
+ info.shortName = name
+
+ funcInfoNameMap[name] = info
+ funcInfoMapMu.Lock()
+ funcInfoNameMap[name] = info
+ funcInfoMapMu.Unlock()
+ }
+ return info
+ }
+
+ // This is likely the first time we have seen this function
+ //
+ // Get the runtime.func for this function (if we can)
+ f := runtime.FuncForPC(ptr)
+ if f != nil {
+ info = convertToFuncInfo(f)
+
+ // cache this info globally
+ funcInfoMapMu.Lock()
+ funcInfoMap[ptr] = info
+
+ // if we have been provided with a friendlyName override the short name we've generated
+ if len(friendlyName) == 1 {
+ name := friendlyName[0]
+ info = copyFuncInfo(info)
+ info.shortName = name
+ funcInfoNameMap[name] = info
+ }
+ funcInfoMapMu.Unlock()
+ }
+ return info
+}
+
+// convertToFuncInfo take a runtime.Func and convert it to a logFuncInfo, fill in shorten filename, etc
+func convertToFuncInfo(f *runtime.Func) *FuncInfo {
+ file, line := f.FileLine(f.Entry())
+
+ info := &FuncInfo{
+ file: strings.ReplaceAll(file, "\\", "/"),
+ line: line,
+ name: f.Name(),
+ }
+
+ // only keep last 2 names in path, fall back to funcName if not
+ info.shortFile = shortenFilename(info.file, info.name)
+
+ // remove package prefix. eg: "xxx.com/pkg1/pkg2.foo" => "pkg2.foo"
+ pos := strings.LastIndexByte(info.name, '/')
+ if pos >= 0 {
+ info.shortName = info.name[pos+1:]
+ } else {
+ info.shortName = info.name
+ }
+
+ // remove ".func[0-9]*" suffix for anonymous func
+ info.shortName = trimAnonymousFunctionSuffix(info.shortName)
+
+ return info
+}
+
+func copyFuncInfo(l *FuncInfo) *FuncInfo {
+ return &FuncInfo{
+ file: l.file,
+ shortFile: l.shortFile,
+ line: l.line,
+ name: l.name,
+ shortName: l.shortName,
+ }
+}
+
+// shortenFilename generates a short source code filename from a full package path, eg: "code.gitea.io/routers/common/logger_context.go" => "common/logger_context.go"
+func shortenFilename(filename, fallback string) string {
+ if filename == "" {
+ return fallback
+ }
+ if lastIndex := strings.LastIndexByte(filename, '/'); lastIndex >= 0 {
+ if secondLastIndex := strings.LastIndexByte(filename[:lastIndex], '/'); secondLastIndex >= 0 {
+ return filename[secondLastIndex+1:]
+ }
+ }
+ return filename
+}
+
+// trimAnonymousFunctionSuffix trims ".func[0-9]*" from the end of anonymous function names, we only want to see the main function names in logs
+func trimAnonymousFunctionSuffix(name string) string {
+ // if the name is an anonymous name, it should be like "{main-function}.func1", so the length can not be less than 7
+ if len(name) < 7 {
+ return name
+ }
+
+ funcSuffixIndex := strings.LastIndex(name, ".func")
+ if funcSuffixIndex < 0 {
+ return name
+ }
+
+ hasFuncSuffix := true
+
+ // len(".func") = 5
+ for i := funcSuffixIndex + 5; i < len(name); i++ {
+ if name[i] < '0' || name[i] > '9' {
+ hasFuncSuffix = false
+ break
+ }
+ }
+
+ if hasFuncSuffix {
+ return name[:funcSuffixIndex]
+ }
+ return name
+}
diff --git a/modules/web/routing/funcinfo_test.go b/modules/web/routing/funcinfo_test.go
new file mode 100644
index 0000000000..9cea7e2817
--- /dev/null
+++ b/modules/web/routing/funcinfo_test.go
@@ -0,0 +1,81 @@
+// 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 routing
+
+import (
+ "fmt"
+ "testing"
+)
+
+func Test_shortenFilename(t *testing.T) {
+ tests := []struct {
+ filename string
+ fallback string
+ expected string
+ }{
+ {
+ "code.gitea.io/routers/common/logger_context.go",
+ "NO_FALLBACK",
+ "common/logger_context.go",
+ },
+ {
+ "common/logger_context.go",
+ "NO_FALLBACK",
+ "common/logger_context.go",
+ },
+ {
+ "logger_context.go",
+ "NO_FALLBACK",
+ "logger_context.go",
+ },
+ {
+ "",
+ "USE_FALLBACK",
+ "USE_FALLBACK",
+ },
+ }
+ for _, tt := range tests {
+ t.Run(fmt.Sprintf("shortenFilename('%s')", tt.filename), func(t *testing.T) {
+ if gotShort := shortenFilename(tt.filename, tt.fallback); gotShort != tt.expected {
+ t.Errorf("shortenFilename('%s'), expect '%s', but get '%s'", tt.filename, tt.expected, gotShort)
+ }
+ })
+ }
+}
+
+func Test_trimAnonymousFunctionSuffix(t *testing.T) {
+ tests := []struct {
+ name string
+ want string
+ }{
+ {
+ "notAnonymous",
+ "notAnonymous",
+ },
+ {
+ "anonymous.func1",
+ "anonymous",
+ },
+ {
+ "notAnonymous.funca",
+ "notAnonymous.funca",
+ },
+ {
+ "anonymous.func100",
+ "anonymous",
+ },
+ {
+ "anonymous.func100.func6",
+ "anonymous.func100",
+ },
+ }
+ for _, tt := range tests {
+ t.Run(tt.name, func(t *testing.T) {
+ if got := trimAnonymousFunctionSuffix(tt.name); got != tt.want {
+ t.Errorf("trimAnonymousFunctionSuffix() = %v, want %v", got, tt.want)
+ }
+ })
+ }
+}
diff --git a/modules/web/routing/logger.go b/modules/web/routing/logger.go
new file mode 100644
index 0000000000..cf3b50725d
--- /dev/null
+++ b/modules/web/routing/logger.go
@@ -0,0 +1,106 @@
+// 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 routing
+
+import (
+ "net/http"
+ "time"
+
+ "code.gitea.io/gitea/modules/context"
+ "code.gitea.io/gitea/modules/log"
+)
+
+// NewLoggerHandler is a handler that will log routing to the router log taking account of
+// routing information
+func NewLoggerHandler() func(next http.Handler) http.Handler {
+ manager := requestRecordsManager{
+ requestRecords: map[uint64]*requestRecord{},
+ }
+ manager.startSlowQueryDetector(3 * time.Second)
+
+ logger := log.GetLogger("router")
+ manager.print = logPrinter(logger)
+ return manager.handler
+}
+
+var (
+ startMessage = log.NewColoredValueBytes("started ", log.DEBUG.Color())
+ slowMessage = log.NewColoredValueBytes("slow ", log.WARN.Color())
+ pollingMessage = log.NewColoredValueBytes("polling ", log.INFO.Color())
+ failedMessage = log.NewColoredValueBytes("failed ", log.WARN.Color())
+ completedMessage = log.NewColoredValueBytes("completed", log.INFO.Color())
+ unknownHandlerMessage = log.NewColoredValueBytes("completed", log.ERROR.Color())
+)
+
+func logPrinter(logger log.Logger) func(trigger Event, record *requestRecord) {
+ return func(trigger Event, record *requestRecord) {
+ if trigger == StartEvent {
+ if !logger.IsTrace() {
+ // for performance, if the "started" message shouldn't be logged, we just return as early as possible
+ // developers can set the router log level to TRACE to get the "started" request messages.
+ return
+ }
+ // when a request starts, we have no information about the handler function information, we only have the request path
+ req := record.request
+ logger.Trace("router: %s %v %s for %s", startMessage, log.ColoredMethod(req.Method), req.RequestURI, req.RemoteAddr)
+ return
+ }
+
+ req := record.request
+
+ // Get data from the record
+ record.lock.Lock()
+ handlerFuncInfo := record.funcInfo.String()
+ isLongPolling := record.isLongPolling
+ isUnknownHandler := record.funcInfo == nil
+ panicErr := record.panicError
+ record.lock.Unlock()
+
+ if trigger == StillExecutingEvent {
+ message := slowMessage
+ level := log.WARN
+ if isLongPolling {
+ level = log.INFO
+ message = pollingMessage
+ }
+ _ = logger.Log(0, level, "router: %s %v %s for %s, elapsed %v @ %s",
+ message,
+ log.ColoredMethod(req.Method), req.RequestURI, req.RemoteAddr,
+ log.ColoredTime(time.Since(record.startTime)),
+ handlerFuncInfo,
+ )
+ return
+ }
+
+ if panicErr != nil {
+ _ = logger.Log(0, log.WARN, "router: %s %v %s for %s, panic in %v @ %s, err=%v",
+ failedMessage,
+ log.ColoredMethod(req.Method), req.RequestURI, req.RemoteAddr,
+ log.ColoredTime(time.Since(record.startTime)),
+ handlerFuncInfo,
+ panicErr,
+ )
+ return
+ }
+
+ var status int
+ if v, ok := record.responseWriter.(context.ResponseWriter); ok {
+ status = v.Status()
+ }
+ level := log.INFO
+ message := completedMessage
+ if isUnknownHandler {
+ level = log.ERROR
+ message = unknownHandlerMessage
+ }
+
+ _ = logger.Log(0, level, "router: %s %v %s for %s, %v %v in %v @ %s",
+ message,
+ log.ColoredMethod(req.Method), req.RequestURI, req.RemoteAddr,
+ log.ColoredStatus(status), log.ColoredStatus(status, http.StatusText(status)), log.ColoredTime(time.Since(record.startTime)),
+ handlerFuncInfo,
+ )
+ }
+}
diff --git a/modules/web/routing/logger_manager.go b/modules/web/routing/logger_manager.go
new file mode 100644
index 0000000000..31fd09f312
--- /dev/null
+++ b/modules/web/routing/logger_manager.go
@@ -0,0 +1,122 @@
+// 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 routing
+
+import (
+ "context"
+ "net/http"
+ "sync"
+ "time"
+
+ "code.gitea.io/gitea/modules/graceful"
+)
+
+// Event indicates when the printer is triggered
+type Event int
+
+const (
+ //StartEvent at the beginning of a request
+ StartEvent Event = iota
+
+ //StillExecutingEvent the request is still executing
+ StillExecutingEvent
+
+ //EndEvent the request has ended (either completed or failed)
+ EndEvent
+)
+
+// Printer is used to output the log for a request
+type Printer func(trigger Event, record *requestRecord)
+
+type requestRecordsManager struct {
+ print Printer
+
+ lock sync.Mutex
+
+ requestRecords map[uint64]*requestRecord
+ count uint64
+}
+
+func (manager *requestRecordsManager) startSlowQueryDetector(threshold time.Duration) {
+ go graceful.GetManager().RunWithShutdownContext(func(baseCtx context.Context) {
+ // This go-routine checks all active requests every second.
+ // If a request has been running for a long time (eg: /user/events), we also print a log with "still-executing" message
+ // After the "still-executing" log is printed, the record will be removed from the map to prevent from duplicated logs in future
+
+ // We do not care about accurate duration here. It just does the check periodically, 0.5s or 1.5s are all OK.
+ t := time.NewTicker(time.Second)
+ for {
+ select {
+ case <-baseCtx.Done():
+ return
+ case <-t.C:
+ now := time.Now()
+
+ var slowRequests []*requestRecord
+
+ // find all slow requests with lock
+ manager.lock.Lock()
+ for index, record := range manager.requestRecords {
+ if now.Sub(record.startTime) < threshold {
+ continue
+ }
+
+ slowRequests = append(slowRequests, record)
+ delete(manager.requestRecords, index)
+ }
+ manager.lock.Unlock()
+
+ // print logs for slow requests
+ for _, record := range slowRequests {
+ manager.print(StillExecutingEvent, record)
+ }
+ }
+ }
+ })
+}
+
+func (manager *requestRecordsManager) handler(next http.Handler) http.Handler {
+ return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
+ record := &requestRecord{
+ startTime: time.Now(),
+ request: req,
+ responseWriter: w,
+ }
+
+ // generate a record index an insert into the map
+ manager.lock.Lock()
+ record.index = manager.count
+ manager.count++
+ manager.requestRecords[record.index] = record
+ manager.lock.Unlock()
+
+ defer func() {
+ // just in case there is a panic. now the panics are all recovered in middleware.go
+ localPanicErr := recover()
+ if localPanicErr != nil {
+ record.lock.Lock()
+ record.panicError = localPanicErr
+ record.lock.Unlock()
+ }
+
+ // remove from the record map
+ manager.lock.Lock()
+ delete(manager.requestRecords, record.index)
+ manager.lock.Unlock()
+
+ // log the end of the request
+ manager.print(EndEvent, record)
+
+ if localPanicErr != nil {
+ // the panic wasn't recovered before us, so we should pass it up, and let the framework handle the panic error
+ panic(localPanicErr)
+ }
+ }()
+
+ req = req.WithContext(context.WithValue(req.Context(), contextKey, record))
+ manager.print(StartEvent, record)
+ next.ServeHTTP(w, req)
+ })
+}
diff --git a/modules/web/routing/requestrecord.go b/modules/web/routing/requestrecord.go
new file mode 100644
index 0000000000..5e225f32e4
--- /dev/null
+++ b/modules/web/routing/requestrecord.go
@@ -0,0 +1,29 @@
+// 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 routing
+
+import (
+ "net/http"
+ "sync"
+ "time"
+)
+
+type requestRecord struct {
+ // index of the record in the records map
+ index uint64
+
+ // immutable fields
+ startTime time.Time
+ request *http.Request
+ responseWriter http.ResponseWriter
+
+ // mutex
+ lock sync.RWMutex
+
+ // mutable fields
+ isLongPolling bool
+ funcInfo *FuncInfo
+ panicError interface{}
+}
diff --git a/modules/web/wrap.go b/modules/web/wrap.go
new file mode 100644
index 0000000000..b55b876069
--- /dev/null
+++ b/modules/web/wrap.go
@@ -0,0 +1,117 @@
+// 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 web
+
+import (
+ goctx "context"
+ "net/http"
+ "strings"
+
+ "code.gitea.io/gitea/modules/context"
+ "code.gitea.io/gitea/modules/web/routing"
+)
+
+// Wrap converts all kinds of routes to standard library one
+func Wrap(handlers ...interface{}) http.HandlerFunc {
+ if len(handlers) == 0 {
+ panic("No handlers found")
+ }
+
+ ourHandlers := make([]wrappedHandlerFunc, 0, len(handlers))
+
+ for _, handler := range handlers {
+ ourHandlers = append(ourHandlers, convertHandler(handler))
+ }
+ return wrapInternal(ourHandlers)
+}
+
+func wrapInternal(handlers []wrappedHandlerFunc) http.HandlerFunc {
+ return func(resp http.ResponseWriter, req *http.Request) {
+ var defers []func()
+ defer func() {
+ for i := len(defers) - 1; i >= 0; i-- {
+ defers[i]()
+ }
+ }()
+ for i := 0; i < len(handlers); i++ {
+ handler := handlers[i]
+ others := handlers[i+1:]
+ done, deferrable := handler(resp, req, others...)
+ if deferrable != nil {
+ defers = append(defers, deferrable)
+ }
+ if done {
+ return
+ }
+ }
+ }
+}
+
+// Middle wrap a context function as a chi middleware
+func Middle(f func(ctx *context.Context)) func(next http.Handler) http.Handler {
+ funcInfo := routing.GetFuncInfo(f)
+ return func(next http.Handler) http.Handler {
+ return http.HandlerFunc(func(resp http.ResponseWriter, req *http.Request) {
+ routing.UpdateFuncInfo(req.Context(), funcInfo)
+ ctx := context.GetContext(req)
+ f(ctx)
+ if ctx.Written() {
+ return
+ }
+ next.ServeHTTP(ctx.Resp, ctx.Req)
+ })
+ }
+}
+
+// MiddleCancel wrap a context function as a chi middleware
+func MiddleCancel(f func(ctx *context.Context) goctx.CancelFunc) func(netx http.Handler) http.Handler {
+ funcInfo := routing.GetFuncInfo(f)
+ return func(next http.Handler) http.Handler {
+ return http.HandlerFunc(func(resp http.ResponseWriter, req *http.Request) {
+ routing.UpdateFuncInfo(req.Context(), funcInfo)
+ ctx := context.GetContext(req)
+ cancel := f(ctx)
+ if cancel != nil {
+ defer cancel()
+ }
+ if ctx.Written() {
+ return
+ }
+ next.ServeHTTP(ctx.Resp, ctx.Req)
+ })
+ }
+}
+
+// MiddleAPI wrap a context function as a chi middleware
+func MiddleAPI(f func(ctx *context.APIContext)) func(next http.Handler) http.Handler {
+ funcInfo := routing.GetFuncInfo(f)
+ return func(next http.Handler) http.Handler {
+ return http.HandlerFunc(func(resp http.ResponseWriter, req *http.Request) {
+ routing.UpdateFuncInfo(req.Context(), funcInfo)
+ ctx := context.GetAPIContext(req)
+ f(ctx)
+ if ctx.Written() {
+ return
+ }
+ next.ServeHTTP(ctx.Resp, ctx.Req)
+ })
+ }
+}
+
+// WrapWithPrefix wraps a provided handler function at a prefix
+func WrapWithPrefix(pathPrefix string, handler http.HandlerFunc, friendlyName ...string) func(next http.Handler) http.Handler {
+ funcInfo := routing.GetFuncInfo(handler, friendlyName...)
+
+ return func(next http.Handler) http.Handler {
+ return http.HandlerFunc(func(resp http.ResponseWriter, req *http.Request) {
+ if !strings.HasPrefix(req.URL.Path, pathPrefix) {
+ next.ServeHTTP(resp, req)
+ return
+ }
+ routing.UpdateFuncInfo(req.Context(), funcInfo)
+ handler(resp, req)
+ })
+ }
+}
diff --git a/modules/web/wrap_convert.go b/modules/web/wrap_convert.go
new file mode 100644
index 0000000000..f2e05de7c1
--- /dev/null
+++ b/modules/web/wrap_convert.go
@@ -0,0 +1,101 @@
+// 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 web
+
+import (
+ goctx "context"
+ "fmt"
+ "net/http"
+
+ "code.gitea.io/gitea/modules/context"
+ "code.gitea.io/gitea/modules/web/routing"
+)
+
+type wrappedHandlerFunc func(resp http.ResponseWriter, req *http.Request, others ...wrappedHandlerFunc) (done bool, deferrable func())
+
+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)
+ t(resp, req)
+ if r, ok := resp.(context.ResponseWriter); ok && r.Status() > 0 {
+ done = true
+ }
+ 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)
+ t(resp, req)
+ if r, ok := resp.(context.ResponseWriter); ok && r.Status() > 0 {
+ done = true
+ }
+ 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)
+ ctx := context.GetContext(req)
+ t(ctx)
+ done = ctx.Written()
+ 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)
+ ctx := context.GetContext(req)
+ deferrable = t(ctx)
+ done = ctx.Written()
+ return
+ }
+ case func(*context.APIContext):
+ return func(resp http.ResponseWriter, req *http.Request, others ...wrappedHandlerFunc) (done bool, deferrable func()) {
+ routing.UpdateFuncInfo(req.Context(), funcInfo)
+ ctx := context.GetAPIContext(req)
+ t(ctx)
+ done = ctx.Written()
+ 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)
+ ctx := context.GetAPIContext(req)
+ deferrable = t(ctx)
+ done = ctx.Written()
+ return
+ }
+ case func(*context.PrivateContext):
+ return func(resp http.ResponseWriter, req *http.Request, others ...wrappedHandlerFunc) (done bool, deferrable func()) {
+ routing.UpdateFuncInfo(req.Context(), funcInfo)
+ ctx := context.GetPrivateContext(req)
+ t(ctx)
+ done = ctx.Written()
+ 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)
+ ctx := context.GetPrivateContext(req)
+ deferrable = t(ctx)
+ done = ctx.Written()
+ return
+ }
+ case func(http.Handler) http.Handler:
+ return func(resp http.ResponseWriter, req *http.Request, others ...wrappedHandlerFunc) (done bool, deferrable func()) {
+ var next = http.HandlerFunc(func(http.ResponseWriter, *http.Request) {})
+ if len(others) > 0 {
+ next = wrapInternal(others)
+ }
+ routing.UpdateFuncInfo(req.Context(), funcInfo)
+ t(next).ServeHTTP(resp, req)
+ return
+ }
+ default:
+ panic(fmt.Sprintf("Unsupported handler type: %#v", t))
+ }
+}
generated by cgit v1.2.3 (git 2.39.1) at 2025-01-19 11:39:56 +0000