Bootstrap failed, please help :(

Installation
1

Trying to update and Discourse is failing to bootstrap, can anyone advise what steps I should take to get my site back online? I ran discourse-doctor, but it wasn’t able to rebuild either. I’ll paste my logs from my (third?) attempt below:

 I, [2020-04-11T13:05:40.743940 #1]  INFO -- : Loading --stdin
I, [2020-04-11T13:05:40.750131 #1]  INFO -- : > locale-gen $LANG && update-locale
I, [2020-04-11T13:05:40.800464 #1]  INFO -- : Generating locales (this might take a while)...
Generation complete.

I, [2020-04-11T13:05:40.800750 #1]  INFO -- : > mkdir -p /shared/postgres_run
I, [2020-04-11T13:05:40.804473 #1]  INFO -- : 
I, [2020-04-11T13:05:40.804720 #1]  INFO -- : > chown postgres:postgres /shared/postgres_run
I, [2020-04-11T13:05:40.809297 #1]  INFO -- : 
I, [2020-04-11T13:05:40.809573 #1]  INFO -- : > chmod 775 /shared/postgres_run
I, [2020-04-11T13:05:40.813859 #1]  INFO -- : 
I, [2020-04-11T13:05:40.814113 #1]  INFO -- : > rm -fr /var/run/postgresql
I, [2020-04-11T13:05:40.818749 #1]  INFO -- : 
I, [2020-04-11T13:05:40.819005 #1]  INFO -- : > ln -s /shared/postgres_run /var/run/postgresql
I, [2020-04-11T13:05:40.823141 #1]  INFO -- : 
I, [2020-04-11T13:05:40.823401 #1]  INFO -- : > socat /dev/null UNIX-CONNECT:/shared/postgres_run/.s.PGSQL.5432 || exit 0 && echo postgres already running stop container ; exit 1
2020/04/11 13:05:40 socat[26] E connect(6, AF=1 "/shared/postgres_run/.s.PGSQL.5432", 36): Connection refused
I, [2020-04-11T13:05:40.831215 #1]  INFO -- : 
I, [2020-04-11T13:05:40.831436 #1]  INFO -- : > rm -fr /shared/postgres_run/.s*
I, [2020-04-11T13:05:40.837350 #1]  INFO -- : 
I, [2020-04-11T13:05:40.837549 #1]  INFO -- : > rm -fr /shared/postgres_run/*.pid
I, [2020-04-11T13:05:40.843241 #1]  INFO -- : 
I, [2020-04-11T13:05:40.843486 #1]  INFO -- : > mkdir -p /shared/postgres_run/10-main.pg_stat_tmp
I, [2020-04-11T13:05:40.848311 #1]  INFO -- : 
I, [2020-04-11T13:05:40.848643 #1]  INFO -- : > chown postgres:postgres /shared/postgres_run/10-main.pg_stat_tmp
I, [2020-04-11T13:05:40.853421 #1]  INFO -- : 
I, [2020-04-11T13:05:40.863897 #1]  INFO -- : File > /etc/service/postgres/run  chmod: +x  chown: 
I, [2020-04-11T13:05:40.873965 #1]  INFO -- : File > /etc/service/postgres/log/run  chmod: +x  chown: 
I, [2020-04-11T13:05:40.884485 #1]  INFO -- : File > /etc/runit/3.d/99-postgres  chmod: +x  chown: 
I, [2020-04-11T13:05:40.895036 #1]  INFO -- : File > /root/upgrade_postgres  chmod: +x  chown: 
I, [2020-04-11T13:05:40.895478 #1]  INFO -- : > chown -R root /var/lib/postgresql/10/main
I, [2020-04-11T13:06:09.192272 #1]  INFO -- : 
I, [2020-04-11T13:06:09.192593 #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, [2020-04-11T13:06:09.197837 #1]  INFO -- : 
I, [2020-04-11T13:06:09.197992 #1]  INFO -- : > chown -R postgres:postgres /shared/postgres_data
I, [2020-04-11T13:06:09.228153 #1]  INFO -- : 
I, [2020-04-11T13:06:09.228375 #1]  INFO -- : > chown -R postgres:postgres /var/run/postgresql
I, [2020-04-11T13:06:09.233425 #1]  INFO -- : 
I, [2020-04-11T13:06:09.233760 #1]  INFO -- : > /root/upgrade_postgres
I, [2020-04-11T13:06:09.243357 #1]  INFO -- : 
I, [2020-04-11T13:06:09.243596 #1]  INFO -- : > rm /root/upgrade_postgres
I, [2020-04-11T13:06:09.249007 #1]  INFO -- : 
I, [2020-04-11T13:06:09.249495 #1]  INFO -- : Replacing data_directory = '/var/lib/postgresql/10/main' with data_directory = '/shared/postgres_data' in /etc/postgresql/10/main/postgresql.conf
I, [2020-04-11T13:06:09.272106 #1]  INFO -- : Replacing (?-mix:#?listen_addresses *=.*) with listen_addresses = '*' in /etc/postgresql/10/main/postgresql.conf
I, [2020-04-11T13:06:09.272853 #1]  INFO -- : Replacing (?-mix:#?synchronous_commit *=.*) with synchronous_commit = $db_synchronous_commit in /etc/postgresql/10/main/postgresql.conf
I, [2020-04-11T13:06:09.273496 #1]  INFO -- : Replacing (?-mix:#?shared_buffers *=.*) with shared_buffers = $db_shared_buffers in /etc/postgresql/10/main/postgresql.conf
I, [2020-04-11T13:06:09.274139 #1]  INFO -- : Replacing (?-mix:#?work_mem *=.*) with work_mem = $db_work_mem in /etc/postgresql/10/main/postgresql.conf
I, [2020-04-11T13:06:09.274757 #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, [2020-04-11T13:06:09.275288 #1]  INFO -- : > install -d -m 0755 -o postgres -g postgres /shared/postgres_backup
I, [2020-04-11T13:06:09.282029 #1]  INFO -- : 
I, [2020-04-11T13:06:09.282556 #1]  INFO -- : Replacing (?-mix:#?max_wal_senders *=.*) with max_wal_senders = $db_max_wal_senders in /etc/postgresql/10/main/postgresql.conf
I, [2020-04-11T13:06:09.330309 #1]  INFO -- : Replacing (?-mix:#?wal_level *=.*) with wal_level = $db_wal_level in /etc/postgresql/10/main/postgresql.conf
I, [2020-04-11T13:06:09.331016 #1]  INFO -- : Replacing (?-mix:#?checkpoint_segments *=.*) with checkpoint_segments = $db_checkpoint_segments in /etc/postgresql/10/main/postgresql.conf
I, [2020-04-11T13:06:09.331655 #1]  INFO -- : Replacing (?-mix:#?logging_collector *=.*) with logging_collector = $db_logging_collector in /etc/postgresql/10/main/postgresql.conf
I, [2020-04-11T13:06:09.332347 #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, [2020-04-11T13:06:09.333020 #1]  INFO -- : Replacing (?-mix:^#local +replication +postgres +peer$) with local replication postgres  peer in /etc/postgresql/10/main/pg_hba.conf
I, [2020-04-11T13:06:09.333660 #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, [2020-04-11T13:06:09.334205 #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, [2020-04-11T13:06:09.338659 #1]  INFO -- : > sleep 5
2020-04-11 13:06:09.481 UTC [49] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2020-04-11 13:06:09.482 UTC [49] LOG:  listening on IPv6 address "::", port 5432
2020-04-11 13:06:09.544 UTC [49] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2020-04-11 13:06:10.813 UTC [52] LOG:  database system shutdown was interrupted; last known up at 2020-04-11 12:42:48 UTC
2020-04-11 13:06:12.356 UTC [52] LOG:  database system was not properly shut down; automatic recovery in progress
2020-04-11 13:06:12.416 UTC [52] LOG:  redo starts at 84/BD1A85B0
2020-04-11 13:06:12.446 UTC [52] LOG:  invalid record length at 84/BD7B3570: wanted 24, got 0
2020-04-11 13:06:12.446 UTC [52] LOG:  redo done at 84/BD7B3530
2020-04-11 13:06:12.446 UTC [52] LOG:  last completed transaction was at log time 2020-04-11 11:53:53.069757+00
I, [2020-04-11T13:06:14.343128 #1]  INFO -- : 
I, [2020-04-11T13:06:14.343449 #1]  INFO -- : > su postgres -c 'createdb discourse' || true
2020-04-11 13:06:14.409 UTC [56] postgres@postgres FATAL:  the database system is starting up
2020-04-11 13:06:14.411 UTC [57] postgres@template1 FATAL:  the database system is starting up
createdb: could not connect to database template1: FATAL:  the database system is starting up
I, [2020-04-11T13:06:14.413548 #1]  INFO -- : 
I, [2020-04-11T13:06:14.413822 #1]  INFO -- : > su postgres -c 'psql discourse -c "create user discourse;"' || true
2020-04-11 13:06:14.493 UTC [68] postgres@discourse FATAL:  the database system is starting up
psql: FATAL:  the database system is starting up
I, [2020-04-11T13:06:14.495917 #1]  INFO -- : 
I, [2020-04-11T13:06:14.496250 #1]  INFO -- : > su postgres -c 'psql discourse -c "grant all privileges on database discourse to discourse;"' || true
2020-04-11 13:06:14.574 UTC [79] postgres@discourse FATAL:  the database system is starting up
psql: FATAL:  the database system is starting up
I, [2020-04-11T13:06:14.576284 #1]  INFO -- : 
I, [2020-04-11T13:06:14.576674 #1]  INFO -- : > su postgres -c 'psql discourse -c "alter schema public owner to discourse;"'
2020-04-11 13:06:14.655 UTC [90] postgres@discourse FATAL:  the database system is starting up
psql: FATAL:  the database system is starting up
I, [2020-04-11T13:06:14.658074 #1]  INFO -- : 
I, [2020-04-11T13:06:14.658635 #1]  INFO -- : Terminating async processes
I, [2020-04-11T13:06:14.658722 #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: 49
2020-04-11 13:06:14.658 UTC [49] LOG:  received fast shutdown request
I, [2020-04-11T13:06:24.659800 #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 pid:49 did not terminate cleanly, forcing termination!


FAILED
--------------------
Pups::ExecError: su postgres -c 'psql discourse -c "alter schema public owner to discourse;"' failed with return #<Process::Status: pid 80 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;\"'"
3956a617d80571dd1ef87fcf7d23a319190bd909477e703ccb22cb25d0e137c8
** 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.
1 Like
2

Looks like your database is corrupt. Do you have enough disk space? (I doubt that’s the problem, but it would be great if it were.)

The easiest solution is probably to delete the database directory, which will build a new database. Then you can restore from your most recent backup.

5 Likes
5

To give you an update now that I’m out of the heat of it - rebooting the server allowed the app to rebuild. This was a suggestion from @merefield that I stumbled across elsewhere on here, and applied as a Hail Mary solution.

So, whatever Postgres was fussing about remains a mystery to me. Now I have new, but less critical problems. On the bright side, I didn’t have to nuke my large database.

@pfaffman, we have a substantial amount of storage, we’re not even close to hitting the ceiling there.

Thanks for all the feedback, hopefully my painful experience helps someone else out there :slight_smile:

4 Likes
6

Hi there,

we just received the same message on a rebuild for a version upgrade …

… and thought the same was happening to us – for the first time ever –

… and hesitantly looked for the backup directory ;]. A fresh backup was there, so we relaxed a bit.

We also just wanted to share that, while we did not reboot the server, we waited a bit, failed rebuilding a second time with the same error message invalid record length at, but now the update process seems to be working when trying a third time. The server has enough disk space, but is currently a bit under pressure I/O-wise.

Maybe this helps others who may be running into the same situation. From this experience, we would advise to a) mitigate resource overconsumption on the host system before trying another rebuild, and b) not to give up too early.

With kind regards,
Andreas.

2 Likes
7

Well, it says that a recovery is in process, so maybe you can let it recover? I think you’d maybe restart the old container to let it do that.

Did this get worked out?

1 Like
8

Everything worked well and the upgrade concluded without errors on the third attempt. Thank you and a happy new year!

1 Like
9

Similar-looking problems previously seen have been helped by tweaking a timeout value:

Or by waiting:

2 Likes