Forum Home
Press F1
 
Thread ID: 123821 2012-03-18 09:44:00 MySQL Performance Problem Erayd (23) Press F1
Post ID Timestamp Content User
1265694 2012-03-18 09:44:00 Hi Guys,

I've hit a fascinating performance issue with MySQL, where a query that should return one row within a few seconds max instead takes all day, and still doesn't return any rows - I ended up killing the query after letting it run for 12.5 hours. The same query phrased slightly differently finishes in 1.28 seconds, and returns one row.

As if this wasn't enough, the system load average also *drops* while the dodgy query is running - once the query is killed, it climbs back up where it ought to be.

The table (currently contains 1,026,619 rows):
CREATE TABLE `download` (
`id` int(10) unsigned NOT NULL AUTO_INCREMENT,
`when` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP,
`source` varchar(255) NOT NULL,
`format` varchar(16) NOT NULL,
`init` tinyint(3) unsigned NOT NULL,
`ip` varchar(40) DEFAULT NULL,
`uuid` varchar(40) DEFAULT NULL,
`mem` int(11) DEFAULT NULL,
`cpu` int(11) DEFAULT NULL,
PRIMARY KEY (`id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8;

The query that works:
SELECT
DISTINCT uuid
FROM download d
INNER JOIN (
SELECT DISTINCT ip ip
FROM download
WHERE uuid = '9988dcaa-6479-4181-93f3-67b09d19d78f'
) i
ON i.ip = d.ip;

The query that fails:
SELECT
DISTINCT uuid
FROM download
WHERE ip IN (
SELECT DISTINCT ip ip
FROM download
WHERE uuid = '9988dcaa-6479-4181-93f3-67b09d19d78f'
);

If I delete all but the most recent 5,000 rows from the table, the problematic query will finish executing in around 10 seconds - which means it's not deadlocked, but is definitely doing something incredibly inefficient.


mysql> SELECT DISTINCT uuid FROM download WHERE ip IN ( SELECT DISTINCT ip ip FROM download WHERE uuid = '9988dcaa-6479-4181-93f3-67b09d19d78f' );
+--------------------------------------+
| uuid |
+--------------------------------------+
| 9988dcaa-6479-4181-93f3-67b09d19d78f |
+--------------------------------------+
1 row in set (10.30 sec)

mysql> SELECT COUNT(1) FROM download;
+----------+
| count(1) |
+----------+
| 5000 |
+----------+
1 row in set (0.00 sec)


root@thoth:~# mysqld --version
mysqld Ver 5.1.49-3 for debian-linux-gnu on x86_64 ((Debian))

The server it's running on has a 6-core Xeon X5670 (2.93GHz) with HT enabled, and 12GB of RAM. While the problem query is running, mysqld uses 150% CPU (i.e. 1.5 cores). At all other times, mysqld uses essentially no CPU at all.

So yeah... any bright ideas about why this query could be so horribly inefficient, or why the system load average drops when it's run, would be greatly appreciated. I'm officially stumped, and it's bugging me, dammit! 		Erayd (23)
1265695 2012-03-30 12:11:00 Bump... Erayd (23)
1265696 2012-03-30 20:38:00 Have you tried kicking it? fred_fish (15241)
1265697 2012-03-30 21:03:00 I wonder... with the failing query:


SELECT
DISTINCT uuid
FROM download
WHERE ip IN (
SELECT DISTINCT ip ip
FROM download
WHERE uuid = '9988dcaa-6479-4181-93f3-67b09d19d78f'
);


Assuming you either don't have appropriate indexes, or the optimizer is choosing not to use the indexes for whatever reason, whether this is how it's executing it:

-For each row in download...
-- full table scan through every row in the "download" table to select rows which match the uuid
-- sorting the result set
-- getting unique results from the sorted result set
- match the ip from the outer to the inner query
- sort the result set
- get unique results

This could be 1,026,619 full table scans through the "download" table for the inner query, or in other words, going through 1053946571161 rows.

Are you able to do an explain plan or similar for the query, and if so, how does it claim to actually be executing it? 		somebody (208)
1265698 2012-03-30 21:35:00 What does iostat (and iotop) say is going on when the dodgy query is running? Is it causing a lot of I/O? somebody (208)
1265699 2012-03-31 00:17:00 Have you tried kicking it?Sadly this isn't an option, as the server in question is located in Philadelphia.


Are you able to do an explain plan or similar for the query, and if so, how does it claim to actually be executing it?
mysql> EXPLAIN SELECT
-> DISTINCT uuid
-> FROM download d
-> INNER JOIN (
-> SELECT DISTINCT ip ip
-> FROM download
-> WHERE uuid = '9988dcaa-6479-4181-93f3-67b09d19d78f'
-> ) i
-> ON i.ip = d.ip;
+----+-------------+------------+------+---------------+------+---------+------+---------+--------------------------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
+----+-------------+------------+------+---------------+------+---------+------+---------+--------------------------------+
| 1 | PRIMARY | <derived2> | ALL | NULL | NULL | NULL | NULL | 32 | Using temporary |
| 1 | PRIMARY | d | ALL | NULL | NULL | NULL | NULL | 1099414 | Using where; Using join buffer |
| 2 | DERIVED | download | ALL | NULL | NULL | NULL | NULL | 1099414 | Using where; Using temporary |
+----+-------------+------------+------+---------------+------+---------+------+---------+--------------------------------+
3 rows in set (0.38 sec)

mysql> EXPLAIN SELECT
-> DISTINCT uuid
-> FROM download
-> WHERE ip IN (
-> SELECT DISTINCT ip ip
-> FROM download
-> WHERE uuid = '9988dcaa-6479-4181-93f3-67b09d19d78f'
-> );
+----+--------------------+----------+------+---------------+------+---------+------+---------+------------------------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
+----+--------------------+----------+------+---------------+------+---------+------+---------+------------------------------+
| 1 | PRIMARY | download | ALL | NULL | NULL | NULL | NULL | 1099529 | Using where; Using temporary |
| 2 | DEPENDENT SUBQUERY | download | ALL | NULL | NULL | NULL | NULL | 1099529 | Using where; Using temporary |
+----+--------------------+----------+------+---------------+------+---------+------+---------+------------------------------+
2 rows in set (0.00 sec)
So yes, it's definitely very inefficient, but it's inefficient for both queries - it just happens that one of them is unusable, whereas the other one runs in a couple of seconds.

The table currently has no indexes, but I've also tried it with indexes, and that didn't help at all.


What does iostat (and iotop) say is going on when the dodgy query is running? Is it causing a lot of I/O?Nope, MySQL uses almost zero I/O while this thing is running. It uses 150% CPU constantly when the failing query is running though. 		Erayd (23)
1