docker-entrypoint-initdb.d sql cannot be executed when I added data binding

[leohliao]

Hello, I am encountering a problem where if I bind my volume to /var/lib/postgresql/data, then my initializing script won't execute even if the folder does not exists in the beginning.

image: postgres:16.6-alpine3.20

Here's what my docker compose

version: "3.7"

services:
  db:
    image: postgres:16.6-alpine3.20
    restart: always
    environment:
      - POSTGRES_DB=db
      - POSTGRES_PASSWORD=${POSTGRES_PASSWORD}
      - PGPORT=${POSTGRES_PORT}
    ports:
      - ${POSTGRES_PORT}:${POSTGRES_PORT}
    volumes:
      - ./my-db:/var/lib/postgresql/data
      - ./db-seed.sql:/docker-entrypoint-initdb.d/seed.sql
    command: postgres -c 'log_statement=all'

My initializing sql is just to create the database

# db-seed.sql

CREATE DATABASE test_db;
\connect test_db;

I am trying to have the initializing sql to run when the my-db folder does not exist.

When I run with one or another then the behavior is as expected, however, if I have both together (and that my my-db folder is deleted and volumes are destroyed) then the initializing sql won't run.

I have tried same thing in postgres 12 and it worked.

Is this an issue with version 16?

[tianon]

I can't reproduce, so I'd suggest checking your logs for any clues to what's going on; here's the relevant snippet from my logs:

db_1  | /usr/local/bin/docker-entrypoint.sh: running /docker-entrypoint-initdb.d/seed.sql
db_1  | 2025-02-26 20:02:30.541 UTC [55] LOG:  statement: CREATE DATABASE test_db;
db_1  | CREATE DATABASE
db_1  | You are now connected to database "test_db" as user "postgres".

[leohliao]

Hello @tianon, thank you very much for your reply.

I execute docker compose up -d and this is the log that I am getting:

db-1  | 2025-02-26T20:12:13.812631599Z The files belonging to this database system will be owned by user "postgres".
db-1  | 2025-02-26T20:12:13.812666307Z This user must also own the server process.
db-1  | 2025-02-26T20:12:13.812668140Z 
db-1  | 2025-02-26T20:12:13.812780015Z The database cluster will be initialized with locale "en_US.utf8".
db-1  | 2025-02-26T20:12:13.812783140Z The default database encoding has accordingly been set to "UTF8".
db-1  | 2025-02-26T20:12:13.812784099Z The default text search configuration will be set to "english".
db-1  | 2025-02-26T20:12:13.812784974Z 
db-1  | 2025-02-26T20:12:13.812785724Z Data page checksums are disabled.
db-1  | 2025-02-26T20:12:13.812786474Z 
db-1  | 2025-02-26T20:12:13.813945140Z fixing permissions on existing directory /var/lib/postgresql/data ... ok
db-1  | 2025-02-26T20:12:13.841897057Z creating subdirectories ... ok
db-1  | 2025-02-26T20:12:13.845353724Z selecting dynamic shared memory implementation ... posix
db-1  | 2025-02-26T20:12:13.867344890Z selecting default max_connections ... 100
db-1  | 2025-02-26T20:12:13.889224474Z selecting default shared_buffers ... 128MB
db-1  | 2025-02-26T20:12:13.908395890Z selecting default time zone ... UTC
db-1  | 2025-02-26T20:12:13.917633474Z creating configuration files ... ok
db-1  | 2025-02-26T20:12:17.324681309Z running bootstrap script ... ok
db-1  | 2025-02-26T20:12:17.661222059Z sh: locale: not found
db-1  | 2025-02-26T20:12:17.661304017Z 2025-02-26 20:12:17.661 UTC [35] WARNING:  no usable system locales were found
db-1  | 2025-02-26T20:12:21.928998602Z performing post-bootstrap initialization ... ok
db-1  | 2025-02-26T20:12:26.287957563Z syncing data to disk ... ok
db-1  | 2025-02-26T20:12:26.287981188Z 
db-1  | 2025-02-26T20:12:26.287982480Z 
db-1  | 2025-02-26T20:12:26.287983605Z Success. You can now start the database server using:
db-1  | 2025-02-26T20:12:26.287984646Z 
db-1  | 2025-02-26T20:12:26.287985438Z     pg_ctl -D /var/lib/postgresql/data -l logfile start
db-1  | 2025-02-26T20:12:26.287986605Z 
db-1  | 2025-02-26T20:12:26.288116021Z initdb: warning: enabling "trust" authentication for local connections
db-1  | 2025-02-26T20:12:26.288118396Z 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.
db-1  | 2025-02-26T20:12:26.334651730Z waiting for server to start....2025-02-26 20:12:26.334 UTC [41] LOG:  starting PostgreSQL 16.6 on aarch64-unknown-linux-musl, compiled by gcc (Alpine 13.2.1_git20240309) 13.2.1 20240309, 64-bit
db-1  | 2025-02-26T20:12:26.336102563Z 2025-02-26 20:12:26.336 UTC [41] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5433"
db-1  | 2025-02-26T20:13:27.375366217Z ........................................................... stopped waiting
db-1  | 2025-02-26T20:13:27.375444009Z pg_ctl: server did not start in time
db-1 exited with code 0

