Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-16796

TRUNCATE TABLE slowdown with innodb_file_per_table=ON

    Details

      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

        1. per_table_0.svg
          330 kB
        2. per_table_1.svg
          422 kB
        3. adapt_0_per_table_0.svg
          510 kB
        4. adapt_0_per_table_1.svg
          443 kB
        5. mem_adapt_1_per_table_0.svg
          417 kB
        6. mem_adapt_0_per_table_0.svg
          530 kB
        7. mem_adapt_0_per_table_1.svg
          521 kB
        8. mem_adapt_1_per_table_1.svg
          534 kB
        9. mem_adapt_1_per_table_0_10.2_safe_truncate_0.svg
          508 kB
        10. mem_adapt_1_per_table_0_10.2_safe_truncate_1.svg
          391 kB

          Issue Links

            Activity

              People

              • Assignee:
                kevg Eugene Kosov
                Reporter:
                GeoffMontee Geoff Montee
              • Votes:
                0 Vote for this issue
                Watchers:
                4 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: