From b699082824dd2e75955fd7489069f09958f54f4c Mon Sep 17 00:00:00 2001 From: avallete Date: Wed, 25 Feb 2026 10:59:52 +0100 Subject: [PATCH] feat(pull): add debug logs for ssl check --- internal/db/diff/diff.go | 34 ++++++++ internal/db/diff/migra.go | 25 ++++++ internal/db/diff/pgdelta.go | 37 --------- internal/db/diff/templates/migra.sh | 10 +++ internal/db/diff/templates/migra.ts | 40 +++++++++- internal/gen/types/types.go | 117 ++++++++++++++++++++++++++-- 6 files changed, 217 insertions(+), 46 deletions(-) diff --git a/internal/db/diff/diff.go b/internal/db/diff/diff.go index 3f7854fc7a..15d4bfe75d 100644 --- a/internal/db/diff/diff.go +++ b/internal/db/diff/diff.go @@ -1,6 +1,7 @@ package diff import ( + "bytes" "context" _ "embed" "fmt" @@ -21,6 +22,7 @@ import ( "github.com/jackc/pgconn" "github.com/jackc/pgx/v4" "github.com/spf13/afero" + "github.com/spf13/viper" "github.com/supabase/cli/internal/db/start" "github.com/supabase/cli/internal/migration/new" "github.com/supabase/cli/internal/utils" @@ -208,3 +210,35 @@ func migrateBaseDatabase(ctx context.Context, config pgconn.Config, migrations [ defer conn.Close(context.Background()) return migration.SeedGlobals(ctx, migrations, conn, afero.NewIOFS(fsys)) } + +func diffWithStream(ctx context.Context, env []string, script string, stdout io.Writer) error { + cmd := []string{"edge-runtime", "start", "--main-service=."} + if viper.GetBool("DEBUG") { + cmd = append(cmd, "--verbose") + } + cmdString := strings.Join(cmd, " ") + entrypoint := []string{"sh", "-c", `cat <<'EOF' > index.ts && ` + cmdString + ` +` + script + ` +EOF +`} + var stderr bytes.Buffer + if err := utils.DockerRunOnceWithConfig( + ctx, + container.Config{ + Image: utils.Config.EdgeRuntime.Image, + Env: env, + Entrypoint: entrypoint, + }, + container.HostConfig{ + Binds: []string{utils.EdgeRuntimeId + ":/root/.cache/deno:rw"}, + NetworkMode: network.NetworkHost, + }, + network.NetworkingConfig{}, + "", + stdout, + &stderr, + ); err != nil && !strings.Contains(stderr.String(), "main worker has been destroyed") { + return errors.Errorf("error diffing schema: %w:\n%s", err, stderr.String()) + } + return nil +} diff --git a/internal/db/diff/migra.go b/internal/db/diff/migra.go index 6ef830ff57..a50dbc3663 100644 --- a/internal/db/diff/migra.go +++ b/internal/db/diff/migra.go @@ -4,6 +4,8 @@ import ( "bytes" "context" _ "embed" + "fmt" + "os" "strings" "github.com/docker/docker/api/types/container" @@ -69,6 +71,9 @@ func DiffSchemaMigraBash(ctx context.Context, source, target pgconn.Config, sche "SOURCE=" + utils.ToPostgresURL(source), "TARGET=" + utils.ToPostgresURL(target), } + if v := os.Getenv("SUPABASE_SSL_DEBUG"); strings.EqualFold(v, "true") { + env = append(env, "SUPABASE_SSL_DEBUG="+v) + } // Passing in script string means command line args must be set manually, ie. "$@" args := "set -- " + strings.Join(schema, " ") + ";" cmd := []string{"/bin/sh", "-c", args + diffSchemaScript} @@ -108,10 +113,30 @@ func DiffSchemaMigra(ctx context.Context, source, target pgconn.Config, schema [ "SOURCE=" + utils.ToPostgresURL(source), "TARGET=" + utils.ToPostgresURL(target), } + sslDebug := strings.EqualFold(os.Getenv("SUPABASE_SSL_DEBUG"), "true") + if sslDebug { + env = append(env, "SUPABASE_SSL_DEBUG=true") + } + if sslDebug { + fmt.Fprintf(os.Stderr, "[ssl-debug] DiffSchemaMigra source_host=%s source_port=%d target_host=%s target_port=%d target_db=%s\n", + source.Host, + source.Port, + target.Host, + target.Port, + target.Database, + ) + fmt.Fprintf(os.Stderr, "[ssl-debug] DiffSchemaMigra docker_daemon=%s image=%s\n", utils.Docker.DaemonHost(), utils.Config.EdgeRuntime.Image) + } if ca, err := types.GetRootCA(ctx, utils.ToPostgresURL(target), options...); err != nil { + if sslDebug { + fmt.Fprintf(os.Stderr, "[ssl-debug] DiffSchemaMigra GetRootCA error=%v\n", err) + } return "", err } else if len(ca) > 0 { env = append(env, "SSL_CA="+ca) + if sslDebug { + fmt.Fprintf(os.Stderr, "[ssl-debug] DiffSchemaMigra GetRootCA ca_bundle_len=%d\n", len(ca)) + } } if len(schema) > 0 { env = append(env, "INCLUDED_SCHEMAS="+strings.Join(schema, ",")) diff --git a/internal/db/diff/pgdelta.go b/internal/db/diff/pgdelta.go index 0403dd91f9..e3b1b4fa7a 100644 --- a/internal/db/diff/pgdelta.go +++ b/internal/db/diff/pgdelta.go @@ -4,15 +4,10 @@ import ( "bytes" "context" _ "embed" - "io" "strings" - "github.com/docker/docker/api/types/container" - "github.com/docker/docker/api/types/network" - "github.com/go-errors/errors" "github.com/jackc/pgconn" "github.com/jackc/pgx/v4" - "github.com/spf13/viper" "github.com/supabase/cli/internal/gen/types" "github.com/supabase/cli/internal/utils" ) @@ -42,35 +37,3 @@ func DiffPgDelta(ctx context.Context, source, target pgconn.Config, schema []str } return out.String(), nil } - -func diffWithStream(ctx context.Context, env []string, script string, stdout io.Writer) error { - cmd := []string{"edge-runtime", "start", "--main-service=."} - if viper.GetBool("DEBUG") { - cmd = append(cmd, "--verbose") - } - cmdString := strings.Join(cmd, " ") - entrypoint := []string{"sh", "-c", `cat <<'EOF' > index.ts && ` + cmdString + ` -` + script + ` -EOF -`} - var stderr bytes.Buffer - if err := utils.DockerRunOnceWithConfig( - ctx, - container.Config{ - Image: utils.Config.EdgeRuntime.Image, - Env: env, - Entrypoint: entrypoint, - }, - container.HostConfig{ - Binds: []string{utils.EdgeRuntimeId + ":/root/.cache/deno:rw"}, - NetworkMode: network.NetworkHost, - }, - network.NetworkingConfig{}, - "", - stdout, - &stderr, - ); err != nil && !strings.HasPrefix(stderr.String(), "main worker has been destroyed") { - return errors.Errorf("error diffing schema: %w:\n%s", err, stderr.String()) - } - return nil -} diff --git a/internal/db/diff/templates/migra.sh b/internal/db/diff/templates/migra.sh index f4a814527f..e630bd1147 100755 --- a/internal/db/diff/templates/migra.sh +++ b/internal/db/diff/templates/migra.sh @@ -1,6 +1,13 @@ #!/bin/sh set -eu +if [ "${SUPABASE_SSL_DEBUG:-}" = "true" ]; then + [ -n "${SOURCE:-}" ] && source_set=true || source_set=false + [ -n "${TARGET:-}" ] && target_set=true || target_set=false + echo "[ssl-debug] migra.sh uname=$(uname -a)" >&2 + echo "[ssl-debug] migra.sh source_set=$source_set target_set=$target_set schemas=$*" >&2 +fi + # migra doesn't shutdown gracefully, so kill it ourselves trap 'kill -9 %1' TERM @@ -14,6 +21,9 @@ run_migra() { for schema in "$@"; do # migra exits 2 when differences are found run_migra "$SOURCE" "$TARGET" || status=$? + if [ "${SUPABASE_SSL_DEBUG:-}" = "true" ]; then + echo "[ssl-debug] migra.sh schema=$schema exit_status=${status:-0}" >&2 + fi if [ ${status:-2} -ne 2 ]; then exit $status fi diff --git a/internal/db/diff/templates/migra.ts b/internal/db/diff/templates/migra.ts index a8ae28d804..9e493c02d3 100644 --- a/internal/db/diff/templates/migra.ts +++ b/internal/db/diff/templates/migra.ts @@ -3,8 +3,35 @@ import { Migration } from "npm:@pgkit/migra"; // Avoids error on self-signed certificate const ca = Deno.env.get("SSL_CA"); -const clientBase = createClient(Deno.env.get("SOURCE")); -const clientHead = createClient(Deno.env.get("TARGET"), { +const source = Deno.env.get("SOURCE"); +const target = Deno.env.get("TARGET"); +const sslDebug = Deno.env.get("SUPABASE_SSL_DEBUG")?.toLowerCase() === "true"; + +function redactUrl(raw: string | undefined): string { + if (!raw) return ""; + try { + const u = new URL(raw); + if (u.password) u.password = "xxxxx"; + return u.toString(); + } catch { + return ""; + } +} + +if (sslDebug) { + console.error( + `[ssl-debug] migra.ts deno=${Deno.version.deno} v8=${Deno.version.v8} os=${Deno.build.os}`, + ); + console.error( + `[ssl-debug] migra.ts source=${redactUrl(source)} target=${redactUrl(target)}`, + ); + console.error( + `[ssl-debug] migra.ts ssl_ca_set=${ca != null} ssl_ca_len=${ca?.length ?? 0}`, + ); +} + +const clientBase = createClient(source); +const clientHead = createClient(target, { pgpOptions: { connect: { ssl: ca && { ca } } }, }); const includedSchemas = Deno.env.get("INCLUDED_SCHEMAS")?.split(",") ?? []; @@ -83,6 +110,15 @@ try { } console.log(result); } catch (e) { + if (sslDebug) { + if (e instanceof Error) { + console.error( + `[ssl-debug] migra.ts error_name=${e.name} message=${e.message} stack=${e.stack ?? ""}`, + ); + } else { + console.error(`[ssl-debug] migra.ts error=${String(e)}`); + } + } console.error(e); } finally { await Promise.all([clientHead.end(), clientBase.end()]); diff --git a/internal/gen/types/types.go b/internal/gen/types/types.go index e5e7d73633..199c335f82 100644 --- a/internal/gen/types/types.go +++ b/internal/gen/types/types.go @@ -4,7 +4,9 @@ import ( "context" _ "embed" "fmt" + "net/url" "os" + "runtime" "strings" "time" @@ -120,37 +122,138 @@ var ( ) func GetRootCA(ctx context.Context, dbURL string, options ...func(*pgx.ConnConfig)) (string, error) { + if isSSLDebugEnabled() { + logSSLDebugf("GetRootCA start db_url=%s", redactPostgresURL(dbURL)) + logSSLDebugf("env SUPABASE_CA_SKIP_VERIFY=%q SUPABASE_SSL_DEBUG=%q PGSSLROOTCERT=%q SSL_CERT_FILE=%q SSL_CERT_DIR=%q", + os.Getenv("SUPABASE_CA_SKIP_VERIFY"), + os.Getenv("SUPABASE_SSL_DEBUG"), + os.Getenv("PGSSLROOTCERT"), + os.Getenv("SSL_CERT_FILE"), + os.Getenv("SSL_CERT_DIR"), + ) + logSSLDebugf("runtime goos=%s goarch=%s go=%s", runtime.GOOS, runtime.GOARCH, runtime.Version()) + } // node-postgres does not support sslmode=prefer - if require, err := isRequireSSL(ctx, dbURL, options...); !require { + require, err := isRequireSSL(ctx, dbURL, options...) + if isSSLDebugEnabled() { + logSSLDebugf("GetRootCA probe_result require_ssl=%t err=%v", require, err) + } + if !require { return "", err } // Merge all certs to support --db-url flag - return caStaging + caProd + caSnap, nil + ca := caStaging + caProd + caSnap + if isSSLDebugEnabled() { + logSSLDebugf("GetRootCA return ca_bundle_len=%d", len(ca)) + } + return ca, nil } func isRequireSSL(ctx context.Context, dbUrl string, options ...func(*pgx.ConnConfig)) (bool, error) { - // pgx v4's sslmode=require verifies the server certificate against system CAs, // unlike libpq where require skips verification. When SUPABASE_CA_SKIP_VERIFY=true, // skip verification for this probe only (detects whether the server speaks TLS). + // pgconn may still install VerifyPeerCertificate callback when sslrootcert is set, + // so we also clear custom verification callbacks on all TLS configs. // Cert validation happens downstream in the migra/pgdelta Deno scripts using GetRootCA. - opts := options + opts := append([]func(*pgx.ConnConfig){}, options...) if os.Getenv("SUPABASE_CA_SKIP_VERIFY") == "true" { opts = append(opts, func(cc *pgx.ConnConfig) { + // #nosec G402 -- Intentionally skipped for this TLS capability probe only. + // Downstream migra/pgdelta flows still validate certificates using GetRootCA. if cc.TLSConfig != nil { - // #nosec G402 -- Intentionally skipped for this TLS capability probe only. - // Downstream migra/pgdelta flows still validate certificates using GetRootCA. cc.TLSConfig.InsecureSkipVerify = true + cc.TLSConfig.VerifyPeerCertificate = nil + cc.TLSConfig.VerifyConnection = nil + } + for _, fc := range cc.Fallbacks { + if fc.TLSConfig == nil { + continue + } + fc.TLSConfig.InsecureSkipVerify = true + fc.TLSConfig.VerifyPeerCertificate = nil + fc.TLSConfig.VerifyConnection = nil } }) } + if isSSLDebugEnabled() { + logSSLDebugf("isRequireSSL probe db_url=%s skip_verify=%t", redactPostgresURL(dbUrl), os.Getenv("SUPABASE_CA_SKIP_VERIFY") == "true") + opts = append(opts, logTLSConfigState("isRequireSSL", dbUrl)) + } conn, err := utils.ConnectByUrl(ctx, dbUrl+"&sslmode=require", opts...) if err != nil { + if isSSLDebugEnabled() { + logSSLDebugf("isRequireSSL probe_error err=%v", err) + } if strings.HasSuffix(err.Error(), "(server refused TLS connection)") { + if isSSLDebugEnabled() { + logSSLDebugf("isRequireSSL result require_ssl=false reason=server_refused_tls") + } return false, nil } return false, err } // SSL is not supported in debug mode - return !viper.GetBool("DEBUG"), conn.Close(ctx) + require := !viper.GetBool("DEBUG") + if isSSLDebugEnabled() { + logSSLDebugf("isRequireSSL result require_ssl=%t debug_mode=%t", require, viper.GetBool("DEBUG")) + } + return require, conn.Close(ctx) +} + +func isSSLDebugEnabled() bool { + return strings.EqualFold(os.Getenv("SUPABASE_SSL_DEBUG"), "true") +} + +func logSSLDebugf(format string, args ...any) { + fmt.Fprintf(os.Stderr, "[ssl-debug] "+format+"\n", args...) +} + +func redactPostgresURL(raw string) string { + parsed, err := url.Parse(raw) + if err != nil { + return "" + } + if parsed.User != nil { + username := parsed.User.Username() + if username == "" { + parsed.User = url.UserPassword("redacted", "xxxxx") + } else { + parsed.User = url.UserPassword(username, "xxxxx") + } + } + return parsed.String() +} + +func logTLSConfigState(scope, dbUrl string) func(*pgx.ConnConfig) { + return func(cc *pgx.ConnConfig) { + if cc.TLSConfig == nil { + logSSLDebugf("%s tls_config=nil db_url=%s fallbacks=%d", scope, redactPostgresURL(dbUrl), len(cc.Fallbacks)) + return + } + logSSLDebugf("%s tls_config skip_verify=%t verify_peer_cb=%t verify_conn_cb=%t root_cas=%t server_name=%q fallbacks=%d", + scope, + cc.TLSConfig.InsecureSkipVerify, + cc.TLSConfig.VerifyPeerCertificate != nil, + cc.TLSConfig.VerifyConnection != nil, + cc.TLSConfig.RootCAs != nil, + cc.TLSConfig.ServerName, + len(cc.Fallbacks), + ) + for i, fc := range cc.Fallbacks { + if fc == nil || fc.TLSConfig == nil { + logSSLDebugf("%s fallback[%d] tls_config=nil", scope, i) + continue + } + logSSLDebugf("%s fallback[%d] skip_verify=%t verify_peer_cb=%t verify_conn_cb=%t root_cas=%t server_name=%q", + scope, + i, + fc.TLSConfig.InsecureSkipVerify, + fc.TLSConfig.VerifyPeerCertificate != nil, + fc.TLSConfig.VerifyConnection != nil, + fc.TLSConfig.RootCAs != nil, + fc.TLSConfig.ServerName, + ) + } + } }