[MDEV-16796] TRUNCATE TABLE slowdown with innodb_file_per_table=ON - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Won't Fix
Affects Version/s: 10.1.34
Fix Version/s: None
Component/s: Storage Engine - InnoDB
Labels:
- innodb
- truncate

Description

The documentation for TRUNCATE TABLE says the following:

TRUNCATE TABLE is faster than DELETE, because it drops and re-creates a table. With XtraDB/InnoDB, this is faster if the innodb_file_per_table variable is ON (the default since MariaDB 5.5).

https://mariadb.com/kb/en/library/truncate-table/

What is the basis for the statement that it should be faster if innodb_file_per_table=ON is set? This does not seem to be true for a relatively small table with only 50k rows.

For example, let's create a table and populate it with the following:

CREATE TABLE test_table (

   id int NOT NULL PRIMARY KEY AUTO_INCREMENT,

   val int

);

DELIMITER $$

CREATE PROCEDURE prepare_data(num_rows int)

BEGIN

  DECLARE i INT DEFAULT 0;

  WHILE i < num_rows DO

    INSERT INTO test_table (val) VALUES (FLOOR(RAND() * 1000000));

    SET i = i + 1;

  END WHILE;

END$$

DELIMITER ;

CALL prepare_data(50000);

Then let's run the following statements with both innodb_file_per_table set to ON and OFF:

SHOW GLOBAL VARIABLES LIKE 'innodb_file_per_table';

CREATE TABLE truncate_test AS SELECT * FROM test_table;

SET profiling = 1;

TRUNCATE TABLE truncate_test;

SHOW PROFILES;

SHOW PROFILE ALL;

DROP TABLE truncate_test;

Here are the results:

MariaDB [db1]> SHOW GLOBAL VARIABLES LIKE 'innodb_file_per_table';

+-----------------------+-------+

| Variable_name         | Value |

+-----------------------+-------+

| innodb_file_per_table | ON    |

+-----------------------+-------+

1 row in set (0.00 sec)

MariaDB [db1]> CREATE TABLE truncate_test AS SELECT * FROM test_table;

Query OK, 50000 rows affected (0.24 sec)

Records: 50000  Duplicates: 0  Warnings: 0

MariaDB [db1]> SET profiling = 1;

Query OK, 0 rows affected (0.00 sec)

MariaDB [db1]> TRUNCATE TABLE truncate_test;

Query OK, 0 rows affected (0.01 sec)

MariaDB [db1]> SHOW PROFILES;

+----------+------------+------------------------------+

| Query_ID | Duration   | Query                        |

+----------+------------+------------------------------+

|        1 | 0.01077308 | TRUNCATE TABLE truncate_test |

+----------+------------+------------------------------+

1 row in set (0.00 sec)

MariaDB [db1]> SHOW PROFILE ALL;

+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+--------------+-------------+

| Status               | Duration | CPU_user | CPU_system | Context_voluntary | Context_involuntary | Block_ops_in | Block_ops_out | Messages_sent | Messages_received | Page_faults_major | Page_faults_minor | Swaps | Source_function       | Source_file  | Source_line |

+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+--------------+-------------+

| starting             | 0.000017 | 0.000004 |   0.000007 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | NULL                  | NULL         |        NULL |

| Opening tables       | 0.000007 | 0.000002 |   0.000004 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | open_ltable           | sql_base.cc  |        5176 |

| System lock          | 0.000002 | 0.000001 |   0.000002 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_lock_tables     | lock.cc      |         308 |

| Table lock           | 0.000002 | 0.000001 |   0.000001 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_lock_tables     | lock.cc      |         313 |

| Opening tables       | 0.000002 | 0.000000 |   0.000001 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_lock_tables     | lock.cc      |         328 |

| After opening tables | 0.000012 | 0.000005 |   0.000009 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | open_ltable           | sql_base.cc  |        5245 |

| closing tables       | 0.000002 | 0.000001 |   0.000001 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | close_thread_tables   | sql_base.cc  |         919 |

| Unlocking tables     | 0.000015 | 0.000005 |   0.000010 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_unlock_tables   | lock.cc      |         396 |

| checking permissions | 0.000021 | 0.000008 |   0.000014 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | check_access          | sql_parse.cc |        6154 |

| Opening tables       | 0.000170 | 0.004876 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | open_tables           | sql_base.cc  |        4532 |

| After opening tables | 0.000004 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | open_tables           | sql_base.cc  |        4779 |

| System lock          | 0.000003 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_lock_tables     | lock.cc      |         308 |

| Table lock           | 0.010468 | 0.000000 |   0.000000 |                21 |                   0 |            8 |           256 |             0 |                 0 |                 0 |                 0 |     0 | mysql_lock_tables     | lock.cc      |         313 |

