collector.go 8.8 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349
  1. package servertiming
  2. import (
  3. "context"
  4. "fmt"
  5. "sort"
  6. "strconv"
  7. "strings"
  8. "sync"
  9. "time"
  10. )
  11. const (
  12. HeaderName = "Server-Timing"
  13. AdminUIHeader = "X-Admin-UI-Request"
  14. UserUIHeader = "X-User-UI-Request"
  15. MetricDatabase = "db"
  16. MetricRedis = "redis"
  17. dependencyPrefix = "dep_"
  18. maxMetricNameLength = 48
  19. maxIntervals = 2048
  20. maxHeaderLength = 4096
  21. )
  22. type contextKey struct{}
  23. type interval struct {
  24. start time.Time
  25. end time.Time
  26. }
  27. type metric struct {
  28. count int64
  29. intervals []interval
  30. }
  31. // Collector stores request-scoped timing samples. It is safe for concurrent use.
  32. type Collector struct {
  33. startedAt time.Time
  34. mu sync.Mutex
  35. metrics map[string]*metric
  36. cacheStatus string
  37. }
  38. // New creates a collector whose total duration starts at startedAt.
  39. func New(startedAt time.Time) *Collector {
  40. if startedAt.IsZero() {
  41. startedAt = time.Now()
  42. }
  43. return &Collector{
  44. startedAt: startedAt,
  45. metrics: make(map[string]*metric),
  46. }
  47. }
  48. // WithCollector attaches a collector to a context.
  49. func WithCollector(ctx context.Context, collector *Collector) context.Context {
  50. if ctx == nil {
  51. ctx = context.Background()
  52. }
  53. if collector == nil {
  54. return ctx
  55. }
  56. return context.WithValue(ctx, contextKey{}, collector)
  57. }
  58. // FromContext returns the request timing collector, when one is active.
  59. func FromContext(ctx context.Context) (*Collector, bool) {
  60. if ctx == nil {
  61. return nil, false
  62. }
  63. collector, ok := ctx.Value(contextKey{}).(*Collector)
  64. return collector, ok && collector != nil
  65. }
  66. // Active reports whether timing collection is enabled for this request.
  67. func Active(ctx context.Context) bool {
  68. _, ok := FromContext(ctx)
  69. return ok
  70. }
  71. // Record adds a completed interval and operation count to a metric.
  72. func Record(ctx context.Context, name string, startedAt, endedAt time.Time, count int) {
  73. collector, ok := FromContext(ctx)
  74. if !ok {
  75. return
  76. }
  77. collector.Record(name, startedAt, endedAt, count)
  78. }
  79. // RecordInterval adds timing without incrementing the operation count. It is
  80. // useful when one logical operation has multiple blocking driver calls.
  81. func RecordInterval(ctx context.Context, name string, startedAt, endedAt time.Time) {
  82. collector, ok := FromContext(ctx)
  83. if !ok {
  84. return
  85. }
  86. collector.record(name, startedAt, endedAt, 0)
  87. }
  88. // Record adds a completed interval directly to the collector.
  89. func (c *Collector) Record(name string, startedAt, endedAt time.Time, count int) {
  90. if count <= 0 {
  91. count = 1
  92. }
  93. c.record(name, startedAt, endedAt, count)
  94. }
  95. func (c *Collector) record(name string, startedAt, endedAt time.Time, count int) {
  96. name = normalizeMetricName(name)
  97. if c == nil || name == "" || startedAt.IsZero() || endedAt.Before(startedAt) {
  98. return
  99. }
  100. if count < 0 {
  101. count = 0
  102. }
  103. c.mu.Lock()
  104. m := c.metrics[name]
  105. if m == nil {
  106. m = &metric{}
  107. c.metrics[name] = m
  108. }
  109. m.count += int64(count)
  110. if len(m.intervals) < maxIntervals {
  111. m.intervals = append(m.intervals, interval{start: startedAt, end: endedAt})
  112. }
  113. c.mu.Unlock()
  114. }
  115. // Observe starts a metric span and returns an idempotent completion function.
  116. func Observe(ctx context.Context, name string) func() {
  117. collector, ok := FromContext(ctx)
  118. name = normalizeMetricName(name)
  119. if !ok || name == "" {
  120. return func() {}
  121. }
  122. startedAt := time.Now()
  123. var once sync.Once
  124. return func() {
  125. once.Do(func() {
  126. collector.Record(name, startedAt, time.Now(), 1)
  127. })
  128. }
  129. }
  130. // ObserveDependency starts a named external dependency span.
  131. func ObserveDependency(ctx context.Context, module string) func() {
  132. return Observe(ctx, dependencyMetricName(module))
  133. }
  134. // RecordDependency records a completed external dependency interval.
  135. func RecordDependency(ctx context.Context, module string, startedAt, endedAt time.Time) {
  136. Record(ctx, dependencyMetricName(module), startedAt, endedAt, 1)
  137. }
  138. // SetCacheStatus records the response-cache outcome for the request.
  139. func SetCacheStatus(ctx context.Context, status string) {
  140. collector, ok := FromContext(ctx)
  141. if !ok {
  142. return
  143. }
  144. status = normalizeCacheStatus(status)
  145. if status == "" {
  146. return
  147. }
  148. collector.mu.Lock()
  149. collector.cacheStatus = status
  150. collector.mu.Unlock()
  151. }
  152. // HeaderValue renders a bounded, deterministic Server-Timing header.
  153. func HeaderValue(ctx context.Context, endedAt time.Time, cacheStatus string) string {
  154. collector, ok := FromContext(ctx)
  155. if !ok {
  156. return ""
  157. }
  158. return collector.HeaderValue(endedAt, cacheStatus)
  159. }
  160. // HeaderValue renders a bounded, deterministic Server-Timing header.
  161. func (c *Collector) HeaderValue(endedAt time.Time, cacheStatus string) string {
  162. if c == nil {
  163. return ""
  164. }
  165. if endedAt.IsZero() {
  166. endedAt = time.Now()
  167. }
  168. if endedAt.Before(c.startedAt) {
  169. endedAt = c.startedAt
  170. }
  171. c.mu.Lock()
  172. metrics := make(map[string]metric, len(c.metrics))
  173. allIntervals := make([]interval, 0)
  174. dependencyIntervals := make([]interval, 0)
  175. var dependencyCount int64
  176. for name, source := range c.metrics {
  177. copied := metric{count: source.count, intervals: append([]interval(nil), source.intervals...)}
  178. metrics[name] = copied
  179. allIntervals = append(allIntervals, copied.intervals...)
  180. if strings.HasPrefix(name, dependencyPrefix) {
  181. dependencyIntervals = append(dependencyIntervals, copied.intervals...)
  182. dependencyCount += copied.count
  183. }
  184. }
  185. storedCacheStatus := c.cacheStatus
  186. c.mu.Unlock()
  187. total := endedAt.Sub(c.startedAt)
  188. blocked := unionDuration(allIntervals, c.startedAt, endedAt)
  189. app := total - blocked
  190. if app < 0 {
  191. app = 0
  192. }
  193. cacheStatus = normalizeCacheStatus(cacheStatus)
  194. if cacheStatus == "" {
  195. cacheStatus = normalizeCacheStatus(storedCacheStatus)
  196. }
  197. if cacheStatus == "" {
  198. cacheStatus = "bypass"
  199. }
  200. database := metrics[MetricDatabase]
  201. redisMetric := metrics[MetricRedis]
  202. parts := []string{
  203. "total;dur=" + formatDuration(total),
  204. "app;dur=" + formatDuration(app),
  205. fmt.Sprintf("db;dur=%s;desc=\"queries=%d\"", formatDuration(unionDuration(database.intervals, c.startedAt, endedAt)), database.count),
  206. fmt.Sprintf("redis;dur=%s;desc=\"commands=%d\"", formatDuration(unionDuration(redisMetric.intervals, c.startedAt, endedAt)), redisMetric.count),
  207. "cache;desc=\"" + cacheStatus + "\"",
  208. fmt.Sprintf("deps;dur=%s;desc=\"calls=%d\"", formatDuration(unionDuration(dependencyIntervals, c.startedAt, endedAt)), dependencyCount),
  209. }
  210. dependencyNames := make([]string, 0)
  211. for name := range metrics {
  212. if strings.HasPrefix(name, dependencyPrefix) {
  213. dependencyNames = append(dependencyNames, name)
  214. }
  215. }
  216. sort.Strings(dependencyNames)
  217. for _, name := range dependencyNames {
  218. m := metrics[name]
  219. part := fmt.Sprintf("%s;dur=%s;desc=\"calls=%d\"", name, formatDuration(unionDuration(m.intervals, c.startedAt, endedAt)), m.count)
  220. candidate := strings.Join(append(parts, part), ", ")
  221. if len(candidate) > maxHeaderLength {
  222. break
  223. }
  224. parts = append(parts, part)
  225. }
  226. return strings.Join(parts, ", ")
  227. }
  228. func dependencyMetricName(module string) string {
  229. module = normalizeMetricName(module)
  230. module = strings.TrimPrefix(module, dependencyPrefix)
  231. if module == "" {
  232. module = "http"
  233. }
  234. return dependencyPrefix + module
  235. }
  236. func normalizeMetricName(name string) string {
  237. name = strings.ToLower(strings.TrimSpace(name))
  238. if name == "" {
  239. return ""
  240. }
  241. var b strings.Builder
  242. b.Grow(min(len(name), maxMetricNameLength))
  243. for _, r := range name {
  244. if b.Len() >= maxMetricNameLength {
  245. break
  246. }
  247. switch {
  248. case r >= 'a' && r <= 'z', r >= '0' && r <= '9':
  249. _, _ = b.WriteRune(r)
  250. case r == '_' || r == '-':
  251. _ = b.WriteByte('_')
  252. }
  253. }
  254. return strings.Trim(b.String(), "_")
  255. }
  256. func normalizeCacheStatus(status string) string {
  257. switch strings.ToLower(strings.TrimSpace(status)) {
  258. case "hit":
  259. return "hit"
  260. case "miss":
  261. return "miss"
  262. case "bypass":
  263. return "bypass"
  264. default:
  265. return ""
  266. }
  267. }
  268. func unionDuration(intervals []interval, lowerBound, upperBound time.Time) time.Duration {
  269. if len(intervals) == 0 || !upperBound.After(lowerBound) {
  270. return 0
  271. }
  272. normalized := make([]interval, 0, len(intervals))
  273. for _, item := range intervals {
  274. start := item.start
  275. end := item.end
  276. if start.Before(lowerBound) {
  277. start = lowerBound
  278. }
  279. if end.After(upperBound) {
  280. end = upperBound
  281. }
  282. if end.After(start) {
  283. normalized = append(normalized, interval{start: start, end: end})
  284. }
  285. }
  286. if len(normalized) == 0 {
  287. return 0
  288. }
  289. sort.Slice(normalized, func(i, j int) bool {
  290. return normalized[i].start.Before(normalized[j].start)
  291. })
  292. currentStart := normalized[0].start
  293. currentEnd := normalized[0].end
  294. var total time.Duration
  295. for _, item := range normalized[1:] {
  296. if !item.start.After(currentEnd) {
  297. if item.end.After(currentEnd) {
  298. currentEnd = item.end
  299. }
  300. continue
  301. }
  302. total += currentEnd.Sub(currentStart)
  303. currentStart = item.start
  304. currentEnd = item.end
  305. }
  306. total += currentEnd.Sub(currentStart)
  307. return total
  308. }
  309. func formatDuration(value time.Duration) string {
  310. if value < 0 {
  311. value = 0
  312. }
  313. return strconv.FormatFloat(float64(value)/float64(time.Millisecond), 'f', 1, 64)
  314. }