8

When looking at a particularly annoying query over MyISAM tables which takes a long time to execute on a number of occasions, I have noted that MySQL seems to expose a rather strange I/O pattern: when executing a single query and having to do a significant amount of I/O (e.g for a table scan or when caches are empty as a result of echo 3 > /proc/sys/vm/drop_caches so the indexes need to be loaded off disk first), the queue size for the underlying block device is near the value 1, with abysmal performance of just 4-5 MB/s:

root@mysql-test:~# iostat -xdm 5 /dev/sda
Linux 3.2.0-40-generic (mysql-test)  04/30/2014      _x86_64_        (4 CPU)

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sda               0.14    24.82   18.26   88.79     0.75     4.61   102.56     2.83   26.39   19.29   27.85   2.46  26.31

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sda               0.00    69.29  151.52   72.73     5.31     0.59    53.95     1.21    5.39    7.84    0.29   4.39  98.51

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sda               0.00   153.06  144.29  174.69     4.96     1.36    40.54     1.39    4.36    8.91    0.60   3.15 100.49

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sda               0.00   105.75  150.92  109.03     4.53     0.85    42.41     1.29    4.96    8.15    0.54   3.90 101.36

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sda               0.00    48.89  156.36   51.72     5.28     0.76    59.38     1.28    6.16    8.02    0.55   4.77  99.23

While the 150 IOPS simply are what a single disk in the given configuration is capable of delivering in terms of random I/O, the result still really surprises me as I would expect MySQL be able to run asynchronous I/O for reads and fetch a large amount of blocks simultaneously instead of reading and evaluating them one-by-one, effectively neglecting parallelization gains available in RAID configurations. What design decision or configuration option is responsible for this? Is this a platform-specific issue?

While I have tested this with large-ish MyISAM tables, I see similar effects with the same tables converted to InnoDB (although not as bad, the sample query still takes 20-30 seconds with most of the time being spent on reading the disk with a queue length of 1) after I restart the mysql daemon and therefore the buffer pools are empty. I also have verified that the same issue persists on 5.6 GA and the current 5.7 milestone 14 - as long as I am using a single query thread, MySQL seems unable to parallelize the I/O operations necessary for query processing.


As per request some additional details on the scenario. The behavior can be observed with a multitude of query types. I have arbitrarily chosen one for further testing which reads somewhat like this:

SELECT herp.id, herp.firstname, herp.lastname, derp.label, herp.email, 
(SELECT CONCAT(label, " (", zip_code, " ", city,")" ) FROM subsidiaries WHERE subsidiaries.id=herp.subsidiary_id ) AS subsidiary, 
(SELECT COUNT(fk_herp) from herp_missing_data WHERE fk_herp=herp.id) AS missing_data
FROM herp LEFT JOIN derp ON derp.id=herp.fk_derp
WHERE (herp.fk_pools='123456')  AND herp.city LIKE '%Some City%' AND herp.active='yes' 
ORDER BY herp.id desc LIMIT 0,10;

I know that it has some room for optimization, but I decided to leave it at that for a number of reasons and concentrate on finding a general explanation for the unexpected I/O pattern I am seeing.

The used tables do have a bunch of data in them:

mysql> select table_name, engine, table_rows, data_length, index_length from information_schema.tables WHERE tables.TABLE_SCHEMA = 'mydb' and tables.table_name in ( 'herp', 'derp', 'missing_data', 'subsidiaries');
+-------------------------+--------+------------+-------------+--------------+
| table_name              | engine | table_rows | data_length | index_length |
+-------------------------+--------+------------+-------------+--------------+
| derp                    | MyISAM |      14085 |     1118676 |       165888 |
| herp                    | MyISAM |     821747 |   828106512 |    568057856 |
| missing_data            | MyISAM |    1220186 |    15862418 |     29238272 |
| subsidiaries            | MyISAM |       1499 |     6490308 |       103424 |
+-------------------------+--------+------------+-------------+--------------+
4 rows in set (0.00 sec)

Now when I am running the query above over these tables, I am getting execution times of over 1 Minute while the system is apparently continuously busy reading data off disk with a single thread.

The profile for a sample query execution (which took 1 min 9.17 secs in this example) looks like this:

