2

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.

  • Could you give your machine spec (RAM, CPU, Disk (RAID?))? – Vérace May 21 '15 at 23:39
  • Also, the spec of the machine where it is fast? – Vérace May 21 '15 at 23:55
  • What exactly do you want to know? Is there a command that I can run on either machine and it will give you the infos you need? – donquixote May 22 '15 at 1:16
  • RAM? The relevant bits of "more /proc/meminfo" (not all). CPU? The relevant bits of "more /proc/cpuinfo". HDD? Disk config - RAID info &c. - not sure about exact command. – Vérace May 22 '15 at 1:32
  • I added some specs. I hope this is the relevant info that you need. – donquixote May 22 '15 at 11:36
2

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
  • Unfortunately, this does not change anything for me. Changed the my.cnf, sudo systemctl restart mysqld, run the query again.. (with new table name). No change :( – donquixote May 23 '15 at 0:09
  • oh, i have not checked the profiling yet! just the time reported by the client.. one momentito – donquixote May 23 '15 at 0:10
  • no, profile looks the same. I am going to do some more tests later, out of the house for now. – donquixote May 23 '15 at 0:15
  • Have one for me! :-) – Vérace May 23 '15 at 0:25
  • But interesting that you somehow do reproduce the crazy 0.3* second duration. It really should not be that long. – donquixote May 23 '15 at 7:03
1

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.

  • I have innodb_file_per_table on, because yes, the tables can get quite large. But the same is the case on my server vm. So, you are saying that creating the file for a new table can be slow depending on the filesystem? This does make sense, and is something I should look into. Is there a way to test this (speed of file creation) outside mysql? E.g. git clone creates a ton of files, but it is blazingly fast (if I clone from another folder, not from the web) – donquixote Jun 7 '15 at 0:24

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.