1// Copyright 2019 The Go Authors. All rights reserved.
2// Use of this source code is governed by a BSD-style
3// license that can be found in the LICENSE file.
4
5package debug
6
7import (
8	"context"
9	"fmt"
10	"html/template"
11	"net/http"
12	"sort"
13	"sync"
14	"time"
15
16	"golang.org/x/tools/internal/event"
17	"golang.org/x/tools/internal/event/core"
18	"golang.org/x/tools/internal/event/export"
19	"golang.org/x/tools/internal/event/label"
20	"golang.org/x/tools/internal/lsp/debug/tag"
21)
22
23var RPCTmpl = template.Must(template.Must(BaseTemplate.Clone()).Parse(`
24{{define "title"}}RPC Information{{end}}
25{{define "body"}}
26	<H2>Inbound</H2>
27	{{template "rpcSection" .Inbound}}
28	<H2>Outbound</H2>
29	{{template "rpcSection" .Outbound}}
30{{end}}
31{{define "rpcSection"}}
32	{{range .}}<P>
33		<b>{{.Method}}</b> {{.Started}} <a href="/trace/{{.Method}}">traces</a> ({{.InProgress}} in progress)
34		<br>
35		<i>Latency</i> {{with .Latency}}{{.Mean}} ({{.Min}}<{{.Max}}){{end}}
36		<i>By bucket</i> 0s {{range .Latency.Values}}{{if gt .Count 0}}<b>{{.Count}}</b> {{.Limit}} {{end}}{{end}}
37		<br>
38		<i>Received</i> {{.Received}} (avg. {{.ReceivedMean}})
39		<i>Sent</i> {{.Sent}} (avg. {{.SentMean}})
40		<br>
41		<i>Result codes</i> {{range .Codes}}{{.Key}}={{.Count}} {{end}}
42		</P>
43	{{end}}
44{{end}}
45`))
46
47type Rpcs struct { // exported for testing
48	mu       sync.Mutex
49	Inbound  []*rpcStats // stats for incoming lsp rpcs sorted by method name
50	Outbound []*rpcStats // stats for outgoing lsp rpcs sorted by method name
51}
52
53type rpcStats struct {
54	Method    string
55	Started   int64
56	Completed int64
57
58	Latency  rpcTimeHistogram
59	Received byteUnits
60	Sent     byteUnits
61	Codes    []*rpcCodeBucket
62}
63
64type rpcTimeHistogram struct {
65	Sum    timeUnits
66	Count  int64
67	Min    timeUnits
68	Max    timeUnits
69	Values []rpcTimeBucket
70}
71
72type rpcTimeBucket struct {
73	Limit timeUnits
74	Count int64
75}
76
77type rpcCodeBucket struct {
78	Key   string
79	Count int64
80}
81
82func (r *Rpcs) ProcessEvent(ctx context.Context, ev core.Event, lm label.Map) context.Context {
83	r.mu.Lock()
84	defer r.mu.Unlock()
85	switch {
86	case event.IsStart(ev):
87		if _, stats := r.getRPCSpan(ctx, ev); stats != nil {
88			stats.Started++
89		}
90	case event.IsEnd(ev):
91		span, stats := r.getRPCSpan(ctx, ev)
92		if stats != nil {
93			endRPC(ctx, ev, span, stats)
94		}
95	case event.IsMetric(ev):
96		sent := byteUnits(tag.SentBytes.Get(lm))
97		rec := byteUnits(tag.ReceivedBytes.Get(lm))
98		if sent != 0 || rec != 0 {
99			if _, stats := r.getRPCSpan(ctx, ev); stats != nil {
100				stats.Sent += sent
101				stats.Received += rec
102			}
103		}
104	}
105	return ctx
106}
107
108func endRPC(ctx context.Context, ev core.Event, span *export.Span, stats *rpcStats) {
109	// update the basic counts
110	stats.Completed++
111
112	// get and record the status code
113	if status := getStatusCode(span); status != "" {
114		var b *rpcCodeBucket
115		for c, entry := range stats.Codes {
116			if entry.Key == status {
117				b = stats.Codes[c]
118				break
119			}
120		}
121		if b == nil {
122			b = &rpcCodeBucket{Key: status}
123			stats.Codes = append(stats.Codes, b)
124			sort.Slice(stats.Codes, func(i int, j int) bool {
125				return stats.Codes[i].Key < stats.Codes[j].Key
126			})
127		}
128		b.Count++
129	}
130
131	// calculate latency if this was an rpc span
132	elapsedTime := span.Finish().At().Sub(span.Start().At())
133	latencyMillis := timeUnits(elapsedTime) / timeUnits(time.Millisecond)
134	if stats.Latency.Count == 0 {
135		stats.Latency.Min = latencyMillis
136		stats.Latency.Max = latencyMillis
137	} else {
138		if stats.Latency.Min > latencyMillis {
139			stats.Latency.Min = latencyMillis
140		}
141		if stats.Latency.Max < latencyMillis {
142			stats.Latency.Max = latencyMillis
143		}
144	}
145	stats.Latency.Count++
146	stats.Latency.Sum += latencyMillis
147	for i := range stats.Latency.Values {
148		if stats.Latency.Values[i].Limit > latencyMillis {
149			stats.Latency.Values[i].Count++
150			break
151		}
152	}
153}
154
155func (r *Rpcs) getRPCSpan(ctx context.Context, ev core.Event) (*export.Span, *rpcStats) {
156	// get the span
157	span := export.GetSpan(ctx)
158	if span == nil {
159		return nil, nil
160	}
161	// use the span start event look up the correct stats block
162	// we do this because it prevents us matching a sub span
163	return span, r.getRPCStats(span.Start())
164}
165
166func (r *Rpcs) getRPCStats(lm label.Map) *rpcStats {
167	method := tag.Method.Get(lm)
168	if method == "" {
169		return nil
170	}
171	set := &r.Inbound
172	if tag.RPCDirection.Get(lm) != tag.Inbound {
173		set = &r.Outbound
174	}
175	// get the record for this method
176	index := sort.Search(len(*set), func(i int) bool {
177		return (*set)[i].Method >= method
178	})
179
180	if index < len(*set) && (*set)[index].Method == method {
181		return (*set)[index]
182	}
183
184	old := *set
185	*set = make([]*rpcStats, len(old)+1)
186	copy(*set, old[:index])
187	copy((*set)[index+1:], old[index:])
188	stats := &rpcStats{Method: method}
189	stats.Latency.Values = make([]rpcTimeBucket, len(millisecondsDistribution))
190	for i, m := range millisecondsDistribution {
191		stats.Latency.Values[i].Limit = timeUnits(m)
192	}
193	(*set)[index] = stats
194	return stats
195}
196
197func (s *rpcStats) InProgress() int64       { return s.Started - s.Completed }
198func (s *rpcStats) SentMean() byteUnits     { return s.Sent / byteUnits(s.Started) }
199func (s *rpcStats) ReceivedMean() byteUnits { return s.Received / byteUnits(s.Started) }
200
201func (h *rpcTimeHistogram) Mean() timeUnits { return h.Sum / timeUnits(h.Count) }
202
203func getStatusCode(span *export.Span) string {
204	for _, ev := range span.Events() {
205		if status := tag.StatusCode.Get(ev); status != "" {
206			return status
207		}
208	}
209	return ""
210}
211
212func (r *Rpcs) getData(req *http.Request) interface{} {
213	return r
214}
215
216func units(v float64, suffixes []string) string {
217	s := ""
218	for _, s = range suffixes {
219		n := v / 1000
220		if n < 1 {
221			break
222		}
223		v = n
224	}
225	return fmt.Sprintf("%.2f%s", v, s)
226}
227
228type timeUnits float64
229
230func (v timeUnits) String() string {
231	v = v * 1000 * 1000
232	return units(float64(v), []string{"ns", "μs", "ms", "s"})
233}
234
235type byteUnits float64
236
237func (v byteUnits) String() string {
238	return units(float64(v), []string{"B", "KB", "MB", "GB", "TB"})
239}
240