Update 2.6.0 Beta4 fehlgeschlagen mit scheinbar db-Fehlern

Unterstützung Installation
1

Hi,

I just tried doing a command line ‘launcher rebuild app’ to update from 2.6.0.beta3 (7afb5be5f9), which has been running fine for a while, to 2.6.0.beta4 (as of 20 minutes ago). This is how I usually do my updates.

The update failed, please see output below. I tried running launcher rebuild once more, but it failed with the same error. Next I ran discourse-doctor, which also errored out on the rebuild, but which managed to start Discourse back up on 2.6.0.beta3.

Just to recap that last bit: I’m back up on 2.6.0.beta3 and the site is functioning. But I’m not about to try an update to 2.6.0.beta4 again until I understand what happened.

The launcher output says “database system was interrupted”, but Discourse was up and running fine when I started the launcher rebuild command.

Discourse resides on AWS EFS, so has virtually unlimited space. The server has 32 GB of memory, which is plenty for this site (about 1.3 million pageviews/month).

Appreciate any help and pointers in figuring this out.

Here’s the full output log from running rebuild:

gunnar@dewis:/var/discourse$ sudo ./launcher rebuild 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

2.0.20201004-2310: Pulling from discourse/base
Digest: sha256:076ad6f035d7f38e08a2d4fdd4f429ad7a40a9cc72d9958445261cdb9e743d26
Status: Downloaded newer image for discourse/base:2.0.20201004-2310
docker.io/discourse/base:2.0.20201004-2310
Ensuring launcher is up to date
Fetching origin
remote: Enumerating objects: 15, done.
remote: Counting objects: 100% (15/15), done.
remote: Compressing objects: 100% (12/12), done.
remote: Total 15 (delta 5), reused 9 (delta 3), pack-reused 0
Unpacking objects: 100% (15/15), done.
From https://github.com/discourse/discourse_docker
   1b97cb1..468f1f9  master                 -> origin/master
 * [new branch]      imagemagick-policy-xml -> origin/imagemagick-policy-xml
Updating Launcher...
Updating 1b97cb1..468f1f9
Fast-forward
 samples/mail-receiver.yml | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)
