| Bug #76566 | Double transaction id for a DDL statements | ||
|---|---|---|---|
| Submitted: | 1 Apr 2015 16:34 | Modified: | 2 Apr 2015 7:27 |
| Reporter: | Przemyslaw Malkowski | Email Updates: | |
| Status: | Verified | Impact on me: | |
| Category: | MySQL Server: InnoDB storage engine | Severity: | S3 (Non-critical) |
| Version: | 5.5 5.6, 5.5.44, 5.6.25 | OS: | Any |
| Assigned to: | CPU Architecture: | Any | |
[2 Apr 2015 7:27]
MySQL Verification Team
Hello Przemyslaw, Thank you for the report. Observed similar behavior with latest 5.5 and 5.6 builds. Thanks, Umesh
[2 Apr 2015 7:27]
MySQL Verification Team
// 5.5.44
// primary session
mysql> CREATE TABLE `keyvalue` (
-> `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
-> `name1` varchar(250),
-> `name2` varchar(250),
-> `name3` varchar(250),
-> `name4` varchar(250),
-> PRIMARY KEY (`id`)
-> ) ENGINE=innodb ROW_FORMAT=COMPRESSED;
Query OK, 0 rows affected, 2 warnings (0.00 sec)
mysql>
mysql> set @id:=0;
Query OK, 0 rows affected (0.00 sec)
mysql>
mysql> insert into `keyvalue` values
-> (@id:=@id+1,md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000))
-> , (@id:=@id+1,md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000))
-> , (@id:=@id+1,md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000))
-> , (@id:=@id+1,md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000));
Query OK, 4 rows affected (0.01 sec)
Records: 4 Duplicates: 0 Warnings: 0
mysql>
mysql> insert into `keyvalue`(`id`,`name1`,`name2`,`name3`,`name4`)
-> select @id:=@id+1,md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000) from
-> `keyvalue` k1, `keyvalue` k2, `keyvalue` k3, `keyvalue` k4,`keyvalue` k5,`keyvalue` k6, `keyvalue` k7, `keyvalue` k8, `keyvalue` k9,
-> `keyvalue` k0,`keyvalue` ka, `keyvalue` kb, `keyvalue` kc, `keyvalue` kd limit 5000000;
Query OK, 5000000 rows affected (1 min 11.92 sec)
Records: 5000000 Duplicates: 0 Warnings: 0
mysql> ALTER TABLE keyvalue ADD KEY (name2);
Query OK, 0 rows affected (17.20 sec)
Records: 0 Duplicates: 0 Warnings: 0
// Sec session
------------
TRANSACTIONS
------------
Trx id counter 30C
Purge done for trx's n:o < 309 undo n:o < 0
History list length 1
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 30B, not started
MySQL thread id 1, OS thread handle 0x7f7c04525700, query id 29 localhost root manage keys
ALTER TABLE keyvalue ADD KEY (name2)
---TRANSACTION 0, not started
MySQL thread id 2, OS thread handle 0x7f7c044e4700, query id 30 localhost root
show engine innodb status
---TRANSACTION 30A, ACTIVE 6 sec
mysql tables in use 1, locked 1
1 lock struct(s), heap size 376, 0 row lock(s)
MySQL thread id 1, OS thread handle 0x7f7c04525700, query id 29 localhost root manage keys
ALTER TABLE keyvalue ADD KEY (name2)
// 5.6.25
// pri sesssion
mysql> CREATE TABLE `keyvalue` (
-> `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
-> `name1` varchar(250),
-> `name2` varchar(250),
-> `name3` varchar(250),
-> `name4` varchar(250),
-> PRIMARY KEY (`id`)
-> ) ENGINE=innodb ROW_FORMAT=COMPRESSED;
Query OK, 0 rows affected, 2 warnings (0.00 sec)
mysql>
mysql> set @id:=0;
Query OK, 0 rows affected (0.00 sec)
mysql>
mysql> insert into `keyvalue` values
-> (@id:=@id+1,md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000))
-> , (@id:=@id+1,md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000))
-> , (@id:=@id+1,md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000))
-> , (@id:=@id+1,md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000));
Query OK, 4 rows affected (0.00 sec)
Records: 4 Duplicates: 0 Warnings: 0
mysql>
mysql> insert into `keyvalue`(`id`,`name1`,`name2`,`name3`,`name4`)
-> select @id:=@id+1,md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000),md5(rand()*1000000) from
-> `keyvalue` k1, `keyvalue` k2, `keyvalue` k3, `keyvalue` k4,`keyvalue` k5,`keyvalue` k6, `keyvalue` k7, `keyvalue` k8, `keyvalue` k9,
-> `keyvalue` k0,`keyvalue` ka, `keyvalue` kb, `keyvalue` kc, `keyvalue` kd limit 5000000;
Query OK, 5000000 rows affected (1 min 15.63 sec)
Records: 5000000 Duplicates: 0 Warnings: 0
mysql> ALTER TABLE keyvalue ADD KEY (name2);
Query OK, 0 rows affected, 2 warnings (16.12 sec)
Records: 0 Duplicates: 0 Warnings: 2
// sec session
------------
TRANSACTIONS
------------
Trx id counter 1826
Purge done for trx's n:o < 1824 undo n:o < 0 state: running but idle
History list length 12
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 1825, not started
MySQL thread id 1, OS thread handle 0x7f5e1f17b700, query id 17 localhost root altering table
ALTER TABLE keyvalue ADD KEY (name2)
---TRANSACTION 0, not started
MySQL thread id 2, OS thread handle 0x7f5e1f13a700, query id 18 localhost root init
show engine innodb status
---TRANSACTION 1824, ACTIVE 7 sec
mysql tables in use 1, locked 1
MySQL thread id 1, OS thread handle 0x7f5e1f17b700, query id 17 localhost root altering table
ALTER TABLE keyvalue ADD KEY (name2)
Trx read view will not see trx with id >= 1826, sees < 1825
Description: For ongoing DDLs, engine innodb status is showing two separate transactions for the same MySQL thread id executing the DDL statement. Reproduced on 5.5.42 MySQL Community Server and 5.6.23 MySQL Community Server. It does not happen at a stage when DDL is waiting, like for metadata lock on a table. How to repeat: Create large enough table so that DDL takes time enough to capture innodb status. Do ALTER like: mysql [localhost] {msandbox} (sbtest) > ALTER TABLE sbtest1 ADD KEY(pad); Query OK, 0 rows affected (8.16 sec) Records: 0 Duplicates: 0 Warnings: 0 In second session: mysql [localhost] {msandbox} (sbtest) > show engine innodb status\G ... ------------ TRANSACTIONS ------------ Trx id counter 47F Purge done for trx's n:o < 307 undo n:o < 0 History list length 1 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 47E, not started MySQL thread id 8, OS thread handle 0x7f3fb0266700, query id 719 localhost msandbox manage keys ALTER TABLE sbtest1 ADD KEY(pad) ---TRANSACTION 0, not started MySQL thread id 9, OS thread handle 0x7f3fb0225700, query id 720 localhost msandbox show engine innodb status ---TRANSACTION 47D, ACTIVE 2 sec reading clustered index mysql tables in use 1, locked 1 1 lock struct(s), heap size 376, 0 row lock(s) MySQL thread id 8, OS thread handle 0x7f3fb0266700, query id 719 localhost msandbox manage keys ALTER TABLE sbtest1 ADD KEY(pad) We can see above two transactions: 47E and 47D for the same statement run by MySQL thread id 8. Suggested fix: Fix the output of show engine innodb status if this is a bug and explain otherwise.