アップグレード後、複数のコンテナを実行する際のファイアウォール問題

アップグレードでいくつか問題が発生しました。最初のフォーラムはダッシュボード経由での最初の試行で失敗し、再構築でも再度失敗しましたが、2 回目の再構築で動作したように見えました。ただし、その後さらに 1 回再構築する必要がありました。この経験から、PG12 へのアップデート時にアップグレードを行う際はすべての Discourse インスタンスを停止する必要があることを思い出しました(このサーバーには個別のコンテナを持つ 3 つの Discourse フォーラムがあります)。そのため、他の 2 つのフォーラムについては以下の手順が機能しました。

しかし、何らかの理由で最初のフォーラムにはアクセスできず、Safari は「サーバーが予期せず接続を切断しました」と表示しています。再構築自体は問題なく実行されるようですが、アクセスできず、アプリや Rails コンソールには入れません。データベースは正常に見えます。

再構築時に確認できた、関連する可能性のある警告メッセージは以下の通りです。

168:M 31 Jan 2021 21:39:22.459 # WARNING: The TCP backlog setting of 511 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 128.
168:M 31 Jan 2021 21:39:22.459 # Server initialized
168:M 31 Jan 2021 21:39:22.459 # WARNING overcommit_memory is set to 0! Background save may fail under low memory condition. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
168:M 31 Jan 2021 21:39:22.459 # WARNING you have Transparent Huge Pages (THP) support enabled in your kernel. This will create latency and memory usage issues with Redis. To fix this issue run the command 'echo madvise > /sys/kernel/mm/transparent_hugepage/enabled' as root, and add it to your /etc/rc.local in order to retain the setting after a reboot. Redis must be restarted after THP is disabled (set to 'madvise' or 'never').
168:M 31 Jan 2021 21:39:22.459 * Loading RDB produced by version 6.0.9
168:M 31 Jan 2021 21:39:22.459 * RDB age 21 seconds
168:M 31 Jan 2021 21:39:22.459 * RDB memory usage when created 4.03 Mb
168:M 31 Jan 2021 21:39:22.466 * DB loaded from disk: 0.006 seconds
168:M 31 Jan 2021 21:39:22.466 * Ready to accept connections

production.log:


Job exception: Error connecting to Redis on localhost:6379 (Errno::ENETUNREACH)

