One question I often get is how one can find out queries which should be optimized. By looking at pt-query-digest report it is easy to find slow queries or queries which cause the large portion of the load on the system but how do we know whenever there is any possibility to make this query run better ? The full answer to this question will indeed require complex analyses as there are many possible ways query can be optimized. There is however one extremely helpful metric which you can use – ratio between rows sent and rows analyzed. Lets look at this example:

# Time: 120911 17:09:44
# User@Host: root[root] @ localhost []
# Thread_id: 64914  Schema: sbtest  Last_errno: 0  Killed: 0
# Query_time: 9.031233  Lock_time: 0.000086  Rows_sent: 0  Rows_examined: 10000000  Rows_affected: 0  Rows_read: 0
# Bytes_sent: 213  Tmp_tables: 0  Tmp_disk_tables: 0  Tmp_table_sizes: 0
# InnoDB_trx_id: 12F03
use sbtest;
SET timestamp=1347397784;
select * from sbtest …

Recently there has been a storm of bugs and problems in all variants of MySQL including MySQL, Percona Server, and MariaDB. To list a few:

• MySQL 5.5.25
  UPDATE on InnoDB table enters recursion, consumes all disk space
• All MariaDB and MySQL versions up to 5.1.61, 5.2.11, 5.3.5, 5.5.22
  Security vulnerability in MySQL/MariaDB sql/password.c
• MySQL 5.1.61
  DSA-2429-1 mysql-5.1 — several vulnerabilities
• MySQL 5.5.25a
  Slave crash regression
• Percona Server 5.5.27-28.0 regression
  …

Ever ran into a situation where you saw “some important variable you really needed to know about=<optimized out>” while debugging? Let’s look at an example:

[Roel@qaserver master-data]$ gdb /percona-server/Percona-Server-5.5.25a-rel27.1-285.Linux.x86_64/bin/mysqld ./core.3200 
[...]
(gdb) bt
[...]
#20 handle_select (thd=0x33acd30, lex=0x33ae900, result=0x7f3e840058d0, setup_tables_done_option=1073741824)
    at /percona-server/5.5/Percona-Server-5.5.25a-rel27.1/sql/sql_select.cc:312
#21 mysql_execute_command (thd=thd@entry=0x33acd30)
    at /percona-server/5.5/Percona-Server-5.5.25a-rel27.1/sql/sql_parse.cc:3138
#22 mysql_parse (thd=thd@entry=0x33acd30, rawbuf=<optimized out>, length=72, parser_state=parser_state@entry=0x7f3ed013f810)
    at /percona-server/5.5/Percona-Server-5.5.25a-rel27.1/sql/sql_parse.cc:5809
#23 dispatch_command (command=COM_QUERY, thd=0x33acd30, packet=<optimized out>, …

While doing a performance audit for a customer a few weeks ago, I tried to improve the response time of their top slow query according to pt-query-digest‘s report. This query was run very frequently and had very unstable performance: during the time data was collected, response time varied from 50µs to 1s.

When I ran the query myself (a two-table join with a WHERE condition, the whole dataset was in memory), I always got a consistent response time (about 160ms). Of course, I wanted to know more about how MySQL executes this query. So I used commands you’re probably familiar with: EXPLAIN, SHOW PROFILE, SHOW STATUS LIKE 'Handler%'.
EXPLAIN and Handler counters only confirmed that the execution plan seemed reasonable and that fields were correctly indexed.

With SHOW PROFILE, I saw that most of the time was spent …

Inspiration for this post is courtesy of a friend and former colleague of mine, Greg Youngblood, who pinged me last week with an interesting MySQL puzzle. He was running Percona Server 5.5.21 with a table structure that looks something like this:

CREATE TABLE foo (
 id INT UNSIGNED NOT NULL AUTO_INCREMENT PRIMARY KEY,
 uid INT UNSIGNED NOT NULL,
 update_time DATETIME NOT NULL,
 ....
 INDEX `uid` (uid, update_time),
 INDEX `bar` (some_other_columns)
 ....
) ENGINE=InnoDB;

