Bug #74312 spend too long time to truncate a small table in 5.7.5
Submitted: 10 Oct 2014 9:46 Modified: 29 Jun 2015 13:45
Reporter: zhai weixiang (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S3 (Non-critical)
Version:5.7.5 OS:Any
Assigned to: Krunal Bauskar CPU Architecture:Any
Tags: checkpoint, performance

[10 Oct 2014 9:46] zhai weixiang
Description:
While testing 5.7.5 using sysbench, I wanna to truncate a small table which only have 10 records. and I saw the operation hang..

root@sb1 05:35:42>select * from tt;
+------+
| a    |
+------+
|    1 |
|    2 |
|    3 |
+------+
3 rows in set (0.00 sec)

root@sb1 05:35:46>truncate table tt;
Query OK, 0 rows affected (1 min 58.63 sec)

So it takes 1min58sec to finish the truncate operation..I think it's too long...

I repeated the truncate operation again and it still takes very long time to finish the truncate even this table is empty....

root@sb1 05:43:33>truncate table tt;
Query OK, 0 rows affected (2 min 1.25 sec)

From the backtrace, it seems checkpoint is triggered if doing a truncate operation..

1 sigwaitinfo(libc.so.6),timer_notify_thread_func(posix_timers.c:80),pfs_spawn_thread(pfs.cc:2137),start_thread(libpthread.so.0),clone(libc.so.6)
      1 pwrite64(libpthread.so.0),os_file_io(os0file.cc:2390),os_file_pwrite(os0file.cc:2527),os_file_write_func(os0file.cc:2527),os_aio_func(os0file.cc:4562),pfs_os_aio_func(os0file.ic:241),fil_io(os0file.ic:241),buf_dblwr_flush_buffered_writes(buf0dblwr.cc:889),buf_dblwr_add_to_batch(buf0dblwr.cc:1015),buf_flush_write_block_low(buf0flu.cc:986),buf_flush_page(buf0flu.cc:986),buf_flush_try_neighbors(buf0flu.cc:1329),buf_flush_page_and_try_neighbors(buf0flu.cc:1329),buf_do_flush_list_batch(buf0flu.cc:1662),buf_flush_batch(buf0flu.cc:1662),buf_flush_do_batch(buf0flu.cc:1662),buf_flush_lists(buf0flu.cc:1963),log_preflush_pool_modified_pages(log0log.cc:1383),log_make_checkpoint_at(log0log.cc:1383),row_truncate_table_for_mysql(row0trunc.cc:1708),ha_innobase::truncate(ha_innodb.cc:10511),Sql_cmd_truncate_table::handler_truncate(sql_truncate.cc:242),Sql_cmd_truncate_table::truncate_table(sql_truncate.cc:488),Sql_cmd_truncate_table::execute(sql_truncate.cc:544),mysql_execute_command(sql_parse.cc:4815),mysql_parse(sql_parse.cc:5427),dispatch_command(sql_parse.cc:1250),handle_connection(connection_handler_per_thread.cc:298),pfs_spawn_thread(pfs.cc:2137),start_thread(libpthread.so.0),clone(libc.so.6)

How to repeat:
Run DML workload for a while and then truncate a small table...

Suggested fix:
I don't know...
[10 Oct 2014 9:47] zhai weixiang
edit synopsis
[10 Oct 2014 13:38] Mark Callaghan
Is DROP TABLE also a problem?
[10 Oct 2014 13:40] Peter Laursen
. and "DELETE FROM TABLE"?
[10 Oct 2014 13:49] zhai weixiang
Only TRUNCATE operation is affected.

root@sb1 09:45:05>create table tt (a int);
Query OK, 0 rows affected (0.02 sec)

root@sb1 09:45:11>drop table tt;
Query OK, 0 rows affected (0.20 sec)

root@sb1 09:45:14>create table tt (a int);
Query OK, 0 rows affected (0.03 sec)

root@sb1 09:45:16>truncate table tt;
Query OK, 0 rows affected (1 min 56.49 sec)

root@sb1 09:48:49>
root@sb1 09:48:49>INSERT INTO tt values (1);
Query OK, 1 row affected (0.00 sec)

root@sb1 09:49:02>DELETE FROM t1;
Query OK, 5 rows affected (0.01 sec)

root@sb1 09:49:08>DELETE FROM t1;
Query OK, 0 rows affected (0.00 sec)
[17 Oct 2014 8:31] MySQL Verification Team
related: http://bugs.mysql.com/bug.php?id=68184
[22 Oct 2014 7:36] Sunny Bains
The extra checkpoints are most likely responsible for this. We should quiesce the pages only from the truncated table.
[29 Jun 2015 13:45] Daniel Price
Posted by developer:
 
Fixed as of the upcoming 5.7.8, 5.8.0 releases, and here's the changelog entry:

A TRUNCATE TABLE operation appeared to hang when run in parallel with a
read-write workload. 

Thank you for the bug report.