Wie der MySQL Optimizer schummelt, wenn es um MySQL Cluster geht...

Thu, 2010-05-20 11:50 — oli

Bei einem Kunden sind wir auf ein nettes Beispiel gestossen, wie der MySQL Optimizer schummelt, wenn er mit dem MySQL Cluster zusammen arbeiten sollte. Dieser Kunde hat Abfragen, welche auf dem Entwicklungssystem nicht sonderlich langsam gelaufen sind. Aber wenn er diese Abfragen auf dem Abnahmetest-System (mit wesentlich mehr Daten) ausführt, benötigen diese viel zu viel Zeit, was für ihn nicht akzeptabel ist, da diese Abfragen mehrmals pro Sekunde abgesetzt werden können.

Was ist genau passiert?

Zu aller erst haben wir uns den Ausführungsplan der Abfragen angeschaut, welcher durch den MySQL Optimizer generiert wird:

EXPLAIN
SELECT t0.*, t1.*
  FROM t2
  JOIN t0 ON t2.t0_id = t0.id
  JOIN t1 ON t1.t0_id = t0.id
 WHERE t2.productnumber LIKE '%3301'
   AND t0.organization_id = 157
   AND t0.type = 'User';

1 row in set (8.78 sec)

+-------+--------+---------------------+---------------+---------+----------+------+-----------------------------------+
| table | type   | possible_keys       | key           | key_len | ref      | rows | Extra                             |
+-------+--------+---------------------+---------------+---------+----------+------+-----------------------------------+
| t0    | ref    | PRIMARY,ORG_ID,TYPE | ORG_ID        | 5       | const    |   10 | Using where with pushed condition |
| t1    | eq_ref | PRIMARY             | PRIMARY       | 4       | t0.id    |    1 |                                   |
| t2    | ref    | PRODUCTNUMBER       | PRODUCTNUMBER | 5       | t1.t0_id |    1 | Using where with pushed condition |
+-------+--------+---------------------+---------------+---------+----------+------+-----------------------------------+

Der Ausführungsplan schaut auf den ersten Blick nahezu perfekt aus. 10 Datensätze für die erste Tabelle (t0) und anschliessend ein Nested Loop Join über t1 und t2. Aber das Slow Query Log zeigt ein etwas anderes Bild:

# Query_time: 8.784943  Lock_time: 0.000367 Rows_sent: 1  Rows_examined: 40052

40052 Datensätze werden angelangt (Rows_examined) für ein Resultat von nur einem EINZIGEN Datensatz (Rows_sent). Gemäss dem Ausführungsplan sollten wir nicht mehr als 10 bis 30 Datensätze anlangen müssen (hängt davon ab, wie gezählt wird).

Der SHOW SESSION STATUS Befehl vor und nach der Abfrage gibt uns folgende Information:

SHOW SESSION STATUS LIKE 'ndb%count';

Vorher:

+--------------------------------+-----------+
| Variable_name                  | Value     |
+--------------------------------+-----------+
| Ndb_execute_count              | 0         |
| Ndb_scan_count                 | 0         |
+--------------------------------+-----------+

Nachher:

+--------------------------------+-----------+
| Variable_name                  | Value     |
+--------------------------------+-----------+
| Ndb_execute_count              | 40052     |
| Ndb_scan_count                 | 8         |
+--------------------------------+-----------+

Ndb_execute_count:	Zeigt die Anzahl der Round-Trips zum NDB Kernel, welche durch die Operationen durchgeführt wurden. [1]
Ndb_scan_count:	Diese Variable beinhaltet die Gesamtzahl ausgeführter Scans. [2]

Gemäss den GLOBAL STATUS VARIABLES verursachen wir 40052 Round-Trips zum Cluster und 8 Scans. Aus dem Ausführungsplan erwarte ich kleiner gleich 21 Round-Trips und 2 bis 3 Scans.

Mit dieser Information haben wir immherhin eine erste Spur gefunden, warum es so lange dauern könnte. Eine kleine Schätzung zeigt, dass wir auf der richtigen Fährte sind:

60 µs (ping) pro Round-Trip x 40052 Round-Trips = 2.4 Sekunden.

Mit 2.4 Sekunden sind wir zumindest bei der richtigen Grössenordnung für die Problemsuche angelangt.

Aber warum in aller Welt macht er 40k Round-Trips, wenn wir ca. 20 erwarten?

Versuchen wir händisch auszuführen, was der Optimizer tun sollte:

