Slow "CREATE TABLE" and "TRUNCATE" on MySQL / MariaDB

Question

I am fighting with performance issues on a local MariaDB instance.

Fun thing: I previously had problems with all my INSERT and UPDATE and DELETE queries. This got signigicantly faster (~40ms -> less than 1ms) by changing the innodb_flush_method from O_DIRECT to ALL_O_DIRECT (undoing a previous change), following a suggestion on stackexchange. This is contrary to all other advice I found on the web, that suggests to use O_DIRECT.

EDIT: Not sure anymore about the above. Seen slow INSERT and UPDATE queries again.

What still remains is TRUNCATE and CREATE TABLE being very slow:
~150ms to CREATE TABLE, with a quite simple table structure (InnoDB).
~150ms to TRUNCATE this table, while it is already empty.

All of that in an otherwise empty database, and after purging all the ibdata1 and stuff, as suggested here: https://stackoverflow.com/a/3456885/246724.

The same queries are significantly faster (mysql says 0.00 seconds) on a different machine (my webserver).

Profiling results

Using the awesome profiling feature, I found that the bottleneck is in the 'creating table' step for CREATE, and in the 'After table lock' step for TRUNCATE.

TRUNCATE:

+------------------------------+----------+
| Status                       | Duration |
+------------------------------+----------+
| starting                     | 0.000038 |
| checking permissions         | 0.000042 |
| Opening tables               | 0.000093 |
| After opening tables         | 0.000007 |
| System lock                  | 0.000005 |
| Table lock                   | 0.000003 |
| After table lock             | 0.116224 |
| Waiting for query cache lock | 0.000007 |
| After table lock             | 0.000004 |
| query end                    | 0.000011 |
| closing tables               | 0.000011 |
| freeing items                | 0.000004 |
| updating status              | 0.000010 |
| cleaning up                  | 0.000003 |
+------------------------------+----------+

CREATE TABLE:

+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000093 |
| checking permissions | 0.000013 |
| Opening tables       | 0.000013 |
| After opening tables | 0.000004 |
| System lock          | 0.000002 |
| Table lock           | 0.000002 |
| After table lock     | 0.000016 |
| creating table       | 0.155836 |
| After create         | 0.000006 |
| query end            | 0.000003 |
| closing tables       | 0.000005 |
| freeing items        | 0.000003 |
| updating status      | 0.000007 |
| cleaning up          | 0.000002 |
+----------------------+----------+

When using SHOW PROFILE ALL FOR QUERY 10, I get a lot of zeros in CPU_*, Context_*, Block_ops_*, Messages_*, Page_faults_*, Swaps.

But the non-zero table cells are:

TRUNCATE:
"After table lock" + "Context_voluntary" -> 10
"After table lock" + "Block_ops_out" -> 269

CREATE TABLE:
"creating table" + "Context_voluntary" -> 10
"creating table" + "Block_ops_out" -> 276

Source:
TRUNCATE "After table lock" -> mysql_lock_tables lock.cc 326
CREATE TABLE "creating table" -> create_table_impl sql_table.cc 4775

Table structure

The table structure is:

