Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
10 changes: 10 additions & 0 deletions apps/cli-go/internal/db/diff/diff_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -345,6 +345,16 @@ create schema public`)
Delete("/v" + utils.Docker.ClientVersion() + "/containers/test-shadow-db").
Reply(http.StatusOK)
apitest.MockDockerStart(utils.Docker, utils.GetRegistryImageUrl(utils.Config.EdgeRuntime.Image), "test-migra")
// The edge-runtime diff waits for the container to exit via inspect before
// reading its logs (it must not follow the log stream — that hangs under
// podman, supabase/pg-toolbelt#312), so the diff failure here surfaces from
// the log read rather than the followed stream.
gock.New(utils.Docker.DaemonHost()).
Get("/v" + utils.Docker.ClientVersion() + "/containers/test-migra/json").
Reply(http.StatusOK).
JSON(container.InspectResponse{ContainerJSONBase: &container.ContainerJSONBase{
State: &container.State{ExitCode: 0},
}})
gock.New(utils.Docker.DaemonHost()).
Get("/v" + utils.Docker.ClientVersion() + "/containers/test-migra/logs").
ReplyError(errors.New("network error"))
Expand Down
48 changes: 48 additions & 0 deletions apps/cli-go/internal/db/diff/pgdelta_template_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,48 @@
package diff

import (
"strings"
"testing"

"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)

// lastCodeLine returns the final non-blank, non-comment line of a script.
func lastCodeLine(script string) string {
lines := strings.Split(script, "\n")
for i := len(lines) - 1; i >= 0; i-- {
line := strings.TrimSpace(lines[i])
if line == "" || strings.HasPrefix(line, "//") {
continue
}
return line
}
return ""
}

// Every pg-delta edge-runtime script must force the worker's event loop closed
// once its output has been written. The pg connection pool can leave keepalive
// handles registered even after close() resolves; if the worker never exits,
// the container never stops and the CLI — which streams the container logs with
// Follow:true — blocks forever following them, hanging declarative sync at 0%
// CPU (supabase/pg-toolbelt#312). The success path must terminate
// unconditionally rather than rely on the event loop draining on its own, so
// guard against the force-close being dropped from any template's success path.
func TestPgDeltaScriptsForceCloseOnSuccess(t *testing.T) {
scripts := map[string]string{
"pgdelta.ts": pgDeltaScript,
"pgdelta_declarative_export.ts": pgDeltaDeclarativeExportScript,
"pgdelta_catalog_export.ts": pgDeltaCatalogExportScript,
}
Comment thread
avallete marked this conversation as resolved.
for name, script := range scripts {
t.Run(name, func(t *testing.T) {
require.NotEmpty(t, script)
// The terminating statement runs on the success path (the catch
// branch no longer re-throws), so the worker is torn down whether
// or not the body succeeded.
assert.Equal(t, `throw new Error("");`, lastCodeLine(script),
"success path must force the Edge Runtime worker to exit so the container stops")
})
}
}
6 changes: 6 additions & 0 deletions apps/cli-go/internal/db/diff/templates/pgdelta.ts
Original file line number Diff line number Diff line change
Expand Up @@ -69,3 +69,9 @@ try {
// Force close event loop
throw new Error("");
}
// Force close the event loop on the success path too. When SOURCE/TARGET are
// live database URLs the plan opens connections whose keepalive handles can keep
// the Edge Runtime worker alive after the diff has been written, so the container
// never exits and the CLI — which follows this container's logs — hangs
// indefinitely at 0% CPU (supabase/pg-toolbelt#312).
throw new Error("");
Original file line number Diff line number Diff line change
Expand Up @@ -21,7 +21,16 @@ try {
console.log(stringifyCatalogSnapshot(serializeCatalog(catalog)));
} catch (e) {
console.error(e);
// Force close event loop
throw new Error("");
} finally {
await close();
}
// Force close the event loop on the success path too. The connection pool can
// leave keepalive handles registered even after close() resolves, which keeps
// the Edge Runtime worker (and therefore the container) alive after the catalog
// has already been written to stdout. The CLI streams this container's logs with
// Follow:true, so a worker that never exits hangs the parent `__catalog`
// subprocess — and the declarative-sync command that spawned it — indefinitely
// at 0% CPU (supabase/pg-toolbelt#312).
throw new Error("");
Original file line number Diff line number Diff line change
Expand Up @@ -71,3 +71,9 @@ try {
// Force close event loop
throw new Error("");
}
// Force close the event loop on the success path too. When SOURCE/TARGET are
// live database URLs the plan opens connections whose keepalive handles can keep
// the Edge Runtime worker alive after the export has been written, so the
// container never exits and the CLI — which follows this container's logs —
// hangs indefinitely at 0% CPU (supabase/pg-toolbelt#312).
throw new Error("");
9 changes: 9 additions & 0 deletions apps/cli-go/internal/db/pgcache/cache.go
Original file line number Diff line number Diff line change
Expand Up @@ -49,10 +49,19 @@ try {
console.log(stringifyCatalogSnapshot(serializeCatalog(catalog)));
} catch (e) {
console.error(e);
// Force close event loop
throw new Error("");
} finally {
await close();
}
// Force close the event loop on the success path too. The connection pool can
// leave keepalive handles registered even after close() resolves, which keeps
// the Edge Runtime worker (and therefore the container) alive after the catalog
// has already been written to stdout. The CLI streams this container's logs with
// Follow:true, so a worker that never exits hangs the migrations-catalog cache
// path (db start / db push with pg-delta caching) indefinitely at 0% CPU
// (supabase/pg-toolbelt#312).
throw new Error("");
`
)