SELECT COUNT(*)
  FROM t0
 WHERE t0.organization_id = 157
   AND t0.type = 'User';

40044 rows in set (0.78 sec)

+-------+------+---------------+--------+---------+-------+------+-----------------------------------+
| table | type | possible_keys | key    | key_len | ref   | rows | Extra                             |
+-------+------+---------------+--------+---------+-------+------+-----------------------------------+
| t0    | ref  | ORG_ID,TYPE   | ORG_ID | 5       | const |   10 | Using where with pushed condition |
+-------+------+---------------+--------+---------+-------+------+-----------------------------------+

Aha! Der Ausführungsplan schaut gleich aus. Und die Abfrage gibt 40044 Datensätze (in 0.78 s) zurück anstatt nur 10!!! Also hat uns der Optimizer angeschummelt!

SHOW SESSION STATUS zeigt:

Ndb_execute_count = 1
Ndb_scan_count    = 1

Der zweite Schritt verursacht dann die grosse Anzahl von Round-Trips (und verbraucht die meiste Zeit):

SELECT COUNT(*)
  FROM t0
  JOIN t1 ON t1.t0_id = t0.id
 WHERE t0.organization_id = 157
   AND t0.type = 'User';

7 rows in set (8.73 sec)

Ndb_execute_count = 40044
Ndb_scan_count    = 1

Der letzte Schritt verursacht weitere 7 Round-Trips (7 Datensätze aus Schritt 2) und 6 Scans:

SELECT COUNT(*)
  FROM t2
  JOIN t0 ON t2.t0_id = t0.id
  JOIN t1 ON t1.t0_id = t0.id
 WHERE t2.productnumber LIKE '%3301'
   AND t0.organization_id = 157
   AND t0.type = 'User';

1 row in set (8.78 sec)

Ndb_execute_count = 7
Ndb_scan_count    = 6

Schluss: Der MySQL Optimizer hat die falsche Entscheidung getroffen, als er mit Tabelle t0 anfing.

Wir werden selber Optimizer

Jetzt wollen wir es besser machen... Welche Möglichkeiten haben wir?

Wir könnten anfangen mit:

Tabelle t2, indem wir eine Full-Table-Scan mit anschliessender Filterung oder einen Index-Scan mit anschliessender Filterung auf dem Kriterium t2.productnumber LIKE '%3301', welches ein "schlechter" Filter ist, machen.
Tabelle t0, indem wir einen Full-Table-Scan mit anschliessender Filterung oder einen Index-Scan mit anschliessener Filterung auf organization_id = 157 ODER type = 'User' (zur Zeit gibt es KEINEN kombinierten Index auf beide Attribute zusammen) machen.
Tabelle t1, indem wir einen Full-table-Scan machen (was der Cluster, so wie es aussieht, sowieso macht).

Somit suchen wir als besten Anfangspunk zuerst das kleinste Resultat, weil Round-Trips in MySQL Cluster Joins weh tun:

SELECT COUNT(*)
  FROM t2
 WHERE t2.productnumber LIKE '%3301';

--> 1 Datensatz

SELECT COUNT(*)
  FROM t0
 WHERE t0.organization_id = 157
   AND t0.type = 'User';

--> 40044 Datensätze (das kennen wir bereits und wissen, dass es schlecht ist)

SELECT COUNT(*)
  FROM t1;

--> 325 Datensätze

Mit Tabelle t2 in dieser speziellen Abfrage anzufangen und einen Full-Table-Scan zu riskieren sollte eine wesentlich besser Antwortzeit geben. Mehr über diese Technik finden Sie unter [3].

Um zu sehen, ob unsere Idee eine bessere Antwortzeit ergibt, zwingen wir den MySQL Optimizer den STRAIGHT_JOIN [4] Hint zu verwenden:

SELECT STRAIGHT_JOIN COUNT(*)
  FROM t2
  JOIN t0 ON t2.t0_id = t0.id
  JOIN t1 ON t1.t0_id = t0.id
 WHERE t2.productnumber LIKE '%3301'
   AND t0.organization_id = 157
   AND t0.type = 'User';

1 row in set (0.02 sec)