Launcher updated, restarting...
Ensuring launcher is up to date
Fetching origin
Launcher is up-to-date
Stopping old container
+ /usr/bin/docker stop -t 60 app
app
cd /pups && git pull && /pups/bin/pups --stdin
Already up to date.
I, [2020-10-19T18:46:41.157056 #1]  INFO -- : Loading --stdin
I, [2020-10-19T18:46:41.162007 #1]  INFO -- : > locale-gen $LANG && update-locale
I, [2020-10-19T18:46:41.197444 #1]  INFO -- : Generating locales (this might take a while)...
Generation complete.

I, [2020-10-19T18:46:41.197650 #1]  INFO -- : > mkdir -p /shared/postgres_run
I, [2020-10-19T18:46:41.202176 #1]  INFO -- : 
I, [2020-10-19T18:46:41.202375 #1]  INFO -- : > chown postgres:postgres /shared/postgres_run
I, [2020-10-19T18:46:41.208709 #1]  INFO -- : 
I, [2020-10-19T18:46:41.208877 #1]  INFO -- : > chmod 775 /shared/postgres_run
I, [2020-10-19T18:46:41.215819 #1]  INFO -- : 
I, [2020-10-19T18:46:41.215957 #1]  INFO -- : > rm -fr /var/run/postgresql
I, [2020-10-19T18:46:41.219629 #1]  INFO -- : 
I, [2020-10-19T18:46:41.219800 #1]  INFO -- : > ln -s /shared/postgres_run /var/run/postgresql
I, [2020-10-19T18:46:41.222805 #1]  INFO -- : 
I, [2020-10-19T18:46:41.222936 #1]  INFO -- : > socat /dev/null UNIX-CONNECT:/shared/postgres_run/.s.PGSQL.5432 || exit 0 && echo postgres already running stop container ; exit 1
2020/10/19 18:46:41 socat[27] E connect(6, AF=1 "/shared/postgres_run/.s.PGSQL.5432", 36): Connection refused
I, [2020-10-19T18:46:41.237039 #1]  INFO -- : 
I, [2020-10-19T18:46:41.237173 #1]  INFO -- : > rm -fr /shared/postgres_run/.s*
I, [2020-10-19T18:46:41.292499 #1]  INFO -- : 
I, [2020-10-19T18:46:41.292674 #1]  INFO -- : > rm -fr /shared/postgres_run/*.pid
I, [2020-10-19T18:46:41.304292 #1]  INFO -- : 
I, [2020-10-19T18:46:41.304434 #1]  INFO -- : > mkdir -p /shared/postgres_run/12-main.pg_stat_tmp
I, [2020-10-19T18:46:41.310575 #1]  INFO -- : 
I, [2020-10-19T18:46:41.310782 #1]  INFO -- : > chown postgres:postgres /shared/postgres_run/12-main.pg_stat_tmp
I, [2020-10-19T18:46:41.317554 #1]  INFO -- : 
I, [2020-10-19T18:46:41.322287 #1]  INFO -- : File > /etc/service/postgres/run  chmod: +x  chown: 
I, [2020-10-19T18:46:41.326660 #1]  INFO -- : File > /etc/service/postgres/log/run  chmod: +x  chown: 
I, [2020-10-19T18:46:41.330737 #1]  INFO -- : File > /etc/runit/3.d/99-postgres  chmod: +x  chown: 
I, [2020-10-19T18:46:41.334906 #1]  INFO -- : File > /root/upgrade_postgres  chmod: +x  chown: 
I, [2020-10-19T18:46:41.335100 #1]  INFO -- : > chown -R root /var/lib/postgresql/12/main
I, [2020-10-19T18:46:42.155381 #1]  INFO -- : 
I, [2020-10-19T18:46:42.155536 #1]  INFO -- : > [ ! -e /shared/postgres_data ] && install -d -m 0755 -o postgres -g postgres /shared/postgres_data && sudo -E -u postgres /usr/lib/postgresql/12/bin/initdb -D /shared/postgres_data || exit 0
I, [2020-10-19T18:46:42.157629 #1]  INFO -- : 
I, [2020-10-19T18:46:42.157703 #1]  INFO -- : > chown -R postgres:postgres /shared/postgres_data
I, [2020-10-19T18:47:06.520719 #1]  INFO -- : 
I, [2020-10-19T18:47:06.520876 #1]  INFO -- : > chown -R postgres:postgres /var/run/postgresql
I, [2020-10-19T18:47:06.523564 #1]  INFO -- : 
I, [2020-10-19T18:47:06.523706 #1]  INFO -- : > /root/upgrade_postgres
I, [2020-10-19T18:47:06.540126 #1]  INFO -- : 
I, [2020-10-19T18:47:06.540286 #1]  INFO -- : > rm /root/upgrade_postgres
I, [2020-10-19T18:47:06.542555 #1]  INFO -- : 
I, [2020-10-19T18:47:06.543828 #1]  INFO -- : Replacing data_directory = '/var/lib/postgresql/12/main' with data_directory = '/shared/postgres_data' in /etc/postgresql/12/main/postgresql.conf
I, [2020-10-19T18:47:06.544330 #1]  INFO -- : Replacing (?-mix:#?listen_addresses *=.*) with listen_addresses = '*' in /etc/postgresql/12/main/postgresql.conf
I, [2020-10-19T18:47:06.545027 #1]  INFO -- : Replacing (?-mix:#?synchronous_commit *=.*) with synchronous_commit = $db_synchronous_commit in /etc/postgresql/12/main/postgresql.conf
I, [2020-10-19T18:47:06.545814 #1]  INFO -- : Replacing (?-mix:#?shared_buffers *=.*) with shared_buffers = $db_shared_buffers in /etc/postgresql/12/main/postgresql.conf
I, [2020-10-19T18:47:06.546523 #1]  INFO -- : Replacing (?-mix:#?work_mem *=.*) with work_mem = $db_work_mem in /etc/postgresql/12/main/postgresql.conf
I, [2020-10-19T18:47:06.547230 #1]  INFO -- : Replacing (?-mix:#?default_text_search_config *=.*) with default_text_search_config = '$db_default_text_search_config' in /etc/postgresql/12/main/postgresql.conf
I, [2020-10-19T18:47:06.547896 #1]  INFO -- : > install -d -m 0755 -o postgres -g postgres /shared/postgres_backup
I, [2020-10-19T18:47:06.561717 #1]  INFO -- : 
I, [2020-10-19T18:47:06.562046 #1]  INFO -- : Replacing (?-mix:#?checkpoint_segments *=.*) with checkpoint_segments = $db_checkpoint_segments in /etc/postgresql/12/main/postgresql.conf
I, [2020-10-19T18:47:06.562327 #1]  INFO -- : Replacing (?-mix:#?logging_collector *=.*) with logging_collector = $db_logging_collector in /etc/postgresql/12/main/postgresql.conf
I, [2020-10-19T18:47:06.563080 #1]  INFO -- : Replacing (?-mix:#?log_min_duration_statement *=.*) with log_min_duration_statement = $db_log_min_duration_statement in /etc/postgresql/12/main/postgresql.conf
I, [2020-10-19T18:47:06.564238 #1]  INFO -- : Replacing (?-mix:^#local +replication +postgres +peer$) with local replication postgres  peer in /etc/postgresql/12/main/pg_hba.conf
I, [2020-10-19T18:47:06.564505 #1]  INFO -- : Replacing (?-mix:^host.*all.*all.*127.*$) with host all all 0.0.0.0/0 md5 in /etc/postgresql/12/main/pg_hba.conf
I, [2020-10-19T18:47:06.565039 #1]  INFO -- : > HOME=/var/lib/postgresql USER=postgres exec chpst -u postgres:postgres:ssl-cert -U postgres:postgres:ssl-cert /usr/lib/postgresql/12/bin/postmaster -D /etc/postgresql/12/main
I, [2020-10-19T18:47:06.566806 #1]  INFO -- : > sleep 5
2020-10-19 18:47:06.629 UTC [50] LOG:  starting PostgreSQL 12.4 (Debian 12.4-1.pgdg100+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 8.3.0-6) 8.3.0, 64-bit
2020-10-19 18:47:06.629 UTC [50] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2020-10-19 18:47:06.629 UTC [50] LOG:  listening on IPv6 address "::", port 5432
2020-10-19 18:47:06.665 UTC [50] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2020-10-19 18:47:07.211 UTC [53] LOG:  database system was interrupted; last known up at 2020-10-19 18:40:46 UTC
I, [2020-10-19T18:47:11.568937 #1]  INFO -- : 
I, [2020-10-19T18:47:11.569207 #1]  INFO -- : > su postgres -c 'createdb discourse' || true
2020-10-19 18:47:11.636 UTC [57] postgres@postgres FATAL:  the database system is starting up
2020-10-19 18:47:11.638 UTC [58] postgres@template1 FATAL:  the database system is starting up
createdb: error: could not connect to database template1: FATAL:  the database system is starting up
I, [2020-10-19T18:47:11.640042 #1]  INFO -- : 
I, [2020-10-19T18:47:11.640270 #1]  INFO -- : > su postgres -c 'psql discourse -c "create user discourse;"' || true
2020-10-19 18:47:11.704 UTC [69] postgres@discourse FATAL:  the database system is starting up
psql: error: could not connect to server: FATAL:  the database system is starting up
I, [2020-10-19T18:47:11.706232 #1]  INFO -- : 
I, [2020-10-19T18:47:11.706429 #1]  INFO -- : > su postgres -c 'psql discourse -c "grant all privileges on database discourse to discourse;"' || true
2020-10-19 18:47:11.761 UTC [80] postgres@discourse FATAL:  the database system is starting up
psql: error: could not connect to server: FATAL:  the database system is starting up
I, [2020-10-19T18:47:11.763159 #1]  INFO -- : 
I, [2020-10-19T18:47:11.763357 #1]  INFO -- : > su postgres -c 'psql discourse -c "alter schema public owner to discourse;"'
2020-10-19 18:47:11.818 UTC [91] postgres@discourse FATAL:  the database system is starting up
psql: error: could not connect to server: FATAL:  the database system is starting up
I, [2020-10-19T18:47:11.819734 #1]  INFO -- : 
I, [2020-10-19T18:47:11.819998 #1]  INFO -- : Terminating async processes
I, [2020-10-19T18:47:11.820025 #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/12/bin/postmaster -D /etc/postgresql/12/main pid: 50
2020-10-19 18:47:11.820 UTC [50] LOG:  received fast shutdown request
I, [2020-10-19T18:47:21.820568 #1]  INFO -- : HOME=/var/lib/postgresql USER=postgres exec chpst -u postgres:postgres:ssl-cert -U postgres:postgres:ssl-cert /usr/lib/postgresql/12/bin/postmaster -D /etc/postgresql/12/main pid:50 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 81 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;\"'"
809e00dc988196b9a3c0bfe215ff0ba30fa00056e1d2ad92818bc6b9d911df62
** 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.
gunnar@dewis:/var/discourse$
1 „Gefällt mir“
2

Das ist eine sehr ungewöhnliche Wahl. Warum nicht RDS verwenden?

Das tritt auf, wenn der Container nicht ordnungsgemäß heruntergefahren wurde. In diesem Fall muss PostgreSQL beim nächsten Start einen Wiederherstellungsprozess durchführen.

Normalerweise geht das sehr schnell, aber wenn deine Datenbank groß ist (dein Fall) und/oder die Festplatte langsam ist (wirklich dein Fall), kann dies zu lange dauern, und unser Rebuild-Skript weiß dann nicht, was es tun soll.

Eine einfache Wiederherstellungsmethode besteht darin, den Container erneut mit ./launcher start app zu starten, ihn eine Weile (sagen wir 1 Stunde) laufen zu lassen und später einen Rebuild zu versuchen.

5 „Gefällt mir“
3

Weil ich überhaupt keine Ahnung habe, wie man das überhaupt angehen soll. Es ist zwar eine interessante Idee.

EFS ist einfach nur ein Dateisystem, also einfach zu implementieren. Und für normale Operationen schnell genug, zumindest für unseren Anwendungsfall. Oder, zumindest dachte ich das.

Richtig, das dachte ich auch. Der interessante Teil ist, dass Discourse, als ich den Launcher startete, schon eine Weile lief. Also war es das Launcher-Skript selbst, das PostgreSQL heruntergefahren hat.

OK, ich werde das versuchen. Danke!

2 „Gefällt mir“
4

Weißt du, wann dein vorheriger Neuaufbau das letzte Mal durchgeführt wurde?

Ich habe die Wartezeit für das ordnungsgemäße Herunterfahren der Datenbank in wait a bit more if necessary for container stop · discourse/discourse_docker@49ed141 · GitHub erhöht. Wenn du vor diesem Commit warst, war dies ein häufiges Problem.

2 „Gefällt mir“
5

Nicht sicher, aber es war definitiv nach Mai, als ich sah, dass der Change committet wurde. Wahrscheinlich eher vor einem Monat. Man kann im obigen Output sogar das „-t 60“ sehen.

Ich habe den Neuaufbau gerade erneut versucht, und diesmal wurde er erfolgreich abgeschlossen. Ich vermute, ich muss in Zukunft zuerst prüfen und sicherstellen, dass PostgreSQL im Leerlauf oder fast im Leerlauf ist, bevor ich auf Neuaufbau klicke.

Danke für deine ganze Hilfe!

2 „Gefällt mir“
6

[quote=“Gunnar, Beitrag 5, Thema 167661”]
Ich bin mir nicht sicher, aber es war definitiv nach Mai, als ich sah, dass die Änderung committet wurde. Wahrscheinlich eher vor einem Monat. Man kann sogar das „-t 60

1 „Gefällt mir“
7

Ich kann es nicht mit Sicherheit sagen, aber ich bin mir ziemlich sicher, dass es nicht so lange wie 60 Sekunden gedauert hat. Ich werde in Zukunft, wenn ich es wieder aufbaue, mehr darauf achten.

2 „Gefällt mir“
8

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.