Skip to content

Commit 2eb7b3c

Browse files
authored
refactor: routing info middleware (#37653)
fix #37650
1 parent 7621b65 commit 2eb7b3c

5 files changed

Lines changed: 87 additions & 95 deletions

File tree

modules/web/routing/logger.go

Lines changed: 1 addition & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -11,19 +11,6 @@ import (
1111
"code.gitea.io/gitea/modules/web/types"
1212
)
1313

14-
// NewLoggerHandler is a handler that will log routing to the router log taking account of
15-
// routing information
16-
func NewLoggerHandler() func(next http.Handler) http.Handler {
17-
manager := requestRecordsManager{
18-
requestRecords: map[uint64]*requestRecord{},
19-
}
20-
manager.startSlowQueryDetector(3 * time.Second)
21-
22-
logger := log.GetLogger("router")
23-
manager.print = logPrinter(logger)
24-
return manager.handler
25-
}
26-
2714
var (
2815
startMessage = log.NewColoredValue("started ", log.DEBUG.ColorAttributes()...)
2916
slowMessage = log.NewColoredValue("slow ", log.WARN.ColorAttributes()...)
@@ -89,7 +76,7 @@ func logPrinter(logger log.Logger) func(trigger Event, record *requestRecord) {
8976
}
9077

9178
var status int
92-
if v, ok := record.responseWriter.(types.ResponseStatusProvider); ok {
79+
if v, ok := record.respWriter.(types.ResponseStatusProvider); ok {
9380
status = v.WrittenStatus()
9481
}
9582
logLevel := record.logLevel

modules/web/routing/logger_manager.go

Lines changed: 32 additions & 68 deletions
Original file line numberDiff line numberDiff line change
@@ -6,7 +6,6 @@ package routing
66
import (
77
"context"
88
"fmt"
9-
"net/http"
109
"sync"
1110
"time"
1211

@@ -29,26 +28,21 @@ const (
2928
EndEvent
3029
)
3130

32-
// Printer is used to output the log for a request
33-
type Printer func(trigger Event, record *requestRecord)
31+
// logPrinterFunc is used to output the log for a request
32+
type logPrinterFunc func(trigger Event, record *requestRecord)
3433

35-
type requestRecordsManager struct {
36-
print Printer
37-
38-
lock sync.Mutex
39-
40-
requestRecords map[uint64]*requestRecord
41-
count uint64
34+
type loggerRequestManager struct {
35+
logPrint logPrinterFunc
36+
reqRecords sync.Map // it only contains the active requests which haven't been detected as "slow"
4237
}
4338

44-
func (manager *requestRecordsManager) startSlowQueryDetector(threshold time.Duration) {
39+
func (manager *loggerRequestManager) startSlowQueryDetector(threshold time.Duration) {
4540
go graceful.GetManager().RunWithShutdownContext(func(ctx context.Context) {
4641
ctx, _, finished := process.GetManager().AddTypedContext(ctx, "Service: SlowQueryDetector", process.SystemProcessType, true)
4742
defer finished()
4843
// This go-routine checks all active requests every second.
4944
// If a request has been running for a long time (eg: /user/events), we also print a log with "still-executing" message
5045
// After the "still-executing" log is printed, the record will be removed from the map to prevent from duplicated logs in future
51-
5246
// We do not care about accurate duration here. It just does the check periodically, 0.5s or 1.5s are all OK.
5347
t := time.NewTicker(time.Second)
5448
for {
@@ -58,69 +52,39 @@ func (manager *requestRecordsManager) startSlowQueryDetector(threshold time.Dura
5852
case <-t.C:
5953
now := time.Now()
6054

61-
var slowRequests []*requestRecord
62-
63-
// find all slow requests with lock
64-
manager.lock.Lock()
65-
for index, record := range manager.requestRecords {
66-
if now.Sub(record.startTime) < threshold {
67-
continue
68-
}
69-
70-
slowRequests = append(slowRequests, record)
71-
delete(manager.requestRecords, index)
72-
}
73-
manager.lock.Unlock()
74-
7555
// print logs for slow requests
76-
for _, record := range slowRequests {
77-
manager.print(StillExecutingEvent, record)
78-
}
56+
manager.reqRecords.Range(func(key, value any) bool {
57+
index, record := key.(uint64), value.(*requestRecord)
58+
if now.Sub(record.startTime) >= threshold {
59+
manager.logPrint(StillExecutingEvent, record)
60+
manager.reqRecords.Delete(index)
61+
}
62+
return true
63+
})
7964
}
8065
}
8166
})
8267
}
8368

84-
func (manager *requestRecordsManager) handler(next http.Handler) http.Handler {
85-
return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
86-
record := &requestRecord{
87-
startTime: time.Now(),
88-
request: req,
89-
responseWriter: w,
69+
func (manager *loggerRequestManager) handleRequestRecord(record *requestRecord) func() {
70+
manager.reqRecords.Store(record.index, record)
71+
manager.logPrint(StartEvent, record)
72+
73+
return func() {
74+
// just in case there is a panic. now the panics are all recovered in middleware.go
75+
localPanicErr := recover()
76+
if localPanicErr != nil {
77+
record.lock.Lock()
78+
record.panicError = fmt.Errorf("%v\n%s", localPanicErr, log.Stack(2))
79+
record.lock.Unlock()
9080
}
9181

92-
// generate a record index an insert into the map
93-
manager.lock.Lock()
94-
record.index = manager.count
95-
manager.count++
96-
manager.requestRecords[record.index] = record
97-
manager.lock.Unlock()
82+
manager.reqRecords.Delete(record.index)
83+
manager.logPrint(EndEvent, record)
9884

99-
defer func() {
100-
// just in case there is a panic. now the panics are all recovered in middleware.go
101-
localPanicErr := recover()
102-
if localPanicErr != nil {
103-
record.lock.Lock()
104-
record.panicError = fmt.Errorf("%v\n%s", localPanicErr, log.Stack(2))
105-
record.lock.Unlock()
106-
}
107-
108-
// remove from the record map
109-
manager.lock.Lock()
110-
delete(manager.requestRecords, record.index)
111-
manager.lock.Unlock()
112-
113-
// log the end of the request
114-
manager.print(EndEvent, record)
115-
116-
if localPanicErr != nil {
117-
// the panic wasn't recovered before us, so we should pass it up, and let the framework handle the panic error
118-
panic(localPanicErr)
119-
}
120-
}()
121-
122-
req = req.WithContext(context.WithValue(req.Context(), contextKey, record))
123-
manager.print(StartEvent, record)
124-
next.ServeHTTP(w, req)
125-
})
85+
if localPanicErr != nil {
86+
// the panic wasn't recovered before us, so we should pass it up, and let the framework handle the panic error
87+
panic(localPanicErr)
88+
}
89+
}
12690
}

modules/web/routing/requestinfo.go

Lines changed: 43 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,43 @@
1+
// Copyright 2026 The Gitea Authors. All rights reserved.
2+
// SPDX-License-Identifier: MIT
3+
4+
package routing
5+
6+
import (
7+
"context"
8+
"net/http"
9+
"sync/atomic"
10+
"time"
11+
12+
"code.gitea.io/gitea/modules/log"
13+
"code.gitea.io/gitea/modules/setting"
14+
)
15+
16+
// NewRequestInfoHandler is a handler that saves request info into request context.
17+
// If router logger is enabled, it will also print request logs and detect slow requests.
18+
func NewRequestInfoHandler() func(next http.Handler) http.Handler {
19+
var reqLogger *loggerRequestManager
20+
if setting.IsRouteLogEnabled() {
21+
reqLogger = &loggerRequestManager{
22+
logPrint: logPrinter(log.GetLogger("router")),
23+
}
24+
reqLogger.startSlowQueryDetector(3 * time.Second)
25+
}
26+
var requestCounter atomic.Uint64
27+
return func(next http.Handler) http.Handler {
28+
return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
29+
record := &requestRecord{
30+
index: requestCounter.Add(1),
31+
startTime: time.Now(),
32+
respWriter: w,
33+
}
34+
req = req.WithContext(context.WithValue(req.Context(), contextKey, record))
35+
record.request = req
36+
if reqLogger != nil {
37+
end := reqLogger.handleRequestRecord(record)
38+
defer end()
39+
}
40+
next.ServeHTTP(w, req)
41+
})
42+
}
43+
}

modules/web/routing/requestrecord.go

Lines changed: 10 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -12,20 +12,20 @@ import (
1212
)
1313

1414
type requestRecord struct {
15-
// index of the record in the records map
16-
index uint64
17-
1815
// immutable fields
19-
startTime time.Time
20-
request *http.Request
21-
responseWriter http.ResponseWriter
16+
index uint64 // unique number (per process) for the request
17+
startTime time.Time
18+
request *http.Request
19+
respWriter http.ResponseWriter
2220

2321
// mutex
2422
lock sync.RWMutex
2523

26-
// mutable fields
24+
// below are mutable fields
25+
funcInfo *FuncInfo
26+
// * for "mark as long polling"
2727
isLongPolling bool
28-
logLevel log.Level
29-
funcInfo *FuncInfo
30-
panicError error
28+
// * for router logger
29+
logLevel log.Level
30+
panicError error
3131
}

routers/common/middleware.go

Lines changed: 1 addition & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -34,9 +34,7 @@ func ProtocolMiddlewares() (handlers []any) {
3434
handlers = append(handlers, ForwardedHeadersHandler(setting.ReverseProxyLimit, setting.ReverseProxyTrustedProxies))
3535
}
3636

37-
if setting.IsRouteLogEnabled() {
38-
handlers = append(handlers, routing.NewLoggerHandler())
39-
}
37+
handlers = append(handlers, routing.NewRequestInfoHandler())
4038

4139
if setting.IsAccessLogEnabled() {
4240
handlers = append(handlers, context.AccessLogger())

0 commit comments

Comments
 (0)