+----+-------------+-------+--------+---------------------+---------+---------+----------+------+-----------------------------------+
| id | select_type | table | type   | possible_keys       | key     | key_len | ref      | rows | Extra                             |
+----+-------------+-------+--------+---------------------+---------+---------+----------+------+-----------------------------------+
|  1 | SIMPLE      | t2    | ALL    | PRODUCTNUMBER       | NULL    | NULL    | NULL     | 1099 | Using where with pushed condition |
|  1 | SIMPLE      | t0    | eq_ref | PRIMARY,ORG_ID,TYPE | PRIMARY | 4       | t2.t0_id |    1 | Using where with pushed condition |
|  1 | SIMPLE      | t1    | eq_ref | PRIMARY             | PRIMARY | 4       | t0.id    |    1 | Using where                       |
+----+-------------+-------+--------+---------------------+---------+---------+----------+------+-----------------------------------+

Ndb_execute_count = 3
Ndb_scan_count    = 1

SELECT STRAIGHT_JOIN COUNT(*)
  FROM t2
  JOIN t1 ON t1.t0_id = t2.t0_id
  JOIN t0 ON t1.t0_id = t0.id
 WHERE t2.productnumber LIKE '%3301'
   AND t0.organization_id = 157
   AND t0.type = 'User';

1 row in set (0.02 sec)

+----+-------------+-------+--------+---------------------+---------+---------+----------+------+-----------------------------------+
| id | select_type | table | type   | possible_keys       | key     | key_len | ref      | rows | Extra                             |
+----+-------------+-------+--------+---------------------+---------+---------+----------+------+-----------------------------------+
|  1 | SIMPLE      | t2    | ALL    | PRODUCTNUMBER       | NULL    | NULL    | NULL     | 1099 | Using where with pushed condition |
|  1 | SIMPLE      | t1    | eq_ref | PRIMARY             | PRIMARY | 4       | t2.t0_id |    1 |                                   |
|  1 | SIMPLE      | t0    | eq_ref | PRIMARY,ORG_ID,TYPE | PRIMARY | 4       | t1.t0_id |    1 | Using where with pushed condition |
+----+-------------+-------+--------+---------------------+---------+---------+----------+------+-----------------------------------+

Ndb_execute_count 3
Ndb_scan_count    1

Es schaut so aus als ob Variante 2 und 3 mehr oder minder gleichwertig sind. Und wir haben die Abfrage von ca. 9 Sekunden auf ca. 20 ms (f=450!) verbessert.

Unglücklicherweise konnte der Kunde diese Lösung nicht akzeptieren, weil sein generisches Framework Abfrage-Hints nicht erlaubt und seine Applikation generisch auch für andere Datenbank-Backends sein soll.

Was mir als Alternative weiter in den Sinn kam, ist eine VIEW anzulegen um den Hint zu kapseln:

CREATE VIEW t2_t1_t0_v AS
SELECT STRAIGHT_JOIN t0.*, t1.*, t2.productnumber
  FROM t2
  JOIN t1 ON t1.t0_id = t2.t0_id
  JOIN t0 ON t1.t0_id = t0.id;

Aber es sieht danach aus, dass die Abfrage derart umgeschrieben wird, dass der Hint ignoriert wird:

EXPLAIN
SELECT COUNT(*)
  FROM t2_t1_t0_v
 WHERE productnumber LIKE '%3301'
   AND organization_id = 157
   AND type = 'User';

+----+-------------+-------+--------+---------------------+---------------+---------+----------+------+-----------------------------------+
| id | select_type | table | type   | possible_keys       | key           | key_len | ref      | rows | Extra                             |
+----+-------------+-------+--------+---------------------+---------------+---------+----------+------+-----------------------------------+
|  1 | SIMPLE      | t0    | ref    | PRIMARY,ORG_ID,TYPE | ORG_ID        | 5       | const    |   10 | Using where with pushed condition |
|  1 | SIMPLE      | t1    | eq_ref | PRIMARY             | PRIMARY       | 4       | t0.id    |    1 |                                   |
|  1 | SIMPLE      | t2    | ref    | PRODUCTNUMBER       | PRODUCTNUMBER | 5       | t1.t0_id |    1 | Using where                       |
+----+-------------+-------+--------+---------------------+---------------+---------+----------+------+-----------------------------------+

Wenn die Abfrage wie folgt (mit Hint) abgesetzt wird, wird sie wieder in der richtigen Reihenfolge ausgeführt. Aber das wollen wir ja gerade wegen unserem Kunden vermeiden...

SELECT STRAIGHT_JOIN COUNT(*)
  FROM t2_t1_t0_v
 WHERE productnumber LIKE '%3301'
   AND organization_id = 157
   AND type = 'User';

