Init scripts hang on set_config when a SQL file is provided

[gfrn]

I've dumped an existing database with pg_dump -U $POSTGRES_DB -h $HOST -d $DATABASE > dump.sql (names altered for brevity and privacy), and once I added this file to /docker-entrypoint-initdb.d, the container hung on startup indefinitely.

On closer inspection, once queries were echo'd out, it hung on the following line, which is just a standard search_path vulnerability mitigation:

SELECT pg_catalog.set_config('search_path', '', false);

It also hangs on any other similar functions, such as pg_catalog.setval('public."Item_itemId_seq"', 40, true);. I've left the container running for roughly 16 hours, but it did not progress any further.

However, when I create an empty database, and restore the data with psql -U $POSTGRES_DB -h $HOST -d $DATABASE -f data.sql from outside the container, it does so with no issue at all.

The container is also able to complete the initialisation process if I comment out any lines mentioning pg_catalog.

Asking pg_dump to create a dump file that performs a clean restore, creating all databases also does not help, since set_config is invoked before any databases are dropped.

Postgres configs are all default.

Versions tested: 16.1-bookworm, 13.13-bookworm, 12.17-bookworm
Dockerfile:

FROM postgres:16.1-bookworm

WORKDIR /docker-entrypoint-initdb.d

ADD dump.sql /docker-entrypoint-initdb.d/dump.sql

# ... ENVs go here

