maria-developers team mailing list archive

[Elena Stepanova <elenst@xxxxxxxxxxxxxxxx>]

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