Skip to content

Commit 17e02c8

Browse files
avalleteCopilot
avallete
and
Copilot
authored
feat(pull): add debug logs for ssl check (#4894)
* feat(pull): add debug logs for ssl check * Apply suggestions from code review Co-authored-by: Copilot Autofix powered by AI <175728472+Copilot@users.noreply.github.com> * chore: apply some code clean --------- Co-authored-by: Copilot Autofix powered by AI <175728472+Copilot@users.noreply.github.com>
1 parent 3b50e7e commit 17e02c8

6 files changed

Lines changed: 209 additions & 46 deletions

File tree

‎internal/db/diff/diff.go‎

Lines changed: 36 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
package diff
22

33
import (
4+
"bytes"
45
"context"
56
_ "embed"
67
"fmt"
@@ -21,6 +22,7 @@ import (
2122
"github.com/jackc/pgconn"
2223
"github.com/jackc/pgx/v4"
2324
"github.com/spf13/afero"
25+
"github.com/spf13/viper"
2426
"github.com/supabase/cli/internal/db/start"
2527
"github.com/supabase/cli/internal/migration/new"
2628
"github.com/supabase/cli/internal/utils"
@@ -208,3 +210,37 @@ func migrateBaseDatabase(ctx context.Context, config pgconn.Config, migrations [
208210
defer conn.Close(context.Background())
209211
return migration.SeedGlobals(ctx, migrations, conn, afero.NewIOFS(fsys))
210212
}
213+
214+
func diffWithStream(ctx context.Context, env []string, script string, stdout io.Writer) error {
215+
cmd := []string{"edge-runtime", "start", "--main-service=."}
216+
if viper.GetBool("DEBUG") {
217+
cmd = append(cmd, "--verbose")
218+
}
219+
cmdString := strings.Join(cmd, " ")
220+
entrypoint := []string{"sh", "-c", `cat <<'EOF' > index.ts && ` + cmdString + `
221+
` + script + `
222+
EOF
223+
`}
224+
var stderr bytes.Buffer
225+
if err := utils.DockerRunOnceWithConfig(
226+
ctx,
227+
container.Config{
228+
Image: utils.Config.EdgeRuntime.Image,
229+
Env: env,
230+
Entrypoint: entrypoint,
231+
},
232+
container.HostConfig{
233+
Binds: []string{utils.EdgeRuntimeId + ":/root/.cache/deno:rw"},
234+
NetworkMode: network.NetworkHost,
235+
},
236+
network.NetworkingConfig{},
237+
"",
238+
stdout,
239+
&stderr,
240+
// The "main worker has been destroyed" message may not appear at the start of stderr
241+
// (e.g. preceded by other Deno runtime output), so use Contains instead of HasPrefix.
242+
); err != nil && !strings.Contains(stderr.String(), "main worker has been destroyed") {
243+
return errors.Errorf("error diffing schema: %w:\n%s", err, stderr.String())
244+
}
245+
return nil
246+
}

‎internal/db/diff/migra.go‎

Lines changed: 18 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -69,6 +69,9 @@ func DiffSchemaMigraBash(ctx context.Context, source, target pgconn.Config, sche
6969
"SOURCE=" + utils.ToPostgresURL(source),
7070
"TARGET=" + utils.ToPostgresURL(target),
7171
}
72+
if types.IsSSLDebugEnabled() {
73+
env = append(env, "SUPABASE_SSL_DEBUG=true")
74+
}
7275
// Passing in script string means command line args must be set manually, ie. "$@"
7376
args := "set -- " + strings.Join(schema, " ") + ";"
7477
cmd := []string{"/bin/sh", "-c", args + diffSchemaScript}
@@ -108,10 +111,25 @@ func DiffSchemaMigra(ctx context.Context, source, target pgconn.Config, schema [
108111
"SOURCE=" + utils.ToPostgresURL(source),
109112
"TARGET=" + utils.ToPostgresURL(target),
110113
}
114+
debugf := func(string, ...any) {}
115+
if types.IsSSLDebugEnabled() {
116+
debugf = types.LogSSLDebugf
117+
env = append(env, "SUPABASE_SSL_DEBUG=true")
118+
debugf("DiffSchemaMigra source_host=%s source_port=%d target_host=%s target_port=%d target_db=%s",
119+
source.Host,
120+
source.Port,
121+
target.Host,
122+
target.Port,
123+
target.Database,
124+
)
125+
debugf("DiffSchemaMigra docker_daemon=%s image=%s", utils.Docker.DaemonHost(), utils.Config.EdgeRuntime.Image)
126+
}
111127
if ca, err := types.GetRootCA(ctx, utils.ToPostgresURL(target), options...); err != nil {
128+
debugf("DiffSchemaMigra GetRootCA error=%v", err)
112129
return "", err
113130
} else if len(ca) > 0 {
114131
env = append(env, "SSL_CA="+ca)
132+
debugf("DiffSchemaMigra GetRootCA ca_bundle_len=%d", len(ca))
115133
}
116134
if len(schema) > 0 {
117135
env = append(env, "INCLUDED_SCHEMAS="+strings.Join(schema, ","))

‎internal/db/diff/pgdelta.go‎

Lines changed: 0 additions & 37 deletions
Original file line numberDiff line numberDiff line change
@@ -4,15 +4,10 @@ import (
44
"bytes"
55
"context"
66
_ "embed"
7-
"io"
87
"strings"
98

10-
"github.com/docker/docker/api/types/container"
11-
"github.com/docker/docker/api/types/network"
12-
"github.com/go-errors/errors"
139
"github.com/jackc/pgconn"
1410
"github.com/jackc/pgx/v4"
15-
"github.com/spf13/viper"
1611
"github.com/supabase/cli/internal/gen/types"
1712
"github.com/supabase/cli/internal/utils"
1813
)
@@ -42,35 +37,3 @@ func DiffPgDelta(ctx context.Context, source, target pgconn.Config, schema []str
4237
}
4338
return out.String(), nil
4439
}
45-
46-
func diffWithStream(ctx context.Context, env []string, script string, stdout io.Writer) error {
47-
cmd := []string{"edge-runtime", "start", "--main-service=."}
48-
if viper.GetBool("DEBUG") {
49-
cmd = append(cmd, "--verbose")
50-
}
51-
cmdString := strings.Join(cmd, " ")
52-
entrypoint := []string{"sh", "-c", `cat <<'EOF' > index.ts && ` + cmdString + `
53-
` + script + `
54-
EOF
55-
`}
56-
var stderr bytes.Buffer
57-
if err := utils.DockerRunOnceWithConfig(
58-
ctx,
59-
container.Config{
60-
Image: utils.Config.EdgeRuntime.Image,
61-
Env: env,
62-
Entrypoint: entrypoint,
63-
},
64-
container.HostConfig{
65-
Binds: []string{utils.EdgeRuntimeId + ":/root/.cache/deno:rw"},
66-
NetworkMode: network.NetworkHost,
67-
},
68-
network.NetworkingConfig{},
69-
"",
70-
stdout,
71-
&stderr,
72-
); err != nil && !strings.HasPrefix(stderr.String(), "main worker has been destroyed") {
73-
return errors.Errorf("error diffing schema: %w:\n%s", err, stderr.String())
74-
}
75-
return nil
76-
}

‎internal/db/diff/templates/migra.sh‎

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,13 @@
11
#!/bin/sh
22
set -eu
33

4+
if [ "${SUPABASE_SSL_DEBUG:-}" = "true" ]; then
5+
[ -n "${SOURCE:-}" ] && source_set=true || source_set=false
6+
[ -n "${TARGET:-}" ] && target_set=true || target_set=false
7+
echo "[ssl-debug] migra.sh uname=$(uname -a)" >&2
8+
echo "[ssl-debug] migra.sh source_set=$source_set target_set=$target_set schemas=$*" >&2
9+
fi
10+
411
# migra doesn't shutdown gracefully, so kill it ourselves
512
trap 'kill -9 %1' TERM
613

@@ -14,6 +21,9 @@ run_migra() {
1421
for schema in "$@"; do
1522
# migra exits 2 when differences are found
1623
run_migra "$SOURCE" "$TARGET" || status=$?
24+
if [ "${SUPABASE_SSL_DEBUG:-}" = "true" ]; then
25+
echo "[ssl-debug] migra.sh schema=$schema exit_status=${status:-0}" >&2
26+
fi
1727
if [ ${status:-2} -ne 2 ]; then
1828
exit $status
1929
fi

‎internal/db/diff/templates/migra.ts‎

Lines changed: 38 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -3,8 +3,35 @@ import { Migration } from "npm:@pgkit/migra";
33

44
// Avoids error on self-signed certificate
55
const ca = Deno.env.get("SSL_CA");
6-
const clientBase = createClient(Deno.env.get("SOURCE"));
7-
const clientHead = createClient(Deno.env.get("TARGET"), {
6+
const source = Deno.env.get("SOURCE");
7+
const target = Deno.env.get("TARGET");
8+
const sslDebug = Deno.env.get("SUPABASE_SSL_DEBUG")?.toLowerCase() === "true";
9+
10+
function redactPostgresUrl(raw: string | undefined): string {
11+
if (!raw) return "<unset>";
12+
try {
13+
const u = new URL(raw);
14+
if (u.password) u.password = "xxxxx";
15+
return u.toString();
16+
} catch {
17+
return "<invalid-url>";
18+
}
19+
}
20+
21+
if (sslDebug) {
22+
console.error(
23+
`[ssl-debug] migra.ts deno=${Deno.version.deno} v8=${Deno.version.v8} os=${Deno.build.os}`,
24+
);
25+
console.error(
26+
`[ssl-debug] migra.ts source=${redactPostgresUrl(source)} target=${redactPostgresUrl(target)}`,
27+
);
28+
console.error(
29+
`[ssl-debug] migra.ts ssl_ca_set=${ca != null} ssl_ca_len=${ca?.length ?? 0}`,
30+
);
31+
}
32+
33+
const clientBase = createClient(source);
34+
const clientHead = createClient(target, {
835
pgpOptions: { connect: { ssl: ca && { ca } } },
936
});
1037
const includedSchemas = Deno.env.get("INCLUDED_SCHEMAS")?.split(",") ?? [];
@@ -83,6 +110,15 @@ try {
83110
}
84111
console.log(result);
85112
} catch (e) {
113+
if (sslDebug) {
114+
if (e instanceof Error) {
115+
console.error(
116+
`[ssl-debug] migra.ts error_name=${e.name} message=${e.message} stack=${e.stack ?? "<none>"}`,
117+
);
118+
} else {
119+
console.error(`[ssl-debug] migra.ts error=${String(e)}`);
120+
}
121+
}
86122
console.error(e);
87123
} finally {
88124
await Promise.all([clientHead.end(), clientBase.end()]);

‎internal/gen/types/types.go‎

Lines changed: 107 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -4,7 +4,9 @@ import (
44
"context"
55
_ "embed"
66
"fmt"
7+
"net/url"
78
"os"
9+
"runtime"
810
"strings"
911
"time"
1012

@@ -120,37 +122,135 @@ var (
120122
)
121123

122124
func GetRootCA(ctx context.Context, dbURL string, options ...func(*pgx.ConnConfig)) (string, error) {
125+
debugf := func(string, ...any) {}
126+
if IsSSLDebugEnabled() {
127+
debugf = LogSSLDebugf
128+
}
129+
debugf("GetRootCA start db_url=%s", redactPostgresURL(dbURL))
130+
debugf("env SUPABASE_CA_SKIP_VERIFY=%q SUPABASE_SSL_DEBUG=%q PGSSLROOTCERT=%q SSL_CERT_FILE=%q SSL_CERT_DIR=%q",
131+
os.Getenv("SUPABASE_CA_SKIP_VERIFY"),
132+
os.Getenv("SUPABASE_SSL_DEBUG"),
133+
os.Getenv("PGSSLROOTCERT"),
134+
os.Getenv("SSL_CERT_FILE"),
135+
os.Getenv("SSL_CERT_DIR"),
136+
)
137+
debugf("runtime goos=%s goarch=%s go=%s", runtime.GOOS, runtime.GOARCH, runtime.Version())
123138
// node-postgres does not support sslmode=prefer
124-
if require, err := isRequireSSL(ctx, dbURL, options...); !require {
139+
require, err := isRequireSSL(ctx, dbURL, options...)
140+
debugf("GetRootCA probe_result require_ssl=%t err=%v", require, err)
141+
if !require {
125142
return "", err
126143
}
127144
// Merge all certs to support --db-url flag
128-
return caStaging + caProd + caSnap, nil
145+
ca := caStaging + caProd + caSnap
146+
debugf("GetRootCA return ca_bundle_len=%d", len(ca))
147+
return ca, nil
129148
}
130149

131150
func isRequireSSL(ctx context.Context, dbUrl string, options ...func(*pgx.ConnConfig)) (bool, error) {
132-
151+
debugf := func(string, ...any) {}
152+
if IsSSLDebugEnabled() {
153+
debugf = LogSSLDebugf
154+
}
133155
// pgx v4's sslmode=require verifies the server certificate against system CAs,
134156
// unlike libpq where require skips verification. When SUPABASE_CA_SKIP_VERIFY=true,
135157
// skip verification for this probe only (detects whether the server speaks TLS).
158+
// pgconn may still install VerifyPeerCertificate callback when sslrootcert is set,
159+
// so we also clear custom verification callbacks on all TLS configs.
136160
// Cert validation happens downstream in the migra/pgdelta Deno scripts using GetRootCA.
137-
opts := options
161+
opts := append([]func(*pgx.ConnConfig){}, options...)
138162
if os.Getenv("SUPABASE_CA_SKIP_VERIFY") == "true" {
163+
fmt.Fprintln(os.Stderr, "WARNING: TLS certificate verification disabled for SSL probe (SUPABASE_CA_SKIP_VERIFY=true)")
139164
opts = append(opts, func(cc *pgx.ConnConfig) {
165+
// #nosec G402 -- Intentionally skipped for this TLS capability probe only.
166+
// Downstream migra/pgdelta flows still validate certificates using GetRootCA.
140167
if cc.TLSConfig != nil {
141-
// #nosec G402 -- Intentionally skipped for this TLS capability probe only.
142-
// Downstream migra/pgdelta flows still validate certificates using GetRootCA.
143168
cc.TLSConfig.InsecureSkipVerify = true
169+
cc.TLSConfig.VerifyPeerCertificate = nil
170+
cc.TLSConfig.VerifyConnection = nil
171+
}
172+
for _, fc := range cc.Fallbacks {
173+
if fc.TLSConfig == nil {
174+
continue
175+
}
176+
fc.TLSConfig.InsecureSkipVerify = true
177+
fc.TLSConfig.VerifyPeerCertificate = nil
178+
fc.TLSConfig.VerifyConnection = nil
144179
}
145180
})
146181
}
182+
debugf("isRequireSSL probe db_url=%s skip_verify=%t", redactPostgresURL(dbUrl), os.Getenv("SUPABASE_CA_SKIP_VERIFY") == "true")
183+
if IsSSLDebugEnabled() {
184+
opts = append(opts, logTLSConfigState("isRequireSSL", dbUrl))
185+
}
147186
conn, err := utils.ConnectByUrl(ctx, dbUrl+"&sslmode=require", opts...)
148187
if err != nil {
188+
debugf("isRequireSSL probe_error err=%v", err)
149189
if strings.HasSuffix(err.Error(), "(server refused TLS connection)") {
190+
debugf("isRequireSSL result require_ssl=false reason=server_refused_tls")
150191
return false, nil
151192
}
152193
return false, err
153194
}
154195
// SSL is not supported in debug mode
155-
return !viper.GetBool("DEBUG"), conn.Close(ctx)
196+
require := !viper.GetBool("DEBUG")
197+
debugf("isRequireSSL result require_ssl=%t debug_mode=%t", require, viper.GetBool("DEBUG"))
198+
return require, conn.Close(ctx)
199+
}
200+
201+
func IsSSLDebugEnabled() bool {
202+
return strings.EqualFold(os.Getenv("SUPABASE_SSL_DEBUG"), "true")
203+
}
204+
205+
func LogSSLDebugf(format string, args ...any) {
206+
fmt.Fprintf(os.Stderr, "[ssl-debug] "+format+"\n", args...)
207+
}
208+
209+
func redactPostgresURL(raw string) string {
210+
parsed, err := url.Parse(raw)
211+
if err != nil {
212+
return "<invalid-url>"
213+
}
214+
if parsed.User != nil {
215+
username := parsed.User.Username()
216+
if username == "" {
217+
parsed.User = url.UserPassword("redacted", "xxxxx")
218+
} else {
219+
parsed.User = url.UserPassword(username, "xxxxx")
220+
}
221+
}
222+
return parsed.String()
223+
}
224+
225+
func logTLSConfigState(scope, dbUrl string) func(*pgx.ConnConfig) {
226+
return func(cc *pgx.ConnConfig) {
227+
if cc.TLSConfig == nil {
228+
LogSSLDebugf("%s tls_config=nil db_url=%s fallbacks=%d", scope, redactPostgresURL(dbUrl), len(cc.Fallbacks))
229+
return
230+
}
231+
LogSSLDebugf("%s tls_config skip_verify=%t verify_peer_cb=%t verify_conn_cb=%t root_cas=%t server_name=%q fallbacks=%d",
232+
scope,
233+
cc.TLSConfig.InsecureSkipVerify,
234+
cc.TLSConfig.VerifyPeerCertificate != nil,
235+
cc.TLSConfig.VerifyConnection != nil,
236+
cc.TLSConfig.RootCAs != nil,
237+
cc.TLSConfig.ServerName,
238+
len(cc.Fallbacks),
239+
)
240+
for i, fc := range cc.Fallbacks {
241+
if fc == nil || fc.TLSConfig == nil {
242+
LogSSLDebugf("%s fallback[%d] tls_config=nil", scope, i)
243+
continue
244+
}
245+
LogSSLDebugf("%s fallback[%d] skip_verify=%t verify_peer_cb=%t verify_conn_cb=%t root_cas=%t server_name=%q",
246+
scope,
247+
i,
248+
fc.TLSConfig.InsecureSkipVerify,
249+
fc.TLSConfig.VerifyPeerCertificate != nil,
250+
fc.TLSConfig.VerifyConnection != nil,
251+
fc.TLSConfig.RootCAs != nil,
252+
fc.TLSConfig.ServerName,
253+
)
254+
}
255+
}
156256
}

0 commit comments

Comments
 (0)