Slow postgresql startup in docker container

Question

We built a debian docker image with postgresql to run one of our service. The database is for internal container use and does not need port mapping. I believe it is installed via apt-get in the Dockerbuild file.

We stop and start this service often, and it is a performance issue that the database is slow to startup. Although empty, takes sightly over 20s to accept connection on the first time we start the docker image. The log is as follow :

2019-04-05 13:05:30.924 UTC [19] LOG:  could not bind IPv6 socket: Cannot assign requested address
2019-04-05 13:05:30.924 UTC [19] HINT:  Is another postmaster already running on port 5432? If not, wait a few seconds and retry.
2019-04-05 13:05:30.982 UTC [20] LOG:  database system was shut down at 2019-04-05 12:57:16 UTC
2019-04-05 13:05:30.992 UTC [20] LOG:  MultiXact member wraparound protections are now enabled
2019-04-05 13:05:30.998 UTC [19] LOG:  database system is ready to accept connections
2019-04-05 13:05:30.998 UTC [24] LOG:  autovacuum launcher started
2019-04-05 13:05:31.394 UTC [26] [unknown]@[unknown] LOG:  incomplete startup packet
2019-04-19 13:21:58.974 UTC [37] LOG:  could not bind IPv6 socket: Cannot assign requested address
2019-04-19 13:21:58.974 UTC [37] HINT:  Is another postmaster already running on port 5432? If not, wait a few seconds and retry.
2019-04-19 13:21:59.025 UTC [38] LOG:  database system was interrupted; last known up at 2019-04-05 13:05:34 UTC
2019-04-19 13:21:59.455 UTC [39] [unknown]@[unknown] LOG:  incomplete startup packet
2019-04-19 13:21:59.971 UTC [42] postgres@postgres FATAL:  the database system  is starting up
[...]
2019-04-19 13:22:15.221 UTC [85] root@postgres FATAL:  the database system is starting up
2019-04-19 13:22:15.629 UTC [38] LOG:  database system was not properly shut down; automatic recovery in progress
2019-04-19 13:22:15.642 UTC [38] LOG:  redo starts at 0/14EEBA8
2019-04-19 13:22:15.822 UTC [38] LOG:  invalid record length at 0/24462D0: wanted 24, got 0
2019-04-19 13:22:15.822 UTC [38] LOG:  redo done at 0/24462A8
2019-04-19 13:22:15.822 UTC [38] LOG:  last completed transaction was at log time 2019-04-05 13:05:36.602318+00
2019-04-19 13:22:16.084 UTC [38] LOG:  MultiXact member wraparound protections are now enabled
2019-04-19 13:22:16.094 UTC [37] LOG:  database system is ready to accept connections
2019-04-19 13:22:16.094 UTC [89] LOG:  autovacuum launcher started
2019-04-19 13:22:21.528 UTC [92] root@test LOG:  could not receive data from client: Connection reset by peer
2019-04-19 13:22:21.528 UTC [92] root@test LOG:  unexpected EOF on client connection with an open transaction

Any suggetion in fixing this startup issue ?

EDIT : Some requested the dockerfile, here is relevant lines

RUN apt-get update \
 && apt-get install -y --force-yes \
    postgresql-9.6-pgrouting \
    postgresql-9.6-postgis-2.3 \
    postgresql-9.6-postgis-2.3-scripts \
    [...]

# Download, compile and install GRASS 7.2
[...]

USER postgres
# Create a database 'grass_backend' owned by the "root" role.
RUN /etc/init.d/postgresql start \
&& psql --command "CREATE USER root WITH SUPERUSER [...];" \
&& psql --command "CREATE EXTENSION postgis; CREATE EXTENSION plpython3u;" --dbname [dbname] \
 && psql --command "CREATE EXTENSION postgis_sfcgal;" --dbname [dbname] \
 && psql --command "CREATE EXTENSION postgis; CREATE EXTENSION plpython3u;" --dbname grass_backend

WORKDIR [...]

End of file after workdir, meaning I guess the database isn't properly shut down

Answer I stopped properly postgresql inside the docker install. It now starts 15s faster. Thanks for replying

Answer 1

Considering the line database system was not properly shut down; automatic recovery in progress that would definitely explain slow startup, please don't kill the service, send the stop command and wait for it to close properly.

Please note that the system might kill the process if it takes to long to stop, this will happen in the case of postgresql if there are connections still held to it (probably from your application). If you disconnect all the connections and than stop, postgresql should be able to stop relatively quickly.

Also make sure you stop the postgresql service inside the container before turning it off.

TCP will linger connections for a while, if you are starting and stopping in quick succession without properly stopping the service inside that would explain your error of why the port is unavailable, normally the service can start/stop in very quick succession on my machine if nothing is connected to it.

3 start-stop cycles of postgresql on my machine (I have 2 decently sized databases)

$ time bash -c 'for i in 1 2 3; do /etc/init.d/postgresql-11 restart; done'
 * Stopping PostgreSQL 11 (this can take up to 92 seconds) ...                        [ ok ]
 * /run/postgresql: correcting mode
 * Starting PostgreSQL 11 ...                                                         [ ok ]
 * Stopping PostgreSQL 11 (this can take up to 92 seconds) ...                        [ ok ]
 * /run/postgresql: correcting mode
 * Starting PostgreSQL 11 ...                                                         [ ok ]
 * Stopping PostgreSQL 11 (this can take up to 92 seconds) ...                        [ ok ]
 * /run/postgresql: correcting mode
 * Starting PostgreSQL 11 ...                                                         [ ok ]

real    0m1.188s
user    0m0.260s
sys     0m0.080s