diff --git a/acceptance/testdata/telemetry/no-telemetry-for-completion.txtar b/acceptance/testdata/telemetry/no-telemetry-for-completion.txtar index ffde6e605..20139ce5f 100644 --- a/acceptance/testdata/telemetry/no-telemetry-for-completion.txtar +++ b/acceptance/testdata/telemetry/no-telemetry-for-completion.txtar @@ -4,4 +4,4 @@ env GH_TELEMETRY=log env GH_TELEMETRY_SAMPLE_RATE=100 exec gh completion -s bash -! stderr 'Telemetry payload:' +stderr 'Telemetry payload: none' diff --git a/acceptance/testdata/telemetry/no-telemetry-for-extension.txtar b/acceptance/testdata/telemetry/no-telemetry-for-extension.txtar index fcb820e0c..19f3d69cc 100644 --- a/acceptance/testdata/telemetry/no-telemetry-for-extension.txtar +++ b/acceptance/testdata/telemetry/no-telemetry-for-extension.txtar @@ -22,7 +22,7 @@ cd $WORK # Run the extension and verify no telemetry is logged exec gh hello stdout 'hello from extension' -! stderr 'Telemetry payload:' +stderr 'Telemetry payload: none' -- gh-hello.sh -- #!/usr/bin/env bash diff --git a/acceptance/testdata/telemetry/no-telemetry-for-ghes-user.txtar b/acceptance/testdata/telemetry/no-telemetry-for-ghes-user.txtar index 0fe6f4bb2..f04fabf36 100644 --- a/acceptance/testdata/telemetry/no-telemetry-for-ghes-user.txtar +++ b/acceptance/testdata/telemetry/no-telemetry-for-ghes-user.txtar @@ -5,4 +5,4 @@ env GH_TELEMETRY_SAMPLE_RATE=100 env GH_ENTERPRISE_TOKEN=fake-enterprise-token exec gh version -! stderr 'Telemetry payload:' +stderr 'Telemetry payload: none' diff --git a/acceptance/testdata/telemetry/no-telemetry-for-send-telemetry.txtar b/acceptance/testdata/telemetry/no-telemetry-for-send-telemetry.txtar index 7f9d0457a..28436aaae 100644 --- a/acceptance/testdata/telemetry/no-telemetry-for-send-telemetry.txtar +++ b/acceptance/testdata/telemetry/no-telemetry-for-send-telemetry.txtar @@ -8,7 +8,7 @@ env GH_TELEMETRY_ENDPOINT_URL=http://localhost:1 # It will fail to connect but that's fine — we only care about telemetry logging. stdin payload.json ! exec gh send-telemetry -! stderr 'Telemetry payload:' +stderr 'Telemetry payload: none' -- payload.json -- {"events":[{"type":"test","dimensions":{},"measures":{}}]} diff --git a/internal/ghcmd/cmd.go b/internal/ghcmd/cmd.go index 34806f874..9512e4b55 100644 --- a/internal/ghcmd/cmd.go +++ b/internal/ghcmd/cmd.go @@ -82,19 +82,31 @@ func Main() exitCode { case cfgErr != nil: // Without a valid on-disk config we can't honour user telemetry preferences, so disable it to be safe. telemetryService = &telemetry.NoOpService{} - case os.Getenv("GH_PRIVATE_ENABLE_TELEMETRY") == "" || mightBeGHESUser(cfg): - telemetryService = &telemetry.NoOpService{} default: telemetryState := telemetry.ParseTelemetryState(cfg.Telemetry().Value) + telemetryDisabled := os.Getenv("GH_PRIVATE_ENABLE_TELEMETRY") == "" || mightBeGHESUser(cfg) + switch telemetryState { case telemetry.Disabled: telemetryService = &telemetry.NoOpService{} case telemetry.Logged: + // Always construct the real service in log mode so that the log + // flusher runs and surfaces an explicit "Telemetry payload: none" + // marker when no events will be sent. This gives the user an + // observable signal that telemetry is wired up even when their + // context (e.g. GHES) causes events to be dropped. telemetryService = telemetry.NewService( telemetry.LogFlusher(ioStreams.ErrOut, ioStreams.ColorEnabled()), telemetry.WithAdditionalCommonDimensions(additionalCommonDimensions), ) + if telemetryDisabled { + telemetryService.Disable() + } case telemetry.Enabled: + if telemetryDisabled { + telemetryService = &telemetry.NoOpService{} + break + } sampleRate := 1 if v, err := strconv.Atoi(os.Getenv("GH_TELEMETRY_SAMPLE_RATE")); err == nil && v >= 0 && v <= 100 { sampleRate = v diff --git a/internal/telemetry/telemetry.go b/internal/telemetry/telemetry.go index 67fb8b762..e5dcbad9a 100644 --- a/internal/telemetry/telemetry.go +++ b/internal/telemetry/telemetry.go @@ -3,6 +3,7 @@ package telemetry import ( "bytes" + "encoding/binary" "encoding/json" "errors" "fmt" @@ -166,17 +167,24 @@ func WithSampleRate(rate int) telemetryServiceOption { } // LogFlusher returns a flush function that writes telemetry payloads to the provided log writer. This is used for the "log" telemetry mode, which is intended for debugging and development. +// When there are no events to report (for example the command opted out of telemetry, the user is on GHES, or no events were recorded), a "Telemetry payload: none" marker is written so that the absence of events is observable. var LogFlusher = func(log io.Writer, colorEnabled bool) func(payload SendTelemetryPayload) { return func(payload SendTelemetryPayload) { + header := "Telemetry payload:" + if colorEnabled { + header = ansi.Color(header, "cyan+b") + } + + if len(payload.Events) == 0 { + fmt.Fprintf(log, "%s none\n", header) + return + } + payloadBytes, err := json.Marshal(payload) if err != nil { return } - header := "Telemetry payload:" - if colorEnabled { - header = ansi.Color(header, "cyan+b") - } fmt.Fprintf(log, "%s\n", header) if colorEnabled { @@ -190,8 +198,12 @@ var LogFlusher = func(log io.Writer, colorEnabled bool) func(payload SendTelemet } // GitHubFlusher returns a flush function that sends telemetry payloads to a child `gh send-telemetry` process. This is used for the "enabled" telemetry mode. +// Empty payloads are dropped without spawning a subprocess. var GitHubFlusher = func(executable string) func(payload SendTelemetryPayload) { return func(payload SendTelemetryPayload) { + if len(payload.Events) == 0 { + return + } SpawnSendTelemetry(executable, payload) } } @@ -221,7 +233,7 @@ func NewService(flusher func(SendTelemetryPayload), opts ...telemetryServiceOpti maps.Copy(commonDimensions, telemetryServiceOpts.additionalDimensions) hash := uuid.NewSHA1(uuid.Nil, []byte(invocationID)) - sampleBucket := hash[0] % 100 + sampleBucket := byte(binary.BigEndian.Uint32(hash[:4]) % 100) s := &service{ flush: flusher, @@ -278,28 +290,29 @@ func (s *service) Flush() { s.mu.Lock() defer s.mu.Unlock() - if s.disabled { - return - } - if s.previouslyCalled { return } s.previouslyCalled = true - if len(s.events) == 0 { - return - } - if s.sampleRate > 0 && s.sampleRate < 100 && int(s.sampleBucket) >= s.sampleRate { return } - payload := SendTelemetryPayload{ - Events: make([]PayloadEvent, len(s.events)), + // When the service has been disabled mid-invocation (e.g. an enterprise host + // was contacted), discard any recorded events. We still call the flusher + // with an empty payload so that the log-mode flusher can surface the + // absence of telemetry rather than leaving the user staring at silence. + events := s.events + if s.disabled { + events = nil } - for i, recorded := range s.events { + payload := SendTelemetryPayload{ + Events: make([]PayloadEvent, len(events)), + } + + for i, recorded := range events { dimensions := map[string]string{ "timestamp": recorded.recordedAt.UTC().Format("2006-01-02T15:04:05.000Z"), } diff --git a/internal/telemetry/telemetry_test.go b/internal/telemetry/telemetry_test.go index 207d611ee..a796afd67 100644 --- a/internal/telemetry/telemetry_test.go +++ b/internal/telemetry/telemetry_test.go @@ -351,6 +351,23 @@ func TestNewServiceLogModeWithColorLogsToWriter(t *testing.T) { assert.Contains(t, output, "\033[", "expected ANSI escape sequences when color is enabled") } +func TestLogFlusherWritesNoneMarkerForEmptyPayload(t *testing.T) { + t.Run("no color", func(t *testing.T) { + var buf bytes.Buffer + LogFlusher(&buf, false)(SendTelemetryPayload{}) + assert.Equal(t, "Telemetry payload: none\n", buf.String()) + }) + + t.Run("with color", func(t *testing.T) { + var buf bytes.Buffer + LogFlusher(&buf, true)(SendTelemetryPayload{}) + output := buf.String() + assert.Contains(t, output, "Telemetry payload:") + assert.Contains(t, output, "none") + assert.Contains(t, output, "\x1b") // ANSI escape char for color codes + }) +} + func TestServiceDeviceIDFallback(t *testing.T) { t.Cleanup(stubDeviceIDError(errors.New("no device id"))) @@ -365,14 +382,19 @@ func TestServiceDeviceIDFallback(t *testing.T) { } func TestServiceFlush(t *testing.T) { - t.Run("does nothing when no events recorded", func(t *testing.T) { + t.Run("calls flusher with empty payload when no events recorded", func(t *testing.T) { t.Cleanup(stubDeviceID("test-device")) + var captured SendTelemetryPayload called := false - svc := newService(func(SendTelemetryPayload) { called = true }, nil) + svc := newService(func(p SendTelemetryPayload) { + called = true + captured = p + }, nil) svc.Flush() - assert.False(t, called, "flusher should not be called with no events") + assert.True(t, called, "flusher should be called even with no events so log mode can surface the absence") + assert.Empty(t, captured.Events, "payload should have no events") }) t.Run("flushes events with merged dimensions", func(t *testing.T) { @@ -599,24 +621,33 @@ func TestWithAdditionalCommonDimensions(t *testing.T) { } func TestServiceDisable(t *testing.T) { - t.Run("prevents flush from sending events", func(t *testing.T) { + t.Run("drops recorded events from flushed payload", func(t *testing.T) { t.Cleanup(stubDeviceID("test-device")) + var captured SendTelemetryPayload called := false - svc := newService(func(SendTelemetryPayload) { called = true }, nil) + svc := newService(func(p SendTelemetryPayload) { + called = true + captured = p + }, nil) svc.Record(ghtelemetry.Event{Type: "test"}) svc.Disable() svc.Flush() - assert.False(t, called, "flusher should not be called after Disable()") + assert.True(t, called, "flusher should still be called so log mode can surface the absence of events") + assert.Empty(t, captured.Events, "recorded events should be dropped after Disable()") }) - t.Run("prevents flush even with multiple recorded events", func(t *testing.T) { + t.Run("drops events even with multiple recorded events", func(t *testing.T) { t.Cleanup(stubDeviceID("test-device")) + var captured SendTelemetryPayload called := false - svc := newService(func(SendTelemetryPayload) { called = true }, nil) + svc := newService(func(p SendTelemetryPayload) { + called = true + captured = p + }, nil) svc.Record(ghtelemetry.Event{Type: "event1"}) svc.Record(ghtelemetry.Event{Type: "event2"}) @@ -624,20 +655,26 @@ func TestServiceDisable(t *testing.T) { svc.Disable() svc.Flush() - assert.False(t, called, "flusher should not be called after Disable()") + assert.True(t, called, "flusher should still be called") + assert.Empty(t, captured.Events, "recorded events should be dropped after Disable()") }) t.Run("can be called before any events are recorded", func(t *testing.T) { t.Cleanup(stubDeviceID("test-device")) + var captured SendTelemetryPayload called := false - svc := newService(func(SendTelemetryPayload) { called = true }, nil) + svc := newService(func(p SendTelemetryPayload) { + called = true + captured = p + }, nil) svc.Disable() svc.Record(ghtelemetry.Event{Type: "test"}) svc.Flush() - assert.False(t, called, "flusher should not be called when disabled before recording") + assert.True(t, called, "flusher should still be called") + assert.Empty(t, captured.Events, "events recorded after Disable() should be dropped") }) }