ページアクセス時に500エラーが発生する

orphanizee · 2024 年 11 月 23 日午後 4:17

【環境情報】
・baserCMSのバージョン：5.1.3
・レンタルサーバー名：ローカル開発環境(Windows11)
・使用テーマ：bc_sample
・PHPスキル（自己評価）：D

【事象】
全てのbaserCMSページへのアクセス時に500エラーが発生し、「 An Internal Error Has Occurred.」が表示される
エラーログ

2024-11-24 00:40:41 error: [Cake\Database\Exception\DatabaseException] Cannot describe sites. It has 0 columns. in /var/www/html/vendor/cakephp/cakephp/src/Database/Schema/Collection.php on line 118
Stack Trace:
- /var/www/html/vendor/cakephp/cakephp/src/ORM/Table.php:544
- /var/www/html/vendor/cakephp/cakephp/src/ORM/Query/CommonQueryTrait.php:48
- /var/www/html/vendor/cakephp/cakephp/src/ORM/Query/SelectQuery.php:202
- /var/www/html/vendor/cakephp/cakephp/src/ORM/Query/QueryFactory.php:34
- /var/www/html/vendor/cakephp/cakephp/src/ORM/Table.php:1755
- /var/www/html/vendor/cakephp/cakephp/src/ORM/Table.php:1294
- /var/www/html/plugins/baser-core/src/BaserCorePlugin.php:276
- /var/www/html/plugins/baser-core/src/BaserCorePlugin.php:169
- /var/www/html/vendor/cakephp/cakephp/src/Http/BaseApplication.php:198
- /var/www/html/vendor/cakephp/cakephp/src/Http/Server.php:124
- /var/www/html/vendor/cakephp/cakephp/src/Http/Server.php:84
- /var/www/html/webroot/index.php:42
- [main]:

キャッシュが原因の可能性を考えてbin/cake cache clear_all 実行したところ、下のエラーが発生しました。

root@41f73c2f3f55:/var/www/html# bin/cake cache clear_all
[Cake\Database\Exception\DatabaseException] Cannot describe sites. It has 0 columns. in /var/www/html/vendor/cakephp/cakephp/src/Database/Schema/Collection.php on line 118

Stack Trace:

Cake\Database\Schema\Collection->describe() - CORE/src/ORM/Table.php, line 544
Cake\ORM\Table->getSchema() - CORE/src/ORM/Query/CommonQueryTrait.php, line 48
Cake\ORM\Query\SelectQuery->addDefaultTypes() - CORE/src/ORM/Query/SelectQuery.php, line 202
Cake\ORM\Query\SelectQuery->__construct() - CORE/src/ORM/Query/QueryFactory.php, line 34
Cake\ORM\Query\QueryFactory->select() - CORE/src/ORM/Table.php, line 1755
Cake\ORM\Table->selectQuery() - CORE/src/ORM/Table.php, line 1294
Cake\ORM\Table->find() - ROOT/plugins/baser-core/src/BaserCorePlugin.php, line 276
BaserCore\BaserCorePlugin->getAvailableThemes() - ROOT/plugins/baser-core/src/BaserCorePlugin.php, line 169
BaserCore\BaserCorePlugin->bootstrap() - CORE/src/Http/BaseApplication.php, line 198
Cake\Http\BaseApplication->pluginBootstrap() - CORE/src/Console/CommandRunner.php, line 192
Cake\Console\CommandRunner->bootstrap() - CORE/src/Console/CommandRunner.php, line 137
Cake\Console\CommandRunner->run() - ROOT/bin/cake.php, line 10
[main] - [main], line 0

root@41f73c2f3f55:/var/www/html#

【再現率】
100%

【再現手順】
https://localhost/ にアクセス

【発生したきっかけ】
/plugins 配下にダウンロードしたプラグインを配置したところ、読み込まれなかったので、配置したプラグインを削除してdocker-compose up -dで再起動しました。

【備考】

プラグインを配置・削除する前はページが表示されていました。
pgAdmin4でテーブルを確認したところ、テーブルが存在しない？（見方がよく分かってないです）

image325×531 13.5 KB

orphanizee · 2024 年 11 月 23 日午後 5:42

再インストールして再現手順を確認しました。
アドオンマイグレーターを読み込むと、全てのテーブルが削除されて当該エラーが発生するようです。

maeno · 2024 年 11 月 25 日午前 9:26

@orphanizee
こんにちは。

私の方でも再現確認してみようと思っているのですがうまく再現せず、もう少し詳細を共有いただけますでしょうか。

■ データベースについて
データベースはPostgreを利用されていますか？

pgAdmin4でテーブルを確認

とあったので念のための確認になります

■ 手順について

アドオンマイグレーターを読み込むと、全てのテーブルが削除されて当該エラーが発生

もう少し詳細な手順を共有いただけないでしょうか
例えば

/plugins に設置してブラウザを再読み込みした
管理画面のプラグイン管理からインストールした
アドオンマイグレーターで変換したプラグインをインストールした

など

orphanizee · 2024 年 11 月 27 日午後 12:20

こんにちは。ご確認ありがとうございます。