I was using docker compose logs db -tf to see the logs, but then it got exited by itself.

Then after I run the same command to trace logs again, I see

db-1  | 2025-02-26T20:13:28.657206884Z 
db-1  | 2025-02-26T20:13:28.657221051Z PostgreSQL Database directory appears to contain a database; Skipping initialization
db-1  | 2025-02-26T20:13:28.657236718Z 
db-1  | 2025-02-26T20:13:28.684626426Z 2025-02-26 20:13:28.684 UTC [1] LOG:  starting PostgreSQL 16.6 on aarch64-unknown-linux-musl, compiled by gcc (Alpine 13.2.1_git20240309) 13.2.1 20240309, 64-bit
db-1  | 2025-02-26T20:13:28.684641009Z 2025-02-26 20:13:28.684 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5433
db-1  | 2025-02-26T20:13:28.684676926Z 2025-02-26 20:13:28.684 UTC [1] LOG:  listening on IPv6 address "::", port 5433
db-1  | 2025-02-26T20:13:28.686903468Z 2025-02-26 20:13:28.686 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5433"
db-1  | 2025-02-26T20:13:28.700915801Z 2025-02-26 20:13:28.700 UTC [28] LOG:  database system was shut down at 2025-02-26 20:12:21 UTC
db-1  | 2025-02-26T20:13:28.727957218Z 2025-02-26 20:13:28.727 UTC [1] LOG:  database system is ready to accept connections

As you can see, the CREATE DATABASE on mine was never executed.

I also used docker exec -it db bash to access the container and confirm that the seed.sql file was there in the docker-entrypoint-initdb.d folder.

In addition, I've passed POSTGRES_DB in my environment, and that table was not created as well.

Is there anything else I can try to resolve this?

P.S. I am using Rancher Desktop, not sure if this makes a great difference.

[leohliao]

This is the log if I remove the initializing script:

version: "3.7"

services:
  db:
    image: postgres:16.6-alpine3.20
    restart: always
    environment:
      - POSTGRES_DB=db
      - POSTGRES_PASSWORD=${POSTGRES_PASSWORD}
      - PGPORT=${POSTGRES_PORT}
    ports:
      - ${POSTGRES_PORT}:${POSTGRES_PORT}
    volumes:
      - ./my-db:/var/lib/postgresql/data
      # - ./db-seed.sql:/docker-entrypoint-initdb.d/seed.sql            => commented out 
    command: postgres -c 'log_statement=all'

