14
11

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

More than 5 years have passed since last update.

【学習メモ】 Dockerfileでレイヤーを変えてMySQLを起動するとエラーになる

Last updated at Posted at 2017-09-04

#はじめに
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を使用したときに発生しました。overlay2aufsdevicemapperでは発生しませんでした。

詳しいことは分かりませんが、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の知識不足でそれ以上のことはわかりません。

参考資料
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

14
11
11

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
14
11

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?