Обновление 2.6.0 Beta4 не удалось, судя по ошибкам БД

Поддержка Самостоятельное хостинг
1

Привет,

Я только что попробовал выполнить команду в строке «launcher rebuild app» для обновления с версии 2.6.0.beta3 (7afb5be5f9), которая работала стабильно уже некоторое время, до версии 2.6.0.beta4 (выпущенной 20 минут назад). Обычно я обновляюсь именно так.

Обновление не удалось, см. вывод ниже. Я попытался запустить launcher rebuild ещё раз, но получил ту же ошибку. Затем я запустил discourse-doctor, который также выдал ошибку при попытке rebuild, но всё же смог запустить Discourse обратно на версии 2.6.0.beta3.

Напомню: система снова работает на версии 2.6.0.beta3, и сайт функционирует нормально. Но я не собираюсь снова пытаться обновиться до 2.6.0.beta4, пока не разберусь, что произошло.

В выводе launcher указано: «database system was interrupted», хотя Discourse работал без проблем в момент запуска команды launcher rebuild.

Discourse размещён на AWS EFS, поэтому пространство практически не ограничено. У сервера 32 ГБ оперативной памяти, чего более чем достаточно для этого сайта (около 1,3 миллиона просмотров страниц в месяц).

Буду благодарен за любую помощь и подсказки в решении этой проблемы.

Ниже приведён полный лог вывода команды 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$
2

Это очень необычный выбор. Почему бы не использовать RDS?

Это происходит, когда контейнер завершает работу некорректно, поэтому PostgreSQL должен будет выполнить процесс восстановления при следующем запуске.

Обычно это происходит очень быстро, но если ваша база данных большая (как в вашем случае) и/или диск медленный (действительно ваш случай), это может занять слишком много времени, и наш скрипт восстановления не знает, что делать.

Простой метод восстановления — снова запустить контейнер с помощью команды ./launcher start app, дать ему поработать некоторое время (например, 1 час), а затем попробовать выполнить восстановление.

3

Потому что я понятия не имею, с чего вообще начать его внедрение. Хотя идея интересная.

EFS — это просто файловая система, поэтому её легко реализовать. И для обычных операций она достаточно быстрая, по крайней мере для наших задач. По крайней мере, так я думал.

Да, именно так я и думал. Интересный момент в том, что когда я запустил launcher, Discourse уже работал какое-то время. То есть именно скрипт launcher сам завершил работу PostgreSQL.

Хорошо, я попробую. Спасибо!

4

Вы знаете, когда было ваше предыдущее обновление?

Я увеличил время ожидания для корректного завершения работы базы данных в wait a bit more if necessary for container stop · discourse/discourse_docker@49ed141 · GitHub, поэтому, если вы находились до этого коммита, это была распространённая проблема.

5

Не уверен, но это точно было после мая, когда я увидел, что изменение было закоммичено. Скорее всего, около месяца назад. Вы даже можете увидеть «-t 60» в выводе выше.

Я только что снова попробовал выполнить восстановление, и на этот раз оно завершилось успешно. Похоже, в будущем мне нужно сначала проверить и убедиться, что PostgreSQL находится в состоянии простоя или близкого к нему, прежде чем запускать восстановление.

Спасибо за всю вашу помощь!

6

Не знаю, как я это пропустил :man_facepalming:.

Вы помните, занял ли этот шаг полные 60 секунд и продолжался ли после этого?

Ура!

7

Я не могу сказать точно, но я почти уверен, что это заняло меньше 60 секунд. В будущем, когда я буду собирать заново, я обращу на это больше внимания.