db-1  | 2025-02-26T20:22:45.702572525Z The files belonging to this database system will be owned by user "postgres".
db-1  | 2025-02-26T20:22:45.702592733Z This user must also own the server process.
db-1  | 2025-02-26T20:22:45.702594108Z 
db-1  | 2025-02-26T20:22:45.702612400Z The database cluster will be initialized with locale "en_US.utf8".
db-1  | 2025-02-26T20:22:45.702614192Z The default database encoding has accordingly been set to "UTF8".
db-1  | 2025-02-26T20:22:45.702615150Z The default text search configuration will be set to "english".
db-1  | 2025-02-26T20:22:45.702616067Z 
db-1  | 2025-02-26T20:22:45.702616817Z Data page checksums are disabled.
db-1  | 2025-02-26T20:22:45.702617567Z 
db-1  | 2025-02-26T20:22:45.703815858Z fixing permissions on existing directory /var/lib/postgresql/data ... ok
db-1  | 2025-02-26T20:22:45.734508567Z creating subdirectories ... ok
db-1  | 2025-02-26T20:22:45.737698150Z selecting dynamic shared memory implementation ... posix
db-1  | 2025-02-26T20:22:45.756451942Z selecting default max_connections ... 100
db-1  | 2025-02-26T20:22:45.774351025Z selecting default shared_buffers ... 128MB
db-1  | 2025-02-26T20:22:45.790905608Z selecting default time zone ... UTC
db-1  | 2025-02-26T20:22:45.800790358Z creating configuration files ... ok
db-1  | 2025-02-26T20:22:49.143710152Z running bootstrap script ... ok
db-1  | 2025-02-26T20:22:49.465694652Z sh: locale: not found
db-1  | 2025-02-26T20:22:49.465749818Z 2025-02-26 20:22:49.465 UTC [35] WARNING:  no usable system locales were found
db-1  | 2025-02-26T20:22:53.751759779Z performing post-bootstrap initialization ... ok
db-1  | 2025-02-26T20:22:58.058551197Z syncing data to disk ... ok
db-1  | 2025-02-26T20:22:58.058568614Z 
db-1  | 2025-02-26T20:22:58.058569864Z 
db-1  | 2025-02-26T20:22:58.058570656Z Success. You can now start the database server using:
db-1  | 2025-02-26T20:22:58.058571489Z 
db-1  | 2025-02-26T20:22:58.058572239Z     pg_ctl -D /var/lib/postgresql/data -l logfile start
db-1  | 2025-02-26T20:22:58.058572947Z 
db-1  | 2025-02-26T20:22:58.058591489Z initdb: warning: enabling "trust" authentication for local connections
db-1  | 2025-02-26T20:22:58.058596156Z 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.
db-1  | 2025-02-26T20:22:58.099101989Z waiting for server to start....2025-02-26 20:22:58.099 UTC [41] LOG:  starting PostgreSQL 16.6 on aarch64-unknown-linux-musl, compiled by gcc (Alpine 13.2.1_git20240309) 13.2.1 20240309, 64-bit
db-1  | 2025-02-26T20:22:58.099963364Z 2025-02-26 20:22:58.099 UTC [41] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5433"
db-1  | 2025-02-26T20:22:58.114036323Z 2025-02-26 20:22:58.113 UTC [44] LOG:  database system was shut down at 2025-02-26 20:22:53 UTC
db-1  | 2025-02-26T20:22:58.141649364Z 2025-02-26 20:22:58.141 UTC [41] LOG:  database system is ready to accept connections
db-1  | 2025-02-26T20:22:58.178670239Z  done
db-1  | 2025-02-26T20:22:58.178681906Z server started
db-1  | 2025-02-26T20:22:58.221855614Z 2025-02-26 20:22:58.221 UTC [50] LOG:  statement: SELECT 1 FROM pg_database WHERE datname = 'db' ;
db-1  | 2025-02-26T20:22:58.269235114Z 2025-02-26 20:22:58.269 UTC [52] LOG:  statement: CREATE DATABASE "test_db" ;

The biggest different between those is that I am getting the error message server did not start in time...

[tianon]

Oh, I think PGPORT is the problem; try this:

version: "3.7"

services:
  db:
    image: postgres:16.6-alpine3.20
    restart: always
    environment:
      - POSTGRES_DB=db
      - POSTGRES_PASSWORD=${POSTGRES_PASSWORD}
    ports:
      - ${POSTGRES_PORT}:5432
    volumes:
      - ./my-db:/var/lib/postgresql/data
      - ./db-seed.sql:/docker-entrypoint-initdb.d/seed.sql
    command: postgres -c 'log_statement=all'

[leohliao]

Thanks, removing PGPORT didn't work on my end.

In addition the port was created in the default 5432 instead of the one that my env file assigned :'o