CREATE TABLE `cache_bootstrap` (
`cid` varchar(255) NOT NULL DEFAULT '' COMMENT 'Primary Key: Unique cache ID.',
`data` longblob COMMENT 'A collection of data to cache.',
`expire` int(11) NOT NULL DEFAULT '0' COMMENT 'A Unix timestamp indicating when the cache entry should expire, or 0 for never.',
`created` int(11) NOT NULL DEFAULT '0' COMMENT 'A Unix timestamp indicating when the cache entry was created.',
`serialized` smallint(6) NOT NULL DEFAULT '0' COMMENT 'A flag to indicate whether content is serialized (1) or not (0).',
PRIMARY KEY (`cid`),
KEY `expire` (`expire`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 COMMENT='Cache table for data required to bootstrap Drupal, may be...';

Simplifying this to just one column, either string key or auto-increment, still leaves me with ~100ms for CREATE TABLE and TRUNCATE. But the Context_voluntary changes to 2, and the Block_ops_out changes to 16.

System specs on desktop, where this issue occurs

MySQL version:
mysql Ver 15.1 Distrib 10.0.15-MariaDB, for Linux (x86_64) using readline 5.1

OS: Manjaro / Arch Linux.

Memory: 16 GB
CPU: Intel(R) Core(TM) i5-4570 CPU @ 3.20GHz
Board: ASRock H97 Pro4
HDD (/dev/sda): WDC WD30EZRX-00DC0B0, 3TB, connected with SATA
HDD Partitions:
/dev/sda5 mounted to /, 33% full, 52.1GB total, ext4
/dev/sda4 mounted to /home, 34% full, 524GB total, ext4
Other partitions probably not relevant here.. /var/lib/mysql is on /dev/sda5.
Second HDD probably not relevant here.

System spec on webserver, where these queries are much faster

mysql Ver 14.14 Distrib 5.1.73, for debian-linux-gnu (x86_64) using readline 6.1

Memory: 1GB
CPU: Intel(R) Xeon(R) CPU E5520 @ 2.27GHz

Since this is a virtual machine provided by a hosting company, it won't let me see info about harddrives.

Answer 1

I experimented with this and found something very interesting.

Running Fedora release 20 (Heisenbug) 3.11.10-301.fc20.x86_64, 2GB RAM (I know!), 2 processor Intel centrino.

If you enable the Performance Schema (P_S), the times seem to drop dramatically. Why this is, I simply don't know - the P_S is for monitoring, and not changing anything. I have put what I put in my my.cnf at the end.

Could you test this for your 3 scenarios (CREATE, TRUNCATE & DELETE) running your server using the new my.cnf. If you obtain similar results to mine, then we can investigate further.

Strangely, as far as I can see, the client reports a time of approx 0.3 seconds for me for all of my experiments - but the results from the profiling seem very different. Still puzzling through this one.

Below are my results just for the CREATE table statement before and after enabling the performance schema.

Before enabling P_S.

mysql> show profile for CREATE TABLE cache_bootstrap;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000290 |
| checking permissions | 0.000021 |
| Opening tables       | 0.000141 |
| creating table       | 0.365769 |  <<====
| After create         | 0.000037 |
| query end            | 0.000023 |
| closing tables       | 0.000018 |
| freeing items        | 0.000114 |
| cleaning up          | 0.000030 |
+----------------------+----------+
9 rows in set, 1 warning (0.00 sec)

After enabling P_S

mysql> show profile for CREATE TABLE cache_bootstrap;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000188 |
| checking permissions | 0.000131 |
| query end            | 0.000015 |
| closing tables       | 0.000020 |
| freeing items        | 0.000068 |
| cleaning up          | 0.000052 |
+----------------------+----------+
6 rows in set, 1 warning (0.00 sec)

MariaDB

Before enabling P_S

Query OK, 0 rows affected (0.33 sec)

MariaDB [test]> show profile for CREATE TABLE cache_bootstrap;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000321 |
| checking permissions | 0.000024 |
| Opening tables       | 0.000073 |
| After opening tables | 0.000017 |
| System lock          | 0.000011 |
| Table lock           | 0.000019 |
| After opening tables | 0.000056 |
| creating table       | 0.328769 |  <<======
| After create         | 0.000043 |
| query end            | 0.000026 |
| closing tables       | 0.000022 |
| freeing items        | 0.000043 |
| updating status      | 0.000050 |
| cleaning up          | 0.000039 |
+----------------------+----------+
14 rows in set (0.00 sec)

After enabling P_S on MariaDB

MariaDB [test]> show profile for CREATE TABLE cache_bootstrap
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000311 |
| checking permissions | 0.000024 |
| Opening tables       | 0.000044 |
| After opening tables | 0.000038 |
| System lock          | 0.000014 |
| Table lock           | 0.000012 |
| After opening tables | 0.000347 |
| After create         | 0.000015 |
| query end            | 0.000014 |
| closing tables       | 0.000021 |
| freeing items        | 0.000014 |
| updating status      | 0.000026 |
| cleaning up          | 0.000034 |
+----------------------+----------+
13 rows in set (0.00 sec)

To be added in the [mysqld] section of my.cnf

[mysqld]

performance_schema
performance_schema_instrument = '%=on'
performance_schema_consumer_events_stages_current = ON
performance_schema_consumer_events_stages_history = ON
performance_schema_consumer_events_stages_history_long = ON
performance_schema_consumer_events_statements_history = ON
performance_schema_consumer_events_statements_history_long = ON
performance_schema_consumer_events_waits_current = ON
performance_schema_consumer_events_waits_history = ON
performance_schema_consumer_events_waits_history_long = ON

Answer 2

O_DIRECT vs. ALL_O_DIRECT -- depends on OS, HDD vs SDD, and distribution of files across multiple filesystems. Probably ALL_O_DIRECT is best for your config.

Was it previously "ext4"? That is not necessarily as good as XFS or ZFS.

What is the value of innodb_file_per_table when doing CREATE TABLE?
OFF (the old default) led to writing the data and indexes to the already-open file ibdata1
ON (the new default) requires creating a .ibd file.

In general, ON is better for large tables; potentially worse for small tables.

TRUNCATE, if I am not mistaken, is DROP + CREATE.