| Writing to binlog    | 0.000018 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | write_bin_log         | sql_table.cc |        1969 |

| query end            | 0.000005 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_execute_command | sql_parse.cc |        5706 |

| closing tables       | 0.000002 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | close_thread_tables   | sql_base.cc  |         919 |

| Unlocking tables     | 0.000007 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_unlock_tables   | lock.cc      |         396 |

| freeing items        | 0.000003 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_parse           | sql_parse.cc |        7466 |

| updating status      | 0.000008 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | dispatch_command      | sql_parse.cc |        1954 |

| cleaning up          | 0.000002 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | dispatch_command      | sql_parse.cc |        1973 |

+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+--------------+-------------+

20 rows in set (0.00 sec)

MariaDB [db1]> DROP TABLE truncate_test;

Query OK, 0 rows affected (0.01 sec)

MariaDB [db1]> SHOW GLOBAL VARIABLES LIKE 'innodb_file_per_table';

+-----------------------+-------+

| Variable_name         | Value |

+-----------------------+-------+

| innodb_file_per_table | OFF   |

+-----------------------+-------+

1 row in set (0.00 sec)

MariaDB [db1]> CREATE TABLE truncate_test AS SELECT * FROM test_table;

Query OK, 50000 rows affected (0.16 sec)

Records: 50000  Duplicates: 0  Warnings: 0

MariaDB [db1]> SET profiling = 1;

Query OK, 0 rows affected (0.00 sec)

MariaDB [db1]> TRUNCATE TABLE truncate_test;

Query OK, 0 rows affected (0.00 sec)

MariaDB [db1]> SHOW PROFILES;

+----------+------------+------------------------------+

| Query_ID | Duration   | Query                        |

+----------+------------+------------------------------+

|        1 | 0.00474932 | TRUNCATE TABLE truncate_test |

+----------+------------+------------------------------+

1 row in set (0.00 sec)

MariaDB [db1]> SHOW PROFILE ALL;

+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+--------------+-------------+

| Status               | Duration | CPU_user | CPU_system | Context_voluntary | Context_involuntary | Block_ops_in | Block_ops_out | Messages_sent | Messages_received | Page_faults_major | Page_faults_minor | Swaps | Source_function       | Source_file  | Source_line |

+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+--------------+-------------+

| starting             | 0.000016 | 0.000005 |   0.000006 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | NULL                  | NULL         |        NULL |

| Opening tables       | 0.000008 | 0.000004 |   0.000004 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | open_ltable           | sql_base.cc  |        5176 |

| System lock          | 0.000002 | 0.000001 |   0.000001 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_lock_tables     | lock.cc      |         308 |

| Table lock           | 0.000002 | 0.000001 |   0.000001 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_lock_tables     | lock.cc      |         313 |

| Opening tables       | 0.000002 | 0.000001 |   0.000001 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_lock_tables     | lock.cc      |         328 |

| After opening tables | 0.000015 | 0.000008 |   0.000008 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | open_ltable           | sql_base.cc  |        5245 |

| closing tables       | 0.000002 | 0.000001 |   0.000001 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | close_thread_tables   | sql_base.cc  |         919 |

| Unlocking tables     | 0.000016 | 0.000008 |   0.000008 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 1 |     0 | mysql_unlock_tables   | lock.cc      |         396 |

| checking permissions | 0.000020 | 0.000010 |   0.000010 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 1 |     0 | check_access          | sql_parse.cc |        6154 |

| Opening tables       | 0.000147 | 0.000074 |   0.000075 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | open_tables           | sql_base.cc  |        4532 |

| After opening tables | 0.000005 | 0.000002 |   0.000001 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | open_tables           | sql_base.cc  |        4779 |

| System lock          | 0.000002 | 0.000001 |   0.000002 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_lock_tables     | lock.cc      |         308 |

| Table lock           | 0.004469 | 0.001860 |   0.000000 |                11 |                   1 |            0 |            40 |             0 |                 0 |                 0 |                 5 |     0 | mysql_lock_tables     | lock.cc      |         313 |

| Writing to binlog    | 0.000017 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | write_bin_log         | sql_table.cc |        1969 |

| query end            | 0.000004 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_execute_command | sql_parse.cc |        5706 |

| closing tables       | 0.000003 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | close_thread_tables   | sql_base.cc  |         919 |

| Unlocking tables     | 0.000008 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_unlock_tables   | lock.cc      |         396 |

| freeing items        | 0.000003 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_parse           | sql_parse.cc |        7466 |