EXPOSE 5432```

[greenape]

I do believe we're also observing this for 15.5-bullseye onwards, 16.1-bullseye onwards, when calling postgres functions as part of init (I've observed it at least for AddRasterConstraints and AddGeometryColumn).

Here's a spinup log: https://app.circleci.com/pipelines/github/Flowminder/FlowKit/22071/workflows/8cfc1081-f2f4-43ea-8665-a4886f34c0f6/jobs/594514/parallel-runs/0/steps/0-1

Which corresponds to this dockerfile: https://github.com/Flowminder/FlowKit/blob/0a2674ee8e3c74b8009af3710a59dee704c3222c/flowdb_testdata.Dockerfile which is built on https://github.com/Flowminder/FlowKit/blob/0a2674ee8e3c74b8009af3710a59dee704c3222c/flowdb.Dockerfile

[xiaoweihong]

same. when some function in the init.sql,the pg container will hang.

[yosifkit]

I am unable to replicate a failure. If there is an issue with the image we'd love to fix it, but without being able to replicate the failure, there isn't anything to change.

$ cat docker-entrypoint-initdb.d/test.sql
# ... A few random creates, inserts, and alters of the foo and bar tables

SELECT pg_catalog.set_config('search_path', '/', false);
SELECT pg_catalog.set_config('search_path', '', false);

$ # same result with postgres:16-bookworm
$ docker run -it --rm --name posty -e POSTGRES_PASSWORD=12345 -v "$PWD/docker-entrypoint-initdb.d/:/docker-entrypoint-initdb.d/" postgres:16-bullseye
Unable to find image 'postgres:16-bullseye' locally
16-bullseye: Pulling from library/postgres
5de87e84afee: Pull complete
213dd6a3996b: Pull complete
070d2f1f842e: Pull complete
1a09eced7f92: Pull complete
20b502c5af29: Pull complete
699fe861d8e5: Pull complete
d06fc374253d: Pull complete
6dd8b0dffbb7: Pull complete
7e1a4bc9a0fb: Pull complete
a1d66c245883: Pull complete
475a5bdaf20f: Pull complete
aeb9ceb01a88: Pull complete
5ef520759c99: Pull complete
d6252cbfcc9f: Pull complete
Digest: sha256:19bf873c1c9351c1c5b168a4c478016125f13d0780d6dd0a967c37ea00deadba
Status: Downloaded newer image for postgres:16-bullseye
The files belonging to this database system will be owned by user "postgres".
This user must also own the server process.

The database cluster will be initialized with locale "en_US.utf8".
The default database encoding has accordingly been set to "UTF8".
The default text search configuration will be set to "english".

Data page checksums are disabled.

fixing permissions on existing directory /var/lib/postgresql/data ... ok
creating subdirectories ... ok
selecting dynamic shared memory implementation ... posix
selecting default max_connections ... 100
selecting default shared_buffers ... 128MB
selecting default time zone ... Etc/UTC
creating configuration files ... ok
running bootstrap script ... ok
performing post-bootstrap initialization ... ok
syncing data to disk ... ok

initdb: warning: enabling "trust" authentication for local connections
initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.

Success. You can now start the database server using:

    pg_ctl -D /var/lib/postgresql/data -l logfile start

waiting for server to start....2024-07-29 18:11:45.401 UTC [48] LOG:  starting PostgreSQL 16.3 (Debian 16.3-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-07-29 18:11:45.403 UTC [48] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2024-07-29 18:11:45.407 UTC [51] LOG:  database system was shut down at 2024-07-29 18:11:45 UTC
2024-07-29 18:11:45.409 UTC [48] LOG:  database system is ready to accept connections
 done
server started

/usr/local/bin/docker-entrypoint.sh: running /docker-entrypoint-initdb.d/test.sql
CREATE TABLE
CREATE TABLE
INSERT 0 1
INSERT 0 1
ALTER TABLE
ALTER TABLE
DELETE 2
 set_config
------------
 /
(1 row)

 set_config
------------

(1 row)



2024-07-29 18:11:45.559 UTC [48] LOG:  received fast shutdown request
waiting for server to shut down....2024-07-29 18:11:45.560 UTC [48] LOG:  aborting any active transactions
2024-07-29 18:11:45.561 UTC [48] LOG:  background worker "logical replication launcher" (PID 54) exited with exit code 1
2024-07-29 18:11:45.561 UTC [49] LOG:  shutting down
2024-07-29 18:11:45.562 UTC [49] LOG:  checkpoint starting: shutdown immediate
2024-07-29 18:11:45.578 UTC [49] LOG:  checkpoint complete: wrote 49 buffers (0.3%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.004 s, sync=0.008 s, total=0.017 s; sync files=39, longest=0.002 s, average=0.001 s; distance=159 kB, estimate=159 kB; lsn=0/150E618, redo lsn=0/150E618
2024-07-29 18:11:45.579 UTC [48] LOG:  database system is shut down
 done
server stopped

PostgreSQL init process complete; ready for start up.

2024-07-29 18:11:45.679 UTC [1] LOG:  starting PostgreSQL 16.3 (Debian 16.3-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
2024-07-29 18:11:45.679 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2024-07-29 18:11:45.679 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2024-07-29 18:11:45.681 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2024-07-29 18:11:45.684 UTC [66] LOG:  database system was shut down at 2024-07-29 18:11:45 UTC
2024-07-29 18:11:45.687 UTC [1] LOG:  database system is ready to accept connections

[xiaoweihong]

I find the reason.
I use docker -it to run the postgres image

docker run -it -d --name pg \
  -v `pwd`/init:/docker-entrypoint-initdb.d \
  -v /etc/localtime:/etc/localtime \
  -p 5432:5432 \
  -e POSTGRES_USER=postgres \
  -e POSTGRES_PASSWORD=123456 \
postgres:16

when i remove -t, it doesn't hang any more.

docker run -i -d --name pg \
  -v `pwd`/init:/docker-entrypoint-initdb.d \
  -v /etc/localtime:/etc/localtime \
  -p 5432:5432 \
  -e POSTGRES_USER=postgres \
  -e POSTGRES_PASSWORD=123456 \
postgres:16

[xiaoweihong]

maybe -d effect,I remove -d,it also not hang

docker run -it  --name pg \
  -v `pwd`/init:/docker-entrypoint-initdb.d \
  -v /etc/localtime:/etc/localtime \
  -p 5432:5432 \
  -e POSTGRES_USER=postgres \
  -e POSTGRES_PASSWORD=123456 \
postgres:16

[LaurentGoderre]

Maybe something in your startup scripts is expecting an input from stdin?

[luhn]

For whatever reason, this is affecting my CI (Codeship) but works fine on my Macbook M1.

Current workaround is using the 16-alpine image, which works fine.

[tianon]

I recall some of the PostgreSQL tools default to using a pager when run interactively and one is available/configured -- maybe try something cheeky like PAGER=cat to help rule that out?

[luhn]

That seems to have worked!