Hi all,
Over the last couple of days, some of you have seen or even participated
in a "thread" on #maria IRC channel regarding the performance problem on
query execution that james_woods observed on MariaDB 10.0 instance
comparing to a Percona 5.5 instance. This email is for those who are
curious about the outcome/current status.
Summary
-------
The original complaint sounded like this:
"After switching to MariaDB 10 I see 5-10 very long running queries -
which are not using indices as they do on Percona 5.5."
The data in both instances is exactly the same.
The HW is essentially different, but it's better on the machine with
MariaDB 10.
After some back-and-forth, the complaint got split into three main parts:
- the query is considerably slower on MariaDB 10.0 instance than on
Percona 5.5 instance;
- the query plans show very different row counts, although the data is
identical;
- Percona uses indices when MariaDB doesn't.
Sergei Petrunia investigated the alleged issues with query plans and
found that there was no problem:
- the row counts that Percona 5.5 reported for derived tables were
smaller because EXPLAIN in Percona 5.5 had actually executed the query.
- the difference in index usage was an effect of table elimination. A
table was removed, hence no index use for it was shown in the explain.
He also broke down the query and got a simple flat one, without
subqueries, which still revealed ~4x difference in execution time.
Upon his request, I ran some tests locally to see if I could reproduce
such a difference between Percona 5.5 and MariaDB 10.0 and found that I
couldn't (of course I don't have the HW that james_woods uses, the but
the difference this big was likely to be seen anywhere).
Meanwhile, james_woods installed Percona 5.5 on the machine where
MariaDB 10.0 was running, and didn't get any performance gain -- that
is, the difference was not between Percona 5.5 and MariaDB 10.0, but was
caused by something else (HW, environment, ...). As of now, we don't
know what it is.
(end of summary).
Sergei asked me to share the numbers I got while running the local
tests. I will also put here the initial queries and explains, for the
reference.
It's mainly for the record, there is nothing particularly interesting in
here; if you stop reading now, you won't lose much.
Queries and plans
-----------------
The initial offending query:
SELECT SUM(visits) FROM (
SELECT
IFNULL(ref.probename_unique_visits,'tr_trafficother2_uv')
AS probename,
SUM(x.value) AS visits,
IFNULL(ref.category,'Other') AS category
FROM (
SELECT
aggregated_data._getSource(source, source2, source3, fb_source,
request_ids) AS source,
COUNT(DISTINCT u.fbuserid) AS value
FROM g9_tracker.app_logins u
WHERE u.created_date = '2014-04-22'
GROUP BY 1
) x
LEFT JOIN aggregated_data.ref_parameter_mappings ref
ON (ref.value_of_ref_parameter = x.source)
GROUP BY 1,3
) y;
EXPLAINs (that's where row counts were off; note EXPLAIN execution time):
MariaDB 10.0:
+------+-------------+------------+------+-------------------------------+-------------------------------+---------+----------+---------+---------------------------------+
| id | select_type | table | type | possible_keys
| key | key_len | ref | rows | Extra
|
+------+-------------+------------+------+-------------------------------+-------------------------------+---------+----------+---------+---------------------------------+
| 1 | PRIMARY | <derived2> | ALL | NULL
| NULL | NULL | NULL | 3394453 |
|
| 2 | DERIVED | <derived3> | ALL | NULL
| NULL | NULL | NULL | 3394453 | Using
temporary; Using filesort |
| 2 | DERIVED | ref | ref | value_of_ref_parameter_UNIQUE
| value_of_ref_parameter_UNIQUE | 603 | x.source | 1 | Using
where |
| 3 | DERIVED | u | ALL | NULL
| NULL | NULL | NULL | 3394453 | Using
where; Using filesort |
+------+-------------+------------+------+-------------------------------+-------------------------------+---------+----------+---------+---------------------------------+
4 rows in set (0,03 sec)
Percona 5.5:
+----+-------------+------------+------+-------------------------------+-------------------------------+---------+----------+---------+---------------------------------+
| id | select_type | table | type | possible_keys |
key | key_len | ref | rows | Extra
|
+----+-------------+------------+------+-------------------------------+-------------------------------+---------+----------+---------+---------------------------------+
| 1 | PRIMARY | <derived2> | ALL | NULL |
NULL | NULL | NULL | 15 |
|
| 2 | DERIVED | <derived3> | ALL | NULL |
NULL | NULL | NULL | 75 | Using
temporary; Using filesort |
| 2 | DERIVED | ref | ref | value_of_ref_parameter_UNIQUE |
value_of_ref_parameter_UNIQUE | 603 | x.source | 1 |
|
| 3 | DERIVED | u | ALL | NULL |
NULL | NULL | NULL | 3669609 | Using
filesort |
+----+-------------+------------+------+-------------------------------+-------------------------------+---------+----------+---------+---------------------------------+
4 rows in set (1 min 40,20 sec)
Example of the indices difference (caused by table elimination):
Query:
SELECT COUNT(*) FROM (
SELECT
aggregated_data._getSource(source, source2, source3, fb_source,
request_ids) AS source,
COUNT(DISTINCT u.fbuserid) AS value
FROM g9_tracker.app_logins u
WHERE u.created_date = '2014-04-22'
GROUP BY 1
) x
LEFT JOIN aggregated_data.ref_parameter_mappings ref
ON (ref.value_of_ref_parameter = x.source);
EXPLAINs:
MariaDB 10.0:
+------+-------------+------------+------+---------------+------+---------+------+---------+----------+-----------------------------+
| id | select_type | table | type | possible_keys | key |
key_len | ref | rows | filtered | Extra |
+------+-------------+------------+------+---------------+------+---------+------+---------+----------+-----------------------------+
| 1 | PRIMARY | <derived2> | ALL | NULL | NULL | NULL
| NULL | 3394453 | 100.00 | |
| 2 | DERIVED | u | ALL | NULL | NULL | NULL
| NULL | 3394453 | 100.00 | Using where; Using filesort |
+------+-------------+------------+------+---------------+------+---------+------+---------+----------+-----------------------------+
2 rows in set, 1 warning (0,02 sec)
Percona 5.5:
+----+-------------+------------+------+-------------------------------+-------------------------------+---------+----------+---------+----------+----------------+
| id | select_type | table | type | possible_keys |
key | key_len | ref | rows | filtered
| Extra |
+----+-------------+------------+------+-------------------------------+-------------------------------+---------+----------+---------+----------+----------------+
| 1 | PRIMARY | <derived2> | ALL | NULL |
NULL | NULL | NULL | 75 | 100.00
| |
| 1 | PRIMARY | ref | ref | value_of_ref_parameter_UNIQUE |
value_of_ref_parameter_UNIQUE | 603 | x.source | 1 | 100.00
| Using index |
| 2 | DERIVED | u | ALL | NULL |
NULL | NULL | NULL | 3669609 | 100.00
| Using filesort |
+----+-------------+------------+------+-------------------------------+-------------------------------+---------+----------+---------+----------+----------------+
3 rows in set, 1 warning (1 min 43,62 sec)
Numbers
-------
The query that Sergei suggested to run in local tests:
SELECT
SUM(varchar_non_indexed_column_with_non_empty_different_values='foo')
FROM table_with_3_mio_rows
I ran tests on Percona 5.5/5.6, MariaDB 5.5/10.0, MySQL 5.5/5.6. Only
the relevant results are here, I'll skip the rest.
For every run the caches were cleaned, the server was started, and then
the queries were executed, 3 times each.
Initially servers were run with the default options (not server default,
but packaging default, how they are installed on Wheezy).
The difference between 5.5 and 5.6/10.0 was astonishing, but it was
explained by Performance Schema. It went like this:
5.5
select sum(c2='foo') from t_innodb;
1 row in set (8.17 sec)
1 row in set (0.99 sec)
1 row in set (0.95 sec)
select sum(c2='foo') from t_myisam;
1 row in set (3.04 sec)
1 row in set (0.56 sec)
1 row in set (0.55 sec)
5.6 / 10.0
select sum(c2='foo') from t_innodb;
1 row in set (24.24 sec)
1 row in set (21.65 sec)
1 row in set (23.43 sec)
select sum(c2='foo') from t_myisam;
1 row in set (18.83 sec)
1 row in set (17.23 sec)
1 row in set (16.05 sec)
Pretty much the same picture for MariaDB, Percona and MySQL. It would
explain everything, but it turned out that james_woods already had
Performance Schema turned off.
(Note: we *really* should consider switching off Performance schema, at
least in configs provided upon the new package installation).
Then I ran another test, with the PS turned off, and otherwise default
options (now really default, without any pre-installed config).
There was still a difference between 5.5 and 5.6/10.0, although not that
big, and for InnoDB only:
Percona 5.5
select sum(c2='foo') from t_innodb;
1 row in set (5.97 sec)
1 row in set (0.79 sec)
1 row in set (0.79 sec)
select sum(c2='foo') from t_myisam;
1 row in set (3.68 sec)
1 row in set (0.56 sec)
1 row in set (0.56 sec)
Percona 5.6
select sum(c2='foo') from t_innodb;
1 row in set (7.33 sec)
1 row in set (2.32 sec)
1 row in set (1.48 sec)
select sum(c2='foo') from t_myisam;
1 row in set (2.90 sec)
1 row in set (0.59 sec)
1 row in set (0.59 sec)
MariaDB 5.5
select sum(c2='foo') from t_innodb;
1 row in set (8.17 sec)
1 row in set (0.99 sec)
1 row in set (0.95 sec)
select sum(c2='foo') from t_myisam;
1 row in set (3.04 sec)
1 row in set (0.56 sec)
1 row in set (0.55 sec)
MariaDB 10.0
select sum(c2='foo') from t_innodb;
1 row in set (7.34 sec)
1 row in set (2.07 sec)
1 row in set (2.07 sec)
select sum(c2='foo') from t_myisam;
1 row in set (3.49 sec)
1 row in set (0.58 sec)
1 row in set (0.57 sec)
MySQL 5.6
select sum(c2='foo') from t_innodb;
1 row in set (7.88 sec)
1 row in set (1.95 sec)
1 row in set (2.11 sec)
select sum(c2='foo') from t_myisam;
1 row in set (4.11 sec)
1 row in set (0.55 sec)
1 row in set (0.57 sec)
So, on 5.6/10.0 with default options the query from the "warm" InnoDB
table was approximately 2x slower than on 5.5.
Then I took non-default options from james_woods and applied them, as
much as I could, considering the HW difference, to my modest VM. In
fact, only innodb_buffer_pool_size mattered. After doubling it on
5.6/10.0, I got pretty much the same results as on 5.5.
Percona 5.5 (default options)
select sum(c2='foo') from t1;
1 row in set (5.97 sec)
1 row in set (0.79 sec)
1 row in set (0.79 sec)
Percona 5.6 (default options + no PS + increased buffer pool)
select sum(c2='foo') from t1;
1 row in set (8.33 sec)
1 row in set (0.83 sec)
1 row in set (0.82 sec)
MariaDB 5.5 (default options)
select sum(c2='foo') from t1;
1 row in set (8.17 sec)
1 row in set (0.99 sec)
1 row in set (0.95 sec)
MariaDB 10.0 (default options + no PS + increased buffer pool)
select sum(c2='foo') from t1;
1 row in set (7.85 sec)
1 row in set (0.86 sec)
1 row in set (0.86 sec)
There are still some minor differences, but my VM is not suitable for
fine-grained performance testing. If somebody wants to investigate it
further, it should be done in a proper way; in any case I'm sure it can
be tuned and made to perform better on 5.6/10.0, nobody who cares about
differences this small actually runs the server with default options.
Regards,
/E