mysql> show profile for query 1;
+--------------------------------+-----------+
| Status                         | Duration  |
+--------------------------------+-----------+
| starting                       |  0.000118 |
| Waiting for query cache lock   |  0.000035 |
| init                           |  0.000033 |
| checking query cache for query |  0.000399 |
| checking permissions           |  0.000077 |
| checking permissions           |  0.000030 |
| checking permissions           |  0.000031 |
| checking permissions           |  0.000035 |
| Opening tables                 |  0.000158 |
| init                           |  0.000294 |
| System lock                    |  0.000056 |
| Waiting for query cache lock   |  0.000032 |
| System lock                    |  0.000116 |
| optimizing                     |  0.000063 |
| statistics                     |  0.001964 |
| preparing                      |  0.000104 |
| Sorting result                 |  0.000033 |
| executing                      |  0.000030 |
| Sending data                   |  2.031349 |
| optimizing                     |  0.000054 |
| statistics                     |  0.000039 |
| preparing                      |  0.000024 |
| executing                      |  0.000013 |
| Sending data                   |  0.000044 |
| optimizing                     |  0.000017 |
| statistics                     |  0.000021 |
| preparing                      |  0.000019 |
| executing                      |  0.000013 |
| Sending data                   | 21.477528 |
| executing                      |  0.000070 |
| Sending data                   |  0.000075 |
| executing                      |  0.000027 |
| Sending data                   | 45.692623 |
| end                            |  0.000076 |
| query end                      |  0.000036 |
| closing tables                 |  0.000109 |
| freeing items                  |  0.000067 |
| Waiting for query cache lock   |  0.000038 |
| freeing items                  |  0.000080 |
| Waiting for query cache lock   |  0.000044 |
| freeing items                  |  0.000037 |
| storing result in query cache  |  0.000033 |
| logging slow query             |  0.000103 |
| cleaning up                    |  0.000073 |
+--------------------------------+-----------+
44 rows in set, 1 warning (0.00 sec)
  • Do you have a repeatable (ideally simple) test case you could explain in more detail? E.g. a query that generates this behavior? Under what circumstances? You started down that road with "echo 3 >..." & "restart the mysql daemon" but didn't go into detail. – Scott Leadley May 5 '14 at 12:14
  • @ScottLeadley thanks for looking into this. I do not think I would be able to make it "simple" - the issue only would be observable if a largeish amount of data would need to be read for a single query and it would be mostly random I/O. Tables and queries are reasonably straightforward and while I could post the DDL and Query texts, I doubt anybody would be able to reproduce it right away unless the table / index data has grown to hundreds of Megabytes. – syneticon-dj May 5 '14 at 13:04
  • As you alluded to, the 5 ms await for reads is consistent with a the average rotational latency of one 5400 RPM disk. Seek contention when reading "a largeish amount of data ... mostly random I/O" would account for that. As for RAID, you've mentioned it, but haven't given any details of this specific configuration. – Scott Leadley May 5 '14 at 13:29
  • Not sure I can help you directly, because I don't run your config. But the StackExchange rule of thumb is that a really good question gets more attention than a bounty. Writing the perfect question – Scott Leadley May 5 '14 at 13:31
  • @ScottLeadley the 5 ms await are mostly due to the latency of the employed storage system. I have tested this in different scenarios - from a simple 4-disk RAID10 to a tiered storage filer with a 16-disk shelf and SSD backing, the results consistently show that the I/O load is not parallelized and thus latency-bound. Which I feel is fundamentally wrong. I have added the query details to the question, but I am not yet convinced they would be of great help. – syneticon-dj May 5 '14 at 13:49
8
+50

First let me clarify by confirming that MyISAM does not do asynchronous I/O, but that InnoDB does and will by default from MySQL 5.5. Prior to 5.5 it used "simulated AIO" by using worker threads.

I think it is also important to distinguish between three situations:

  1. Multiple queries executing at once
  2. A single query executing in parallel
  3. Some sort of logical read ahead for table scans / clear cases where the next pages are well known.

For (1) I/O will be able to execute in parallel for this. There are some limits with MyISAM: table locking and a global lock protecting the key_buffer (index cache). InnoDB in MySQL 5.5+ really shines here.

For (2) this is currently not supported. A good use case would be with partitioning, where you could search each partitioned table in parallel.

For (3) InnoDB has linear read-ahead to read a full extent (group of 64 pages) if >56 pages are read (this is configurable), but there is room for further enhancement. Facebook has written about implementing logical-readhead in their branch (with a 10x perf gain on tablescans).

  • Thanks, this gives me some additional understanding of what I am seeing. Does that generally mean that MyISAM is unable to utilize more than one disk worth of IOPS for a single-threaded load? I cannot find any references to this in the docs - do you happen to have something handy? – syneticon-dj May 8 '14 at 11:54
  • Yes. I can't think of a place in the docs where this would be. – Morgan Tocker May 8 '14 at 14:44
2

I hope missing_data is not MyISAM because an empty MyISAM table usually has a 1024 byte .MYI. A nonzero byte size is expected of a MyISAM. A zero byte .MYI sounds a little creepy to me.

If you run this metadata query

select table_name, table_rows, data_length, index_length, engine
from information_schema.tables
WHERE tables.TABLE_SCHEMA = 'mydb'
and tables.table_name = 'missing_data';

and that table's engine is MyISAM, you need to repair it.

SIDE NOTE : If the engine is NULL, it's a view. If it is a view or it's not MyISAM, please ignore the rest of my post and add that info to the question. If the table is MyISAM, read on...

According to your metadata query, missing_data.MYD is about 46M.

First, run this

SHOW CREATE TABLE mydb.missing_data\G

You will either get the table description or an error message saying something like

ERROR 126 (HY000): Incorrect key file for table ...

If you get the table description and it is MyISAM, please run

OPTIMIZE TABLE mydb.missing_data;

It will recreate the table with no fragmentation and compute fresh index statistics. If that does not work then try:

REPAIR TABLE mydb.missing_data;

That should regenerate the index pages for the MyISAM.

Just to be safe (if using MySQL 5.6), run this after the repair

FLUSH TABLES mydb.missing_data;

Your Question

The indexes of your table may not be loaded into memory if the MySQL Query Optimizer decides not to use. If your WHERE clause dictates the a significant amount of row have to be read from the indexes, MySQL Query Optimizer will see that when constructing the EXPLAIN plan and decide to use a full table scan instead.

Parallel I/O operations on a MyISAM table is unattainable because it is unconfigurable.

InnoDB can be tuned for increase performance like that.

  • I must empasize it again: If mydb.missing_data is MyISAM and has a zero byte index, something is definitely wrong. – RolandoMySQLDBA May 6 '14 at 2:39
  • I've updated the data to be more coherent - it now shows MyISAM-only results from a single host so folks would not get confused. – syneticon-dj May 6 '14 at 13:20

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.