db-1  | 2025-02-26T22:31:26.671374832Z The files belonging to this database system will be owned by user "postgres".
db-1  | 2025-02-26T22:31:26.671394248Z This user must also own the server process.
db-1  | 2025-02-26T22:31:26.671395832Z 
db-1  | 2025-02-26T22:31:26.671396665Z The database cluster will be initialized with locale "en_US.utf8".
db-1  | 2025-02-26T22:31:26.671397582Z The default database encoding has accordingly been set to "UTF8".
db-1  | 2025-02-26T22:31:26.671398457Z The default text search configuration will be set to "english".
db-1  | 2025-02-26T22:31:26.671399582Z 
db-1  | 2025-02-26T22:31:26.671400332Z Data page checksums are disabled.
db-1  | 2025-02-26T22:31:26.671418082Z 
db-1  | 2025-02-26T22:31:26.672243957Z fixing permissions on existing directory /var/lib/postgresql/data ... ok
db-1  | 2025-02-26T22:31:26.695908332Z creating subdirectories ... ok
db-1  | 2025-02-26T22:31:26.698746915Z selecting dynamic shared memory implementation ... posix
db-1  | 2025-02-26T22:31:26.718524123Z selecting default max_connections ... 100
db-1  | 2025-02-26T22:31:26.739524873Z selecting default shared_buffers ... 128MB
db-1  | 2025-02-26T22:31:26.753443373Z selecting default time zone ... UTC
db-1  | 2025-02-26T22:31:26.763375790Z creating configuration files ... ok
db-1  | 2025-02-26T22:31:30.242971958Z running bootstrap script ... ok
db-1  | 2025-02-26T22:31:30.580847708Z sh: locale: not found
db-1  | 2025-02-26T22:31:30.580870208Z 2025-02-26 22:31:30.580 UTC [35] WARNING:  no usable system locales were found
db-1  | 2025-02-26T22:31:34.928947919Z performing post-bootstrap initialization ... ok
db-1  | 2025-02-26T22:31:39.179847879Z initdb: warning: enabling "trust" authentication for local connections
db-1  | 2025-02-26T22:31:39.179866588Z 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.
db-1  | 2025-02-26T22:31:39.179909171Z syncing data to disk ... ok
db-1  | 2025-02-26T22:31:39.179910629Z 
db-1  | 2025-02-26T22:31:39.179911421Z 
db-1  | 2025-02-26T22:31:39.179912129Z Success. You can now start the database server using:
db-1  | 2025-02-26T22:31:39.179912921Z 
db-1  | 2025-02-26T22:31:39.179913629Z     pg_ctl -D /var/lib/postgresql/data -l logfile start
db-1  | 2025-02-26T22:31:39.179914338Z 
db-1  | 2025-02-26T22:31:39.220055629Z waiting for server to start....2025-02-26 22:31:39.219 UTC [41] LOG:  starting PostgreSQL 16.6 on aarch64-unknown-linux-musl, compiled by gcc (Alpine 13.2.1_git20240309) 13.2.1 20240309, 64-bit
db-1  | 2025-02-26T22:31:39.220962838Z 2025-02-26 22:31:39.220 UTC [41] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
db-1  | 2025-02-26T22:32:40.278210075Z pg_ctl: server did not start in time
db-1  | 2025-02-26T22:32:40.278210367Z ........................................................... stopped waiting
db-1 exited with code 0

...(exited automatically and had to docker compose logs again)

db-1  | 2025-02-26T22:37:08.861865411Z pg_ctl: server did not start in time
db-1  | 2025-02-26T22:37:10.261813995Z 
db-1  | 2025-02-26T22:37:10.261826245Z PostgreSQL Database directory appears to contain a database; Skipping initialization
db-1  | 2025-02-26T22:37:10.261833079Z 
db-1  | 2025-02-26T22:37:10.288373537Z 2025-02-26 22:37:10.288 UTC [1] LOG:  starting PostgreSQL 16.6 on aarch64-unknown-linux-musl, compiled by gcc (Alpine 13.2.1_git20240309) 13.2.1 20240309, 64-bit
db-1  | 2025-02-26T22:37:10.288446495Z 2025-02-26 22:37:10.288 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
db-1  | 2025-02-26T22:37:10.288450912Z 2025-02-26 22:37:10.288 UTC [1] LOG:  listening on IPv6 address "::", port 5432
db-1  | 2025-02-26T22:37:10.290722329Z 2025-02-26 22:37:10.290 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
db-1  | 2025-02-26T22:37:10.304143370Z 2025-02-26 22:37:10.304 UTC [29] LOG:  database system was shut down at 2025-02-26 22:36:03 UTC
db-1  | 2025-02-26T22:37:10.332587329Z 2025-02-26 22:37:10.332 UTC [1] LOG:  database system is ready to accept connections

The initialization sql still didn't get executed.

[LaurentGoderre]

What happens if you comment out ./my-db the data mount?

[leohliao]

@LaurentGoderre Thanks for checking!

If I comment out the line./my-db, the initialization sql will be executed and I will be able to see both test_db (in the initalized sql) and db (created from environment POSTGRES_DB=db) in my postgres container.

Similar operation will be successful if I comment out my volumes for ./db-seed.sql:/docker-entrypoint-initdb.d/seed.sql,
both db (created from environment POSTGRES_DB=db) and the folder my-db will be created. This is my current workaround but I wouldn't have the ability to create multiple database on initialization.

[LaurentGoderre]

The initialization of a DB only happens when there is no data on the volume. That is expected behavior

[leohliao]

@LaurentGoderre

The initialization of a DB only happens when there is no data on the volume. That is expected behavior

Yes, I am doing it with no data, meaning that my-db/ folder does not exists in the project when I execute docker compose up.

The folder was created but initializing sql/script didn't run. I kept on deleting the folder and tried to execute again.
I tried remove volumes docker compose down --volumes and/or docker compose rm and neither was working.

Am I missing something else?

[LaurentGoderre]

I am also unable to reproduce using your example. I tried a bunch of combination of permissions too

[leohliao]

@LaurentGoderre Thanks again for trying it. I am not sure what's incorrect as well. Will update if I (ever) find an answer. Thanks!

[leohliao]

This is resolved automatically, but I am not sure how. Perhaps just needed to restart my computer...

Thanks again for everyone's time, help and support!