Database system was not properly shut down error when rebuilding

Product Support Self-hosting

AI-generated summary

The user GuilhermeBac is experiencing a “Database system was not properly shut down” error when rebuilding their Discourse app. pfaffman identified the issue as a problem with the database, specifically that the database system was not properly shut down.

pfaffman suggested starting the app and waiting for the database recovery to complete before rebuilding. However, GuilhermeBac reported that this did not resolve the issue.

pfaffman then suggested deleting the postgres_data directory, rebuilding, and restoring a backup as a potential solution. Alternatively, pfaffman offered to fix the issue for a fee of $500, or refund the money if unsuccessful.

1 
==================== SERIOUS PROBLEM!!!! ====================
app not running!
Attempting to rebuild
==================== REBUILD LOG ====================
Ensuring launcher is up to date
Fetching origin
Launcher is up-to-date
cd /pups && git pull && /pups/bin/pups --stdin
Already up to date.
I, [2019-09-19T03:25:36.256661 #1]  INFO -- : Loading --stdin
I, [2019-09-19T03:25:36.269059 #1]  INFO -- : > locale-gen $LANG && update-locale
I, [2019-09-19T03:25:36.322226 #1]  INFO -- : Generating locales (this might take a while)...
Generation complete.

I, [2019-09-19T03:25:36.322605 #1]  INFO -- : > mkdir -p /shared/postgres_run
I, [2019-09-19T03:25:36.328236 #1]  INFO -- :
I, [2019-09-19T03:25:36.328720 #1]  INFO -- : > chown postgres:postgres /shared/postgres_run
I, [2019-09-19T03:25:36.333983 #1]  INFO -- :
I, [2019-09-19T03:25:36.334293 #1]  INFO -- : > chmod 775 /shared/postgres_run
I, [2019-09-19T03:25:36.337836 #1]  INFO -- :
I, [2019-09-19T03:25:36.338129 #1]  INFO -- : > rm -fr /var/run/postgresql
I, [2019-09-19T03:25:36.343137 #1]  INFO -- :
I, [2019-09-19T03:25:36.343429 #1]  INFO -- : > ln -s /shared/postgres_run /var/run/postgresql
I, [2019-09-19T03:25:36.347597 #1]  INFO -- :
I, [2019-09-19T03:25:36.347819 #1]  INFO -- : > socat /dev/null UNIX-CONNECT:/shared/postgres_run/.s.PGSQL.5432 || exit 0 && echo postgres already running stop container ; exit 1
2019/09/19 03:25:36 socat[28] E connect(6, AF=1 "/shared/postgres_run/.s.PGSQL.5432", 36): No such file or directory
I, [2019-09-19T03:25:36.354672 #1]  INFO -- :
I, [2019-09-19T03:25:36.355006 #1]  INFO -- : > rm -fr /shared/postgres_run/.s*
I, [2019-09-19T03:25:36.359801 #1]  INFO -- :
I, [2019-09-19T03:25:36.360028 #1]  INFO -- : > rm -fr /shared/postgres_run/*.pid
I, [2019-09-19T03:25:36.365218 #1]  INFO -- :
I, [2019-09-19T03:25:36.365462 #1]  INFO -- : > mkdir -p /shared/postgres_run/10-main.pg_stat_tmp
I, [2019-09-19T03:25:36.370636 #1]  INFO -- :
I, [2019-09-19T03:25:36.370987 #1]  INFO -- : > chown postgres:postgres /shared/postgres_run/10-main.pg_stat_tmp
I, [2019-09-19T03:25:36.375238 #1]  INFO -- :
I, [2019-09-19T03:25:36.384014 #1]  INFO -- : File > /etc/service/postgres/run  chmod: +x  chown:
I, [2019-09-19T03:25:36.391893 #1]  INFO -- : File > /etc/service/postgres/log/run  chmod: +x  chown:
I, [2019-09-19T03:25:36.399904 #1]  INFO -- : File > /etc/runit/3.d/99-postgres  chmod: +x  chown:
I, [2019-09-19T03:25:36.409011 #1]  INFO -- : File > /root/upgrade_postgres  chmod: +x  chown:
I, [2019-09-19T03:25:36.409331 #1]  INFO -- : > chown -R root /var/lib/postgresql/10/main
I, [2019-09-19T03:25:39.272591 #1]  INFO -- :
I, [2019-09-19T03:25:39.272827 #1]  INFO -- : > [ ! -e /shared/postgres_data ] && install -d -m 0755 -o postgres -g postgres /shared/postgres_data && sudo -E -u postgres /usr/lib/postgresql/10/bin/initdb -D /shared/postgres_data || exit 0
I, [2019-09-19T03:25:39.276677 #1]  INFO -- :
I, [2019-09-19T03:25:39.276825 #1]  INFO -- : > chown -R postgres:postgres /shared/postgres_data
I, [2019-09-19T03:25:39.300652 #1]  INFO -- :
I, [2019-09-19T03:25:39.300913 #1]  INFO -- : > chown -R postgres:postgres /var/run/postgresql
I, [2019-09-19T03:25:39.305131 #1]  INFO -- :
I, [2019-09-19T03:25:39.305468 #1]  INFO -- : > /root/upgrade_postgres
I, [2019-09-19T03:25:39.315038 #1]  INFO -- :
I, [2019-09-19T03:25:39.315197 #1]  INFO -- : > rm /root/upgrade_postgres
I, [2019-09-19T03:25:39.318486 #1]  INFO -- :
I, [2019-09-19T03:25:39.318940 #1]  INFO -- : Replacing data_directory = '/var/lib/postgresql/10/main' with data_directory = '/shared/postgres_data' in /etc/postgresql/10/main/postgresql.conf
I, [2019-09-19T03:25:39.320086 #1]  INFO -- : Replacing (?-mix:#?listen_addresses *=.*) with listen_addresses = '*' in /etc/postgresql/10/main/postgresql.conf
I, [2019-09-19T03:25:39.322462 #1]  INFO -- : Replacing (?-mix:#?synchronous_commit *=.*) with synchronous_commit = $db_synchronous_commit in /etc/postgresql/10/main/postgresql.conf
I, [2019-09-19T03:25:39.324514 #1]  INFO -- : Replacing (?-mix:#?shared_buffers *=.*) with shared_buffers = $db_shared_buffers in /etc/postgresql/10/main/postgresql.conf
I, [2019-09-19T03:25:39.325648 #1]  INFO -- : Replacing (?-mix:#?work_mem *=.*) with work_mem = $db_work_mem in /etc/postgresql/10/main/postgresql.conf
I, [2019-09-19T03:25:39.326845 #1]  INFO -- : Replacing (?-mix:#?default_text_search_config *=.*) with default_text_search_config = '$db_default_text_search_config' in /etc/postgresql/10/main/postgresql.conf
I, [2019-09-19T03:25:39.328375 #1]  INFO -- : > install -d -m 0755 -o postgres -g postgres /shared/postgres_backup
I, [2019-09-19T03:25:39.334429 #1]  INFO -- :
I, [2019-09-19T03:25:39.334939 #1]  INFO -- : Replacing (?-mix:#?max_wal_senders *=.*) with max_wal_senders = $db_max_wal_senders in /etc/postgresql/10/main/postgresql.conf
I, [2019-09-19T03:25:39.335686 #1]  INFO -- : Replacing (?-mix:#?wal_level *=.*) with wal_level = $db_wal_level in /etc/postgresql/10/main/postgresql.conf
I, [2019-09-19T03:25:39.338130 #1]  INFO -- : Replacing (?-mix:#?checkpoint_segments *=.*) with checkpoint_segments = $db_checkpoint_segments in /etc/postgresql/10/main/postgresql.conf
I, [2019-09-19T03:25:39.341035 #1]  INFO -- : Replacing (?-mix:#?logging_collector *=.*) with logging_collector = $db_logging_collector in /etc/postgresql/10/main/postgresql.conf
I, [2019-09-19T03:25:39.342254 #1]  INFO -- : Replacing (?-mix:#?log_min_duration_statement *=.*) with log_min_duration_statement = $db_log_min_duration_statement in /etc/postgresql/10/main/postgresql.conf
I, [2019-09-19T03:25:39.343427 #1]  INFO -- : Replacing (?-mix:^#local +replication +postgres +peer$) with local replication postgres  peer in /etc/postgresql/10/main/pg_hba.conf
I, [2019-09-19T03:25:39.343950 #1]  INFO -- : Replacing (?-mix:^host.*all.*all.*127.*$) with host all all 0.0.0.0/0 md5 in /etc/postgresql/10/main/pg_hba.conf
I, [2019-09-19T03:25:39.345666 #1]  INFO -- : > HOME=/var/lib/postgresql USER=postgres exec chpst -u postgres:postgres:ssl-cert -U postgres:postgres:ssl-cert /usr/lib/postgresql/10/bin/postmaster -D /etc/postgresql/10/main
I, [2019-09-19T03:25:39.348666 #1]  INFO -- : > sleep 5
2019-09-19 03:25:39.378 UTC [51] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2019-09-19 03:25:39.378 UTC [51] LOG:  listening on IPv6 address "::", port 5432
2019-09-19 03:25:39.384 UTC [51] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2019-09-19 03:25:39.493 UTC [54] LOG:  database system was shut down in recovery at 2019-09-19 03:23:55 UTC
2019-09-19 03:25:39.493 UTC [54] LOG:  database system was not properly shut down; automatic recovery in progress
2019-09-19 03:25:39.509 UTC [54] LOG:  redo starts at 1003/5E792F0
I, [2019-09-19T03:25:44.352528 #1]  INFO -- :
I, [2019-09-19T03:25:44.352957 #1]  INFO -- : > su postgres -c 'createdb discourse' || true
2019-09-19 03:25:44.438 UTC [58] postgres@postgres FATAL:  the database system is starting up
2019-09-19 03:25:44.439 UTC [59] postgres@template1 FATAL:  the database system is starting up
createdb: could not connect to database template1: FATAL:  the database system is starting up
I, [2019-09-19T03:25:44.442572 #1]  INFO -- :
I, [2019-09-19T03:25:44.443122 #1]  INFO -- : > su postgres -c 'psql discourse -c "create user discourse;"' || true
2019-09-19 03:25:44.525 UTC [70] postgres@discourse FATAL:  the database system is starting up
psql: FATAL:  the database system is starting up
I, [2019-09-19T03:25:44.527564 #1]  INFO -- :
I, [2019-09-19T03:25:44.527978 #1]  INFO -- : > su postgres -c 'psql discourse -c "grant all privileges on database discourse to discourse;"' || true
2019-09-19 03:25:44.617 UTC [81] postgres@discourse FATAL:  the database system is starting up
psql: FATAL:  the database system is starting up
I, [2019-09-19T03:25:44.619389 #1]  INFO -- :
I, [2019-09-19T03:25:44.619732 #1]  INFO -- : > su postgres -c 'psql discourse -c "alter schema public owner to discourse;"'
2019-09-19 03:25:44.699 UTC [92] postgres@discourse FATAL:  the database system is starting up
psql: FATAL:  the database system is starting up
I, [2019-09-19T03:25:44.701755 #1]  INFO -- :
I, [2019-09-19T03:25:44.702510 #1]  INFO -- : Terminating async processes
I, [2019-09-19T03:25:44.702584 #1]  INFO -- : Sending INT to HOME=/var/lib/postgresql USER=postgres exec chpst -u postgres:postgres:ssl-cert -U postgres:postgres:ssl-cert /usr/lib/postgresql/10/bin/postmaster -D /etc/postgresql/10/main pid: 51
2019-09-19 03:25:44.702 UTC [51] LOG:  received fast shutdown request
2019-09-19 03:25:44.745 UTC [95] LOG:  shutting down
2019-09-19 03:25:44.926 UTC [51] LOG:  database system is shut down


FAILED
--------------------
Pups::ExecError: su postgres -c 'psql discourse -c "alter schema public owner to discourse;"' failed with return #<Process::Status: pid 82 exit 2>
Location of failure: /pups/lib/pups/exec_command.rb:112:in `spawn'
exec failed with the params "su postgres -c 'psql $db_name -c \"alter schema public owner to $db_user;\"'"
e3c609d02d8197f6efd84dd0ecf99456ed566b02fd3a09d87e286696496e56c8
** FAILED TO BOOTSTRAP ** please scroll up and look for earlier error messages, there may be more than one.
./discourse-doctor may help diagnose the problem.
>

This error started after the last update

  • I already removed the non-official plugins
  • There is a lot of space (more than 600GB)
  • 2GB Swap File
2

There is a problem with your database

 2019-09-19 03:25:39.493 UTC [54] LOG: database system was not properly shut down; automatic recovery in progress

It might be that if you

. /launcher start app

And just wait a while that it’ll finish the recovery and then you can do a rebuild.

3

Thank you for the quick reply, but there are still errors:

After ./launcher start app

WARNING: We are about to start downloading the Discourse base image
This process may take anywhere between a few minutes to an hour, depending on your network speed

Please be patient

Unable to find image 'discourse/base:2.0.20190906-0522' locally
2.0.20190906-0522: Pulling from discourse/base
1ab2bdfe9778: Pulling fs layer
a313ca07f056: Pulling fs layer
1ab2bdfe9778: Download complete
1ab2bdfe9778: Pull complete
a313ca07f056: Verifying Checksum
a313ca07f056: Download complete
a313ca07f056: Pull complete
Digest: sha256:8c58bd323c80b464b2634d2aa8c322772d0c7bff3e08eff06cf2b66d37fe623d
Status: Downloaded newer image for discourse/base:2.0.20190906-0522

Unable to find image 'local_discourse/app:latest' locally
/usr/bin/docker: Error response from daemon: pull access denied for local_discourse/app, repository does not exist or may require 'docker login'.
See '/usr/bin/docker run --help'.
4

Oh.it seems that you have no working container.

The easy solution if you have a backup is to delete the postgres_data directory, rebuild, and restore the backup. If you don’t have a backup, you might be able to [convert two a two container unshakable] (Move from standalone container to separate web and data containers).

I don’t know that those instructions make it clear how to move existing data into the new container.

For $500 I’ll fix or give your money back (and there is a considerable chance that I’ll end up wasting my time and give your money neck). My contact info is in my profile.