rails db:createしたらMySQLでエラー115が出た原因と対処のメモ

2024/12/08に公開

rails db:createしたらMySQLでエラー115が出た原因と対処のメモ

先に結論

ちゃんとMySQLの起動完了を待ってから投入すること。

以下、詳細。

発生事象

compose.yml(抜粋)
services:
  rails:
    depends_on:
      - mysql
  mysql:

これを、ローカル環境(MacBook Air)で動かしたら

$ docker compose up -d
[+] Running 2/2
 ✔ Container example-mysql-1  Started
 ✔ Container example-rails-1  Started
$ docker compose exec rails bundle exec rails db:create
Created database 'example_development'
Created database 'example_test'

という具合で問題なく動いてそうだったので、そっくりそのまま別端末(UbuntuをインストールしたRaspberry Pi 4)に持っていって同じことをしたら

$ docker compose up -d
[+] Running 2/2
 ✔ Container example-mysql-1  Started
 ✔ Container example-rails-1  Started
$ docker compose exec rails bundle exec rails db:create
Can't connect to server on 'mysql' (115)
Couldn't create 'rails_mysql_development' database. Please check your configuration.
bin/rails aborted!
ActiveRecord::ConnectionNotEstablished: Can't connect to server on 'mysql' (115) (ActiveRecord::ConnectionNotEstablished)


Caused by:
Mysql2::Error::ConnectionError: Can't connect to server on 'mysql' (115) (Mysql2::Error::ConnectionError)

Tasks: TOP => db:create
(See full trace by running task with --trace)

となった。

直接原因

MySQLの起動が終わっていない状態でrails db:createを投入したため。

と言うのも、コンテナのステータスがStartedになった時点(あるいはその直後?)のログが

[InnoDB] InnoDB initialization has ended.

であり、これで完了なのかと誤解してしまったのだが、実際には処理はまだまだ続いており、その後、だいぶ時間が経ってからいくつかのメッセージが出た後に

[Server] /usr/sbin/mysqld: ready for connections. Version: '8.4.3'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MySQL Community Server - GPL.

が出て、これでようやく起動完了となる模様。

ここまで到達してからrails db:createをする必要があったのだが、起動完了していないのでConnectionErrorになったのだと思われる。

改めてログを確認したらdocker compose up投入から1時間以上掛かっていた。(そういえばコンテナのビルドにも長時間掛かってた…。)

根本原因

「コンテナのステータスがStartedになっただけでは起動は完了していない」(字面からすれば確かにそのとおりではある)ので、「ちゃんとログを見てから投入する」必要がある。

もっと言うと、そもそもMySQLが起動完了してからRailsを起動するようにしておけば、「Railsが起動した=MySQLも起動完了している」といえるので、いちいちログを見なくてもタイミングは掴めそう。

なので、その対処を行う。

対処

  • Rails側のdepends_oncondition: service_healthyを追加する
  • MySQL側にhealthcheckを追加する
compose.yml(抜粋)
   rails:
     depends_on:
-      - mysql
+      mysql:  
+        condition: service_healthy
   mysql:
+    healthcheck:
+      test: "mysqladmin ping -h 127.0.0.1 -u$$MYSQL_USER -p$$MYSQL_PASSWORD"
+      interval: 1m     # 実行環境により変更する
+      timeout: 30s     # 実行環境により変更する
+      retries: 5       # 実行環境により変更する
+      start_period: 3m # 実行環境により変更する…注1

注1:先述のとおり、Raspberry Pi 4の場合の初回起動時は1時間以上掛かるが、2回目以降の起動時は3分程度であったため、初回とそれ以外で設定を変更する必要がある。あるいは、「初回起動時はhealthcheckをせず自分でログを見て確認」「2回目以降でhealthcheckをする」とよいかも。

対処後の様子

$ docker compose up -d
[+] Running 2/2
 ✔ Container example-mysql-1  Healthy
 ✔ Container example-rails-1  Started
$ docker compose exec rails bundle exec rails db:create
Created database 'example_development'
Created database 'example_test'

自分向けメモ

  • healthchecktestは、検索して出てきたノウハウをそのまま採用させていただいた。よくわかってないので、これがベストなのか?は今後調べる必要がありそう。
  • 待機時間等のパラメータを.envで定義するといい感じ?いずれ試す。
  • 今回はやらなかったけど、Rails側もhealthcheckを入れておくとより安全なのでは。これも追い追い。

Discussion