データベースはPostgreを利用されていますか？

はい、Postgresです。

もう少し詳細な手順を共有いただけないでしょうか

申し訳ございません、改めて再現手順を確認したところ、

Gitクローン
docker-compose up -d
Postgresを選択してインストール
docker-compose down
docker-compose up -d

でした(アドオンマイグレーターは関係ありませんでした)。
私の環境ですと(Windows11)、上の手順でPostgresの中身が全て消えます。

また、永続化のためのボリューム設定をしているフォルダ(docker\volumes\postgres)を確認したところ、空になっていました。

念のため、事象再現時のログを共有いたします。

PS C:\Users\escap\OneDrive\dev\02_study\04_tool\basercms\basercms\docker> docker-compose logs -f bc-pg
bc-pg  | The files belonging to this database system will be owned by user "postgres".
bc-pg  | This user must also own the server process.
bc-pg  | 
bc-pg  | The database cluster will be initialized with locale "en_US.utf8".
bc-pg  | The default text search configuration will be set to "english".
bc-pg  | 
bc-pg  | Data page checksums are disabled.
bc-pg  | 
bc-pg  | fixing permissions on existing directory /var/lib/postgresql/data ... ok
bc-pg  | creating subdirectories ... ok
bc-pg  | selecting dynamic shared memory implementation ... posix
bc-pg  | selecting default max_connections ... 100
bc-pg  | selecting default shared_buffers ... 128MB
bc-pg  | selecting default time zone ... Etc/UTC
bc-pg  | creating configuration files ... ok
bc-pg  | running bootstrap script ... ok
bc-pg  | performing post-bootstrap initialization ... ok
bc-pg  | initdb: warning: enabling "trust" authentication for local connections
bc-pg  | initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.
bc-pg  | syncing data to disk ... ok
bc-pg  |
bc-pg  |
bc-pg  | Success. You can now start the database server using:
bc-pg  |
bc-pg  |     pg_ctl -D /var/lib/postgresql/data -l logfile start
bc-pg  |
bc-pg  | waiting for server to start....2024-11-27 12:11:24.584 UTC [48] LOG:  starting PostgreSQL 15.2 (Debian 15.2-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
bc-pg  | 2024-11-27 12:11:24.587 UTC [48] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
bc-pg  | 2024-11-27 12:11:24.595 UTC [51] LOG:  database system was shut down at 2024-11-27 12:11:23 UTC
bc-pg  | 2024-11-27 12:11:24.599 UTC [48] LOG:  database system is ready to accept connections
bc-pg  |  done
bc-pg  | server started
bc-pg  | CREATE DATABASE
bc-pg  |
bc-pg  |
bc-pg  | /usr/local/bin/docker-entrypoint.sh: running /docker-entrypoint-initdb.d/init.sql
bc-pg  | CREATE DATABASE
bc-pg  | CREATE DATABASE
bc-pg  |
bc-pg  |
bc-pg  | waiting for server to shut down...2024-11-27 12:11:25.094 UTC [48] LOG:  received fast shutdown request
bc-pg  | .2024-11-27 12:11:25.098 UTC [48] LOG:  aborting any active transactions
bc-pg  | 2024-11-27 12:11:25.100 UTC [48] LOG:  background worker "logical replication launcher" (PID 54) exited with exit code 1       
bc-pg  | 2024-11-27 12:11:25.100 UTC [49] LOG:  shutting down
bc-pg  | 2024-11-27 12:11:25.103 UTC [49] LOG:  checkpoint starting: shutdown immediate
bc-pg  | 2024-11-27 12:11:25.547 UTC [49] LOG:  checkpoint complete: wrote 2742 buffers (16.7%); 0 WAL file(s) added, 0 removed, 1 recycled; write=0.039 s, sync=0.385 s, total=0.447 s; sync files=740, longest=0.085 s, average=0.001 s; distance=12650 kB, estimate=12650 kB 
bc-pg  | 2024-11-27 12:11:25.553 UTC [48] LOG:  database system is shut down
bc-pg  |  done
bc-pg  | server stopped
bc-pg  |
bc-pg  | PostgreSQL init process complete; ready for start up.
bc-pg  |
bc-pg  | 2024-11-27 12:11:25.617 UTC [1] LOG:  starting PostgreSQL 15.2 (Debian 15.2-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
bc-pg  | 2024-11-27 12:11:25.617 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
bc-pg  | 2024-11-27 12:11:25.617 UTC [1] LOG:  listening on IPv6 address "::", port 5432
bc-pg  | 2024-11-27 12:11:25.635 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
bc-pg  | 2024-11-27 12:11:25.642 UTC [66] LOG:  database system was shut down at 2024-11-27 12:11:25 UTC
bc-pg  | 2024-11-27 12:11:25.649 UTC [1] LOG:  database system is ready to accept connections
bc-pg  | 2024-11-27 12:16:25.696 UTC [64] LOG:  checkpoint starting: time
bc-pg  | 2024-11-27 12:16:29.846 UTC [64] LOG:  checkpoint complete: wrote 44 buffers (0.3%); 0 WAL file(s) added, 0 removed, 0 recycled; write=4.118 s, sync=0.010 s, total=4.150 s; sync files=12, longest=0.005 s, average=0.001 s; distance=252 kB, estimate=252 kB

orphanizee · 2024 年 11 月 27 日午後 12:38

インストール直後はテーブルが存在しています(この状態でもvolumes/postgres は空です)。
ボリュームマウントの設定に失敗しているのでしょうか？

akasky · 2024 年 11 月 28 日午前 1:45

@orphanizee
挙動を見るとDBデータの永続化ができていないように見えますね。
参考までに、私の場合は以下のように指定してます。

- ./volumes/postgres:/var/lib/postgresql/data

※ymlファイルと同階層にvolumes/postgresディレクトリを作成しています。

orphanizee · 2024 年 11 月 28 日午前 10:17

ご確認ありがとうございます。
そちらの設定で再インストールしたところ、無事永続化＆ページ表示出来るようになりました！ありがとうございました。

やはり、マウント先のディレクトリが不適切だったようです。
修正後のディレクトリにはデータがあり、修正前は空でした。

root@a6c2d28f8ee5:/var/lib# ls -l postgresql/data/
total 128
drwx------ 8 postgres postgres  4096 Nov 27 12:25 base
drwx------ 2 postgres postgres  4096 Nov 28 09:41 global
drwx------ 2 postgres postgres  4096 Nov 27 12:25 pg_commit_ts
drwx------ 2 postgres postgres  4096 Nov 27 12:25 pg_dynshmem
-rw------- 1 postgres postgres  4821 Nov 27 12:25 pg_hba.conf
-rw------- 1 postgres postgres  1636 Nov 27 12:25 pg_ident.conf
drwx------ 4 postgres postgres  4096 Nov 28 09:40 pg_logical
drwx------ 4 postgres postgres  4096 Nov 27 12:25 pg_multixact
drwx------ 2 postgres postgres  4096 Nov 27 12:25 pg_notify
drwx------ 2 postgres postgres  4096 Nov 27 12:25 pg_replslot
drwx------ 2 postgres postgres  4096 Nov 27 12:25 pg_serial
drwx------ 2 postgres postgres  4096 Nov 27 12:25 pg_snapshots
drwx------ 2 postgres postgres  4096 Nov 27 12:25 pg_stat
drwx------ 2 postgres postgres  4096 Nov 27 12:25 pg_stat_tmp
drwx------ 2 postgres postgres  4096 Nov 27 12:25 pg_subtrans
drwx------ 2 postgres postgres  4096 Nov 27 12:25 pg_tblspc
drwx------ 2 postgres postgres  4096 Nov 27 12:25 pg_twophase
-rw------- 1 postgres postgres     3 Nov 27 12:25 PG_VERSION
drwx------ 3 postgres postgres  4096 Nov 27 12:25 pg_wal
drwx------ 2 postgres postgres  4096 Nov 27 12:25 pg_xact
-rw------- 1 postgres postgres    88 Nov 27 12:25 postgresql.auto.conf
-rw------- 1 postgres postgres 29525 Nov 27 12:25 postgresql.conf
-rw------- 1 postgres postgres    36 Nov 28 09:25 postmaster.opts
-rw------- 1 postgres postgres    94 Nov 28 09:25 postmaster.pid
root@a6c2d28f8ee5:/var/lib# ^C

orphanizee · 2024 年 11 月 28 日午前 10:20

質問した事象は解消しましたが、Closeする前に一点質問させてください。

今回の事象は、下のファイルの設定のままインストールした際に発生しました。
そのため、下のファイルの実装が不適切と判断し、Issuesへの起票、またはPull Requestをしたいと思います。

そちらは私の方で実施してもよろしいでしょうか？コントリビューションガイドには従わせていただきます。

github.com

baserproject/basercms/blob/5.1.x/docker/docker-compose.yml.default

#  db-volume: # windowsの場合はコメントを外す

services:
  bc-db:
    container_name: bc-db
    image: mysql:8.0
    volumes:
      - ./volumes/mysql:/var/lib/mysql
      # - db-volume:/var/lib/mysql # windowsの場合はコメントを外し、上の行をコメントアウトする
      - ./mysql/docker-entrypoint-initdb.d:/docker-entrypoint-initdb.d
    ports:
      - 3306:3306
    environment:
      MYSQL_ROOT_PASSWORD: "root"
      MYSQL_DATABASE: "basercms"
    command: mysqld --character-set-server=utf8 --collation-server=utf8_general_ci --innodb-use-native-aio=0 --default_authentication_plugin=mysql_native_password

  bc-php:
    container_name: bc-php
    image: baserproject/basercms:php8.1

This file has been truncated. show original

akasky · 2024 年 11 月 28 日午前 10:24

@orphanizee
ぜひともIssuesの起票、プルリクをして頂ければと思います。
よろしくお願いします。

orphanizee · 2024 年 11 月 28 日午前 10:33

ご返信ありがとうございます。私の方で対応させていただきます。
ご回答いただきありがとうございました。

本件を解決済みにします。