2016年6月21日火曜日

MySQL 5.7のmysql_upgradeがやたら重い件

日々の覚書: MySQL 5.7のmysql_upgradeは本当にDATETIME型を新しいフォーマットに直してくれるけれど でちょっと触れてるんだけど、DATETIME型(TIME型とTIMESTAMP型もあるけど)には現在2つのフォーマットが合って、

- 5.5とそれ以前のDATETIME型(秒部の小数点数非対応、8バイト、以下 旧DATETIME型)
- 5.6とそれ以降のDATETIME型(秒部の小数点数対応、小数部無しの場合は5バイト、以下DATETIME2型)

で、MySQL 5.7のmysql_upgradeは旧DATETIME型をDATETIME2型にアップグレードしてくれるよ、こいつらはレプリケーションで混ぜるとよろしくないから、これで安心だね、みたいなのが 前に書いた記事 のあらすじ。


と、MySQL 5.6 => 5.7のmysql_upgradeが特に問題にはなっていなかったので気付かなかったんだけれど、ふと気付いたら我らが Chiba.pm@masasuz さんが













というわけで計ってみた。
d2.xlargeインスタンスをスポットで借りてゴニョゴニョ。

テストデータはこんな感じ。

$ perl -MDigest::MD5 -e 'for (my $n= 1; $n <= 100000000; $n++) {printf("%d\t%s\n", $n, Digest::MD5::md5_hex($n));}' > /data/md5
mysql> CREATE TABLE t1 (num serial, val varchar(32) not null, dt datetime not null);
mysql> LOAD DATA INFILE '/data/md5' INTO TABLE t1 (num, val) SET dt = NOW();
$ ll d1/t1.ibd -h
-rw-rw---- 1 mysql mysql 6.9G Jun 21 02:16 d1/t1.ibd


結果はこんな感じ。1回ずつしか計ってないから誤差はあると思う。

from to time メモ
5.5(旧DATETIME) 5.7(DATETIME2) 31:16 5.5のmysqldで作ったデータをそのまま5.7のmysqldで起動してmysql_upgrade
5.5(旧DATETIME) 5.6(旧DATETIME) 00:06 5.5のmysqldで作ったデータをそのまま5.6のmysqldで起動してmysql_upgrade
5.6(旧DATETIME) 5.7(旧DATETIME) 00:16 ↑のデータを5.7のmysqld —avoid-temporal-upgradeで起動してmysql_upgrade
5.6(旧DATETIME) 5.7(DATETIME2) 36:53 ↑↑のデータを5.7のmysql_upgrade
5.6(旧DATETIME) 5.6(DATETIME2) 23:01 ↑↑↑のデータを5.6でALTER TABLE t1 FORCE
5.5(旧DATETIME) 5.6(DATETIME2) 22:37 5.5からmysqldumpして5.6にリストア(ダンプに別途1:31かかってる)
5.6(DATETIME2) 5.7(DATETIME2) 00:11 ↑のデータを5.7へmysql_upgrade



5.5のmysqldで作ったデータをそのまま5.7のmysqldで起動してmysql_upgradeした時のリソースの様子。

$ dstat -tamr 10
  date/time   |usr sys idl wai hiq siq| read  writ| recv  send|  in   out | int   csw | used  buff  cach  free| read  writ
21-06 02:23:44|  5   0  64  30   0   0|   0    19M|   6B    4B|   0     0 |1288  1142 |4895M  109M 24.9G  155M|   0   518
21-06 02:23:54|  6   1  65  29   0   0|   0    21M|   0     0 |   0     0 |1385  1176 |4969M  109M 24.8G  152M|   0   563
21-06 02:25:54|  6   0  64  30   0   0|   0    22M|   0     0 |   0     0 |1402  1194 |5822M  115M 24.0G  157M|   0   580


単にdatadirをコピーしてるだけの間は↓これくらい出ていたので、MySQL側の限界ではある様子。

$ dstat -tamr 10
21-06 03:00:14|  0   0  48  52   0   0| 410B  143M|  81B  606B|   0     0 |3491   594 | 889M 75.6M 24.1G 4991M|0.10  3434
21-06 03:00:24|  0   0  50  49   0   0| 410B  137M|  60B  570B|   0     0 |3366   544 | 926M 75.7M 25.4G 3632M|0.10  3295
21-06 03:00:34|  0   0  52  47   0   0|   0   149M|  79B  607B|   0     0 |3616   579 | 964M 75.7M 26.7G 2239M|   0  3576


30秒だけ pt-ioprofile でI/O状況を見てみたらこんな感じ。

# pt-ioprofile --cell sizes
Tue Jun 21 02:22:59 UTC 2016
Tracing process ID 4076
     total     pwrite      fsync      lseek filename
48041558016   96468992          0 47945089024 /data/mysql/d1/#sql-fec_2.ibd
 136257004  136252928       4076          0 /data/mysql/ib_logfile1
 115982336  115982336          0          0 /data/mysql/ibdata1
         0          0          0          0 /data/mysql/ib_logfile0

テンポラリーな.ibdファイルを作ってるので、テーブルコピーのALTER TABLEがまさに走っているはず。
pt-ioprofileを見るに、ibdファイルそのものよりもInnoDBログファイルに書き込んでいる(そう、テーブルコピーのALTER TABLEは1000行ずつコミットするらしい)ので、innodb_flush_log_at_trx_commit= 0とかすると速くなるかも。

0 件のコメント :

コメントを投稿