| updating status      | 0.000006 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | dispatch_command      | sql_parse.cc |        1954 |

| cleaning up          | 0.000002 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | dispatch_command      | sql_parse.cc |        1973 |

+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+--------------+-------------+

20 rows in set (0.00 sec)

MariaDB [db1]> DROP TABLE truncate_test;

Query OK, 0 rows affected (0.00 sec)

It seems to be consistently faster with innodb_file_per_table=OFF set. The difference seems to be in the Table lock state, and there seems to be a difference in the Block_ops_out value.

Is this a bug, or is the statement in the documentation incorrect, or is there an exception to this rule for relatively small tables?

Attachments

- Sort By Name
- Sort By Date
- Ascending
- Descending
- Thumbnails
- List
- Download All

adapt_0_per_table_0.svg
510 kB
2018-10-18 10:40
adapt_0_per_table_1.svg
443 kB
2018-10-18 10:40
mem_adapt_0_per_table_0.svg
530 kB
2018-10-18 11:22
mem_adapt_0_per_table_1.svg
521 kB
2018-10-18 11:22
mem_adapt_1_per_table_0_10.2_safe_truncate_0.svg
508 kB
2018-10-18 12:36
mem_adapt_1_per_table_0_10.2_safe_truncate_1.svg
391 kB
2018-10-18 12:36
mem_adapt_1_per_table_0.svg
417 kB
2018-10-18 11:22
mem_adapt_1_per_table_1.svg
534 kB
2018-10-18 11:22
per_table_0.svg
330 kB
2018-10-17 13:01
per_table_1.svg
422 kB
2018-10-17 13:01

Issue Links

relates to

MDEV-8069 DROP or rebuild of a large table may lock up InnoDB

Closed

MDEV-15528 Avoid writing freed InnoDB pages

Closed

MDEV-17492 Benchmark AHI to find cases where it's useful

Stalled

MDEV-18613 Optimization for dropping table

Closed

Activity

Ascending order - Click to sort in descending order

View 13 older comments

Eugene Kosov (Inactive) added a comment - 2018-10-18 12:44

And now some benchmark results. They're too variative, I know. But after looking at flame graphs I have an optinion than 10.2 is a little bit slower.

safe_truncate=1 is significantly slower, indeed.

mem per_table=0 adaptive=1 10.1

0.0072
0.0159
0.0087
0.0079
0.0080

mem per_table=0 adaptive=1 10.2 safe_truncate=1

0.0093
0.0094
0.0089

mem per_table=0 adaptive=1 10.2 safe_truncate=0

0.0162
0.0078
0.0054
0.0084
0.0086

Eugene Kosov (Inactive) added a comment - 2018-10-18 12:44 And now some benchmark results. They're too variative, I know. But after looking at flame graphs I have an optinion than 10.2 is a little bit slower. safe_truncate=1 is significantly slower, indeed. mem per_table=0 adaptive=1 10.1 0.0072 0.0159 0.0087 0.0079 0.0080 mem per_table=0 adaptive=1 10.2 safe_truncate=1 0.0093 0.0094 0.0089 mem per_table=0 adaptive=1 10.2 safe_truncate=0 0.0162 0.0078 0.0054 0.0084 0.0086

Eugene Kosov (Inactive) added a comment - 2018-10-18 16:10

Nothing more to do with this issue. AHI should be benchmarked to find cases where it brinds performance benefits. And if there aren't many such cases it probably should be removed. Here is the benchmarking task https://jira.mariadb.org/browse/MDEV-17492

Eugene Kosov (Inactive) added a comment - 2018-10-18 16:10 Nothing more to do with this issue. AHI should be benchmarked to find cases where it brinds performance benefits. And if there aren't many such cases it probably should be removed. Here is the benchmarking task https://jira.mariadb.org/browse/MDEV-17492

Geoff Montee (Inactive) added a comment - 2018-10-18 16:35

Thanks for those thorough benchmarks, kevg.

marko,

Thanks for the analysis.

It's probably a good idea to fix the incorrect statement in the documentation. I've changed it to say the following:

TRUNCATE TABLE is faster than DELETE, because it drops and re-creates a table. With XtraDB/InnoDB, this is slower if innodb_file_per_table=ON is set (the default since MariaDB 5.5). This is because TRUNCATE TABLE unlinks the underlying tablespace file, which can be an expensive operation. See ~~MDEV-8069~~ for more details. TRUNCATE TABLE can also perform poorly in cases where the InnoDB buffer pool is very large. In that case, DROP TABLE followed by CREATE TABLE may perform better. In MariaDB 10.2.19 and later, this performance can also be improved by setting innodb_safe_truncate=OFF. See ~~MDEV-9459~~ for more details. Setting innodb_adaptive_hash_index=OFF can improve performance of TRUNCATE TABLE in general.

