Atualização 2.6.0 Beta4 falhou com o que parecem ser erros de banco de dados

Suporte Instalação
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 curtida
2

Essa é uma escolha muito peculiar. Por que não usar o RDS?

Isso ocorre quando o container não é encerrado corretamente, então o PostgreSQL precisará executar um processo de recuperação na próxima inicialização.

Isso geralmente acontece muito rapidamente, mas se seu banco de dados for grande (seu caso) e/ou o disco for lento (realmente seu caso), isso pode ser muito lento e nosso script de reconstrução não saberá o que fazer.

Um método simples de recuperação é reiniciar o container com ./launcher start app, deixar ele rodar tranquilamente por algum tempo (digamos, 1h) e tentar uma reconstrução depois.

5 curtidas
3

Porque não tenho a menor ideia de como começar a implementar isso. É uma ideia interessante, no entanto.

O EFS é apenas um sistema de arquivos, então é fácil de implementar. E rápido o suficiente para operações normais, pelo menos para o nosso caso. Ou, pelo menos, era o que eu pensava.

Certo, era o que eu pensava. O interessante é que, quando iniciei o launcher, o Discourse já estava em execução há algum tempo. Então, foi o próprio script do launcher que desligou o PostgreSQL.

OK, vou tentar isso. Obrigado!

2 curtidas
4

Você sabe quando foi sua última rebuild anterior?

Aumentei o tempo de espera para o banco de dados desligar corretamente em wait a bit more if necessary for container stop · discourse/discourse_docker@49ed141 · GitHub, então, se você estava atrás desse commit, esse era um problema comum.

2 curtidas
5

Não tenho certeza, mas foi definitivamente após maio, quando vi que a alteração foi confirmada. Provavelmente foi há mais ou menos um mês. Você pode até ver o “-t 60” na saída acima.

Acabei de tentar a reconstrução novamente e, desta vez, foi concluída com sucesso. Acho que, no futuro, terei que verificar primeiro e garantir que o PostgreSQL esteja inativo ou quase inativo antes de iniciar a reconstrução.

Obrigado por toda a ajuda!

2 curtidas
6

Não sei como perdi isso :man_facepalming:.

Você se lembra se essa etapa levou os 60 segundos completos e continuou depois disso?

yay!

1 curtida
7

Não posso afirmar com certeza, mas tenho quase certeza de que não demorou tanto quanto 60s. Vou prestar mais atenção a isso no futuro, quando fizer a reconstrução.

2 curtidas
8

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