diff --git a/apps/cli-go/internal/telemetry/client.go b/apps/cli-go/internal/telemetry/client.go index 34b529a3b3..717e4af181 100644 --- a/apps/cli-go/internal/telemetry/client.go +++ b/apps/cli-go/internal/telemetry/client.go @@ -1,11 +1,14 @@ package telemetry import ( + "log" "net/http" "strings" + "time" "github.com/go-errors/errors" "github.com/posthog/posthog-go" + "github.com/supabase/cli/internal/utils" ) type Analytics interface { @@ -24,6 +27,8 @@ type queueClient interface { type constructor func(apiKey string, config posthog.Config) (queueClient, error) +const shutdownTimeout = 2 * time.Second + type Client struct { client queueClient baseProperties posthog.Properties @@ -38,7 +43,15 @@ func NewClient(apiKey string, endpoint string, baseProperties map[string]any, fa return posthog.NewWithConfig(apiKey, config) } } - config := posthog.Config{} + // Without a positive ShutdownTimeout, Close blocks indefinitely when the + // endpoint is unreachable, hanging every command on networks that block + // PostHog; keep it tight because blackholed networks pay the whole timeout + // at exit. The default logger prints delivery failures to stderr even for + // commands that succeeded, so route them to the --debug logger instead. + config := posthog.Config{ + ShutdownTimeout: shutdownTimeout, + Logger: posthog.StdLogger(log.New(utils.GetDebugLogger(), "posthog ", log.LstdFlags), true), + } if endpoint != "" { config.Endpoint = endpoint } diff --git a/apps/cli-go/internal/telemetry/client_test.go b/apps/cli-go/internal/telemetry/client_test.go index 6ee8ccb27a..bcc8db7d24 100644 --- a/apps/cli-go/internal/telemetry/client_test.go +++ b/apps/cli-go/internal/telemetry/client_test.go @@ -1,10 +1,14 @@ package telemetry import ( + "io" "net/http" + "os" "testing" + "time" "github.com/posthog/posthog-go" + "github.com/spf13/viper" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" "github.com/supabase/cli/internal/debug" @@ -40,6 +44,8 @@ func TestNewClient(t *testing.T) { assert.True(t, client.Enabled()) assert.Equal(t, "phc_test", gotKey) assert.Equal(t, "https://eu.i.posthog.com", gotConfig.Endpoint) + assert.Equal(t, 2*time.Second, gotConfig.ShutdownTimeout) + assert.NotNil(t, gotConfig.Logger) }) t.Run("becomes a no-op when key is empty", func(t *testing.T) { @@ -53,6 +59,37 @@ func TestNewClient(t *testing.T) { assert.NoError(t, client.Capture("device-1", EventCommandExecuted, map[string]any{"command": "login"}, nil)) assert.NoError(t, client.Close()) }) + t.Run("routes posthog logs to stderr only in debug mode", func(t *testing.T) { + originalStderr := os.Stderr + originalDebug := viper.GetBool("DEBUG") + reader, writer, err := os.Pipe() + require.NoError(t, err) + os.Stderr = writer + t.Cleanup(func() { + os.Stderr = originalStderr + viper.Set("DEBUG", originalDebug) + }) + + configFor := func(debugEnabled bool) posthog.Config { + viper.Set("DEBUG", debugEnabled) + var gotConfig posthog.Config + _, err := NewClient("phc_test", "", nil, func(apiKey string, config posthog.Config) (queueClient, error) { + gotConfig = config + return &fakeQueue{}, nil + }) + require.NoError(t, err) + return gotConfig + } + + configFor(false).Logger.Errorf("dropped %d messages", 1) + configFor(true).Logger.Errorf("dropped %d messages", 2) + + require.NoError(t, writer.Close()) + output, err := io.ReadAll(reader) + require.NoError(t, err) + assert.NotContains(t, string(output), "dropped 1 messages") + assert.Contains(t, string(output), "dropped 2 messages") + }) t.Run("works when debug wraps the default transport", func(t *testing.T) { original := http.DefaultTransport http.DefaultTransport = debug.NewTransport() diff --git a/apps/cli/src/legacy/telemetry/legacy-analytics.layer.ts b/apps/cli/src/legacy/telemetry/legacy-analytics.layer.ts index c09fc962b1..1a9ccabeaf 100644 --- a/apps/cli/src/legacy/telemetry/legacy-analytics.layer.ts +++ b/apps/cli/src/legacy/telemetry/legacy-analytics.layer.ts @@ -1,5 +1,4 @@ import { Effect, FileSystem, Layer, Option, Path } from "effect"; -import { PostHog } from "posthog-node"; import { aiToolLayer } from "../../shared/telemetry/ai-tool.layer.ts"; import { AiTool } from "../../shared/telemetry/ai-tool.service.ts"; import { @@ -26,6 +25,7 @@ import { PropSchemaVersion, PropSessionId, } from "../../shared/telemetry/event-catalog.ts"; +import { scopedPosthogClient } from "../../shared/telemetry/posthog-client.ts"; import { resolvePosthogConfig } from "../../shared/telemetry/posthog-config.ts"; import { telemetryRuntimeLayer } from "../../shared/telemetry/runtime.layer.ts"; import { TelemetryRuntime } from "../../shared/telemetry/runtime.service.ts"; @@ -158,14 +158,7 @@ export const legacyAnalyticsLayer = Layer.effect( }); } - const client = new PostHog(posthogConfig.key.value, { - host: posthogConfig.host, - flushAt: 1, - flushInterval: 0, - }); - yield* Effect.addFinalizer(() => - Effect.promise(() => client._shutdown(5_000)).pipe(Effect.ignore), - ); + const client = yield* scopedPosthogClient(posthogConfig.key.value, posthogConfig.host); const loadLinkedProject = makeLoadLinkedProject(fs, path); diff --git a/apps/cli/src/shared/telemetry/analytics.layer.ts b/apps/cli/src/shared/telemetry/analytics.layer.ts index 66a3a8e685..e25f983d7f 100644 --- a/apps/cli/src/shared/telemetry/analytics.layer.ts +++ b/apps/cli/src/shared/telemetry/analytics.layer.ts @@ -1,4 +1,3 @@ -import { PostHog } from "posthog-node"; import { Effect, Layer, Option } from "effect"; import type { ProjectLinkStateValue } from "../../next/config/project-link-state.service.ts"; import { ProjectLinkState } from "../../next/config/project-link-state.service.ts"; @@ -7,6 +6,7 @@ import { aiToolLayer } from "./ai-tool.layer.ts"; import { CurrentAnalyticsContext, type AnalyticsContext } from "./analytics-context.ts"; import { Analytics } from "./analytics.service.ts"; import { AiTool } from "./ai-tool.service.ts"; +import { scopedPosthogClient } from "./posthog-client.ts"; import { telemetryRuntimeLayer } from "./runtime.layer.ts"; import { TelemetryRuntime } from "./runtime.service.ts"; @@ -59,13 +59,9 @@ export const analyticsLayer = Layer.effect( }); } - const client = new PostHog(cliConfig.telemetryPosthogKey.value, { - host: cliConfig.telemetryPosthogHost, - flushAt: 1, - flushInterval: 0, - }); - yield* Effect.addFinalizer(() => - Effect.promise(() => client._shutdown(5_000)).pipe(Effect.ignore), + const client = yield* scopedPosthogClient( + cliConfig.telemetryPosthogKey.value, + cliConfig.telemetryPosthogHost, ); const baseProperties = stripUndefined({ diff --git a/apps/cli/src/shared/telemetry/posthog-client.ts b/apps/cli/src/shared/telemetry/posthog-client.ts new file mode 100644 index 0000000000..612c7cb573 --- /dev/null +++ b/apps/cli/src/shared/telemetry/posthog-client.ts @@ -0,0 +1,36 @@ +import { Effect } from "effect"; +import { PostHog, type PostHogOptions } from "posthog-node"; + +const delivered = { + status: 200, + text: () => Promise.resolve(""), + json: () => Promise.resolve({}), +}; + +// posthog-node has no logger hook: delivery failures hit hardcoded +// console.error calls and multi-second retries, so report them as delivered. +export const fireAndForgetFetch: NonNullable = async (url, options) => { + try { + const response = await globalThis.fetch(url, options); + return response.status >= 400 ? delivered : response; + } catch { + return delivered; + } +}; + +export const scopedPosthogClient = (apiKey: string, host: string) => + Effect.acquireRelease( + Effect.sync( + () => + new PostHog(apiKey, { + host, + flushAt: 1, + flushInterval: 0, + requestTimeout: 2_000, + fetch: fireAndForgetFetch, + }), + ), + // Catch on the promise: Effect.promise turns rejections into defects, + // which escape Effect.ignore and fail the command. + (client) => Effect.promise(() => client._shutdown(5_000).catch(() => undefined)), + ); diff --git a/apps/cli/src/shared/telemetry/posthog-client.unit.test.ts b/apps/cli/src/shared/telemetry/posthog-client.unit.test.ts new file mode 100644 index 0000000000..33630b234f --- /dev/null +++ b/apps/cli/src/shared/telemetry/posthog-client.unit.test.ts @@ -0,0 +1,57 @@ +import { describe, expect, it } from "@effect/vitest"; +import { afterEach, vi } from "vitest"; +import { Effect } from "effect"; +import { PostHog } from "posthog-node"; +import { fireAndForgetFetch, scopedPosthogClient } from "./posthog-client.ts"; + +const BATCH_URL = "https://eu.i.posthog.com/batch/"; +const BATCH_OPTIONS = { method: "POST" as const, headers: {}, body: "{}" }; + +describe("fireAndForgetFetch", () => { + afterEach(() => { + vi.unstubAllGlobals(); + }); + + it("passes successful responses through untouched", async () => { + vi.stubGlobal("fetch", async () => new Response(`{"status":1}`, { status: 200 })); + + const response = await fireAndForgetFetch(BATCH_URL, BATCH_OPTIONS); + + expect(response.status).toBe(200); + expect(await response.text()).toBe(`{"status":1}`); + }); + + it("reports success when the network is unreachable", async () => { + vi.stubGlobal("fetch", async () => { + throw new Error("connect ECONNREFUSED"); + }); + + const response = await fireAndForgetFetch(BATCH_URL, BATCH_OPTIONS); + + expect(response.status).toBe(200); + expect(await response.text()).toBe(""); + expect(await response.json()).toEqual({}); + }); + + it("reports success on error responses so the SDK never retries or logs", async () => { + vi.stubGlobal( + "fetch", + async () => new Response("Proxy Authentication Required", { status: 407 }), + ); + + const response = await fireAndForgetFetch(BATCH_URL, BATCH_OPTIONS); + + expect(response.status).toBe(200); + expect(await response.text()).toBe(""); + }); +}); + +describe("scopedPosthogClient", () => { + it.live("captures and shuts down cleanly against an unreachable host", () => + Effect.gen(function* () { + const client = yield* scopedPosthogClient("phc_test", "http://127.0.0.1:9"); + expect(client).toBeInstanceOf(PostHog); + client.capture({ event: "verify_event", distinctId: "device-1" }); + }).pipe(Effect.scoped), + ); +});