| 2013-10-18 15:10:11 |
Sam Lambert |
description |
I have noticed an issue with Percona Server 5.5.33 stalling during a truncate table operation.
I can recreate this issue constantly with the following test case:
- Sysbench running against a single table (sbtest1) to generate some server load and ~25,000 QPS.
- Creating an empty table and then truncating it
Here is the output of my terminal when creating and truncating the table:
root@localhost 07:55:43 DB:sbtest>CREATE TABLE `test_table` ( `id` int(11) unsigned NOT NULL AUTO_INCREMENT, PRIMARY KEY (`id`) ) ENGINE=InnoDB DEFAULT CHARSET=utf8;
Query OK, 0 rows affected (0.00 sec)
root@localhost 07:55:47 DB:sbtest>truncate table test_table;
Query OK, 0 rows affected (6.42 sec)
root@localhost 07:56:01 DB:sbtest>
root@localhost 07:56:42 DB:sbtest>drop table test_table;
Query OK, 0 rows affected (0.00 sec)
Here is the output of sudo mysqladmin ext -i1 | gawk '/Queries/{q=$4-ql;ql=$4; printf("%s, %s\n", strftime("%H:%M:%S"), q, fflush())}' | tee truncate_bug_query.dat during the same time period:
07:55:36, 25130
07:55:37, 25422
07:55:38, 24822
07:55:39, 25734
07:55:40, 25379
07:55:41, 25137
07:55:42, 25504
07:55:43, 25420
07:55:44, 25218
07:55:45, 26111
07:55:46, 25183
07:55:47, 25928
07:55:48, 25402
07:55:49, 25169
07:55:50, 25117
07:55:51, 25278
07:55:52, 24868
07:55:53, 25544
07:55:54, 25484
07:55:56, 17195
07:55:56, 22
07:55:57, 1
07:55:59, 1
07:55:59, 1
07:56:00, 1
07:56:02, 1
07:56:02, 23244
07:56:03, 25834
07:56:05, 25526
07:56:05, 24880
07:56:06, 25288
07:56:08, 26032
07:56:08, 26223
07:56:09, 25806
07:56:11, 25786
07:56:11, 25253
07:56:12, 25358
07:56:14, 25745
07:56:14, 25499
07:56:15, 25467
07:56:16, 25223
07:56:17, 25519
07:56:18, 25117
07:56:19, 25596
07:56:20, 25607
07:56:21, 25833
07:56:22, 25621
07:56:23, 25385
07:56:24, 25305
07:56:25, 26082
07:56:26, 25443
07:56:27, 25440
07:56:28, 25377
07:56:29, 24946
07:56:30, 25820
07:56:31, 24259
07:56:32, 25351
07:56:33, 25271
07:56:34, 25168
07:56:35, 24524
07:56:36, 25608
07:56:37, 25611
07:56:38, 25632
07:56:39, 25322
07:56:40, 25629
07:56:41, 25076
07:56:43, 25966
07:56:43, 26012
07:56:44, 25783
07:56:46, 25830
07:56:46, 24359
07:56:47, 25835
07:56:49, 25224
07:56:49, 25608
07:56:50, 25743
07:56:52, 26011
07:56:52, 24710
07:56:53, 25472
07:56:55, 24979
07:56:55, 24889
07:56:56, 25369
07:56:58, 24919
07:56:58, 25524
07:56:59, 25823
You can see that the truncate causes a severe server stall and that the drop is fine.
I have attached a graph of the data. |
I have noticed an issue with Percona Server 5.5.33 stalling during a truncate table operation.
I can recreate this issue consistently with the following test case:
- Sysbench running against a single table (sbtest1) to generate some server load and ~25,000 QPS.
- Creating an empty table and then truncating it
Here is the output of my terminal when creating and truncating the table:
root@localhost 07:55:43 DB:sbtest>CREATE TABLE `test_table` ( `id` int(11) unsigned NOT NULL AUTO_INCREMENT, PRIMARY KEY (`id`) ) ENGINE=InnoDB DEFAULT CHARSET=utf8;
Query OK, 0 rows affected (0.00 sec)
root@localhost 07:55:47 DB:sbtest>truncate table test_table;
Query OK, 0 rows affected (6.42 sec)
root@localhost 07:56:01 DB:sbtest>
root@localhost 07:56:42 DB:sbtest>drop table test_table;
Query OK, 0 rows affected (0.00 sec)
Here is the output of sudo mysqladmin ext -i1 | gawk '/Queries/{q=$4-ql;ql=$4; printf("%s, %s\n", strftime("%H:%M:%S"), q, fflush())}' | tee truncate_bug_query.dat during the same time period:
07:55:36, 25130
07:55:37, 25422
07:55:38, 24822
07:55:39, 25734
07:55:40, 25379
07:55:41, 25137
07:55:42, 25504
07:55:43, 25420
07:55:44, 25218
07:55:45, 26111
07:55:46, 25183
07:55:47, 25928
07:55:48, 25402
07:55:49, 25169
07:55:50, 25117
07:55:51, 25278
07:55:52, 24868
07:55:53, 25544
07:55:54, 25484
07:55:56, 17195
07:55:56, 22
07:55:57, 1
07:55:59, 1
07:55:59, 1
07:56:00, 1
07:56:02, 1
07:56:02, 23244
07:56:03, 25834
07:56:05, 25526
07:56:05, 24880
07:56:06, 25288
07:56:08, 26032
07:56:08, 26223
07:56:09, 25806
07:56:11, 25786
07:56:11, 25253
07:56:12, 25358
07:56:14, 25745
07:56:14, 25499
07:56:15, 25467
07:56:16, 25223
07:56:17, 25519
07:56:18, 25117
07:56:19, 25596
07:56:20, 25607
07:56:21, 25833
07:56:22, 25621
07:56:23, 25385
07:56:24, 25305
07:56:25, 26082
07:56:26, 25443
07:56:27, 25440
07:56:28, 25377
07:56:29, 24946
07:56:30, 25820
07:56:31, 24259
07:56:32, 25351
07:56:33, 25271
07:56:34, 25168
07:56:35, 24524
07:56:36, 25608
07:56:37, 25611
07:56:38, 25632
07:56:39, 25322
07:56:40, 25629
07:56:41, 25076
07:56:43, 25966
07:56:43, 26012
07:56:44, 25783
07:56:46, 25830
07:56:46, 24359
07:56:47, 25835
07:56:49, 25224
07:56:49, 25608
07:56:50, 25743
07:56:52, 26011
07:56:52, 24710
07:56:53, 25472
07:56:55, 24979
07:56:55, 24889
07:56:56, 25369
07:56:58, 24919
07:56:58, 25524
07:56:59, 25823
You can see that the truncate causes a severe server stall and that the drop is fine.
I have attached a graph of the data. |
|
