GA

2017/06/28

MySQLのauto_incrementは実質ULLONG_MAX - 2で打ち止まるはなし

TL;DR


とある事情があってInnoDBのAUTO_INCREMENT関連のコードを読んでいた時に、innobase_next_autoincの中でこんなコードになっていることに気が付いた。
 2497         if (block >= max_value
 2498             || offset > max_value
 2499             || current >= max_value
 2500             || max_value - offset <= offset) {
 2501
 2502                 next_value = max_value;
 2503         } else {
いわゆるフツーのオートインクリメント処理の前段に入るチェックで、現在のauto_incrementの値にauto_increment_incrementの値を足してもデータ型の限界を超えないかとかそんなチェックをしているんだけれど、どうやら 足した結果データ型の限界を超える場合はデータ型の限界値を返す らしい。
データ型の最大値が常に返るから、ぶち抜いた時のエラーは ERROR 1062 (23000): Duplicate entry '..' for key 'PRIMARY' になるのか。ふむふむ。
しかし流れで読んでいたhandler::update_auto_incrementの中にちょっと気になる記述を見つけた。
3589       if (nr == ULLONG_MAX)
3590         DBUG_RETURN(HA_ERR_AUTOINC_READ_FAILED);  // Mark failure
はて。
  • 「払い出されたauto_incrementの値がULLONG_MAXだったらHA_ERR_AUTOINC_READ_FAILED」
ということは
  • 「現在のauto_increment値がUULONG_MAX - 1の時にauto_incrementの払い出しをしようとすると、UULONG_MAXが払い出されるから(データ型上はまだ入るけど)エラー」
なのか?
mysql57 13> INSERT INTO t1 VALUES (18446744073709551614, 'BIGINT MAX - 1');
Query OK, 1 row affected (0.00 sec)

mysql57 13> SELECT * FROM t1;
+----------------------+----------------+
| num                  | val            |
+----------------------+----------------+
| 18446744073709551614 | BIGINT MAX - 1 |
+----------------------+----------------+
1 row in set (0.00 sec)

mysql57 13> INSERT INTO t1 VALUES (NULL, 'NEXT');
ERROR 1467 (HY000): Failed to read auto-increment value from storage engine

mysql57 13> SELECT * FROM t1;
+----------------------+----------------+
| num                  | val            |
+----------------------+----------------+
| 18446744073709551614 | BIGINT MAX - 1 |
+----------------------+----------------+
1 row in set (0.00 sec)
おおおホントだ入らない。 しかしデータ型としてはまだもう1つ行けるので、直接値を指定すれば入る。
mysql57 13> INSERT INTO t1 VALUES (18446744073709551615, 'BIGINT MAX');
Query OK, 1 row affected (0.01 sec)

mysql57 13> SELECT * FROM t1;
+----------------------+----------------+
| num                  | val            |
+----------------------+----------------+
| 18446744073709551614 | BIGINT MAX - 1 |
| 18446744073709551615 | BIGINT MAX     |
+----------------------+----------------+
2 rows in set (0.00 sec)
しかもこの時も、auto_incrementの値がBIGINT UNSIGNEDの最大値の18446744073709551615以上になるから18446744073709551615が返ってDuplicate Entryエラーになる前に、払い出しそのものに失敗した扱いでER_AUTOINC_READ_FAILEDが返るのね。。
18446744073709551614と18446744073709551615の差が生死を分けることはないと思いますが、みなさまご注意ください。

2017/06/21

MySQL 5.6のmysqldumpでMySQL 5.7のサーバーに接続してダンプを取ろうとするとコア吐く件

TL;DR

  • MySQL 5.7.12とそれ以降のmysqldumpなら大丈夫
  • 実はバージョン依存ではなく sql_mode=ONLY_FULL_GROUP_BY 依存

別のものを調べている時に /var/log/messages を見てたら、なんかがコア吐いてるのに気が付いた。
Jun 20 04:26:42 archive_host kernel: mysqldump[28611]: segfault at 0 ip 00000030b152859a sp 00007fffd760a358 error 4 in libc-2.12.so[30b1400000+18b000]
Jun 20 04:26:42 archive_host abrtd: Directory 'ccpp-2017-06-20-04:26:42-28611' creation detected
Jun 20 04:26:42 archive_host abrt[28613]: Saved core dump of pid 28611 (/data01/mysqlbin/mysql-5.6.20-linux-glibc2.5-x86_64/bin/mysqldump) to /var/spool/abrt/ccpp-2017-06-20-04:26:42-28611 (2609152 bytes)
Jun 20 04:26:42 archive_host kernel: mysqldump[28615]: segfault at 0 ip 00000030b152859a sp 00007fffbd02f9d8 error 4 in libc-2.12.so[30b1400000+18b000]
Jun 20 04:26:42 archive_host abrt[28617]: Not saving repeating crash in '/data01/mysqlbin/mysql-5.6.20-linux-glibc2.5-x86_64/bin/mysqldump'
Jun 20 04:27:12 archive_host abrtd: 電子メールを送信しています... 
Jun 20 04:27:12 archive_host abrtd: 電子メールが送信されました: root@localhost
Jun 20 04:27:13 archive_host abrtd: Duplicate: UUID
Jun 20 04:27:13 archive_host abrtd: DUP_OF_DIR: /var/spool/abrt/ccpp-2017-01-31-00:25:08-30738
Jun 20 04:27:13 archive_host abrtd: Deleting problem directory ccpp-2017-06-20-04:26:42-28611 (dup of ccpp-2017-01-31-00:25:08-30738)
Jun 20 04:27:13 archive_host abrtd: No actions are found for event 'notify-dup'
mysqldumpさんがSEGVしてコア吐いてる。 しかもなんか今年1月から出てるみたいでDUP_OF_DIRとか言われた(こんな機能あったんですがabrtさん)
$ pwd
/var/spool/abrt/ccpp-2017-01-31-00:25:08-30738

$ file coredump
coredump: ELF 64-bit LSB core file x86-64, version 1 (SYSV), SVR4-style, from '/usr/local/mysql56/bin/mysqldump --user=dev_backup --host=172.19.140.61 --port='
開発環境のダンプを取るmysqldumpだった。パスからわかるようにmysqldumpはMySQL 5.6のもの。
$ gdb /usr/local/mysql56/bin/mysqldump coredump
..
(gdb) bt
#0  0x00000030b152859a in __strcmp_sse42 () from /lib64/libc.so.6
#1  0x000000000040e90f in dump_tablespaces (ts_where=0x0)
    at /export/home/pb2/build/sb_0-12734909-1405700492.82/mysql-5.6.20/client/mysqldump.c:4026
#2  0x0000000000416312 in dump_all_tablespaces (argc=0, argv=0x246f1a8)
    at /export/home/pb2/build/sb_0-12734909-1405700492.82/mysql-5.6.20/client/mysqldump.c:3893
#3  main (argc=0, argv=0x246f1a8) at /export/home/pb2/build/sb_0-12734909-1405700492.82/mysql-5.6.20/client/mysqldump.c:5853
刺さったのは ここ
直前で初期化してる buf[0] がマズいとは考えにくいので、その手前 で組み立てられているクエリーを眺めてみる。
…あれ、俺これなんか見たことあるような気がするぞ………?
$ /usr/local/mysql56/bin/mysql --user=xxx --host=172.19.140.61 --port=3309 --execute="SELECT LOGFILE_GROUP_NAME, FILE_NAME, TOTAL_EXTENTS, INITIAL_SIZE, ENGINE, EXTRA FROM INFORMATION_SCHEMA.FILES WHERE FILE_TYPE = 'UNDO LOG' AND FILE_NAME IS NOT NULL GROUP BY LOGFILE_GROUP_NAME, FILE_NAME, ENGINE ORDER BY LOGFILE_GROUP_NAME"

ERROR 1055 (42000) at line 1: Expression #3 of SELECT list is not in GROUP BY clause and contains nonaggregated column 'information_schema.FILES.TOTAL_EXTENTS' which is not functionally dependent on columns in GROUP BY clause; this is incompatible with sql_mode=only_full_group_by
うん、 sql_mode=ONLY_FULL_GROUP_BY にやられて転けるやつ。
しかしなんでこれが mysql_query(mysql, sqlbuf.str) で0(=成功) 以外が返ってifの中に落ち込まないのかがよくわからない。
(gdb) p mysql->net.last_errno
$4 = 0
なんなんだろうなあ。。 しかしこれどっかで調べた気がするんだよなあ。。どこだったっけなあ。。

2017/05/26

MySQLのSELECT .. FOR UPDATEはREPEATABLE-READでも直近にコミットされたレコードを返す

TL;DR


ドキュメント探してみたけどほんのちょっとだけしか書いてないような気がする。
SELECT … LOCK IN SHARE MODE は、 これらの行のいずれかがコミットされていない別のトランザクションによって変更された場合、クエリーはそのトランザクションが終了するまで待機してから、最新の値を使用します。
しゃらっと 最新の値を使用します と書いてあるけど、最新の値が意味するのは「最後にコミットされた時の値」であって、REPEATABLE-READのはずの分離レベル内でREAD-COMMITTEDっぽい動作が見える。
どういうことかというと
mysql57 4> START TRANSACTION;
mysql57 5> START TRANSACTION;

mysql57 4> SELECT * FROM t1;
+-----+--------+
| num | val    |
+-----+--------+
|   1 | before |
+-----+--------+
1 row in set (0.00 sec)

mysql57 5> SELECT * FROM t1;
+-----+--------+
| num | val    |
+-----+--------+
|   1 | before |
+-----+--------+
1 row in set (0.00 sec)

mysql57 4> UPDATE t1 SET val = 'after' WHERE num = 1;
Query OK, 1 row affected (0.01 sec)
Rows matched: 1  Changed: 1  Warnings: 0

mysql57 4> COMMIT AND CHAIN;
Query OK, 0 rows affected (0.00 sec)

mysql57 4> SELECT * FROM t1;
+-----+-------+
| num | val   |
+-----+-------+
|   1 | after |
+-----+-------+
1 row in set (0.00 sec)
ほぼ同時に開始したトランザクション45がいて、4はある行の値をアップデートしてコミットした。 この時に”after”が見えるのがREAD-COMMITTED、”before”が見えるのがREPEATABLE-READのはずで確かにそうなるんだけど、ブロッキングリード(SELECT .. FOR UPDATE, SELECT .. LOCK IN SHARE MODE)の場合は
mysql57 5> SELECT * FROM t1 FOR UPDATE;
+-----+-------+
| num | val   |
+-----+-------+
|   1 | after |
+-----+-------+
1 row in set (0.00 sec)
コミット済みの値が見える。 同じトランザクションの中で非ブロッキングリードとブロッキングリードをすると
mysql57 5> SELECT * FROM t1;
+-----+--------+
| num | val    |
+-----+--------+
|   1 | before |
+-----+--------+
1 row in set (0.00 sec)

mysql57 5> SELECT * FROM t1 FOR UPDATE;
+-----+-------+
| num | val   |
+-----+-------+
|   1 | after |
+-----+-------+
1 row in set (0.00 sec)

mysql57 5> SELECT * FROM t1;
+-----+--------+
| num | val    |
+-----+--------+
|   1 | before |
+-----+--------+
1 row in set (0.00 sec)
返ってくる値が変わる。
この話自体は有名な気がしていたんだけれど、ドキュメントには小さくしか見つけられなかったのでひょっとしたら有名じゃないのかなって。 (これ実演してみせたら爆笑されたw)

2017/05/22

MySQLユーザ会会 in 長野 2017に参加してきましたよ

MySQLユーザ会会 in 長野 2017に逝ってきました!
開催の経緯とかはとみたさんのブログ MySQLユーザ会会 in 長野 を開催しました - @tmtms のメモ 、当日のふいんき(何故か変換できない)はTogetter MySQLユーザ会会 in 長野 2017 - Togetterまとめ がまとまってます。
セッションの内容は坂井さんMySQLとはみたいなことやると聞いていたし、かじやまさんは「MySQL 8.0」だって聞いてたし、bizstationさんTransactd PHP ORMと聞いていたので(というか、それが聞きたいと頼んだのはわたしだ)
( ´-`).oO(この豪勢なメンツに対抗して自分の色が出せそうなセッション…? 運用ネタ…?
とか考えたんですが、結局
いつもどおり「MySQLを楽しんでいるおじさんっぷり」を話すことにしました。






背景の舞奈たんがさかさまになっているのが謎。手元のPDFファイル(や、SlideshareからダウンロードしたPDF)では天地正しいんですけれども。
最近のお気に入りのGTID、本当はmysqlslavetrxの話も入れたかったし8.0のSET @@GLOBAL.GTID_PURGED = '+gtid_set'も入れたかったなあと思い出してみたり、PMMのデモ(というか本番だけど)を見せられたのは良かったなあと思ったりしました。
yoku0825は絶賛楽しそうなことを探していますので、他に楽しそうなものがあったら教えてください :)

(交通費は自腹でしたが)登壇枠くれたとみたさん、会場提供のケイケンシステムさんありがとうございました!

2017/04/28

MySQL 8.0.1でバイナリーログに original_commit_timestamp と immediate_commit_timestamp が追加された

original_committed_timestampはマスターで実行された時のタイムスタンプが、immediate_commit_timestampはそのサーバーで実際に実行された時のタイムスタンプがそれぞれ入る。 単位はいずれもマイクロ秒。
マスターで実行した CREATE DATABASE d1 のバイナリーログ。
$ /usr/mysql/8.0.1/bin/mysqlbinlog master/data/mysql-bin.000002
..
#170428 17:54:25 server id 1  end_log_pos 226 CRC32 0xe0efd740  GTID    last_committed=0        sequence_number=1       original_committed_timestamp=1493369665593157 immediate_commit_timestamp=1493369665593157
# original_commit_timestamp=1493369665593157 (2017-04-28 17:54:25.593157 JST)
# immediate_commit_timestamp=1493369665593157 (2017-04-28 17:54:25.593157 JST)
/*!80001 SET @@session.original_commit_timestamp=1493369665593157*//*!*/;
SET @@SESSION.GTID_NEXT= '00012009-1111-1111-1111-111111111111:1'/*!*/;
# at 226
#170428 17:54:25 server id 1  end_log_pos 323 CRC32 0xc5704ebe  Query   thread_id=8     exec_time=0     error_code=0    Xid = 44
..
CREATE DATABASE d1
/*!*/;
それがレプリケートされたスレーブのバイナリーログ。
$ /usr/mysql/8.0.1/bin/mysqlbinlog node2/data/mysql-bin.000002
..
# at 154
#170428 17:54:25 server id 1  end_log_pos 233 CRC32 0xddb16cfd  GTID    last_committed=0        sequence_number=1       original_committed_timestamp=1493369665593157 immediate_commit_timestamp=1493369665643968
# original_commit_timestamp=1493369665593157 (2017-04-28 17:54:25.593157 JST)
# immediate_commit_timestamp=1493369665643968 (2017-04-28 17:54:25.643968 JST)
/*!80001 SET @@session.original_commit_timestamp=1493369665593157*//*!*/;
SET @@SESSION.GTID_NEXT= '00012009-1111-1111-1111-111111111111:1'/*!*/;
# at 233
#170428 17:54:25 server id 1  end_log_pos 330 CRC32 0x1ced03f5  Query   thread_id=8     exec_time=0     error_code=0    Xid = 11
..
CREATE DATABASE d1
/*!*/;
これに合わせて、 performance_schema.replication_applier_status_by_worker にも LAST_APPLIED_TRANSACTION_*_TIMESTAMPAPPLYING_TRANSACTION_*_TIMESTAMP が追加されてる。
これを使えば5.7とそれまでの Seconds_Behind_Master みたいにがんばって現在時刻との差とかを求めなくても良くなるようになる(んだと思う)
mysql> SELECT * FROM replication_applier_status_by_worker\G
*************************** 1. row ***************************
                                       CHANNEL_NAME:
                                          WORKER_ID: 0
                                          THREAD_ID: 39
                                      SERVICE_STATE: ON
                                  LAST_ERROR_NUMBER: 0
                                 LAST_ERROR_MESSAGE:
                               LAST_ERROR_TIMESTAMP: 0000-00-00 00:00:00.000000
                           LAST_APPLIED_TRANSACTION: 00012009-1111-1111-1111-111111111111:1
 LAST_APPLIED_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP: 2017-04-28 17:54:25.593157
LAST_APPLIED_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP: 2017-04-28 17:54:25.593157
     LAST_APPLIED_TRANSACTION_START_APPLY_TIMESTAMP: 2017-04-28 17:54:25.596175
       LAST_APPLIED_TRANSACTION_END_APPLY_TIMESTAMP: 2017-04-28 17:54:25.645874
                               APPLYING_TRANSACTION:
     APPLYING_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP: 0000-00-00 00:00:00.000000
    APPLYING_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP: 0000-00-00 00:00:00.000000
         APPLYING_TRANSACTION_START_APPLY_TIMESTAMP: 0000-00-00 00:00:00.000000
1 row in set (0.01 sec)
ところで、スレーブのバイナリーログ上の immediate_commit_timestampp_s. replication_applier_status_by_workerLAST_APPLIED_TRANSACTION_*_TIMESTAMP のどれとも合わないんだけど、これってこれでいいの…?

2017/04/21

MySQL 8.0のDROP TABLEがアトミックになっているっぽい件

MySQL 5.7とそれ以前で、「存在するテーブルと存在しないテーブルを一緒にDROP TABLE」しようとすると
mysql57> CREATE TABLE t1 (num int);
Query OK, 0 rows affected (0.01 sec)

mysql57> CREATE TABLE t3 (num int);
Query OK, 0 rows affected (0.01 sec)

mysql57> SHOW TABLES;
+--------------+
| Tables_in_d1 |
+--------------+
| t1           |
| t3           |
+--------------+
2 rows in set (0.00 sec)

mysql57> DROP TABLE t1, t2, t3;
ERROR 1051 (42S02): Unknown table 'd1.t2'

mysql57> SHOW TABLES;
Empty set (0.00 sec)
エラーにはなるけど消せるものは消える。
MySQL 8.0だと
mysql80> CREATE TABLE t1 (num int);
Query OK, 0 rows affected (0.01 sec)

mysql80> CREATE TABLE t3 (num int);
Query OK, 0 rows affected (0.01 sec)

mysql80> SHOW TABLES;
+--------------+
| Tables_in_d1 |
+--------------+
| t1           |
| t3           |
+--------------+
2 rows in set (0.00 sec)

mysql80> DROP TABLE t1, t2, t3;
ERROR 1051 (42S02): Unknown table 'd1.t2'

mysql80> SHOW TABLES;
+--------------+
| Tables_in_d1 |
+--------------+
| t1           |
| t3           |
+--------------+
2 rows in set (0.00 sec)
おおおおお消えてない! ちゃんと「エラーが返った = 操作は失敗している」が成立しているぞぞぞ。
mysql80> ALTER TABLE t1 ENGINE= MyISAM;
Query OK, 0 rows affected (0.03 sec)
Records: 0  Duplicates: 0  Warnings: 0

mysql80> DROP TABLE t1, t2, t3;
ERROR 1051 (42S02): Unknown table 'd1.t2'

mysql80> SHOW TABLES;
+--------------+
| Tables_in_d1 |
+--------------+
| t1           |
| t3           |
+--------------+
2 rows in set (0.00 sec)
マイア勇 MyISAMに変えても同じ動きだった。ちょっとびっくり。

2017/04/20

MySQLのDATETIME型で秒の小数部を扱うときのDEFAULT句

この CREATE TABLE ステートメントは転ける。
mysql57> CREATE TABLE t1 (num INT UNSIGNED NOT NULL, dt DATETIME(3) DEFAULT CURRENT_TIMESTAMP);
ERROR 1067 (42000): Invalid default value for 'dt'
CURRENT_TIMESTAMP関数DATETIME(0)型 を返すので、dtカラムの型である DATETIME(3)型 と合わないからだというわけで、
mysql57> CREATE TABLE t1 (num INT UNSIGNED NOT NULL, dt DATETIME(3) DEFAULT CURRENT_TIMESTAMP(3));
Query OK, 0 rows affected (0.01 sec)

mysql57> SHOW CREATE TABLE t1\G
*************************** 1. row ***************************
       Table: t1
Create Table: CREATE TABLE `t1` (
  `num` int(10) unsigned NOT NULL,
  `dt` datetime(3) DEFAULT CURRENT_TIMESTAMP(3)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4
1 row in set (0.00 sec)
これで通る。 なお、 ON UPDATE 句を書いた場合も同じ。
mysql57> CREATE TABLE t2 (num INT UNSIGNED NOT NULL, dt DATETIME(3) ON UPDATE CURRENT_TIMESTAMP);
ERROR 1294 (HY000): Invalid ON UPDATE clause for 'dt' column

mysql57> CREATE TABLE t2 (num INT UNSIGNED NOT NULL, dt DATETIME(3) ON UPDATE CURRENT_TIMESTAMP(3));Query OK, 0 rows affected (0.01 sec)

mysql57> SHOW CREATE TABLE t2\G
*************************** 1. row ***************************
       Table: t2
Create Table: CREATE TABLE `t2` (
  `num` int(10) unsigned NOT NULL,
  `dt` datetime(3) DEFAULT NULL ON UPDATE CURRENT_TIMESTAMP(3)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4
1 row in set (0.00 sec)
とても余談として、CURRENT_TIMESTAMP関数が NOW関数 のシノニムってことは、これひょっとして DEFAULT NOW() でもいけるのでは? と思ったらいけた。しかも昔からだった。
mysql55> CREATE TABLE t1 (num INT UNSIGNED NOT NULL, dt TIMESTAMP DEFAULT NOW()); -- 5.5だからTIMESTAMP型じゃないとデフォルトを受けられない
Query OK, 0 rows affected (0.01 sec)

mysql55> SHOW CREATE TABLE t1\G
*************************** 1. row ***************************
       Table: t1
Create Table: CREATE TABLE `t1` (
  `num` int(10) unsigned NOT NULL,
  `dt` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4
1 row in set (0.00 sec)
ちゃんとCURRENT_TIMESTAMPとして扱われている。 ただし、CURRENT_TIMESTAMPと違ってNOWはかっこは省略できない。
mysql55> SELECT CURRENT_TIMESTAMP;
+---------------------+
| CURRENT_TIMESTAMP   |
+---------------------+
| 2017-04-20 15:07:50 |
+---------------------+
1 row in set (0.00 sec)

mysql55> SELECT CURRENT_TIMESTAMP();
+---------------------+
| CURRENT_TIMESTAMP() |
+---------------------+
| 2017-04-20 15:08:03 |
+---------------------+
1 row in set (0.00 sec)

mysql55> SELECT NOW;
ERROR 1054 (42S22): Unknown column 'NOW' in 'field list'

mysql55> SELECT NOW();
+---------------------+
| NOW()               |
+---------------------+
| 2017-04-20 15:08:15 |
+---------------------+
1 row in set (0.00 sec)