https://mariadb.com/kb/en/library/truncate-table/

Did I forget or misunderstand anything important?

Thanks!

Geoff Montee (Inactive) added a comment - 2018-10-18 16:35 Thanks for those thorough benchmarks, kevg . marko , Thanks for the analysis. It's probably a good idea to fix the incorrect statement in the documentation. I've changed it to say the following: TRUNCATE TABLE is faster than DELETE, because it drops and re-creates a table. With XtraDB/InnoDB, this is slower if innodb_file_per_table=ON is set (the default since MariaDB 5.5). This is because TRUNCATE TABLE unlinks the underlying tablespace file, which can be an expensive operation. See MDEV-8069 for more details. TRUNCATE TABLE can also perform poorly in cases where the InnoDB buffer pool is very large. In that case, DROP TABLE followed by CREATE TABLE may perform better. In MariaDB 10.2.19 and later, this performance can also be improved by setting innodb_safe_truncate=OFF. See MDEV-9459 for more details. Setting innodb_adaptive_hash_index=OFF can improve performance of TRUNCATE TABLE in general. https://mariadb.com/kb/en/library/truncate-table/ Did I forget or misunderstand anything important? Thanks!

Eugene Kosov (Inactive) added a comment - 2018-10-19 13:04

Hi!. I'll summarise:

adapt=0 per_file=0:
Iterate all table pages to mark them as free.

adapt=0 per_file=1:
Unlink file.

adapt=1 per_file=0:
Iterate all table pages to mark them as free. Also iterate every row to remove it from AHI.

adapt=1 per_file=1:
Iterate buffer pool pages to find records and remove them from AHI. Unlink file.

> TRUNCATE TABLE can also perform poorly in cases where the InnoDB buffer pool is very large.

That's a bit imprecise. Only adapt=1 per_file=1 case iterates through buffer pool.

Everything else seems correct.

Btw, I haven't checked https://mariadb.com/kb/en/library/truncate-table/ because it doesn't work for me today.

Eugene Kosov (Inactive) added a comment - 2018-10-19 13:04 Hi!. I'll summarise: adapt=0 per_file=0: Iterate all table pages to mark them as free. adapt=0 per_file=1: Unlink file. adapt=1 per_file=0: Iterate all table pages to mark them as free. Also iterate every row to remove it from AHI. adapt=1 per_file=1: Iterate buffer pool pages to find records and remove them from AHI. Unlink file. > TRUNCATE TABLE can also perform poorly in cases where the InnoDB buffer pool is very large. That's a bit imprecise. Only adapt=1 per_file=1 case iterates through buffer pool. Everything else seems correct. Btw, I haven't checked https://mariadb.com/kb/en/library/truncate-table/ because it doesn't work for me today.

Geoff Montee (Inactive) added a comment - 2018-10-19 20:02

> TRUNCATE TABLE can also perform poorly in cases where the InnoDB buffer pool is very large.

That's a bit imprecise. Only adapt=1 per_file=1 case iterates through buffer pool.

The note about TRUNCATE and large buffer pools in the documentation was not originally related to this issue. It was related to ~~MDEV-9459~~, which was related to the following upstream bug:

https://bugs.mysql.com/bug.php?id=68184

After looking more closely at the upstream bug report, I see that it is indeed directly related to the issues with innodb_adaptive_hash_index. Thanks for pointing that out. I've clarified the documentation.

Btw, I haven't checked https://mariadb.com/kb/en/library/truncate-table/ because it doesn't work for me today.

The knowledge base site has been having some intermittent issues after the latest web site update.

Geoff Montee (Inactive) added a comment - 2018-10-19 20:02 > TRUNCATE TABLE can also perform poorly in cases where the InnoDB buffer pool is very large. That's a bit imprecise. Only adapt=1 per_file=1 case iterates through buffer pool. The note about TRUNCATE and large buffer pools in the documentation was not originally related to this issue. It was related to MDEV-9459 , which was related to the following upstream bug: https://bugs.mysql.com/bug.php?id=68184 After looking more closely at the upstream bug report, I see that it is indeed directly related to the issues with innodb_adaptive_hash_index. Thanks for pointing that out. I've clarified the documentation. Btw, I haven't checked https://mariadb.com/kb/en/library/truncate-table/ because it doesn't work for me today. The knowledge base site has been having some intermittent issues after the latest web site update.

MariaDB Server

TRUNCATE TABLE slowdown with innodb_file_per_table=ON

Details

Description

Attachments

Attachments

Issue Links

Activity

People

Dates

Git Integration