From 98de6d326e10504e9fae4b1e7e12bf2a87f3f0c5 Mon Sep 17 00:00:00 2001 From: Gonzalo Serrano Date: Wed, 5 Aug 2026 14:43:24 +0200 Subject: [PATCH 1/3] fix(service): don't report READY before the endpoint accepts connections service create/start/fork waited only on the control-plane status field, which flips to READY before Postgres binds its port. ready.go already documents READY as "accepting connections", so callers that connect immediately raced it and got ECONNREFUSED. Add WaitForConnectable, which probes the endpoint until it answers, and run it after the status wait. Any Postgres protocol error counts as serving so the probe works without credentials; 57P03 keeps waiting. Best-effort: an unverified endpoint warns rather than failing, since a VPC-only or allowlisted service is legitimately unreachable from the CLI host while being healthy. --- internal/cmd/service_create.go | 15 +- internal/cmd/service_fork.go | 9 + internal/cmd/service_start.go | 10 + internal/common/wait_connectable.go | 224 +++++++++++++++++++++++ internal/common/wait_connectable_test.go | 221 ++++++++++++++++++++++ 5 files changed, 478 insertions(+), 1 deletion(-) create mode 100644 internal/common/wait_connectable.go create mode 100644 internal/common/wait_connectable_test.go diff --git a/internal/cmd/service_create.go b/internal/cmd/service_create.go index eff8c137..3cc16f64 100644 --- a/internal/cmd/service_create.go +++ b/internal/cmd/service_create.go @@ -206,7 +206,20 @@ Note: You can specify both CPU and memory together, or specify only one (the oth }); waitErr != nil { fmt.Fprintf(statusOutput, "❌ Error: %s\n", waitErr) } else { - fmt.Fprintf(statusOutput, "🎉 Service is ready and running!\n") + // READY only means the control plane finished reconciling. Confirm + // the endpoint serves before claiming the service is usable. + if common.WaitForConnectable(cmd.Context(), common.ConnectableWaitArgs{ + Client: cfg.Client, + ProjectID: cfg.ProjectID, + ServiceID: serviceID, + Role: "tsdbadmin", + InitialPassword: util.Deref(service.InitialPassword), + Output: statusOutput, + }) { + fmt.Fprintf(statusOutput, "🎉 Service is ready and running!\n") + } else { + fmt.Fprintf(statusOutput, "✅ Service provisioned.\n") + } printConnectMessage(statusOutput, passwordSaved, createNoSetDefault, serviceID) } } diff --git a/internal/cmd/service_fork.go b/internal/cmd/service_fork.go index 58c5f6a6..9eb7d3b6 100644 --- a/internal/cmd/service_fork.go +++ b/internal/cmd/service_fork.go @@ -227,6 +227,15 @@ Examples: }); waitErr != nil { fmt.Fprintf(statusOutput, "❌ Error: %s\n", waitErr) } else { + // A fresh fork reports READY before its endpoint is up, same as create. + common.WaitForConnectable(cmd.Context(), common.ConnectableWaitArgs{ + Client: cfg.Client, + ProjectID: cfg.ProjectID, + ServiceID: forkedServiceID, + Role: "tsdbadmin", + InitialPassword: util.Deref(forkedService.InitialPassword), + Output: statusOutput, + }) fmt.Fprintf(statusOutput, "🎉 Service fork completed successfully!\n") printConnectMessage(statusOutput, passwordSaved, forkNoSetDefault, forkedServiceID) } diff --git a/internal/cmd/service_start.go b/internal/cmd/service_start.go index e9be236e..b007ea47 100644 --- a/internal/cmd/service_start.go +++ b/internal/cmd/service_start.go @@ -105,6 +105,16 @@ Examples: return err } + // A resumed service reports READY before its endpoint is back up, so + // confirm it serves before handing control back. + common.WaitForConnectable(cmd.Context(), common.ConnectableWaitArgs{ + Client: cfg.Client, + ProjectID: cfg.ProjectID, + ServiceID: serviceID, + Role: "tsdbadmin", + Output: statusOutput, + }) + fmt.Fprintf(statusOutput, "✅ Service has been successfully started!\n") return nil }, diff --git a/internal/common/wait_connectable.go b/internal/common/wait_connectable.go new file mode 100644 index 00000000..2606cae0 --- /dev/null +++ b/internal/common/wait_connectable.go @@ -0,0 +1,224 @@ +package common + +import ( + "context" + "errors" + "fmt" + "io" + "net" + "syscall" + "time" + + "github.com/jackc/pgx/v5" + "github.com/jackc/pgx/v5/pgconn" + + "github.com/timescale/tiger-cli/internal/api" +) + +// A READY status means the control plane finished reconciling, which is not the +// same as Postgres having bound its port: on a fast provision the endpoint still +// refuses connections for a few seconds after the status flips. ready.go already +// documents READY as "accepting connections", so waiting on the status alone +// leaves that promise unkept, and any caller that connects immediately (rather +// than after some incidental latency) races it. +// +// WaitForConnectable closes that gap by probing the endpoint until it answers. + +// DefaultConnectableTimeout bounds the endpoint probe. It is deliberately much +// shorter than the provisioning wait: once the control plane reports READY the +// endpoint comes up in seconds, so a longer wait here only delays the report +// that we could not reach it. +const DefaultConnectableTimeout = 2 * time.Minute + +// connectableProbeTimeout bounds a single connection attempt, so one blackholed +// dial can't consume the whole budget. +const connectableProbeTimeout = 5 * time.Second + +type ConnectableWaitArgs struct { + Client *api.ClientWithResponses + ProjectID string + ServiceID string + + // Role is the database role to probe with (e.g. "tsdbadmin"). + Role string + + // InitialPassword lets the probe authenticate fully. It is optional: without + // it the server answers with an auth error, which still proves the endpoint + // is serving (see classifyProbe). + InitialPassword string + + Output io.Writer + + // Timeout bounds the whole probe. Zero means DefaultConnectableTimeout. + Timeout time.Duration +} + +// WaitForConnectable blocks until the service's Postgres endpoint answers and +// reports whether it got there. It is best-effort by design: an unverified +// endpoint warns on Output instead of failing, because a service can be +// legitimately unreachable from where the CLI runs (VPC-only, IP allowlist) +// while being perfectly healthy, and failing those users buys nothing. +func WaitForConnectable(ctx context.Context, args ConnectableWaitArgs) bool { + timeout := args.Timeout + if timeout <= 0 { + timeout = DefaultConnectableTimeout + } + ctx, cancel := context.WithTimeout(ctx, timeout) + defer cancel() + + verified, cause := args.pollEndpoint(ctx) + if !verified { + warnUnverified(args.Output, cause) + } + return verified +} + +// pollEndpoint owns the spinner so it is always stopped before the caller prints +// anything, and returns the last failure to explain why it gave up. +func (args ConnectableWaitArgs) pollEndpoint(ctx context.Context) (bool, error) { + spinner := NewSpinner(args.Output, "Waiting for the endpoint to accept connections") + defer spinner.Stop() + + ticker := time.NewTicker(1 * time.Second) + defer ticker.Stop() + + for { + verdict, err := args.probe(ctx) + switch verdict { + case probeServing: + return true, nil + case probeUnreachable: + // Not "not yet" but "not from here": waiting longer won't help. + return false, err + } + + if err != nil { + spinner.Update(fmt.Sprintf("Endpoint not accepting connections yet: %s", err)) + } + + select { + case <-ctx.Done(): + return false, err + case <-ticker.C: + } + } +} + +func warnUnverified(out io.Writer, cause error) { + fmt.Fprintf(out, "⚠️ Warning: service reports READY but its endpoint could not be verified from here") + if cause != nil { + fmt.Fprintf(out, " (%s)", cause) + } + fmt.Fprintf(out, ".\n The service may still be starting, or may not be reachable from this network.\n") +} + +// probe fetches the current service and makes one connection attempt. The +// service is re-fetched every round because the create response predates the +// endpoint being assigned, so the host/port can appear part-way through. +func (args ConnectableWaitArgs) probe(ctx context.Context) (probeVerdict, error) { + resp, err := args.Client.GetServiceWithResponse(ctx, args.ProjectID, args.ServiceID) + if err != nil { + return probeNotYet, err + } + if resp.StatusCode() != 200 || resp.JSON200 == nil { + return probeNotYet, fmt.Errorf("unexpected %s while fetching service", resp.Status()) + } + + details, err := GetConnectionDetails(*resp.JSON200, ConnectionDetailsOptions{ + Role: args.Role, + WithPassword: true, + InitialPassword: args.InitialPassword, + }) + if err != nil { + // Typically "endpoint host not available": not assigned yet. + return probeNotYet, err + } + + attemptCtx, cancel := context.WithTimeout(ctx, connectableProbeTimeout) + defer cancel() + + conn, err := pgx.Connect(attemptCtx, details.String()) + if err != nil { + return classifyProbe(ctx, err), err + } + defer conn.Close(attemptCtx) + + if err := conn.Ping(attemptCtx); err != nil { + return classifyProbe(ctx, err), err + } + return probeServing, nil +} + +// probeVerdict is what one connection attempt tells us about the endpoint. +type probeVerdict int + +const ( + // probeNotYet: the endpoint isn't up but plausibly will be. Keep waiting. + probeNotYet probeVerdict = iota + // probeServing: Postgres answered. Ready, even if it refused our credentials. + probeServing + // probeUnreachable: we can't tell from here. Stop waiting and say so. + probeUnreachable +) + +// classifyProbe decides what a failed connection attempt means. +// +// The load-bearing rule: any Postgres protocol error proves the server is up and +// talking, so it counts as serving even when it's an auth failure. That keeps +// the probe useful without credentials, which matters because +// --password-storage=none leaves the CLI with no password to offer. +// +// parent is the overall wait context, used to tell "this attempt timed out" from +// "the whole budget ran out". +func classifyProbe(parent context.Context, err error) probeVerdict { + if err == nil { + return probeServing + } + + // 57P03 (CANNOT_CONNECT_NOW) is the one protocol error that means "up but + // still starting", so it's the one that keeps us waiting. + var pgErr *pgconn.PgError + if errors.As(err, &pgErr) { + if pgErr.Code == "57P03" { + return probeNotYet + } + return probeServing + } + + switch { + // A single slow attempt is inconclusive; keep waiting unless the whole + // budget is spent, in which case the caller reports it unverified. + case errors.Is(err, context.DeadlineExceeded): + if parent.Err() != nil { + return probeUnreachable + } + return probeNotYet + case errors.Is(err, context.Canceled): + return probeUnreachable + // Nothing listening yet: the exact shape of the race this fixes. + case errors.Is(err, syscall.ECONNREFUSED): + return probeNotYet + // Endpoint DNS can lag the status flip. + case isDNSNotFound(err): + return probeNotYet + // Any other dial-stage failure. Checked after the specific cases above so + // the common ones stay self-documenting, and so the fix doesn't depend on + // one errno matching identically on every platform we release for. + case isDialFailure(err): + return probeNotYet + } + + // Anything else (TLS failure, unexpected protocol framing) is not something + // more waiting resolves. + return probeUnreachable +} + +func isDNSNotFound(err error) bool { + var dnsErr *net.DNSError + return errors.As(err, &dnsErr) && dnsErr.IsNotFound +} + +func isDialFailure(err error) bool { + var opErr *net.OpError + return errors.As(err, &opErr) +} diff --git a/internal/common/wait_connectable_test.go b/internal/common/wait_connectable_test.go new file mode 100644 index 00000000..ab732c14 --- /dev/null +++ b/internal/common/wait_connectable_test.go @@ -0,0 +1,221 @@ +package common + +import ( + "context" + "encoding/json" + "errors" + "fmt" + "net" + "net/http" + "net/http/httptest" + "strings" + "syscall" + "testing" + "time" + + "github.com/jackc/pgx/v5/pgconn" + + "github.com/timescale/tiger-cli/internal/api" + "github.com/timescale/tiger-cli/internal/util" +) + +// liveCtx is a context that hasn't expired, i.e. budget remaining. +func liveCtx() context.Context { return context.Background() } + +// spentCtx is a context whose deadline has already passed, i.e. budget gone. +func spentCtx(t *testing.T) context.Context { + t.Helper() + ctx, cancel := context.WithDeadline(context.Background(), time.Now().Add(-time.Second)) + t.Cleanup(cancel) + return ctx +} + +func TestClassifyProbe(t *testing.T) { + tests := []struct { + name string + parent context.Context + err error + want probeVerdict + }{ + { + name: "success", + err: nil, + want: probeServing, + }, + { + // The race this exists to fix: control plane said READY, nothing listening. + name: "connection refused", + err: &net.OpError{Op: "dial", Err: syscall.ECONNREFUSED}, + want: probeNotYet, + }, + { + name: "endpoint dns not resolving yet", + err: &net.OpError{Op: "dial", Err: &net.DNSError{IsNotFound: true}}, + want: probeNotYet, + }, + { + // 57P03 is the server saying "up, still starting". + name: "cannot connect now", + err: &pgconn.PgError{Code: "57P03"}, + want: probeNotYet, + }, + { + // The load-bearing case: no password to offer, server rejects us, but + // it answered, so the endpoint is serving. + name: "invalid password proves the server is serving", + err: &pgconn.PgError{Code: "28P01"}, + want: probeServing, + }, + { + name: "insufficient privilege also proves it is serving", + err: &pgconn.PgError{Code: "42501"}, + want: probeServing, + }, + { + name: "wrapped pg error is still unwrapped", + err: fmt.Errorf("failed to connect: %w", &pgconn.PgError{Code: "28P01"}), + want: probeServing, + }, + { + name: "attempt timed out but budget remains", + parent: liveCtx(), + err: context.DeadlineExceeded, + want: probeNotYet, + }, + { + name: "attempt timed out and budget is gone", + // parent set to a spent context below. + err: context.DeadlineExceeded, + want: probeUnreachable, + }, + { + name: "canceled", + err: context.Canceled, + want: probeUnreachable, + }, + { + // Waiting doesn't fix TLS. Report rather than spin. + name: "tls failure is not a waiting problem", + err: errors.New("tls: failed to verify certificate"), + want: probeUnreachable, + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + parent := tt.parent + if parent == nil { + if tt.want == probeUnreachable && errors.Is(tt.err, context.DeadlineExceeded) { + parent = spentCtx(t) + } else { + parent = liveCtx() + } + } + if got := classifyProbe(parent, tt.err); got != tt.want { + t.Errorf("classifyProbe(%v) = %v, want %v", tt.err, got, tt.want) + } + }) + } +} + +// A refused dial must keep the probe waiting regardless of which platform's +// errno shape it arrives in, since that is the failure the fix targets. +func TestClassifyProbeRefusedVariants(t *testing.T) { + for _, err := range []error{ + syscall.ECONNREFUSED, + &net.OpError{Op: "dial", Net: "tcp", Err: syscall.ECONNREFUSED}, + fmt.Errorf("dial tcp 10.0.0.1:5432: %w", syscall.ECONNREFUSED), + &net.OpError{Op: "dial", Err: errors.New("some platform-specific refusal")}, + } { + if got := classifyProbe(liveCtx(), err); got != probeNotYet { + t.Errorf("classifyProbe(%v) = %v, want probeNotYet", err, got) + } + } +} + +// closedPort returns a port with nothing listening on it, so a dial gets +// refused: the same signal the endpoint gives while Postgres is still starting. +func closedPort(t *testing.T) int { + t.Helper() + l, err := net.Listen("tcp", "127.0.0.1:0") + if err != nil { + t.Fatalf("reserving a port: %v", err) + } + port := l.Addr().(*net.TCPAddr).Port + if err := l.Close(); err != nil { + t.Fatalf("closing listener: %v", err) + } + return port +} + +// A refused endpoint must give up on its own budget and warn, never hang: this +// runs inside `tiger service create`, so an unbounded loop would wedge the CLI. +func TestWaitForConnectableGivesUpWithinBudget(t *testing.T) { + port := closedPort(t) + host := "127.0.0.1" + status := api.READY + + server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("Content-Type", "application/json") + if err := json.NewEncoder(w).Encode(api.Service{ + ServiceId: util.Ptr("svc-test"), + Status: &status, + Endpoint: &api.Endpoint{Host: &host, Port: &port}, + }); err != nil { + t.Errorf("encoding service: %v", err) + } + })) + t.Cleanup(server.Close) + + client, err := api.NewClientWithResponses(server.URL) + if err != nil { + t.Fatalf("building client: %v", err) + } + + var out strings.Builder + budget := 2 * time.Second + start := time.Now() + + // InitialPassword is set so the probe skips password storage entirely; this + // test is about the loop, not about credential lookup. + verified := WaitForConnectable(context.Background(), ConnectableWaitArgs{ + Client: client, + ProjectID: "proj-test", + ServiceID: "svc-test", + Role: "tsdbadmin", + InitialPassword: "irrelevant", + Output: &out, + Timeout: budget, + }) + elapsed := time.Since(start) + + if verified { + t.Error("WaitForConnectable() = true for a refused endpoint, want false") + } + if elapsed > budget+5*time.Second { + t.Errorf("took %v, want it to respect its %v budget", elapsed, budget) + } + if !strings.Contains(out.String(), "could not be verified") { + t.Errorf("output = %q, want an unverified warning", out.String()) + } +} + +func TestWarnUnverifiedMentionsCause(t *testing.T) { + var sb strings.Builder + warnUnverified(&sb, errors.New("connection refused")) + got := sb.String() + + for _, want := range []string{"Warning", "READY", "connection refused"} { + if !strings.Contains(got, want) { + t.Errorf("warnUnverified() = %q, want it to contain %q", got, want) + } + } +} + +func TestWarnUnverifiedWithoutCause(t *testing.T) { + var sb strings.Builder + warnUnverified(&sb, nil) + if got := sb.String(); !strings.Contains(got, "Warning") || strings.Contains(got, "()") { + t.Errorf("warnUnverified(nil) = %q, want a warning with no empty parens", got) + } +} From e5780dc9132d0758b46fbacffba0438d65307ee8 Mon Sep 17 00:00:00 2001 From: Gonzalo Serrano Date: Mon, 10 Aug 2026 11:27:05 +0200 Subject: [PATCH 2/3] docs(service): correct what the READY status actually gates on The original comment said READY flips before Postgres binds its port. Tracing savannah-deployer shows binding is already gated: leaderStatus Reconciler requires podIsServing plus passing post-deploy runners. Both are in-cluster checks, and the post-deploy runners connect to the pod (directly or via port-forward), never to the customer endpoint. The ungated gap is the external path: allocated port, DNS, load balancer. --- internal/common/wait_connectable.go | 15 +++++++++------ 1 file changed, 9 insertions(+), 6 deletions(-) diff --git a/internal/common/wait_connectable.go b/internal/common/wait_connectable.go index 2606cae0..a630da7a 100644 --- a/internal/common/wait_connectable.go +++ b/internal/common/wait_connectable.go @@ -15,14 +15,17 @@ import ( "github.com/timescale/tiger-cli/internal/api" ) -// A READY status means the control plane finished reconciling, which is not the -// same as Postgres having bound its port: on a fast provision the endpoint still -// refuses connections for a few seconds after the status flips. ready.go already -// documents READY as "accepting connections", so waiting on the status alone -// leaves that promise unkept, and any caller that connects immediately (rather -// than after some incidental latency) races it. +// A READY status means the control plane finished reconciling. savannah-deployer +// gates it on in-cluster signals (the leader pod serving, post-deploy runners +// passing) and never on the customer-facing endpoint, so the allocated port, DNS +// and load balancer can all still be catching up when the status flips. +// ready.go documents READY as "accepting connections", so waiting on the status +// alone leaves that promise unkept, and any caller that connects immediately +// (rather than after some incidental latency) races it. // // WaitForConnectable closes that gap by probing the endpoint until it answers. +// No control-plane gate can fully replace this: readiness is a property of the +// path between a particular client and the service, not of the service alone. // DefaultConnectableTimeout bounds the endpoint probe. It is deliberately much // shorter than the provisioning wait: once the control plane reports READY the From cc3050965e7ad3aa814d019f1bdd8a8ab9428136 Mon Sep 17 00:00:00 2001 From: Gonzalo Serrano Date: Mon, 10 Aug 2026 12:16:58 +0200 Subject: [PATCH 3/3] fix(service): adapt the readiness probe to the App config refactor main gained *config.Config on the connection helpers and moved command wiring to App.GetAll (#183), which lands as a silent break here: the merge is textually clean but the call sites stop compiling. Thread Config through ConnectableWaitArgs, take the client as api.ClientWithResponsesInterface to match WaitForServiceArgs, and read client/projectID from App.GetAll at the three call sites. --- internal/cmd/service_create.go | 5 +++-- internal/cmd/service_fork.go | 5 +++-- internal/cmd/service_start.go | 5 +++-- internal/common/wait_connectable.go | 6 ++++-- 4 files changed, 13 insertions(+), 8 deletions(-) diff --git a/internal/cmd/service_create.go b/internal/cmd/service_create.go index 6cb2d47e..263b5b06 100644 --- a/internal/cmd/service_create.go +++ b/internal/cmd/service_create.go @@ -206,8 +206,9 @@ Note: You can specify both CPU and memory together, or specify only one (the oth // READY only means the control plane finished reconciling. Confirm // the endpoint serves before claiming the service is usable. if common.WaitForConnectable(cmd.Context(), common.ConnectableWaitArgs{ - Client: cfg.Client, - ProjectID: cfg.ProjectID, + Client: client, + Config: cfg, + ProjectID: projectID, ServiceID: serviceID, Role: "tsdbadmin", InitialPassword: util.Deref(service.InitialPassword), diff --git a/internal/cmd/service_fork.go b/internal/cmd/service_fork.go index 90c0f2b2..d62f37da 100644 --- a/internal/cmd/service_fork.go +++ b/internal/cmd/service_fork.go @@ -226,8 +226,9 @@ Examples: } else { // A fresh fork reports READY before its endpoint is up, same as create. common.WaitForConnectable(cmd.Context(), common.ConnectableWaitArgs{ - Client: cfg.Client, - ProjectID: cfg.ProjectID, + Client: client, + Config: cfg, + ProjectID: projectID, ServiceID: forkedServiceID, Role: "tsdbadmin", InitialPassword: util.Deref(forkedService.InitialPassword), diff --git a/internal/cmd/service_start.go b/internal/cmd/service_start.go index d23df258..2089a990 100644 --- a/internal/cmd/service_start.go +++ b/internal/cmd/service_start.go @@ -107,8 +107,9 @@ Examples: // A resumed service reports READY before its endpoint is back up, so // confirm it serves before handing control back. common.WaitForConnectable(cmd.Context(), common.ConnectableWaitArgs{ - Client: cfg.Client, - ProjectID: cfg.ProjectID, + Client: client, + Config: cfg, + ProjectID: projectID, ServiceID: serviceID, Role: "tsdbadmin", Output: statusOutput, diff --git a/internal/common/wait_connectable.go b/internal/common/wait_connectable.go index a630da7a..a6e5eac8 100644 --- a/internal/common/wait_connectable.go +++ b/internal/common/wait_connectable.go @@ -13,6 +13,7 @@ import ( "github.com/jackc/pgx/v5/pgconn" "github.com/timescale/tiger-cli/internal/api" + "github.com/timescale/tiger-cli/internal/config" ) // A READY status means the control plane finished reconciling. savannah-deployer @@ -38,7 +39,8 @@ const DefaultConnectableTimeout = 2 * time.Minute const connectableProbeTimeout = 5 * time.Second type ConnectableWaitArgs struct { - Client *api.ClientWithResponses + Client api.ClientWithResponsesInterface + Config *config.Config ProjectID string ServiceID string @@ -127,7 +129,7 @@ func (args ConnectableWaitArgs) probe(ctx context.Context) (probeVerdict, error) return probeNotYet, fmt.Errorf("unexpected %s while fetching service", resp.Status()) } - details, err := GetConnectionDetails(*resp.JSON200, ConnectionDetailsOptions{ + details, err := GetConnectionDetails(args.Config, *resp.JSON200, ConnectionDetailsOptions{ Role: args.Role, WithPassword: true, InitialPassword: args.InitialPassword,