Error connecting to Redis on localhost:6379 (Errno::ENETUNREACH) subscribe failed, reconnecting in 1 second. Call stack /var/www/discourse/vendor/bundle/ruby/2.7.0/gems/redis-4.2.5/lib/redis/client.rb:367:in `rescue in establish_connection'

同様のメッセージが unicorn.stderr.log および unicorn.stdout.log にも表示されています。

コンテナ内に进入して redis-cli ping を実行すると、PONG が返ってきます。Redis はサーバー上で動作しています(ただし個別のコンテナ内ではありませんが、これは以前からそのような状況だったと思います)。

何が起きているのか、ご存知でしょうか?

(サーバーを再起動し、安全策としてこのドメイン用の新しい letsencrypt 証明書も作成しましたが、状況は変わりません。)

「いいね!」 1

すべてが正常に動作しているようですが、別のブラウザで試したり、キャッシュをクリアしたりしましたか?それでも解決しない場合は、以下のコマンドの出力結果を貼り付けていただけますか:

curl -vv -o /dev/null <forum url>
「いいね!」 2

複数のブラウザで試しましたが、同じエラーが発生します。そのコマンドの出力は以下の通りです:

~$ curl -vv -o /dev/null https://metaruby.com
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0*   Trying 78.46.110.60...
* TCP_NODELAY set
* Connected to metaruby.com (78.46.110.60) port 443 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
*   CAfile: /etc/ssl/cert.pem
  CApath: none
* TLSv1.2 (OUT), TLS handshake, Client hello (1):
} [226 bytes data]
* TLSv1.2 (IN), TLS handshake, Server hello (2):
{ [93 bytes data]
* TLSv1.2 (IN), TLS handshake, Certificate (11):
{ [2473 bytes data]
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
{ [333 bytes data]
* TLSv1.2 (IN), TLS handshake, Server finished (14):
{ [4 bytes data]
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
} [70 bytes data]
* TLSv1.2 (OUT), TLS change cipher, Change cipher spec (1):
} [1 bytes data]
* TLSv1.2 (OUT), TLS handshake, Finished (20):
} [16 bytes data]
* TLSv1.2 (IN), TLS change cipher, Change cipher spec (1):
{ [1 bytes data]
* TLSv1.2 (IN), TLS handshake, Finished (20):
{ [16 bytes data]
* SSL connection using TLSv1.2 / ECDHE-RSA-AES128-GCM-SHA256
* ALPN, server did not agree to a protocol
* Server certificate:
*  subject: CN=metaruby.com
*  start date: Jan 31 03:33:05 2021 GMT
*  expire date: May  1 03:33:05 2021 GMT
*  subjectAltName: host "metaruby.com" matched cert's "metaruby.com"
*  issuer: C=US; O=Let's Encrypt; CN=R3
*  SSL certificate verify ok.
> GET / HTTP/1.1
> Host: metaruby.com
> User-Agent: curl/7.64.1
> Accept: */*
> 
  0     0    0     0    0     0      0      0 --:--:--  0:00:01 --:--:--     0* TLSv1.2 (IN), TLS alert, close notify (256):
{ [2 bytes data]
* Empty reply from server
  0     0    0     0    0     0      0      0 --:--:--  0:00:01 --:--:--     0
* Connection #0 to host metaruby.com left intact
curl: (52) Empty reply from server
* Closing connection 0
「いいね!」 1

空のレスポンスエラーの原因として考えられるものは以下の通りです:

  1. サーバーが VPN 内にあり、ポートへのアクセスがない場合。
  2. 同じサーバー内に複数の Discourse インスタンスがある場合、その前にリバースプロキシが設定されていると思われます。それが Discourse コンテナを指していることを確認してください(再起動が必要になるかもしれません)。
  3. サーバーの空き容量が不足している場合(df -hT / を実行して確認できます)。

まずはディスクの空き容量を確認することから始めることをお勧めします(3)。

「いいね!」 2

ディスク使用量は31%と表示されていましたが、念のため ./launcher cleanup を実行しました:

docker container ls 
(すべての3つのフォーラムコンテナが稼働していることを確認するため)

./launcher cleanup

WARNING! This will remove all stopped containers.
Are you sure you want to continue? [y/N] y
Total reclaimed space: 0B
WARNING! This will remove all images without at least one container associated to them.
Are you sure you want to continue? [y/N] y
Deleted Images:
...
Total reclaimed space: 32.56GB

HAProxyを使用しており、確認(および再起動)したところ、正常に稼働しています(httpからhttpsへのリダイレクトもHAProxy経由で行っており、ドメインでも正常に機能しています。そのため、HAProxyに問題があるとは考えにくいです。それに、今回のアップデートまでは問題なく動作していました)。

コンテナにはまだログインでき、Railsコンソールにもアクセス可能です。データベースもコンテナに存在し、接続されています。そのため、これは非常に奇妙です。他にアイデアやトラブルシューティングのステップをご存知の方はいらっしゃいますか?

「いいね!」 1

デバッグがうまくいかない場合、コマンドラインからバックアップを取得し、PG13 で動作する新しいサイトに対してリストアするという選択肢があります。あるいは、サイトをすぐに復旧させる必要がある場合は、バージョンを PG12 にダウングレードし、既存の shared/postgres_data_old ディレクトリを shared/postgres_data に戻して再構築することも可能です。ただし、問題がデータベースのアップグレード自体に関連しているようではないため、バックアップとリストアの手法を試すことをお勧めします。

「いいね!」 3

ここでの状況は、標準的なサポート付きのインストールを少し超えていますね。 :slight_smile:

各 Discourse インスタンスが独自の PostgreSQL を持っているのか、それとも3つすべてで1つの PostgreSQL を共有しているのでしょうか?

もし単一の PostgreSQL/データコンテナを使用している場合、PostgreSQL のアップグレードを試みる前に、すべての Discourse インスタンスを停止する必要があります。

HaProxy は PostgreSQL とは関係ないため、それは問題にならないと思います。

「いいね!」 3

これについて調査するための他のアイデアがあれば、ぜひ試してみたいです、Michael。幸い、このフォーラムはすでに読み取り専用モードで、別のフォーラムに置き換えられていたため、オフラインになっていることは大きな問題ではありません。

もし他に手がかりがなければ、バックアップの復元を試みるつもりですが、可能であればトラブルシューティングを行いたいと考えています。なぜこのようなことが起きたのかを知りたいからです(あなたもそう思っているかもしれません)。もしあなたがさらに調査する気があるなら、私も喜んで協力します。

正直なところ、この件は他のいくつかのフォーラムを Discourse に移行することに対して少し不安を感じさせてしまいました。何が原因で問題が起きたのかを知ることは、私たち全員にとって有益だと思います。

これは「標準的な」マルチコンテナインストールです。各フォーラムは独自の app.yml を持ち、host: discourse/shared-site-name/standalone および host: discourse/shared-site-name/standalone/log/var-log をベースにしたコンテナ構成になっています(私がこのフォーラムで質問し、投稿した内容に基づいています)。

各コンテナに入り、psql (sudo -u postgres psql discourse) と \\l+ を実行すると、コンテナごとに1つの discourse データベースのみが表示されます(サイズもそれぞれ異なります)。したがって、これらは独立した Discourse インスタンスだと推測されます。

サーバー上で複数の独立した Discourse フォーラムを実行する「標準的な」方法に関するリンクはありますか?私の環境がそれと同じかどうか確認できますが、私が持っている構成は Discourse チームからの投稿やガイダンスに基づいていると確信しています。

「いいね!」 2

コンテナ内で nginx を実行していますか?次に試すべきは、リクエストがどこに到達しているかを確認することです。私の理解では、HAProxy が SSL 終端処理を行い、その後リクエストをそれぞれのコンテナにプロキシしているのでしょうか?

「いいね!」 3

ああ、なるほど。つまり、それぞれのアプリに対して ./launcher rebuild YOUR-APP-NAME を 2 回実行する必要がありますね。Web インターフェースからはできないと思います。

また、yml コンテナには SSL と Let’s Encrypt のテンプレートがすべてコメントアウト(または削除)されていますか?

「いいね!」 2

私の認識では、コンテナ自体はすべて「標準」のものであり(つまり、それぞれが nginx を実行していると推測されます)、はい、HAProxy がすべての SSL を処理し、リクエストを各コンテナに誘導しています。

私の設定は、こちらのガイドに従っています:https://meta.discourse.org/t/how-to-set-up-discourse-on-a-server-with-existing-apache-sites/30013(HAProxy 設定の SSL 版はこちらです:https://meta.discourse.org/t/how-to-set-up-discourse-on-a-server-with-existing-apache-sites/30013/18)。

HAProxy 設定には一つ問題がありました:

backend main_apache_sites
  server server1 127.0.0.1:8080 cookie A check
  cookie JSESSIONID prefix nocache

backend discourse_docker
  server server2 127.0.0.1:8888 cookie A check
  cookie JSESSIONID prefix nocache

backend discourse_docker_2
  server server2 127.0.0.1:8889 cookie A check
  cookie JSESSIONID prefix nocache

backend discourse_docker_3
  server server2 127.0.0.1:8890 cookie A check
  cookie JSESSIONID prefix nocache

backend letsencrypt-backend
  server letsencrypt 127.0.0.1:54321

何らかの理由で、すべての Discourse バックエンドの 2 行目に server2 が指定されていました。昨日、これらを server2server3 などに変更しましたが、変化はありません(以前はこの状態で正常に動作していました)。

さらに手がかりを提供する可能性のある特定のログファイルはありますか?Docker ログファイルなどでしょうか?

はい、それらはコメントアウトされています:

templates:
  - "templates/postgres.template.yml"
  - "templates/redis.template.yml"
  - "templates/web.template.yml"
  - "templates/web.ratelimited.template.yml"
## Lets Encrypt (https) を追加したい場合は、以下の 2 行のコメントを外してください
  #- "templates/web.ssl.template.yml"
  #- "templates/web.letsencrypt.ssl.template.yml"
「いいね!」 1

アプリコンテナ内の nginx ログを確認すれば、リクエストがアプリケーションに到達しているかどうかを確認できるはずです。コンテナ内の nginx は、リクエストを unicorn プロセスがある 127.0.0.1:3000 にプロキシしています。

「いいね!」 1

/var/log/nginx および /shared/log/rails を確認しましたが、特に目立つ点は見当たりません。実際、/shared/log/rails/production.log 以外のログファイルは今日(4 日)更新されていません。そのファイルには以下のようなジョブが数件記録されているのみです。

Rails ログ:

Nginx ログ:

また、HAProxy のポートを変更したところ、予想通り「サーバーが見つかりません」というエラーが発生しました。その後、コンテナを同じポートに更新すると、再び元の動作に戻りました(そのため、HAProxy の問題ではないと考えられます)。

確認すべき Docker ログはありますか?それとも、このコンテナを保存またはエクスポートして送付し、確認していただくことは可能でしょうか?私と同じく、何が問題だったのか気になっていることと思います :blush:

「いいね!」 1

実はもう一度確認しました(上記は昨夜のものですが)、現在は以下にもログがあります:

unicorn.stderr.log

(申し訳ありませんが、テキストをコピーすることができません)

nginx のログは今日一切変更されていませんが、1 月 30 日の最後のログには以下のようなエラーが表示されています:7: limiting requests by zone "flood" client: my.ip.address, POST /mini-profiler-resources

編集: 参考になるか分かりませんが、docker logs APPを実行した結果は以下の通りです:

フォーラムが動作しない場合:

# docker logs metaruby
run-parts: executing /etc/runit/1.d/00-ensure-links
run-parts: executing /etc/runit/1.d/00-fix-var-logs
run-parts: executing /etc/runit/1.d/01-cleanup-web-pids
run-parts: executing /etc/runit/1.d/anacron
run-parts: executing /etc/runit/1.d/cleanup-pids
Cleaning stale PID files
run-parts: executing /etc/runit/1.d/copy-env
Started runsvdir, PID is 43
ok: run: redis: (pid 55) 0s
ok: run: postgres: (pid 56) 0s
chgrp: invalid group: 'syslog'
supervisor pid: 50 unicorn pid: 89

フォーラム 2(正常に動作中)の場合:

# docker logs f2

run-parts: executing /etc/runit/1.d/00-ensure-links

run-parts: executing /etc/runit/1.d/00-fix-var-logs

run-parts: executing /etc/runit/1.d/01-cleanup-web-pids

run-parts: executing /etc/runit/1.d/anacron

run-parts: executing /etc/runit/1.d/cleanup-pids

Cleaning stale PID files

run-parts: executing /etc/runit/1.d/copy-env

Started runsvdir, PID is 42

ok: run: redis: (pid 55) 0s

ok: run: postgres: (pid 54) 0s

chgrp: invalid group: 'syslog'

supervisor pid: 51 unicorn pid: 82

(51) Reopening logs

(51) Reopening logs

(51) Reopening logs

(51) Stopping Sidekiq

(51) Reloading unicorn (82)

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid... 22039

(51) Old pid is: 82 New pid is: 22039

(51) Stopping Sidekiq

(51) Reloading unicorn (22039)

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid...

(51) Waiting for new unicorn master pid... 23358

(51) Old pid is: 22039 New pid is: 23358

(51) Reopening logs

(51) Reopening logs

フォーラム 3(これも正常に動作中)の場合:

# docker logs f3

run-parts: executing /etc/runit/1.d/00-ensure-links

run-parts: executing /etc/runit/1.d/00-fix-var-logs

run-parts: executing /etc/runit/1.d/01-cleanup-web-pids

run-parts: executing /etc/runit/1.d/anacron

run-parts: executing /etc/runit/1.d/cleanup-pids

Cleaning stale PID files

run-parts: executing /etc/runit/1.d/copy-env

Started runsvdir, PID is 42

ok: run: redis: (pid 54) 0s

chgrp: invalid group: 'syslog'

ok: run: postgres: (pid 55) 0s

supervisor pid: 56 unicorn pid: 88

(56) Reopening logs

(56) Reopening logs

(56) Reopening logs

(56) Reopening logs

(56) Reopening logs
「いいね!」 1

ログを確認し、これまでの返信を読み返すと、アプリケーションはコンテナ内の localhost:6379 にある Redis にアクセスしようとしています。Redis の起動自体は正常に行われているようですが、何らかの理由で接続できないようです(不思議です)。ただし、これらのエラーメッセージは、message_bus が Redis の起動前に接続を試みたり、再起動時に停止後に接続を試みたりした際に発生したものである可能性もあります。

Redis がサーバー上で動作しているが個々のコンテナ内では動作していないと述べられていましたが、その点について詳しく教えていただけますか?

この設定では、Redis はコンテナ内で動作します(docker ログの出力で確認できます)。

別の話題になりますが、動作していないサイトの URL にアクセスした際、nginx ログには何が表示されますか?error.log は空であるべきで、access.log にはさまざまな HTTP リクエストが記録されているはずです。どこで問題が発生しているのかを特定しようとしています。

「いいね!」 1

すみません、情報を混同していました。実際には Redis は各コンテナ内で動作しています。サーバー自体で確認し、さらに 3 つの Discourse コンテナのそれぞれで同じ結果が得られました。

$ redis-cli ping
PONG
$ redis-server
# Creating Server TCP listening socket *:6379: bind: Address already in use (means it's already started)
$ redis-cli
127.0.0.1:6379> ping
PONG
127.0.0.1:6379> get mykey
(nil)
127.0.0.1:6379> set mykey somevalue
OK
127.0.0.1:6379> get mykey
"somevalue"

3 つすべてで同様の結果が得られています(特に最初の get mykey は常に nil を返します)。したがって、Redis はすべてのコンテナ内で独立して起動・動作していると判断して問題ありません。

そのディレクトリ内では空で、今日何も書き込まれていません。

drwxr-xr-x 2 www-data www-data  4096 Feb  4 21:26 .
drwxrwxr-x 9 root     root      4096 Feb  2 08:03 ..
-rw-r--r-- 1 www-data www-data     0 Feb  3 07:38 access.log
-rw-r--r-- 1 www-data www-data     0 Feb  2 08:03 access.log.1
-rw-r--r-- 1 www-data www-data   294 Feb  1 09:43 access.log.2.gz
-rw-r--r-- 1 www-data www-data 37598 Jan 30 23:56 access.log.3.gz
-rw-r--r-- 1 www-data www-data 58059 Jan 30 07:36 access.log.4.gz
-rw-r--r-- 1 www-data www-data 55988 Jan 29 07:34 access.log.5.gz
-rw-r--r-- 1 www-data www-data 73964 Jan 28 07:49 access.log.6.gz
-rw-r--r-- 1 www-data www-data 78069 Jan 27 07:53 access.log.7.gz
-rw-r--r-- 1 www-data www-data     0 Feb  3 07:38 error.log
-rw-r--r-- 1 www-data www-data     0 Feb  2 08:03 error.log.1
-rw-r--r-- 1 www-data www-data    20 Feb  1 00:31 error.log.2.gz
-rw-r--r-- 1 www-data www-data   632 Jan 30 23:46 error.log.3.gz
-rw-r--r-- 1 www-data www-data   265 Jan 29 09:07 error.log.4.gz
-rw-r--r-- 1 www-data www-data    20 Jan 28 07:50 error.log.5.gz
-rw-r--r-- 1 www-data www-data  3107 Jan 28 07:41 error.log.6.gz
-rw-r--r-- 1 www-data www-data    20 Jan 26 07:53 error.log.7.gz

別のコンテナのアクセスログを確認しましたが正常でした。つまり、このコンテナだけが問題です。

HAProxy はリクエストを転送しているようですが、コンテナ側で処理または受け入れられていないようです。何かリセットできることはないでしょうか?(コンテナを再構築すれば、通常はそれが行われるはずだとは思うのですが)

「いいね!」 1

そのように聞こえますね。ホストで docker ps を実行した際、各コンテナにどのようなポートバインディングが設定されているか確認できますか?

「いいね!」 1

はい、以下の通りです:

IMAGE                   COMMAND             CREATED             STATUS              PORTS                                     \nlocal_discourse/1      \t"/sbin/boot"        20 時間前           20 時間前           0.0.0.0:2225->22/tcp, 0.0.0.0:8892->80/tcp
local_discourse/2   \t"/sbin/boot"        4 日前              4 日前              0.0.0.0:2223->22/tcp, 0.0.0.0:8889->80/tcp
local_discourse/3       "/sbin/boot"        4 日前              4 日前              0.0.0.0:2224->22/tcp, 0.0.0.0:8890->80/tcp

私の直感では、ダッシュボード経由での失敗した試行が原因ではないかと思います。通常、PostgreSQL やメジャーアップデートの場合、ダッシュボードには「再構築が必要」と表示され、ダッシュボードからの更新が無効になるはずです。しかし、何らかの理由でその表示が出ませんでした(もしかすると、そのフォーラムをしばらく更新していなかったため、まずダッシュボードから行うべきだと考えたのかもしれません)。あるいは、再構築を行う前にシャットダウンや起動が正常に行われていなかった可能性もあります。:confused:

「いいね!」 2

HAProxy の設定では、バックエンドがポート 888888898890 への転送用に構成されていることが確認できます:

しかし、アプリコンテナは 889288898890 でリッスンしています。backend discourse_docker において不一致が見られます。これは、その投稿以降に設定で更新されたものですか?

「いいね!」 1

はい、HAProxy のポートは正しいコンテナポートに対応していますね :smiley: これはおそらく関係ないと思います。それまでは正常に動作していましたし、この問題はアップグレード/再構築の直後に発生しました。

コンテナにアクセスして「Top stats」を開き、そこからサイトへ移動しても状況は変わらないようです。参考になればと思い、スクリーンショットを添付します:

もしよろしければ、コンテナを保存して送ることもできます(Docker コンテナでそんなことできるのでしょうか?笑):slight_smile:

「いいね!」 1