Dockerローカル開発環境のCakePHP3アプリ開発でGeneral error: 5 database is locked

2020/03/01

author

masyus

Dockerを駆使したローカル開発環境でCakePHP3を使った開発をしていると、時々ですが

General error: 5 database is locked

と表示されてエラー画面が返されることがありました。今回はその原因と対処法について紹介いたします。検証したCakePHPのバージョンは3.6.13、PHPは7.3です。

原因はSQLiteのデータベースロック

今回の事象の原因を端的に解説しますと、

  • SQLiteのデータベースロックがいつまでも解除されず、リクエストの処理待ち状態が続く
  • php.iniで設定されているMaximum execution timeの設定時間を超える
  • General error: 5 database is lockedのエラーが発生する

という流れになります。以下、なぜSQLiteが登場するかについて解説していきます。

CakePHP3のDebug KitはSQLiteを利用している

CakePHP3には、ローカル開発環境でデバッグを容易にするためのツールとしてDebug Kitというものがあります。Debug Kitを有効化すると、画面右下に赤背景色で白のCakePHPのケーキマークが表示されるようになります。

このDebug Kitは設定を何もいじらないとSQLiteというデータベースを利用し、直近のリクエスト情報や発行されたSQL情報を貯める性質があります。

$ ls -la
total 1292192
drwxrwxrwx  10 hoge  staff        320  3  1 12:34 .
drwxr-xr-x  26 hoge  staff        832 11 14 17:41 ..
-rwxr-xr-x   1 hoge  staff          0  1 17 21:32 .gitkeep
drwxrwxrwx   6 hoge  staff        192 11 14 11:34 cache
-rw-r--r--   1 hoge  staff  503083008  3  1 12:34 debug_kit.sqlite
-rw-r--r--   1 hoge  staff      33536  3  1 12:34 debug_kit.sqlite-journal
drwxrwxrwx   2 hoge  staff         64 12  4  2018 sessions
drwxrwxrwx   2 hoge  staff         64 12  4  2018 tests
$

上記はtmpディレクトリ配下の構成をls -laしたものです。debug_kit.sqliteというDBファイルがあるのが分かります。また、debug_kit.sqlite-journalという関連ファイルもありますが、こちらについては御述します。

debug_kit.sqliteの中身

もしローカル開発環境下でsqlite3コマンドが使えましたら

sqlite3 debug_kit.sqlite

に続いて

.schema

を実行してみてください。SQLiteのテーブル構成を確認することができます。

$ sqlite3 debug_kit.sqlite
SQLite version 3.24.0 2018-06-04 14:10:15
Enter ".help" for usage hints.
sqlite>
sqlite> .schema
CREATE TABLE IF NOT EXISTS "requests" (
"id" CHAR(36) NOT NULL,
"url" TEXT NOT NULL,
"content_type" VARCHAR,
"status_code" INTEGER,
"method" VARCHAR,
"requested_at" DATETIME NOT NULL,
CONSTRAINT "primary" PRIMARY KEY ("id")
);
CREATE TABLE IF NOT EXISTS "panels" (
"id" CHAR(36),
"request_id" CHAR(36) NOT NULL,
"panel" VARCHAR,
"title" VARCHAR,
"element" VARCHAR,
"summary" VARCHAR,
"content" BLOB(4294967295),
CONSTRAINT "primary" PRIMARY KEY ("id"),
CONSTRAINT "unique_panel" UNIQUE ("request_id", "panel"),
CONSTRAINT "request_id_fk" FOREIGN KEY ("request_id") REFERENCES "requests" ("id") ON UPDATE RESTRICT ON DELETE RESTRICT
);
sqlite>

リクエスト情報を格納していると思しきrequestsというテーブルの存在が確認できますね。

SQLiteのjournalファイルとは

話を戻しまして、次はdebug_kit.sqlite-journalについて解説します。SQLiteはMySQLや他のRDBMSと異なり、暗黙のトランザクションオートコミットを実装しています。MySQLでトランザクションをstart/commitさせるには

BEGIN;

# 何らかのSQLを実行

COMMIT;

のように明示的にBEGINCOMMITコマンドを打つ必要がありますが、SQLiteは勝手にそれをしてくれます。

その性質から、SQLiteに何らかの書き込み処理が発生する時、当該書き込み情報を一時的に格納しておくためのjournalファイルが生成される仕組みになっています。それと同じ役割を果たしているのがdebug_kit.sqlite-journalになります。つまり、

journalファイルが存在していると、DBへデータを書き込んでいる最中である

ことを意味します。そして

journalファイルがいつまでも残り続けている = データベースのロックが発生している

ということでもあります。

なぜローカル開発環境のCakePHP3でSQLiteデータベースのロックが発生するのか

  • Mac上のローカル開発環境がDockerで構成されている時に発生することがある
  • 同一ページを瞬間的に何度もリロードしたり、別々のページを同時に開こうとする

時に今回の問題が発生しやすいです。MacにVagrantを使ったローカル開発環境を構築していた時はほぼ発生しませんでした。完全に原因を突き止めたわけではないのですが、つまるところ

Docker for Macのvolumeのマウントが遅い

為に発生するようになったものと考えられます。SQLiteのデータベースはこれまで解説してきた通りファイルベースのため、特にこの影響を受けやすいことが想定されます。

SQLiteのデータベースロックを解消する方法

暫定対応

  • debug_kit.sqlite
  • debug_kit.sqlite-journal

の2ファイルをmvコマンドで名前を変えるか、もしくはrmコマンドで削除してください。これでデータベースロックが解除されます。debug_kit.sqliteを削除するとリクエスト履歴も消えてしまいますが、ローカル開発環境のリクエスト情報ですので開発への影響はほぼ無いはずです。

根本対応

  • Dockerでvolumeをマウントする際にcacheddelegatedの設定を入れる
  • SQLiteにリクエスト情報を格納せず、MySQLへリクエスト情報を格納させる

のどれかで解消する可能性があります。特に1.はDockerコンテナへのリクエスト処理を高速にすることにも繋がるため、今回の事象が発生せずとも設定することをお勧めします。2.はCakePHP3のDebug Kitの設定を変えることで、リクエスト情報の格納先を変更させることが可能です。

参考

SQLiteの関連記事

まだ記事がありません