Skip to content

Commit 1574f38

Browse files
committed
refactor/telemetry: add debug diagnostics
Keep expected telemetry failures out of normal output while making them available through debug logging with the underlying error. Narrow the concrete recorder type, require its logger dependency, and retain the server-required parameters and numeric metadata wire format. ## Test Plan - go test ./...
1 parent 12e947e commit 1574f38

2 files changed

Lines changed: 49 additions & 45 deletions

File tree

‎internal/telemetry/telemetry.go‎

Lines changed: 20 additions & 22 deletions
Original file line numberDiff line numberDiff line change
@@ -18,12 +18,13 @@ import (
1818

1919
"github.com/sourcegraph/src-cli/internal/api"
2020

21+
"github.com/sourcegraph/log"
2122
"github.com/sourcegraph/sourcegraph/lib/errors"
2223
)
2324

2425
const (
2526
// clientName identifies src-cli as the source of telemetry events.
26-
clientName = "SRC_CLI"
27+
clientName = "src.cli"
2728

2829
// eventParametersVersion is the schema version of the metadata we attach to
2930
// each event. Bump it when the shape of the metadata changes.
@@ -47,37 +48,37 @@ const recordEventsMutation = `mutation RecordTelemetryEvents($events: [Telemetry
4748
}`
4849

4950
// Recorder records events through an api.Client.
50-
type Recorder struct {
51+
type recorder struct {
5152
client api.Client
5253
clientVersion string
5354
timeout time.Duration
55+
logger log.Logger
5456
}
5557

5658
// NewRecorder returns a Recorder for the given src-cli version.
57-
func NewRecorder(client api.Client, clientVersion string) *Recorder {
58-
return &Recorder{
59+
func NewRecorder(client api.Client, logger log.Logger, clientVersion string) *recorder {
60+
return &recorder{
5961
client: client,
6062
clientVersion: clientVersion,
6163
timeout: defaultTimeout,
64+
logger: logger,
6265
}
6366
}
6467

6568
// Record sends an event on a best-effort basis. Feature and action identify the
6669
// event (for example, "srcCli.search" and "succeeded"). Metadata must contain
67-
// only numeric, PII-free facts. Record never returns an error or panics: network,
68-
// GraphQL, timeout, and old-instance failures are silently dropped. It applies
69-
// its own timeout, so the caller's context need not carry a deadline.
70-
func (r *Recorder) Record(ctx context.Context, feature, action string, metadata map[string]float64) {
71-
_ = r.record(ctx, feature, action, metadata)
70+
// only numeric, PII-free facts. Network, GraphQL, timeout, and old-instance
71+
// failures are logged at debug level. Record applies its own timeout, so the
72+
// caller's context need not carry a deadline.
73+
func (r *recorder) Record(ctx context.Context, feature, action string, metadata map[string]float64) {
74+
if err := r.record(ctx, feature, action, metadata); err != nil {
75+
r.logger.Debug("recording telemetry event", log.String("feature", feature), log.String("action", action), log.Error(err))
76+
}
7277
}
7378

7479
// record does the work behind Record and returns any error, so it can be tested
7580
// directly. Callers outside tests should use Record.
76-
func (r *Recorder) record(ctx context.Context, feature, action string, metadata map[string]float64) error {
77-
if r.client == nil {
78-
return errors.New("nil api client")
79-
}
80-
81+
func (r *recorder) record(ctx context.Context, feature, action string, metadata map[string]float64) error {
8182
ctx, cancel := context.WithTimeout(ctx, r.timeout)
8283
defer cancel()
8384

@@ -124,7 +125,7 @@ func buildEventInput(clientVersion, feature, action string, metadata map[string]
124125
return map[string]any{
125126
"feature": feature,
126127
"action": action,
127-
"source": map[string]any{
128+
"source": map[string]string{
128129
"client": clientName,
129130
"clientVersion": clientVersion,
130131
},
@@ -139,16 +140,13 @@ func buildEventInput(clientVersion, feature, action string, metadata map[string]
139140
// the API expects, sorted by key for deterministic output.
140141
func buildMetadata(metadata map[string]float64) []any {
141142
out := make([]any, 0, len(metadata))
142-
if len(metadata) == 0 {
143-
return out
144-
}
145143
keys := make([]string, 0, len(metadata))
146-
for k := range metadata {
147-
keys = append(keys, k)
144+
for key := range metadata {
145+
keys = append(keys, key)
148146
}
149147
sort.Strings(keys)
150-
for _, k := range keys {
151-
out = append(out, map[string]any{"key": k, "value": metadata[k]})
148+
for _, key := range keys {
149+
out = append(out, map[string]any{"key": key, "value": metadata[key]})
152150
}
153151
return out
154152
}

‎internal/telemetry/telemetry_test.go‎

Lines changed: 29 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,8 @@ import (
1818
apimock "github.com/sourcegraph/src-cli/internal/api/mock"
1919
"github.com/sourcegraph/src-cli/internal/oauth"
2020

21+
"github.com/sourcegraph/log"
22+
"github.com/sourcegraph/log/logtest"
2123
"github.com/sourcegraph/sourcegraph/lib/errors"
2224
"github.com/stretchr/testify/assert"
2325
"github.com/stretchr/testify/mock"
@@ -70,7 +72,8 @@ func TestRecord_SendsWellFormedMutation(t *testing.T) {
7072
Return(req, nil)
7173
client.On("Do", req).Return(response(http.StatusOK, "{}"), nil)
7274

73-
rec := NewRecorder(client, testClientVersion)
75+
logger := log.NoOp()
76+
rec := NewRecorder(client, logger, testClientVersion)
7477
rec.Record(context.Background(), "srcCli.search", "succeeded", map[string]float64{
7578
"durationMs": 12,
7679
"exitCode": 0,
@@ -90,20 +93,17 @@ func TestRecord_SendsWellFormedMutation(t *testing.T) {
9093
assert.Equal(t, clientName, source["client"])
9194
assert.Equal(t, testClientVersion, source["clientVersion"])
9295

93-
params := event["parameters"].(map[string]any)
94-
assert.Equal(t, float64(eventParametersVersion), params["version"])
95-
96-
metadata := params["metadata"].([]any)
97-
// sorted by key: durationMs, exitCode
96+
parameters := event["parameters"].(map[string]any)
97+
assert.Equal(t, float64(eventParametersVersion), parameters["version"])
9898
assert.Equal(t, []any{
9999
map[string]any{"key": "durationMs", "value": float64(12)},
100100
map[string]any{"key": "exitCode", "value": float64(0)},
101-
}, metadata)
101+
}, parameters["metadata"])
102102

103103
client.AssertExpectations(t)
104104
}
105105

106-
func TestRecord_EmptyMetadataSendsEmptyList(t *testing.T) {
106+
func TestRecord_NilMetadataSendsEmptyList(t *testing.T) {
107107
client := &apimock.Client{}
108108
req := httptest.NewRequest(http.MethodPost, "/.api/graphql", nil)
109109

@@ -119,12 +119,14 @@ func TestRecord_EmptyMetadataSendsEmptyList(t *testing.T) {
119119
Return(req, nil)
120120
client.On("Do", req).Return(response(http.StatusOK, "{}"), nil)
121121

122-
rec := NewRecorder(client, testClientVersion)
122+
logger := log.NoOp()
123+
rec := NewRecorder(client, logger, testClientVersion)
123124
rec.Record(context.Background(), "srcCli.version", "succeeded", nil)
124125

125126
event := gotPayload.Variables["events"].([]any)[0].(map[string]any)
126-
params := event["parameters"].(map[string]any)
127-
assert.Equal(t, []any{}, params["metadata"])
127+
parameters := event["parameters"].(map[string]any)
128+
assert.Equal(t, float64(eventParametersVersion), parameters["version"])
129+
assert.Equal(t, []any{}, parameters["metadata"])
128130
}
129131

130132
func TestRecord_NetworkErrorSwallowed(t *testing.T) {
@@ -133,12 +135,19 @@ func TestRecord_NetworkErrorSwallowed(t *testing.T) {
133135
client.On("NewHTTPRequest", mock.Anything, http.MethodPost, ".api/graphql", mock.Anything).Return(req, nil)
134136
client.On("Do", req).Return(nil, errors.New("connection refused"))
135137

136-
rec := NewRecorder(client, testClientVersion)
138+
logger, exportLogs := logtest.CapturedWith(t, logtest.LoggerOptions{Level: log.LevelNone})
139+
rec := NewRecorder(client, logger, testClientVersion)
137140

138141
// Must not panic and must not surface the error.
139142
assert.NotPanics(t, func() {
140143
rec.Record(context.Background(), "srcCli.search", "failed", nil)
141144
})
145+
logs := exportLogs()
146+
if assert.Len(t, logs, 1) {
147+
assert.Equal(t, log.LevelDebug, logs[0].Level)
148+
assert.Equal(t, "recording telemetry event", logs[0].Message)
149+
assert.Equal(t, "connection refused", logs[0].Fields["error"])
150+
}
142151

143152
// record itself reports the error for callers that want it.
144153
err := rec.record(context.Background(), "srcCli.search", "failed", nil)
@@ -153,14 +162,8 @@ func TestRecord_GraphQLErrorSwallowed(t *testing.T) {
153162
client.On("NewHTTPRequest", mock.Anything, http.MethodPost, ".api/graphql", mock.Anything).Return(req, nil)
154163
client.On("Do", req).Return(response(http.StatusOK, "{\"errors\":[{\"message\":\"unknown field telemetry\"}]}"), nil)
155164

156-
rec := NewRecorder(client, testClientVersion)
157-
assert.NotPanics(t, func() {
158-
rec.Record(context.Background(), "srcCli.search", "succeeded", nil)
159-
})
160-
}
161-
162-
func TestRecord_NilClientDoesNotPanic(t *testing.T) {
163-
rec := NewRecorder(nil, testClientVersion)
165+
logger := log.NoOp()
166+
rec := NewRecorder(client, logger, testClientVersion)
164167
assert.NotPanics(t, func() {
165168
rec.Record(context.Background(), "srcCli.search", "succeeded", nil)
166169
})
@@ -198,7 +201,8 @@ func TestRecord_OAuthUnauthorizedDoesNotWriteToStdout(t *testing.T) {
198201
os.Stdout = stdoutWriter
199202
t.Cleanup(func() { os.Stdout = oldStdout })
200203

201-
rec := NewRecorder(client, testClientVersion)
204+
logger := log.NoOp()
205+
rec := NewRecorder(client, logger, testClientVersion)
202206
rec.Record(context.Background(), "srcCli.search", "succeeded", nil)
203207

204208
if err := stdoutWriter.Close(); err != nil {
@@ -230,7 +234,8 @@ func TestRecord_AppliesTimeout(t *testing.T) {
230234
Return(req, nil)
231235
client.On("Do", req).Return(response(http.StatusOK, "{}"), nil)
232236

233-
rec := NewRecorder(client, testClientVersion)
237+
logger := log.NoOp()
238+
rec := NewRecorder(client, logger, testClientVersion)
234239
rec.timeout = 50 * time.Millisecond
235240
rec.Record(context.Background(), "srcCli.search", "succeeded", nil)
236241

@@ -240,7 +245,8 @@ func TestRecord_AppliesTimeout(t *testing.T) {
240245
func TestRecord_TimeoutCancelsHTTPRequest(t *testing.T) {
241246
requestCanceled := make(chan struct{})
242247
client := &cancellationClient{canceled: requestCanceled, release: make(chan struct{})}
243-
rec := NewRecorder(client, testClientVersion)
248+
logger := log.NoOp()
249+
rec := NewRecorder(client, logger, testClientVersion)
244250
rec.timeout = 20 * time.Millisecond
245251

246252
ctx, cancel := context.WithCancel(context.Background())

0 commit comments

Comments
 (0)