Expand Down
33 changes: 33 additions & 0 deletions apps/cli-go/internal/db/pgcache/cache_template_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,33 @@
package pgcache

import (
"strings"
"testing"

"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)

// The migrations-catalog cache script (db start / db push with pg-delta caching)
// opens a connection pool and must force the worker's event loop closed once it
// has written its snapshot. If a keepalive handle lingers after close() resolves
// the worker never exits, so the container never stops and the CLI — which
// follows the container logs with Follow:true — hangs indefinitely at 0% CPU
// (supabase/pg-toolbelt#312). Guard against the success-path force-close being
// dropped.
func TestPgDeltaCatalogExportScriptForceClosesOnSuccess(t *testing.T) {
require.NotEmpty(t, pgDeltaCatalogExportTS)

lines := strings.Split(pgDeltaCatalogExportTS, "\n")
last := ""
for i := len(lines) - 1; i >= 0; i-- {
line := strings.TrimSpace(lines[i])
if line == "" || strings.HasPrefix(line, "//") {
continue
}
last = line
break
}
assert.Equal(t, `throw new Error("");`, last,
"success path must force the Edge Runtime worker to exit so the container stops")
}
33 changes: 33 additions & 0 deletions apps/cli-go/internal/pgdelta/pgdelta_apply_template_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,33 @@
package pgdelta

import (
"strings"
"testing"

"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)

// The declarative-apply script connects to TARGET and must force the worker's
// event loop closed once it has written its result JSON. applyDeclarativeSchema
// can leave connection keepalive handles registered, and if the worker never
// exits the container never stops — the CLI, which follows the container logs
// with Follow:true, then hangs indefinitely at 0% CPU (supabase/pg-toolbelt#312).
// The success path must terminate unconditionally, so guard against the
// force-close being dropped.
func TestDeclarativeApplyScriptForceClosesOnSuccess(t *testing.T) {
require.NotEmpty(t, pgDeltaDeclarativeApplyScript)

lines := strings.Split(pgDeltaDeclarativeApplyScript, "\n")
last := ""
for i := len(lines) - 1; i >= 0; i-- {
line := strings.TrimSpace(lines[i])
if line == "" || strings.HasPrefix(line, "//") {
continue
}
last = line
break
}
assert.Equal(t, `throw new Error("");`, last,
"success path must force the Edge Runtime worker to exit so the container stops")
}
Original file line number Diff line number Diff line change
Expand Up @@ -52,3 +52,10 @@ try {
} catch (e) {
throw e instanceof Error ? e : new Error(String(e));
}
// Force close the event loop on the success path. applyDeclarativeSchema opens a
// connection to TARGET whose keepalive handles can keep the Edge Runtime worker
// alive after the result JSON has been written, so the container never exits and
// the CLI — which follows this container's logs — hangs indefinitely at 0% CPU
// (supabase/pg-toolbelt#312). The catch above re-throws the real error, so this
// only runs once a successful apply has been reported on stdout.
throw new Error("");
68 changes: 68 additions & 0 deletions apps/cli-go/internal/utils/docker.go
Original file line number Diff line number Diff line change
Expand Up @@ -486,6 +486,74 @@ func DockerRunOnceWithConfig(ctx context.Context, config container.Config, hostC
return DockerStreamLogs(ctx, container, stdout, stderr)
}

// DockerRunOnceWaitWithConfig is like DockerRunOnceWithConfig but waits for the
// container to exit and then reads its already-buffered logs WITHOUT following
// the stream.
//
// DockerRunOnceWithConfig detects completion by reading a follow=true log stream
// until EOF. That EOF never arrives under podman: its /containers/<id>/logs?follow
// endpoint does not close the response when the container stops, so
// stdcopy.StdCopy blocks on the chunked HTTP body forever and the caller hangs at
// 0% CPU (supabase/pg-toolbelt#312). Waiting on /wait for the exit code and then
// reading the log once is reliable on both Docker and podman.
//
// Use this only for short-lived containers with bounded output (e.g. the
// edge-runtime pg-delta scripts): the full log is read after exit rather than
// streamed, so it is not suitable for large streaming output such as db dump.
func DockerRunOnceWaitWithConfig(ctx context.Context, config container.Config, hostConfig container.HostConfig, networkingConfig network.NetworkingConfig, containerName string, stdout, stderr io.Writer) error {
containerId, err := DockerStart(ctx, config, hostConfig, networkingConfig, containerName)
if err != nil {
return err
}
defer DockerRemove(containerId)
exitCode, err := dockerWaitExit(ctx, containerId)
if err != nil {
return err
}
if err := DockerStreamLogsOnce(ctx, containerId, stdout, stderr); err != nil {
return err
}
switch exitCode {
case 0:
return nil
case 137:
err = ErrContainerKilled
default:
err = errors.Errorf("exit %d", exitCode)
}
return errors.Errorf("error running container: %w", err)
}

// dockerWaitInterval is how often dockerWaitExit polls container state. Kept
// short so bounded one-shot scripts return promptly; it is a package var so
// tests can drop it to zero.
var dockerWaitInterval = 200 * time.Millisecond

// dockerWaitExit polls container state until it stops and returns its exit code.
//
// It deliberately uses ContainerInspect rather than a followed log stream (or
// /wait) to detect completion: inspect is reliable under podman, whereas
// podman's /logs?follow endpoint does not close when the container stops, which
// is what hangs DockerStreamLogs (see DockerRunOnceWaitWithConfig). Reusing
// inspect also keeps the request surface identical to DockerStreamLogs, so the
// existing test mocks continue to apply.
func dockerWaitExit(ctx context.Context, containerId string) (int64, error) {
for {
resp, err := Docker.ContainerInspect(ctx, containerId)
if err != nil {
return 0, errors.Errorf("failed to inspect docker container: %w", err)
}
if resp.State != nil && !resp.State.Running {
return int64(resp.State.ExitCode), nil
}
select {
case <-ctx.Done():
return 0, ctx.Err()
case <-time.After(dockerWaitInterval):
}
}
}

var ErrContainerKilled = errors.New("exit 137")

func DockerStreamLogs(ctx context.Context, containerId string, stdout, stderr io.Writer, opts ...func(*container.LogsOptions)) error {
Expand Down
66 changes: 66 additions & 0 deletions apps/cli-go/internal/utils/docker_wait_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,66 @@
package utils

import (
"bytes"
"context"
"testing"

"github.com/docker/docker/api/types/container"
"github.com/docker/docker/api/types/network"
"github.com/h2non/gock"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
"github.com/supabase/cli/internal/testing/apitest"
)

// DockerRunOnceWaitWithConfig must detect container completion via inspect and
// read logs without following the stream. Following the log stream to detect
// exit hangs forever under podman, whose /logs?follow endpoint never closes when
// the container stops (supabase/pg-toolbelt#312). These tests pin that the runner
// reads the captured output and maps the inspected exit code to an error.
func TestDockerRunOnceWait(t *testing.T) {
imageUrl := GetRegistryImageUrl(imageId)

t.Run("waits for exit then reads buffered logs", func(t *testing.T) {
require.NoError(t, apitest.MockDocker(Docker))
defer gock.OffAll()
apitest.MockDockerStart(Docker, imageUrl, containerId)
require.NoError(t, apitest.MockDockerLogs(Docker, containerId, "CATALOG\n"))
// Run test
var stdout, stderr bytes.Buffer
err := DockerRunOnceWaitWithConfig(
context.Background(),
container.Config{Image: imageUrl},
container.HostConfig{},
network.NetworkingConfig{},
containerId,
&stdout,
&stderr,
)
// Validate
assert.NoError(t, err)
assert.Equal(t, "CATALOG\n", stdout.String())
assert.Empty(t, apitest.ListUnmatchedRequests())
})

t.Run("maps non-zero exit code to error", func(t *testing.T) {
require.NoError(t, apitest.MockDocker(Docker))
defer gock.OffAll()
apitest.MockDockerStart(Docker, imageUrl, containerId)
require.NoError(t, apitest.MockDockerLogsExitCode(Docker, containerId, 1))
// Run test
var stdout, stderr bytes.Buffer
err := DockerRunOnceWaitWithConfig(
context.Background(),
container.Config{Image: imageUrl},
container.HostConfig{},
network.NetworkingConfig{},
containerId,
&stdout,
&stderr,
)
// Validate
assert.ErrorContains(t, err, "error running container: exit 1")
assert.Empty(t, apitest.ListUnmatchedRequests())
})
}
9 changes: 8 additions & 1 deletion apps/cli-go/internal/utils/edgeruntime.go
Original file line number Diff line number Diff line change
Expand Up @@ -94,7 +94,14 @@ func RunEdgeRuntimeScript(ctx context.Context, env []string, script string, bind
if len(state.extraEnv) > 0 {
combinedEnv = append(append([]string{}, env...), state.extraEnv...)
}
if err := DockerRunOnceWithConfig(
// Wait for the container to exit and then read its logs, rather than
// following the log stream to detect completion. The edge-runtime worker is
// forced to exit once the script flushes its output, but podman's
// /logs?follow endpoint does not close when the container stops, so a
// followed read (DockerRunOnceWithConfig) hangs the CLI forever
// (supabase/pg-toolbelt#312). pg-delta script output is bounded, so reading
// the log once after exit is safe.
if err := DockerRunOnceWaitWithConfig(
ctx,
container.Config{
Image: Config.EdgeRuntime.Image,
Expand Down
Loading
Loading