Gemäss MySQL ist das kein Bug sonderen ein "Feature Request"... :-( Mehr Informationen können Sie finden unter MySQL Bug #28700.

Risiken

Ein Problem mit Hints ist, das sie zukünftigen MySQL Releases/Features die Möglichkeit nehmen, Ihre volle Pracht zu entfalten, wenn Sie denn irgendwann einmal in ferner Zukunft implementiert werden sollten. Zum Beispiel wenn BKA (batched key access) [9] oder Push-Down-Joins [5] wahr werden oder wenn der Optimizer schlauer wird und die MySQL Cluster Datenverteilung kennt und damit besser Schätzungen macht. Wir verbauen uns damit möglicherweise besser Ausführungspläne in der Zukunft.
Ein zweiter Problem ist, dass das Beginnen mit einem Full-Table-Scan auf t2 nicht skaliert, wenn die Menge der Daten in Zukunft grösser wird. An einem bestimmten Punkt wird der Full-Table-Scan langsamer werden als 40k Round-Trips.
Was wir in diesem Artikel überhaupt noch nicht angeschaut haben, ist dass es noch grosses Verbesserungspotential bei der Daten- und Tabellenstruktur für das Filterkriterium auf t2 gibt. Eine Suche nach "%xyz% ist für die Datenbank schlecht und führt zu einem Scan. Wenn der Inhalt des Feldes gedreht wird in "zyx%' kann eine Suche den Index nutzen und ein Full-Table-Scan wird vermieden.
Wenn der Trick mit der VIEW funktioniert hätte, gäbe es ein weiteres Problem: Weil die VIEW im SQL Node gespeichert wird und nicht im MySQL Cluster, muss sichergestellt werden, das ALLE SQL Nodes synchron gehalten werden und dass das Backup der VIEWs richtig gemacht wird. Dies ist nicht ganz einfach mit MySQL Cluster in Kombination mit Objekten, welche auf den SQL Nodes gespeichert sind.
Wenn das Filterkriterium auf t2 nicht so selektiv wäre, würde der Trick so nicht funktionieren.

Was haben wir daraus gelernt?

Die Menge der Testdaten ist relevant. Wenn Sie wesentlich mehr Daten auf dem Produktionssystem als auf dem Testsystem haben werden Sie nicht auf die Performance-Probleme stossen, bis sie Life gehen. Also füllen Sie Ihr Testsystem with der selbe Menge an Daten, wie Ihr Produktivsystem, oder zumindest Ihr Acceptance-Test-System.

Der MySQL Optimizer schummelt, weil ihm die wirkliche Datenverteilung nicht bekannt ist. Der MySQL Optimizer arbeitet zur Zeit am besten mit MyISAM/Maria zusammen. Ein "guter" Ausführungsplan für die selbe Abfrage mit MyISAM/Maria Tabellen sieht wie folgt aus:

+----+-------------+-------+--------+---------------------+---------------+---------+----------+------+-------------+
| id | select_type | table | type   | possible_keys       | key           | key_len | ref      | rows | Extra       |
+----+-------------+-------+--------+---------------------+---------------+---------+----------+------+-------------+
|  1 | SIMPLE      | t1    | ALL    | PRIMARY             | NULL          | NULL    | NULL     |  325 |             |
|  1 | SIMPLE      | t2    | ref    | PRODUCTNUMBER       | PRODUCTNUMBER | 5       | t1.t0_id |    3 | Using where |
|  1 | SIMPLE      | t0    | eq_ref | PRIMARY,ORG_ID,TYPE | PRIMARY       | 4       | t1.t0_id |    1 | Using where |
+----+-------------+-------+--------+---------------------+---------------+---------+----------+------+-------------+

Wir könnten auch diese Möglichkeit noch probieren...

Die ndb_%count Status Variable ist irgendwie nicht korrekt implementiert oder die Dokumentation beschreibt nicht das aktuelle verhalten. Siehe auch MySQL bug #52940.
Hints und VIEWs arbeiten nicht wie erwartet zusammen.
MySQL Cluster führt mehr Scans als erwartet aus. Aber wir können dies zumindest mit der ndb_%count Status Variablen nachweisen.

Weitere Untersuchungen

In der Dokumentation sind einige Parameter zu finden (ndb_index_stat_cache_entries, ndb_index_stat_enable und ndb_index_stat_update_freq [7]) welche den Eindruck vermitteln, dass Sie hier helfen könnten. Aber wir haben keine Möglichkeit gefunden, wie wir mit diesen Variablen das Verhalten des MySQL Optimizers beeinflussen können. Wenn uns jemand einen Hinweis oder ein Beispiel dazu zukommen lässt, würde uns dies sehr freuen.