TES Blog

株式会社テクニカルエンジニアリングサポートに所属する社員が、自身が携わるテクノロジーやイベントに関する情報を発信しています。

Docker 18.03でMySQL5.7コンテナ起動時に[File ./ib_logfile101: 'aio write' returned OS error 122.]メッセージが表示されたときの対処法

クイックスタート・ガイド:Docker Compose と Rails — Docker-docs-ja 17.06.Beta ドキュメント

上記のドキュメントを参考にしつつ、 DockerにてRails + MySQLの環境を構築する際に、 docker-compose run 実行時に下記のエラーメッセージが表示されました。

% docker-compose up
Recreating hoge_db_1 ... done
Recreating hoge_web_1 ... done
Attaching to hoge_db_1, hoge_web_1
db_1   | Initializing database
db_1   | 2018-07-06T02:46:35.367468Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
db_1   | 2018-07-06T02:46:35.379436Z 0 [Warning] Setting lower_case_table_names=2 because file system for /var/lib/mysql/ is case insensitive
db_1   | 2018-07-06T02:46:37.409832Z 0 [ERROR] InnoDB: Operating system error number 22 in a file operation.
db_1   | 2018-07-06T02:46:37.410358Z 0 [ERROR] InnoDB: Error number 22 means 'Invalid argument'
db_1   | 2018-07-06T02:46:37.410704Z 0 [ERROR] InnoDB: File ./ib_logfile101: 'aio write' returned OS error 122. Cannot continue operation
db_1   | 2018-07-06T02:46:37.411234Z 0 [ERROR] InnoDB: Cannot continue operation.
hoge_db_1 exited with code 3

無駄だと思いつつ再度 docker-compose run を実行すると…

% docker-compose up
Recreating hoge_db_1 ... done
Recreating hoge_web_1 ... done
Attaching to hoge_db_1, hoge_web_1
db_1   | Initializing database
db_1   | 2018-07-06T02:47:39.513408Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
db_1   | 2018-07-06T02:47:39.517116Z 0 [ERROR] --initialize specified but the data directory has files in it. Aborting.
db_1   | 2018-07-06T02:47:39.517646Z 0 [ERROR] Aborting
db_1   |
hoge_db_1 exited with code 1

やはりダメですね😥

エラーが発生するdocker-compose.yml

上記のエラーが発生する時の docker-compose.yml の状態は、下記の通りです。

version: '3'
services:
  db:
    image: mysql:5.7
    volumes:
      - .mysql_data:/var/lib/mysql
    environment:
      MYSQL_ROOT_PASSWORD: hogehoge
    user: '1000:50'
  web: &web_base
    build: .
    command: bundle exec rails s -p 3000 -b '0.0.0.0'
    volumes:
      - .:/hoge
    ports:
      - '3000:3000'
    depends_on:
      - db

調査

似たような事例を探してみると「パーミッションの問題」とか「ファイル配置がイケてない」的な意見が多かったのですが、今回は特に当てはまらず...。

MySQL docker 5.7.6 and later fails to initialize database · Issue #69 · docker-library/mysql · GitHub

調査を進めていくと、MySQLの設定に innodb_use_native_aio=0 を追加したほうが良いという書き込みを発見。

Issues with Docker db images on Windows 10 Home · Issue #55 · farmOS/farmOS · GitHub

docker-compose.ymlの修正

下記を参考にして、MySQL起動時のコマンドに上記のオプションを追加してみました。
Bountysource (ここを見る限りDockerのバージョンも怪しいですね…)

version: '3'
services:
  db:
    image: mysql:5.7
    volumes:
      - .mysql_data:/var/lib/mysql
    environment:
      MYSQL_ROOT_PASSWORD: hogehoge
    user: '1000:50'
    command: --innodb-use-native-aio=0 # <- 追加!
  web: &web_base
    build: .
    command: bundle exec rails s -p 3000 -b '0.0.0.0'
    volumes:
      - .:/hoge
    ports:
      - '3000:3000'
    depends_on:
      - db

再度 docker-compose run を実行すると…無事起動することができました🐧

MySQL :: MySQL 5.7 Reference Manual :: 14.6.8 Using Asynchronous I/O on Linux
最初に出力されたログでは、Linuxの非同期I/Oを利用しようと試みた結果、volumes で指定したディレクトリ配下のファイルへの読み書きが正常に行えないことがログに出力されています。
今回はローカル環境ということでオプション指定して対処してみましたが、実運用ではまた異なる設定となるので注意したいと思います。