はじめに
DockerfileでMySQLを2つ以上のレイヤー(RUN)で実行すると、
コンテナ起動時や2つ目以降のレイヤーでMySQLが正常に起動できなくなる問題に遭遇しました。
DockerfileでMySQLとPHPをソースインストールしたことが発端でした。
MySQLの初期化後、違うレイヤー(RUN)でPHPをインストールしようとすると、
msyqld_safeで立ち上げても起動に失敗していたところで気づきました。
原因はdockerのstorage driverでした。
storage driverはdocker infoですぐに確認できます。
ストレージドライバの確認
[root@localhost docker]# docker info | grep "Storage Driver"
WARNING: (略)
Storage Driver: overlay
まとめ
ホストで動作するdockerが使用する、storage driverにより発生していました。
この現象はoverlayを使用したときに発生しました。overlay2、aufs、devicemapperでは発生しませんでした。
詳しいことは分かりませんが、Overlayfsでは以下の問題があるようです。今回の問題が関わっているかどうかはわかりません。関わっていたとすればoverlayとoverlay2で挙動が異なるようですが…詳しいことはわかりません。
(公式)limitations-on-overlayfs-compatibility
問題を的確に指摘していただいた@tukiyo3 さんありがとうございました。
storage driverの変更手順
公式にある通りです。
ストレージドライバの指定
/etc/docker/daemon.json
{
"storage-driver": "devicemapper"
}
- overlay2またはdevicemapperを指定します。overlay2はKernel version4.0以上が必要です。
- devicemapperはbase device sizeという定義があり、標準で10GBです。
- MySQLをインストールすると10GBでは不足するので、20GBに設定してみます。
Base Device Sizeの変更
/etc/docker/daemon.jsonで定義します。
{
"storage-driver": "devicemapper",
"storage-opts": [
"dm.use_deferred_removal=true",
"dm.basesize=20G"
]
}
(公式)Use the OverlayFS storage driver
(公式)Select a storage driver
【学習メモ】 dockerのbase device sizeをdaemon.jsonで定義
問題の現象
- ひとつのレイヤー(RUN)の中で、MySQLの初期化や起動、終了は問題なく行えます。
- MySQLを起動した以降のレイヤーでMySQLを起動すると、エラーが発生します。
- 1回目のレイヤーの中なら、
mysqld_safe &やmysqladmin shotdownで起動とシャットダウン繰り返してもエラーにはなりませんでした。 - 1回目のレイヤーだけで、初期化から必要なDBやらダンプやらをしないとだめなようです。
- 1つのレイヤーでMySQLの処理を終えていれば、serviceに登録してコンテナ立ち上げ時に/sbin/initで正常に起動します。
- 2回目以降のレイヤーでMySQLを起動しても、正常に動作しません。
- 2回目以降のレイヤーでMySQLを起動してしまったコンテナは、コンテナを立ち上げたあとに--skip-grant-tablesでMySQLを起動させることができますが、無しでは起動しなくなりました。
OKな例
# dockerfile
RUN ./bin/mysqld --initialize-insecure (中略) && \
./bin/mysqld_safe & sleep 10 && \
./bin/mysqladmin shutdown && \
./bin/mysqld_safe & sleep 10 && \
./bin/mysqladmin shutdown
#コンテナ立ち上げ
docker run --privileged -d ～ /sbin/init
NGな例
RUN ./bin/mysql --initialize-insecure && \
./bin/mysqld_safe & sleep 10 && \
./bin/mysqladmin shutdown
RUN ./bin/mysqld_safe & sleep 10 && \
./bin/mysqladmin shutdown && \
cat ./log/error.log
コンテナ立ち上げ後にMySQLを起動したときに出るエラーの例
## MySQL起動1回目
[ERROR] Fatal error: Can't open and lock privilege tables: Table storage engine for 'user' doesn't have this option
## MySQL起動2回目
[ERROR] Fatal error: Can't open and lock privilege tables: Table storage engine for 'db' doesn't have this option
## MySQL起動3回目
[ERROR] Fatal error: Can't open and lock privilege tables: Table storage engine for 'proxies_priv' doesn't have this option
## MySQL起動4回目
[ERROR] Fatal error: Can't open and lock privilege tables: Table storage engine for 'tables_priv' doesn't have this option
[ERROR] Fatal: can't initialize grant subsystem - 'Table storage engine for 'tables_priv' doesn't have this option'
- mysqld_safeを実行するたび、何か1つずつズレている感じがします。
エラーの追及
壊れたコンテナ
Dockerfileで2つのレイヤーでMySQLを起動したときのログを確認します。
以下、Dockerfileで2つのレイヤーでMySQLを操作し、MySQLが正常に起動しないコンテナを「壊れたコンテナ」と呼びます。
skip-grant-tables
壊れたコンテナを立ち上げて、mysqld_safeをskip-grant-tablesオプションで起動してみます。
正常にデータにアクセスできるか確認します。
コンテナを立ち上げてmysql.userテーブルを見る
[host]# docker run -d --privileged --name mysql mysql /sbin/init
[host]# docker exec -it mysql bash
[mysql]# ./bin/mysqld_safe --skip-grant-tables
[mysql]# ./bin/mysql
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 3
Server version: 5.7.19 Source distribution
Copyright (c) 2000, 2017, Oracle and/or its affiliates. All rights reserved.
Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
mysql> select * from mysql.user-> ;
ERROR 1031 (HY000): Table storage engine for 'user' doesn't have this option
- エラーが発生しました。/sbin/initで起動したときのエラーログに残っているのもこんな感じでmysql.userにアクセスしているのでしょうか。
でも、直後に同じコマンドを発行すると
すぐに同じSQL文を発行する。
mysql> select user, host from mysql.user;
+---------------+-----------+
| user | host |
+---------------+-----------+
| mysql | % |
| mysql | localhost |
| mysql.session | localhost |
| mysql.sys | localhost |
| root | localhost |
+---------------+-----------+
- 問題なく実行されます。1回目だけエラーが出るみたいです。
- 他のコマンドも、--skip-grant-tablesを指定してmysqld_safeを起動したときは動作します。
-
./mysqld -e "select user, host from mysql.user"で実行しても、1回目は失敗、2回以降は表示される同様の結果でした。
MySQLを起動して、databaseを見るコマンドは1回目は必ず失敗しますが、select version()のようなコマンドは1回目でも成功しました。
起動直後のsqlコマンドが成功する例
[root@mysql002 bin]# ./mysqld_safe --skip-grant-tables &
[1] 372
[root@mysql002 bin]# 2017-09-01T20:04:36.696769Z mysqld_safe Logging to '/opt/mysql-5.7.19/log/error.log'.
2017-09-01T20:04:36.733331Z mysqld_safe Starting mysqld daemon with databases from /opt/mysql-5.7.19/data
[root@mysql002 bin]# ./mysql -e "select version();"
+-----------+
| version() |
+-----------+
| 5.7.19 |
+-----------+
壊れたコンテナをBuildしている時のログを確認します。
コンテナを立ち上げたあとのログではありません。
innodb statusも見てみます。
Dockerfileのbuild時に、MySQLを2回目に起動したときのログ
# Dockerfile
RUN /opt/mysql-5.7.19/bin/mysqld_safe --user=mysql & sleep 15 && cat /opt/mysql-5.7.19/log/error.log && \
/opt/mysql-5.7.19/bin/mysql --defaults-file=/opt/mysql-5.7.19/my.cnf --user=mysql \
-e "select version();" && \
# rootのパスワードは空なので、パスワードを空に戻す。
sed -ie "s/password=mysqlpassword/password=/g" /opt/mysql-5.7.19/my.cnf && \
/opt/mysql-5.7.19/bin/mysql --defaults-file=/opt/mysql-5.7.19/my.cnf --user=root \
-e "show engine innodb status\G" && sleep 10 && \
# 実行時のエラー(初期化やユーザー追加などの1回目のレイヤーは省略)
2017-09-04T13:12:35.625350Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2017-09-04T13:12:35.625437Z 0 [Note] --secure-file-priv is set to NULL. Operations related to importing and exporting data are disabled
2017-09-04T13:12:35.625505Z 0 [Note] /opt/mysql-5.7.19/bin/mysqld (mysqld 5.7.19) starting as process 169 ...
2017-09-04T13:12:35.633598Z 0 [Note] InnoDB: PUNCH HOLE support available
2017-09-04T13:12:35.633633Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-09-04T13:12:35.633639Z 0 [Note] InnoDB: Uses event mutexes
2017-09-04T13:12:35.633642Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-09-04T13:12:35.633645Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.3
2017-09-04T13:12:35.633896Z 0 [Note] InnoDB: Number of pools: 1
2017-09-04T13:12:35.633978Z 0 [Note] InnoDB: Using CPU crc32 instructions
2017-09-04T13:12:35.634987Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2017-09-04T13:12:35.641929Z 0 [Note] InnoDB: Completed initialization of buffer pool
2017-09-04T13:12:35.645630Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2017-09-04T13:12:36.611265Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2017-09-04T13:12:36.622744Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2017-09-04T13:12:36.622840Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2017-09-04T13:12:36.731402Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2017-09-04T13:12:36.732727Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
2017-09-04T13:12:36.732747Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2017-09-04T13:12:36.733513Z 0 [Note] InnoDB: Waiting for purge to start
2017-09-04T13:12:36.784250Z 0 [Note] InnoDB: 5.7.19 started; log sequence number 2540012
2017-09-04T13:12:36.784716Z 0 [Note] InnoDB: Loading buffer pool(s) from /opt/mysql-5.7.19/data/ib_buffer_pool
2017-09-04T13:12:36.785723Z 0 [Note] Plugin 'FEDERATED' is disabled.
2017-09-04T13:12:36.920942Z 0 [Warning] Failed to set up SSL because of the following SSL library error: SSL context is not usable without certificate and private key
2017-09-04T13:12:36.920968Z 0 [Note] Server hostname (bind-address): '*'; port: 3306
2017-09-04T13:12:36.921017Z 0 [Note] IPv6 is available.
2017-09-04T13:12:36.921033Z 0 [Note] - '::' resolves to '::';
2017-09-04T13:12:36.921051Z 0 [Note] Server socket created on IP: '::'.
2017-09-04T13:12:36.987179Z 0 [Note] InnoDB: Buffer pool(s) load completed at 170904 13:12:36
2017-09-04T13:12:37.149174Z 0 [Note] Event Scheduler: Loaded 0 events
2017-09-04T13:12:37.149426Z 0 [Note] /opt/mysql-5.7.19/bin/mysqld: ready for connections.
Version: '5.7.19' socket: '/opt/mysql-5.7.19/log/mysql.sock' port: 3306 Source distribution
2017-09-04T13:12:37.149461Z 0 [Note] Executing 'SELECT * FROM INFORMATION_SCHEMA.TABLES;' to get a list of tables using the deprecated partition engine. You may use the startup option '--disable-partition-engine-check' to skip this check.
2017-09-04T13:12:37.149469Z 0 [Note] Beginning of list of non-natively partitioned tables
2017-09-04T13:12:37.162468Z 0 [Note] End of list of non-natively partitioned tables
version()
5.7.19
(show engine innodb statusの結果は省略)
2017-09-04T13:13:01.282089Z mysqld_safe mysqld from pid file /opt/mysql-5.7.19/log/mysql.pid ended
- コンテナを立ち上げた時のようなFatal errorは発生していないようです。
- innodb statusの見方がわかりませんので、保留します。
ログの比較
壊れたコンテナのログを見てもわからないので、正常に起動するコンテナ（以下正常なコンテナ）のログと比較します。
差分
#正常なとき(/sbin/initで立ち上げ)
+[Note] InnoDB: 5.7.19 started; log sequence number 2539795
[Note] Plugin 'FEDERATED' is disabled.
[Warning] Failed to set up SSL because of the following SSL library error: SSL context is not usable without certificate and private key
[Note] Server hostname (bind-address): '*'; port: 3306
[Note] IPv6 is available.
[Note] - '::' resolves to '::';
[Note] Server socket created on IP: '::'.
[Note] InnoDB: Loading buffer pool(s) from /opt/mysql-5.7.19/data/ib_buffer_pool
+[Note] InnoDB: Buffer pool(s) load completed at 170901 20:16:13
+[Note] Event Scheduler: Loaded 0 events
+[Note] /opt/mysql-5.7.19/bin/mysqld: ready for connections.
#異常なとき(/sbin/initで立ち上げ)
-[Note] InnoDB: 5.7.19 started; log sequence number 2539593
[Note] InnoDB: Loading buffer pool(s) from /opt/mysql-5.7.19/data/ib_buffer_pool
[Note] Plugin 'FEDERATED' is disabled.
[Warning] Failed to set up SSL because of the following SSL library error: SSL context is not usable without certificate and private key
[Note] Server hostname (bind-address): '*'; port: 3306
[Note] IPv6 is available.
[Note] - '::' resolves to '::';
[Note] Server socket created on IP: '::'.
-[Note] InnoDB: Buffer pool(s) load completed at 170904 20:06:59
-[ERROR] Fatal error: Can't open and lock privilege tables: Table storage engine for 'user' doesn't have this option
-[ERROR] Aborting
- log sequence number(LSN)かわかりませんが、Buffer poolの読み込みのatの値が異なる。
- InnoDBのBuffer Poolの読み込みは、両方とも終了していると思われます。
- WALファイルがきちんと書き込まれていないのかもしれません。（skip-grant-tablesでDBは書き込まれているので問題はなさそうだけれど…）
壊れたコンテナを立ち上げ、skip-grant-tablesで起動したときの、MySQLのエラーログを確認します。
--skip-grant-tablesで起動したときのerror.logの中身
2017-09-01T20:07:18.490534Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2017-09-01T20:07:18.490693Z 0 [Note] --secure-file-priv is set to NULL. Operations related to importing and exporting data are disabled
2017-09-01T20:07:18.490738Z 0 [Note] /opt/mysql-5.7.19/bin/mysqld (mysqld 5.7.19) starting as process 532 ...
2017-09-01T20:07:18.497584Z 0 [Note] InnoDB: PUNCH HOLE support available
2017-09-01T20:07:18.497639Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-09-01T20:07:18.497648Z 0 [Note] InnoDB: Uses event mutexes
2017-09-01T20:07:18.497653Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-09-01T20:07:18.497657Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.3
2017-09-01T20:07:18.498025Z 0 [Note] InnoDB: Number of pools: 1
2017-09-01T20:07:18.498180Z 0 [Note] InnoDB: Using CPU crc32 instructions
2017-09-01T20:07:18.499507Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2017-09-01T20:07:18.511288Z 0 [Note] InnoDB: Completed initialization of buffer pool
2017-09-01T20:07:18.516564Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2017-09-01T20:07:18.529307Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2017-09-01T20:07:18.536818Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2017-09-01T20:07:18.536917Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2017-09-01T20:07:18.611894Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2017-09-01T20:07:18.613628Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
2017-09-01T20:07:18.613793Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2017-09-01T20:07:18.614646Z 0 [Note] InnoDB: Waiting for purge to start
2017-09-01T20:07:18.665144Z 0 [Note] InnoDB: 5.7.19 started; log sequence number 2544577
2017-09-01T20:07:18.665426Z 0 [Note] InnoDB: Loading buffer pool(s) from /opt/mysql-5.7.19/data/ib_buffer_pool
2017-09-01T20:07:18.665907Z 0 [Note] Plugin 'FEDERATED' is disabled.
2017-09-01T20:07:18.667943Z 0 [Note] InnoDB: Buffer pool(s) load completed at 170901 20:07:18
2017-09-01T20:07:18.670191Z 0 [Warning] Failed to set up SSL because of the following SSL library error: SSL context is not usable without certificate and private key
2017-09-01T20:07:18.670229Z 0 [Note] Server hostname (bind-address): '*'; port: 3306
2017-09-01T20:07:18.670295Z 0 [Note] IPv6 is available.
2017-09-01T20:07:18.670314Z 0 [Note] - '::' resolves to '::';
2017-09-01T20:07:18.670335Z 0 [Note] Server socket created on IP: '::'.
2017-09-01T20:07:18.683690Z 0 [Note] /opt/mysql-5.7.19/bin/mysqld: ready for connections.
Version: '5.7.19' socket: '/opt/mysql-5.7.19/log/mysql.sock' port: 3306 Source distribution
2017-09-01T20:07:18.683756Z 0 [Note] Executing 'SELECT * FROM INFORMATION_SCHEMA.TABLES;' to get a list of tables using the deprecated partition engine. You may use the startup option '--disable-partition-engine-check' to skip this check.
2017-09-01T20:07:18.683767Z 0 [Note] Beginning of list of non-natively partitioned tables
2017-09-01T20:07:18.785847Z 0 [Note] End of list of non-natively partitioned tables
- InnoDBの読み込み後は、正常に起動するときと、差分はないように見えます。
ちなみに、コンテナを/sbin/initで起動し、起動しなかったときのログ。
#異常系(起動しなかったっとき)
2017-09-01T20:06:57.896042Z mysqld_safe Logging to '/opt/mysql-5.7.19/log/error.log'.
2017-09-01T20:06:57.931366Z mysqld_safe Starting mysqld daemon with databases from /opt/mysql-5.7.19/data
2017-09-01T20:06:58.128158Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2017-09-01T20:06:58.128239Z 0 [Note] --secure-file-priv is set to NULL. Operations related to importing and exporting data are disabled
2017-09-01T20:06:58.128263Z 0 [Note] /opt/mysql-5.7.19/bin/mysqld (mysqld 5.7.19) starting as process 336 ...
2017-09-01T20:06:58.133474Z 0 [Note] InnoDB: PUNCH HOLE support available
2017-09-01T20:06:58.133511Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-09-01T20:06:58.133514Z 0 [Note] InnoDB: Uses event mutexes
2017-09-01T20:06:58.133517Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-09-01T20:06:58.133519Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.3
2017-09-01T20:06:58.133818Z 0 [Note] InnoDB: Number of pools: 1
2017-09-01T20:06:58.133910Z 0 [Note] InnoDB: Using CPU crc32 instructions
2017-09-01T20:06:58.135213Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2017-09-01T20:06:58.144329Z 0 [Note] InnoDB: Completed initialization of buffer pool
2017-09-01T20:06:58.147882Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2017-09-01T20:06:59.110355Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2017-09-01T20:06:59.121740Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2017-09-01T20:06:59.121839Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2017-09-01T20:06:59.232903Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2017-09-01T20:06:59.235173Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
2017-09-01T20:06:59.235254Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2017-09-01T20:06:59.236925Z 0 [Note] InnoDB: Waiting for purge to start
2017-09-01T20:06:59.287455Z 0 [Note] InnoDB: 5.7.19 started; log sequence number 2544558
2017-09-01T20:06:59.287743Z 0 [Note] InnoDB: Loading buffer pool(s) from /opt/mysql-5.7.19/data/ib_buffer_pool
2017-09-01T20:06:59.288043Z 0 [Note] Plugin 'FEDERATED' is disabled.
2017-09-01T20:06:59.455271Z 0 [Warning] Failed to set up SSL because of the following SSL library error: SSL context is not usable without certificate and private key
2017-09-01T20:06:59.455444Z 0 [Note] Server hostname (bind-address): '*'; port: 3306
2017-09-01T20:06:59.455815Z 0 [Note] IPv6 is available.
2017-09-01T20:06:59.455837Z 0 [Note] - '::' resolves to '::';
2017-09-01T20:06:59.455860Z 0 [Note] Server socket created on IP: '::'.
2017-09-01T20:06:59.503454Z 0 [Note] InnoDB: Buffer pool(s) load completed at 170901 20:06:59
2017-09-01T20:06:59.520787Z 0 [ERROR] Fatal error: Can't open and lock privilege tables: Table storage engine for 'user' doesn't have this option
2017-09-01T20:06:59.520890Z 0 [ERROR] Aborting
2017-09-01T20:06:59.520930Z 0 [Note] Binlog end
2017-09-01T20:06:59.521048Z 0 [Note] Shutting down plugin 'ngram'
2017-09-01T20:06:59.521056Z 0 [Note] Shutting down plugin 'BLACKHOLE'
2017-09-01T20:06:59.521059Z 0 [Note] Shutting down plugin 'ARCHIVE'
2017-09-01T20:06:59.521060Z 0 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
2017-09-01T20:06:59.521105Z 0 [Note] Shutting down plugin 'MRG_MYISAM'
2017-09-01T20:06:59.521108Z 0 [Note] Shutting down plugin 'MyISAM'
2017-09-01T20:06:59.521118Z 0 [Note] Shutting down plugin 'INNODB_SYS_VIRTUAL'
2017-09-01T20:06:59.521120Z 0 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES'
2017-09-01T20:06:59.521121Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLESPACES'
2017-09-01T20:06:59.521123Z 0 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'
2017-09-01T20:06:59.521124Z 0 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN'
2017-09-01T20:06:59.521126Z 0 [Note] Shutting down plugin 'INNODB_SYS_FIELDS'
2017-09-01T20:06:59.521127Z 0 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS'
2017-09-01T20:06:59.521129Z 0 [Note] Shutting down plugin 'INNODB_SYS_INDEXES'
2017-09-01T20:06:59.521130Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS'
2017-09-01T20:06:59.521154Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLES'
2017-09-01T20:06:59.521155Z 0 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE'
2017-09-01T20:06:59.521157Z 0 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE'
2017-09-01T20:06:59.521158Z 0 [Note] Shutting down plugin 'INNODB_FT_CONFIG'
2017-09-01T20:06:59.521160Z 0 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED'
2017-09-01T20:06:59.521161Z 0 [Note] Shutting down plugin 'INNODB_FT_DELETED'
2017-09-01T20:06:59.521163Z 0 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD'
2017-09-01T20:06:59.521164Z 0 [Note] Shutting down plugin 'INNODB_METRICS'
2017-09-01T20:06:59.521166Z 0 [Note] Shutting down plugin 'INNODB_TEMP_TABLE_INFO'
2017-09-01T20:06:59.521167Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS'
2017-09-01T20:06:59.521168Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU'
2017-09-01T20:06:59.521170Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE'
2017-09-01T20:06:59.521171Z 0 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX_RESET'
2017-09-01T20:06:59.521173Z 0 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX'
2017-09-01T20:06:59.521174Z 0 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET'
2017-09-01T20:06:59.521176Z 0 [Note] Shutting down plugin 'INNODB_CMPMEM'
2017-09-01T20:06:59.521177Z 0 [Note] Shutting down plugin 'INNODB_CMP_RESET'
2017-09-01T20:06:59.521179Z 0 [Note] Shutting down plugin 'INNODB_CMP'
2017-09-01T20:06:59.521180Z 0 [Note] Shutting down plugin 'INNODB_LOCK_WAITS'
2017-09-01T20:06:59.521182Z 0 [Note] Shutting down plugin 'INNODB_LOCKS'
2017-09-01T20:06:59.521183Z 0 [Note] Shutting down plugin 'INNODB_TRX'
2017-09-01T20:06:59.521185Z 0 [Note] Shutting down plugin 'InnoDB'
2017-09-01T20:06:59.521274Z 0 [Note] InnoDB: FTS optimize thread exiting.
2017-09-01T20:06:59.521401Z 0 [Note] InnoDB: Starting shutdown...
2017-09-01T20:06:59.621873Z 0 [Note] InnoDB: Dumping buffer pool(s) to /opt/mysql-5.7.19/data/ib_buffer_pool
2017-09-01T20:06:59.622078Z 0 [Note] InnoDB: Buffer pool(s) dump completed at 170901 20:06:59
2017-09-01T20:07:00.732473Z 0 [Note] InnoDB: Shutdown completed; log sequence number 2544577
2017-09-01T20:07:00.734642Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2017-09-01T20:07:00.734666Z 0 [Note] Shutting down plugin 'MEMORY'
2017-09-01T20:07:00.734671Z 0 [Note] Shutting down plugin 'CSV'
2017-09-01T20:07:00.734676Z 0 [Note] Shutting down plugin 'sha256_password'
2017-09-01T20:07:00.734679Z 0 [Note] Shutting down plugin 'mysql_native_password'
2017-09-01T20:07:00.734845Z 0 [Note] Shutting down plugin 'binlog'
2017-09-01T20:07:00.735188Z 0 [Note] /opt/mysql-5.7.19/bin/mysqld: Shutdown complete
2017-09-01T20:07:00.747258Z mysqld_safe mysqld from pid file /opt/mysql-5.7.19/log/mysql.pid ended
innodb statusの確認
壊れたコンテナのinnodb statusを確認します。
壊れたコンテナ
*************************** 1. row ***************************
Type: InnoDB
Name:
Status:
=====================================
2017-09-04 13:10:26 0x7f158c0ef700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 13 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 1 srv_active, 0 srv_shutdown, 12 srv_idle
srv_master_thread log flush and writes: 13
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 13
OS WAIT ARRAY INFO: signal count 13
RW-shared spins 0, rounds 6, OS waits 2
RW-excl spins 0, rounds 0, OS waits 0
RW-sx spins 0, rounds 0, OS waits 0
Spin rounds per wait: 6.00 RW-shared, 0.00 RW-excl, 0.00 RW-sx
------------
TRANSACTIONS
------------
Trx id counter 1795
Purge done for trx's n:o < 0 undo n:o < 0 state: running but idle
History list length 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421205745112912, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (read thread)
I/O thread 4 state: waiting for i/o request (read thread)
I/O thread 5 state: waiting for i/o request (read thread)
I/O thread 6 state: waiting for i/o request (write thread)
I/O thread 7 state: waiting for i/o request (write thread)
I/O thread 8 state: waiting for i/o request (write thread)
I/O thread 9 state: waiting for i/o request (write thread)
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 0; buffer pool: 0
252 OS file reads, 56 OS file writes, 7 OS fsyncs
7.00 reads/s, 16384 avg bytes/read, 3.31 writes/s, 0.38 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 0 merges
merged operations:
insert 0, delete mark 0, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 34673, node heap has 0 buffer(s)
Hash table size 34673, node heap has 0 buffer(s)
Hash table size 34673, node heap has 0 buffer(s)
Hash table size 34673, node heap has 0 buffer(s)
Hash table size 34673, node heap has 0 buffer(s)
Hash table size 34673, node heap has 0 buffer(s)
Hash table size 34673, node heap has 0 buffer(s)
Hash table size 34673, node heap has 0 buffer(s)
0.00 hash searches/s, 6.61 non-hash searches/s
---
LOG
---
Log sequence number 2540056
Log flushed up to 2540056
Pages flushed up to 2540056
Last checkpoint at 2540047
0 pending log flushes, 0 pending chkp writes
10 log i/o's done, 0.23 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 137428992
Dictionary memory allocated 102398
Buffer pool size 8191
Free buffers 7933
Database pages 258
Old database pages 0
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 223, created 35, written 39
5.77 reads/s, 0.08 creates/s, 3.00 writes/s
Buffer pool hit rate 818 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 258, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Process ID=169, Main thread ID=139729997612800, state: sleeping
Number of rows inserted 0, updated 0, deleted 0, read 8
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.62 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
正常なコンテナのinnodb status。
正常なコンテナ
*************************** 1. row ***************************
Type: InnoDB
Name:
Status:
=====================================
2017-09-04 12:39:11 0x7ffb5417b700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 59 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 1 srv_active, 0 srv_shutdown, 58 srv_idle
srv_master_thread log flush and writes: 59
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 16
OS WAIT ARRAY INFO: signal count 16
RW-shared spins 0, rounds 6, OS waits 2
RW-excl spins 0, rounds 0, OS waits 0
RW-sx spins 0, rounds 0, OS waits 0
Spin rounds per wait: 6.00 RW-shared, 0.00 RW-excl, 0.00 RW-sx
------------
TRANSACTIONS
------------
Trx id counter 1795
Purge done for trx's n:o < 0 undo n:o < 0 state: running but idle
History list length 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 422192625579856, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (read thread)
I/O thread 4 state: waiting for i/o request (read thread)
I/O thread 5 state: waiting for i/o request (read thread)
I/O thread 6 state: waiting for i/o request (write thread)
I/O thread 7 state: waiting for i/o request (write thread)
I/O thread 8 state: waiting for i/o request (write thread)
I/O thread 9 state: waiting for i/o request (write thread)
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 0; buffer pool: 0
252 OS file reads, 56 OS file writes, 7 OS fsyncs
4.13 reads/s, 24594 avg bytes/read, 0.92 writes/s, 0.11 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 0 merges
merged operations:
insert 0, delete mark 0, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 34673, node heap has 0 buffer(s)
Hash table size 34673, node heap has 0 buffer(s)
Hash table size 34673, node heap has 0 buffer(s)
Hash table size 34673, node heap has 0 buffer(s)
Hash table size 34673, node heap has 0 buffer(s)
Hash table size 34673, node heap has 0 buffer(s)
Hash table size 34673, node heap has 0 buffer(s)
Hash table size 34673, node heap has 0 buffer(s)
0.00 hash searches/s, 2.54 non-hash searches/s
---
LOG
---
Log sequence number 2540056
Log flushed up to 2540056
Pages flushed up to 2540056
Last checkpoint at 2540047
0 pending log flushes, 0 pending chkp writes
10 log i/o's done, 0.16 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 137428992
Dictionary memory allocated 102398
Buffer pool size 8191
Free buffers 7933
Database pages 258
Old database pages 0
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 223, created 35, written 39
3.78 reads/s, 0.59 creates/s, 0.66 writes/s
Buffer pool hit rate 830 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 258, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Process ID=336, Main thread ID=140716533602048, state: sleeping
Number of rows inserted 0, updated 0, deleted 0, read 8
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.14 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
- LOGセクションは同じ表示なので、データ自体は同じものが記録されているように思います。
- WAFのバッファが書き込まれていないような心配をしていましたが、そんなことはないようです。
- innoDBの知識不足でそれ以上のことはわかりません。
現状
原因は不明のまま。
結局、DockerfileでMySQLを初期化したらそのまま&&でつなげながら、PHPのインストールまで完了させなければならないようです。
参考資料
Fatal error: Can't open and lock privilege tables: Table storage engine for 'user' doesn't have this option
docker-library/mysql
環境
環境
MySQL version : 5.7.19
ダウンロード先 : /tmp/mysql-5.7.19.tar.gz
インストール先 : /opt/mysql-5.7.19/
オプション : /opt/mysql-5.7.19/my.cnf
Download-cmake-make-install
RUN wget -P /tmp https://dev.mysql.com/get/Downloads/MySQL-5.7/mysql-5.7.19.tar.gz && \
tar xf /tmp/mysql-5.7.19.tar.gz -C /tmp && \
useradd mysql -s /sbin/nologin && \
yum install -y cmake ncurses-devel gcc-c++
RUN cd /tmp/mysql-5.7.19 ; cmake -j2 . \
-DCMAKE_INSTALL_PREFIX=/opt/mysql-5.7.19/ \
-DDEFAULT_CHARSET=utf8mb4 \
-DDEFAULT_COLLATION=utf8mb4_general_ci \
-DWITH_INNOBASE_STORAGE_ENGINE=1 \
-DWITH_PARTITION_STORAGE_ENGINE=0 \
-DSYSCONFDIR=/opt/mysql-5.7.19 \
-DDOWNLOAD_BOOST=1 \
-DWITH_BOOST=/tmp/boost && \
cd /tmp/mysql-5.7.19 ; make -j2 && \
cd /tmp/mysql-5.7.19 ; make install && \
cd /opt/mysql-5.7.19 ; mkdir log ; chown -R mysql:mysql /opt/mysql-5.7.19 && \
### mysql.service作成
echo -e "[Unit]\n\
Description=MySQL Server\n\
After=mysqlinit.service\n\
[Service]\n\
Type=simple\n\
User=mysql\n\
Group=mysql\n\
ExecStartPre=/usr/bin/sleep 5 \n\
ExecStart=/opt/mysql-5.7.19/bin/mysqld_safe --user=mysql\n\
Restart=on-failure\n\
[Install]\n\
WantedBy=multi-user.target" >> /usr/lib/systemd/system/mysql.service
### my.cnf作成
RUN echo -e "[client]\n\
port=3306\n\
socket=/opt/mysql-5.7.19/log/mysql.sock\n\
password=\n\n\
[mysqld]\n\
datadir=/opt/mysql-5.7.19/data/\n\
port=3306\n\
socket=/opt/mysql-5.7.19/log/mysql.sock\n\
key_buffer_size=16M\n\
max_allowed_packet=8M\n\
log-error=/opt/mysql-5.7.19/log/error.log\n\
[mysqld_safe]\n\
pid-file=/opt/mysql-5.7.19/log/mysql.pid" \
>> /opt/mysql-5.7.19/my.cnf && chown mysql:mysql /opt/mysql-5.7.19/my.cnf && \
(続き)MySQLの初期化
### mysqlの初期化
/opt/mysql-5.7.19/bin/mysqld --initialize-insecure --user=mysql --basedir=/opt/mysql-5.7.19/ --datadir=/opt/mysql-5.7.19/data/ && \
### mysqlの起動
/opt/mysql-5.7.19/bin/mysqld_safe --user=mysql & sleep 15 && cat /opt/mysql-5.7.19/log/error.log && \
## 'mysql'@'%'の追加
/opt/mysql-5.7.19/bin/mysql --defaults-file=/opt/mysql-5.7.19/my.cnf \
-e "create user 'mysql'@'%' IDENTIFIED BY 'mysqlpassword'" && sleep 2 &&\
### 'mysql'@'localhost'の追加
/opt/mysql-5.7.19/bin/mysql --defaults-file=/opt/mysql-5.7.19/my.cnf \
-e "create user 'mysql'@'localhost' IDENTIFIED BY 'mysqlpassword'" && sleep 2 && \
### usertableの確認
/opt/mysql-5.7.19/bin/mysql --defaults-file=/opt/mysql-5.7.19/my.cnf \
-e "select user, host from mysql.user;" >> /opt/mysql-5.7.19/log/mysqlusers.log && sleep 2 &&\
### mysql@localhostの動作確認
/opt/mysql-5.7.19/bin/mysql --defaults-file=/opt/mysql-5.7.19/my.cnf \
-e "select version();" >> /opt/mysql-5.7.19/log/version.log && \
### my.cnfのパスワードをmysql用からroot(空)に変更する
sed -ie "s/password=mysqlpassword/password=/g" /opt/mysql-5.7.19/my.cnf && \
### mysqlをシャットダウンする
/opt/mysql-5.7.19/bin/mysqladmin --defaults-file=/opt/mysql-5.7.19/my.cnf shutdown && \
### mysqlをもう1回起動する(同じRUN内ならエラーが起きない)
/opt/mysql-5.7.19/bin/mysqld_safe --user=mysql & sleep 15 && cat /opt/mysql-5.7.19/log/error.log && \
### mysqlをシャットダウンする(2回目)
/opt/mysql-5.7.19/bin/mysqladmin --defaults-file=/opt/mysql-5.7.19/my.cnf shutdown && \
### 自動起動の設定
systemctl enable mysql && \
### my.cnfのパスワードをroot(空)からmysql用に変更する
sed -ie "s/password=/password=mysqlpassword/g" /opt/mysql-5.7.19/my.cnf