When he ran this query:

SELECT MIN(update_time) FROM foo WHERE update_time IS NOT NULL AND update_time <> '0000-00-00 00:00:00';

The result came back as 2012-06-22 10:28:16. However, when he ran a slightly different query:

SELECT MIN(t.update_time) FROM (SELECT uid, MIN(update_time) AS "update_time" FROM foo WHERE update_time IS NOT NULL AND update_time <> '0000-00-00 00:00:00' GROUP BY 1) t;

The answer which came …

When you process MySQL slow query logs using pt-query-digest you can store samples of each query into query_review table and historical values for review trend analysis into query_review_history table. But it could be difficult to easily browse those tables without a good GUI tool.

For the visual browsing of tables created by pt-query-digest you may want to use some kind of web tools besides phpMyAdmin

Query Digest UI

This is a advanced, but easy to install, ui for pt-query-digest or mk-query-digest.

Main features:
* Dynamic filtering and searching of queries
* Colorized and normalized SQL syntax
* Explain the query …

I got the message in the morning today about the bug being fixed in MySQL 5.6.6…. which I reported in Early 2006 (while still being with MySQL) and running MySQL 4.1 I honestly thought this issue was fixed long ago as it was indeed pretty annoying. I must say I’m very impressed with Oracle team going and cleaning up such very old bugs. Here is a description from the bug:

If you perform  match of constant which is too large  to the column
instead of simply responding with empty set MySQL   truncates the
constant, performs the lookup  and only when  discards results:

CREATE TABLE `trunc` (
  `i` int(11) NOT NULL default '0',
  KEY `i` (`i`)
) ENGINE=MyISAM DEFAULT CHARSET=utf8



mysql> select i,count(*) cnt from trunc  group by i order by cnt desc
limit 10;
+------------+-------+
| i          | cnt   |
+------------+-------+
| 2147483647 | 76047 |
| 1421638051 |     3 |
|  985505567 | …

If you ever had a replication slave that is severely behind, you probably noticed that it’s not catching up with a busy master at a steady pace. Instead, the “Seconds behind master” is going up and down so you can’t really tell whether the replica is catching up or not by looking at just few samples, unless these are spread apart. And even then you can’t tell at a glance when it is going to catch up.

Normally, the “severely behind” thing should not happen, but it does often happen in our consulting practice:

• sometimes replication would break and then it needs to catch up after it is fixed,
• other times new replication slave is built from a backup which is normally hours behind,
• or, it could be that replication slave became too slow to catch up due to missing index

Whatever the case is, single question I am being asked by the customer every time this happens is this: …

As an instructor with Percona I’m sometimes asked about the differences between the READ COMMITTED and REPEATABLE READ transaction isolation levels.  There are a few differences between READ-COMMITTED and REPEATABLE-READ, and they are all related to locking.

Extra locking (not gap locking)
It is important to remember that InnoDB actually locks index entries, not rows. During the execution of a statement InnoDB must lock every entry in the index that it traverses to find the rows it is modifying. It must do this to prevent deadlocks and maintain the isolation level.

If you run an UPDATE that is not well indexed you will lock many rows:

update employees set store_id = 0 where store_id = 1;
---TRANSACTION 1EAB04, ACTIVE 7 sec
633 lock struct(s), heap size 96696, 218786 row lock(s), undo log entries 1
MySQL thread id 4, OS thread handle 0x7f8dfc35d700, query id 47 localhost root …

You can use pt-query-digest to process a MySQL slow query log and store historical values for review trend analysis into query_review_history table. According to its official documentation you can populate many columns in that table but there are other important ones such as ‘user’, ‘host’, ‘db’ which are not included by default. I will explain how to implement this.

Also the documentation says:

Any columns not mentioned above are inspected to see if they follow a certain naming convention. The column is special if the name ends with an underscore followed by any of these MAGIC_history_cols values:

pct|avt|cnt|sum|min|max|pct_95|stddev|median|rank

…