1. 1
2. 2
3. 3
4. 4
5. 5
6. 6
7. 7
8. 8
9. 9
10. 10
11. 11
12. 12
13. 13
14. 14
15. 15
16. 16
17. 17
18. 18
19. 19
20. 20
21. 21
22. 22
23. 23
24. 24
25. 25
26. 26
27. 27
28. 28
29. 29
30. 30
31. 31
32. 32
33. 33
34. 34
35. 35
36. 36
37. 37
38. 38
39. 39
40. 40
41. 41
42. 42
43. 43
44. 44
45. 45
46. 46
47. 47
48. 48
49. 49
50. 50
51. 51
52. 52
53. 53
54. 54
55. 55
56. 56
57. 57
58. 58
59. 59
60. 60
61. 61
62. 62
63. 63
64. 64
65. 65
66. 66
67. 67
68. 68
69. 69
70. 70
71. 71
72. 72
73. 73
74. 74
75. 75
76. 76
77. 77
78. 78
79. 79
80. 80
81. 81
82. 82
83. 83
84. 84
85. 85
86. 86
87. 87
88. 88
89. 89
90. 90
91. 91
92. 92
93. 93
94. 94
95. 95
96. 96
97. 97
98. 98
99. 99
100. 100
101. 101
102. 102
103. 103
104. 104
105. 105
106. 106
107. 107
108. 108
109. 109
110. 110
111. 111
112. 112
113. 113
114. 114
115. 115
116. 116
117. 117
118. 118
119. 119
120. 120
121. 121
122. 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)
	})
}