summaryrefslogtreecommitdiffstats
path: root/modules/web/routing/logger_manager.go
diff options
context:
space:
mode:
Diffstat (limited to '')
-rw-r--r--modules/web/routing/logger_manager.go124
1 files changed, 124 insertions, 0 deletions
diff --git a/modules/web/routing/logger_manager.go b/modules/web/routing/logger_manager.go
new file mode 100644
index 0000000..aa25ec3
--- /dev/null
+++ b/modules/web/routing/logger_manager.go
@@ -0,0 +1,124 @@
+// Copyright 2021 The Gitea Authors. All rights reserved.
+// SPDX-License-Identifier: MIT
+
+package routing
+
+import (
+ "context"
+ "net/http"
+ "sync"
+ "time"
+
+ "code.gitea.io/gitea/modules/graceful"
+ "code.gitea.io/gitea/modules/process"
+)
+
+// 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(ctx context.Context) {
+ ctx, _, finished := process.GetManager().AddTypedContext(ctx, "Service: SlowQueryDetector", process.SystemProcessType, true)
+ defer finished()
+ // 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 <-ctx.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)
+ })
+}