動作しているフォーラムがあり、数日前に問題が発生した内容を確認したいと考えています。AWS を使用しているため、動作中のフォーラムの AMI を作成し、新しいインスタンスを起動して、数日前のバックアップを復元しようとしましたが、以下のメッセージで失敗しました。
サーバーは動作中のフォーラムの新しいイメージから構築されているため、バージョンやスキーマの不整合が原因であるはずがありません。
再構築を試みました。
1 日前の別のバックアップからの復元を試みましたが、同じ結果でした。
私が行った唯一の奇妙な操作は、空き容量を確保するためにアップロードディレクトリ(…/uploads/original/1X/*.pdf)から PDF ファイルを削除したことです。このステップを省いて再度試してみますが、これが原因である可能性は低いと思われます。
> [2019-11-30 01:17:44] 'admin' has started the restore!
> [2019-11-30 01:17:44] Marking restore as running...
> [2019-11-30 01:17:44] Making sure /var/www/discourse/tmp/restores/default/2019-11-30-011744 exists...
> [2019-11-30 01:17:44] Downloading archive to tmp directory...
> [2019-11-30 01:23:24] Unzipping archive, this may take a while...
> [2019-11-30 01:27:52] No metadata file to extract.
> [2019-11-30 01:27:52] Validating metadata...
> [2019-11-30 01:27:52] Current version: 20191129144706
> [2019-11-30 01:27:52] Restored version: 20191120015344
> [2019-11-30 01:27:52] Extracting dump file...
> [2019-11-30 01:50:57] invalid command \N
> [2019-11-30 01:50:57] invalid command \N
>
> < 約 100 回繰り返される >
>
> [2019-11-30 01:51:07] invalid command \N
> [2019-11-30 01:54:13] invalid command \N
> [2019-11-30 01:54:13] EXCEPTION: psql failed
> [2019-11-30 01:54:14] /var/www/discourse/lib/backup_restore/restorer.rb:331:in `restore_dump'
> /var/www/discourse/lib/backup_restore/restorer.rb:75:in `run'
> /var/www/discourse/lib/backup_restore.rb:166:in `block in start!'
> /var/www/discourse/lib/backup_restore.rb:163:in `fork'
> /var/www/discourse/lib/backup_restore.rb:163:in `start!'
> /var/www/discourse/lib/backup_restore.rb:22:in `restore!'
> /var/www/discourse/app/controllers/admin/backups_controller.rb:119:in `restore'
> など...
RGJ
(Richard - Communiteq)
2019 年 11 月 30 日午前 6:41
2
それでもなお、invalid command \N エラーは、Postgres のバージョン不整合に典型的なものです。
root@example:/var/www/discourse# psql --version
psql (PostgreSQL) 10.10 (Debian 10.10-1.pgdg100+1)
新しいサーバーと動作しているフォーラムでも同じバージョンです。
pfaffman
(Jay Pfaffman)
2019 年 11 月 30 日午後 12:05
4
私はそのエラーを PostgreSQL のバージョン不一致に関連付けようとしていましたが、先日、ディスク容量が不足していたシステムで \N エラーが発生しているのを目にしました(バックアップを作成した同じシステムにリストアしていました)。問題の診断は完了していません(当時、私が直面していた別の奇妙な問題であり、バックアップを別のサーバーにリストアすることで解決しました。同じサーバーにリストアしても解決したかどうかは疑問です)。
あなたはディスク容量が不足していると述べられていました。おそらく、それが原因だと思われます。リストア時には、バックアップを解凍するため、バックアップの完全なコピーが 2 つ存在する状態になり、さらにリストアに必要なスペースと、失敗時にロールバックできるためのスペースも必要となります。
RGJ
(Richard - Communiteq)
2019 年 11 月 30 日午後 2:59
5
つまり、失敗するまでに23分かかるということですか?
状況はさらに悪化しますが、もしかすると真の問題に近づいているかもしれません…ディスク容量が不足しているという仮説に基づき、以前は 50 GB だったものを今回は 100 GB にして、イメージから新しいインスタンスを作成しました。(バックアップは各 5 GB で S3 に保存されています。)今回は「No space left on device(デバイスに空き領域がありません)」という明確なエラーが表示されました。しかし、df コマンドを見ると空き容量はたっぷりあります。
> [2019-11-29 22:42:58] Making sure /var/www/discourse/tmp/restores/default/2019-11-29-224258 exists...
> [2019-11-29 22:42:58] Downloading archive to tmp directory...
> [2019-11-29 22:45:46] Unzipping archive, this may take a while...
> [2019-11-29 22:51:46] No metadata file to extract.
> [2019-11-29 22:51:46] Validating metadata...
> [2019-11-29 22:51:46] Current version: 20191129144706
> [2019-11-29 22:51:46] Restored version: 20191108000414
> [2019-11-29 22:51:46] Extracting dump file...
> [2019-11-29 22:53:47] EXCEPTION: No space left on device @ io_write - /shared/tmp/restores/default/2019-11-29-224258/dump.sql
> [ec2-user@ip-172-31-47-237 discourse]$ df / -h
> Filesystem Size Used Avail Use% Mounted on
> /dev/xvda1 99G 28G 71G 28% /
興味深いことに、参照されているディレクトリには何も存在しません。
> /var/www/discourse# ls /shared/tmp/*
> /shared/tmp/backups:
> < empty >
> /shared/tmp/restores:
> < empty >
スワップファイルに問題があるのでしょうか?EC2 インスタンスはメモリ 2 GB の t2.small であるため、動作しているフォーラムでは以前から スワップファイルを作成 していました。新しいインスタンスにもスワップファイルが複製されていると推測されます。私は専門家ではありませんが、新しいスワップファイルを作成できないこと、および以下の出力から、スワップファイルは存在していると考えています。
> /var/www/discourse# swapon -s
> Filename Type Size Used Priority
> /swapfile file 2097148 1024 -2
RGJ
(Richard - Communiteq)
2019 年 12 月 1 日午前 7:42
7
inode の問題かもしれません。df -i の出力結果はどうなっていますか?
df -i
ファイルシステム イノード 使用数 空き数 使用率 マウント先
devtmpfs 252562 437 252125 1% /dev
tmpfs 255203 1 255202 1% /dev/shm
/dev/xvda1 6553600 737194 5816406 12% /
専門外のことですが、これは問題ないと思われますか?
RGJ
(Richard - Communiteq)
2019 年 12 月 1 日午前 8:14
9
いいえ、大丈夫です。
「No space left on device(デバイスに空き領域がありません)」というエラーは、ギガバイト単位の容量が尽きたときだけでなく、ファイルシステムが inode を使い果たしたときにも発生します。ただし、今回のケースでは明らかにそれが原因ではありません(その場合、iUse% は 100% になっていたはずです)。
まだうまくいきません。動作している EC2 インスタンスの AMI を起動する代わりに、新しい Lightsail インスタンスでリストアを試してみようと思いました。それでも失敗しますが、エラーメッセージは少し異なります。
古いインスタンスも新しいインスタンスも最新の状態であり、どちらも 標準的な Docker インストール で、同じ PostgreSQL バージョンを実行しています。
psql --version
psql (PostgreSQL) 10.10 (Debian 10.10-1.pgdg100+1)
これは正常でしょうか。
Creating missing functions in the discourse_functions schema
Cannot restore into different schema, restoring in-place
プラグインが原因でしょうか?「ソース」サイトには、サポートされているプラグインとカスタムプラグインの両方を含む複数のプラグインがインストールされています。いくつかのカスタムユーザーフィールドを使用するものもあります。「ソース」サイトとは別に、プラグインあり・なしのクリーンな「宛先」サイトへのリストアを試みました。
スキーマを比較し始めるためのヒントはありますか?
> [2019-12-07 04:51:36] 'admin' has started the restore!
> [2019-12-07 04:51:36] Marking restore as running...
> [2019-12-07 04:51:36] Making sure /var/www/discourse/tmp/restores/default/2019-12-07-045136 exists...
> [2019-12-07 04:51:36] Downloading archive to tmp directory...
> [2019-12-07 04:53:49] Unzipping archive, this may take a while...
> [2019-12-07 04:57:12] No metadata file to extract.
> [2019-12-07 04:57:12] Validating metadata...
> [2019-12-07 04:57:12] Current version: 20191129144706
> [2019-12-07 04:57:12] Restored version: 20191120015344
> [2019-12-07 04:57:12] Extracting dump file...
> [2019-12-07 04:59:10] Creating missing functions in the discourse_functions schema
> [2019-12-07 04:59:11] Cannot restore into different schema, restoring in-place
> [2019-12-07 05:05:02] ERROR: current transaction is aborted, commands ignored until end of transaction block
> [2019-12-07 05:05:03] ERROR: current transaction is aborted, commands ignored until end of transaction block
> < 約 100 回繰り返される >
> [2019-12-07 05:05:03] ERROR: current transaction is aborted, commands ignored until end of transaction block
> [2019-12-07 05:05:03] EXCEPTION: psql failed
> [2019-12-07 05:05:03] /var/www/discourse/lib/backup_restore/restorer.rb:331:in `restore_dump'
> /var/www/discourse/lib/backup_restore/restorer.rb:75:in `run'
> /var/www/discourse/lib/backup_restore.rb:166:in `block in start!'
> /var/www/discourse/lib/backup_restore.rb:163:in `fork'
> /var/www/discourse/lib/backup_restore.rb:163:in `start!'
> /var/www/discourse/lib/backup_restore.rb:22:in `restore!'
> /var/www/discourse/app/controllers/admin/backups_controller.rb:119:in `restore'
> < 以降のトレースバック >
RGJ
(Richard - Communiteq)
2019 年 12 月 7 日午前 5:49
11
Mark_Schmucker:
これは正常ですか:
discourse_functions スキーマに欠落した関数を作成中
異なるスキーマへのリストアはできません。その場でリストアしています
はい、それは正常です。
PostgreSQL の内部で明らかに何かが問題を起こしています。ログを確認されましたか?
可能性は低いですが、メモリに関連する問題でしょうか?リストア中に free -m の出力を監視し、(仮想)メモリが枯渇していないか確認してみてください。
問題が何なのか分からないので難しい質問ですが、一般的にプラグインは復元を試みる前に対象サイトへインストールすべきでしょうか?それとも復元時にプラグインを自動的に取得して構築してくれるのでしょうか?
RGJ
(Richard - Communiteq)
2019 年 12 月 7 日午前 6:55
13
はい、インストールすべきです。復元処理では自動的には行われません。
ただし、これはあなたの問題の原因ではないと思います。なぜなら、復元処理は正しいデータベース構造(プラグイン固有の設定を含む)を自動的に整えてくれるからです。
4GB のメモリを搭載した新しい $20 の Lightsail インスタンスを作成しました。復元中に ‘free -m’ を監視しましたが、常に十分な空きメモリと利用可能なメモリがありました。
発生する具体的なエラーは、プラグインがインストールされているかどうかによって異なりますが、おそらく同じ根本原因によるものです。今回の場合、バックアップ前にプラグインはインストールしていませんでした。エラーには以下の 2 つのタイプがあります。
PostgreSQL ログには、以下のようなエラーが多数表示されます。場合によっては文字位置 34、またはいくつかの場合では文字位置 41 で発生します。
discourse@discourse ERROR: relation “user_auth_tokens” does not exist at character 34
これらのエラーは、管理画面 > バックアップ > ログページには対応する出力が表示されず、これらのエラーが発生しても復元は数分間続きます。
2 つ目のエラーは、プラグインがインストールされているかどうかによって異なります。今回はプラグインをインストールしなかったため、Data Explorer に関するエラーが発生し、そこで完全に状況が悪化しました。
管理画面 > バックアップ > ログ:
[2019-12-07 07:38:34] CREATE INDEX
[2019-12-07 07:38:34] CREATE INDEX
[2019-12-07 07:38:34] ERROR: could not create unique index “index_plugin_store_rows_on_plugin_name_and_key”
[2019-12-07 07:38:34] DETAIL: Key (plugin_name, key)=(discourse-data-explorer, q:-6) is duplicated.
[2019-12-07 07:38:34] ERROR: current transaction is aborted, commands ignored until end of transaction block
[2019-12-07 07:38:34] ERROR: current transaction is aborted, commands ignored until end of transaction block
< 1000 回繰り返されて終了 >
また、PostgreSQL ログには以下のような対応する出力があります:
2019-12-07 07:38:34.718 UTC [8991] discourse@discourse LOG: duration: 165.427 ms statement: CREATE INDEX index_notifications_on_user_
id_and_topic_id_and_post_number ON public.notifications USING btree (user_id, topic_id, post_number);
2019-12-07 07:38:34.767 UTC [8991] discourse@discourse ERROR: could not create unique index “index_plugin_store_rows_on_plugin_name_an
d_key”
2019-12-07 07:38:34.767 UTC [8991] discourse@discourse DETAIL: Key (plugin_name, key)=(discourse-data-explorer, q:-6) is duplicated.
2019-12-07 07:38:34.767 UTC [8991] discourse@discourse STATEMENT: CREATE UNIQUE INDEX index_plugin_store_rows_on_plugin_name_and_key O
N public.plugin_store_rows USING btree (plugin_name, key);
2019-12-07 07:38:34.984 UTC [8991] discourse@discourse ERROR: current transaction is aborted, commands ignored until end of transactio
n block
2019-12-07 07:38:34.984 UTC [8991] discourse@discourse STATEMENT: CREATE INDEX index_policy_users_on_post_policy_id_and_user_id ON pub
lic.policy_users USING btree (post_policy_id, user_id);
RGJ
(Richard - Communiteq)
2019 年 12 月 7 日午前 8:18
15
#1 は致命的ではなく、インプレース復元による副作用だと考えられます。
バックアップを作成する前に、データエクスプローラーのクエリをすべて(エクスポートして)削除し、データエクスプローラープラグインを削除することを検討してください。
あるいは、plugin_store_rows テーブルの関連する内容を投稿してもらえますか?
実際には、(plugin_name, key) のペアが重複しているクエリが存在します。例えば q:-11 と q:-2 などですが、ID は一意です。これらの重複に特定のパターンは見当たりません。お気に入りのクエリであるなどという傾向もありません。
そのため、次のステップとして重複を削除し、バックアップを作成してから、そのバックアップから復元を試みる予定です。
SELECT id, plugin_name, key from plugin_store_rows
WHERE plugin_name = ‘discourse-data-explorer’
ORDER BY key
id
plugin_name
key
1138
discourse-data-explorer
q:-1
1136
discourse-data-explorer
q:-10
813
discourse-data-explorer
q:10
1142
discourse-data-explorer
q:-11
1397
discourse-data-explorer
q:-11
825
discourse-data-explorer
q:11
889
discourse-data-explorer
q:13
1004
discourse-data-explorer
q:14
1005
discourse-data-explorer
q:15
1043
discourse-data-explorer
q:17
1044
discourse-data-explorer
q:18
514
discourse-data-explorer
q:-2
1249
discourse-data-explorer
q:-2
764
discourse-data-explorer
q:2
1053
discourse-data-explorer
q:21
1066
discourse-data-explorer
q:22
1082
discourse-data-explorer
q:23
1097
discourse-data-explorer
q:24
1131
discourse-data-explorer
q:26
1132
discourse-data-explorer
q:27
1134
discourse-data-explorer
q:28
1135
discourse-data-explorer
q:29
775
discourse-data-explorer
q:3
1137
discourse-data-explorer
q:30
1140
discourse-data-explorer
q:31
1141
discourse-data-explorer
q:32
1143
discourse-data-explorer
q:33
1149
discourse-data-explorer
q:34
1155
discourse-data-explorer
q:35
1156
discourse-data-explorer
q:36
1157
discourse-data-explorer
q:37
1158
discourse-data-explorer
q:38
1161
discourse-data-explorer
q:39
513
discourse-data-explorer
q:-4
777
discourse-data-explorer
q:4
1211
discourse-data-explorer
q:40
1215
discourse-data-explorer
q:41
1223
discourse-data-explorer
q:42
1224
discourse-data-explorer
q:43
1225
discourse-data-explorer
q:44
1226
discourse-data-explorer
q:45
1269
discourse-data-explorer
q:46
1272
discourse-data-explorer
q:47
1273
discourse-data-explorer
q:48
1274
discourse-data-explorer
q:49
1279
discourse-data-explorer
q:50
1281
discourse-data-explorer
q:51
1282
discourse-data-explorer
q:52
1301
discourse-data-explorer
q:53
1349
discourse-data-explorer
q:54
1369
discourse-data-explorer
q:55
1373
discourse-data-explorer
q:56
1384
discourse-data-explorer
q:57
1387
discourse-data-explorer
q:58
1396
discourse-data-explorer
q:59
1222
discourse-data-explorer
q:-6
1348
discourse-data-explorer
q:-6
781
discourse-data-explorer
q:6
763
discourse-data-explorer
q:-7
782
discourse-data-explorer
q:7
515
discourse-data-explorer
q:-8
791
discourse-data-explorer
q:8
1139
discourse-data-explorer
q:-9
798
discourse-data-explorer
q:9
507
discourse-data-explorer
q:_id
実際、重複を削除するにはどうすればよいですか?3つすべてが「system」に所有されているため、編集や削除ができません。
パターンが見つかりました。システム所有のクエリを実行すると重複が作成され、それが復元を破損させるようです。
クリーンなテストサイトでは再現できませんが、本番サイトでは一貫して発生します。本番環境のすべてのプラグインをテストサイトにインストールしましたが、依然として再現しません。
本番サイトの問題点を特定するにはどうすればよいですか?
重複クエリはシステムが所有しているため、どのように削除すればよいですか?sudo -u postgres psql discourse...を実行する必要がありますか?少し恐ろしく感じます。
riking
(Kane York)
2019 年 12 月 8 日午前 1:33
20
バックアップを復元可能にするには、バックアップされた SQL ファイルから重複行を削除するとよいでしょう。
何らかの理由で開発用データベースにそのインデックスが欠落している可能性がありますか?