MySQL indexes behaving badly

If you have a MySQL query that for no apparent reason stops working or no longer behaves as it used to, the first thing to do is EXPLAIN it. If the explain is unreasonable (for example, using different indexes then it used to or using an index but still scanning millions or rows) then you should try to CHECK TABLE.

One thing that I accidently found out was that CHECK TABLE also updates the key statistics. This made many problems magically disappear.

A few things that should be noted:

1. CHECK TABLE will only update key statistics for MyISAM tables
, for InnoDB you must use OPTIMIZE TABLE.

2. If you use OPTIMIZE TABLE to update the key statistics you should be aware that OPTIMIZE TABLE does other (good) things as well, so it usually takes much longer and it locks your table while doing it. Also, for InnoDB it actually re-builds the table using ALTER TABLE.
   
3. The CHECK TABLE have several options. Only the MEDIUM (the default) or EXTENDED update the key statistics. (i think).

So, if your indexes stop working, or just mis-behave, try to check them.

slow lstat, slow php, slow drupal

If you are short on time go to bottom line.

Ok, the lstat() and stat() system calls system call are not really slow per se. But take a look at an apache strace -r dump from a drupal installation I was testing:

[user@host ~]# strace -o strace.load -r -s 256 -p <PID>
...
0.000081 getcwd("/mnt/var/www/html/drupal", 4096) = 32
0.000048 lstat("/mnt", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
0.000805 lstat("/mnt/var", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
0.001596 lstat("/mnt/var/www", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
0.000104 lstat("/mnt/var/www/html", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
0.000362 lstat("/mnt/var/www/html/drupal", {st_mode=S_IFDIR|0755, st_size=8192, ...}) = 0
0.000804 lstat("/mnt/var/www/html/drupal/sites", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
0.057575 lstat("/mnt/var/www/html/drupal/sites/all", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
0.000297 lstat("/mnt/var/www/html/drupal/sites/all/modules", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
0.014762 lstat("/mnt/var/www/html/drupal/sites/all/modules/Internet", {st_mode=S_IFDIR|0755, st_size=4096,
0.000214 lstat("/mnt/var/www/html/drupal/sites/all/modules/Internet/date", {st_mode=S_IFDIR|0755, st_size=4
0.000112 lstat("/mnt/var/www/html/drupal/sites/all/modules/Internet/date/date.module", {st_mode=S_IFREG|064
0.010816 open("/mnt/var/www/html/drupal/sites/all/modules/Internet/date/date.module", O_RDONLY) = 20
0.000835 fstat(20, {st_mode=S_IFREG|0644, st_size=44118, ...}) = 0
0.000069 lseek(20, 0, SEEK_CUR)    = 0
0.000063 stat("././sites/all/modules/Internet/date/date.module", {st_mode=S_IFREG|0644, st_size=44118, ...}) = 0
0.000159 close(20)                 = 0
...

As you can see, for every file included in the system there are around 10-15 lstat calls. this means that if we have ~200 files included we have ~2500 lstat calls per page. A simple sum on the strace results gave me ~8 seconds per page of lstat time, which was over a third of my test page time. see?

[user@host ~]# cat strace.single | awk '{printf " " $1 "\n " $2}' |sed 1d | sed \$d |awk '{printf $2 "+"}'  | sed s/.$/\\n/ | bc
21.204960
[user@host ~]# cat strace.single | awk '{printf " " $1 "\n " $2}' |sed 1d | sed \$d | fgrep lstat | awk '{printf $2 "+"}'  | sed s/.$/\\n/ | bc
8.361994

if you really want to understand this shell script let me know. It deserves a post by itself

Now we have 3 options: a) make lstat() faster. b) make php stop doing all those lstats(). c) make drupal include less files.

Well, (a) is not an option as our infrastructure team (aka sysadmins) insist there is nothing wrong with the filesystem and nothing can be done to enhance it's performance. Since I gave up being a sysadmin when it was still call 'sysadmin' it would be hard for me to prove them wrong (especially since they might be are right).

As (c) would require us to refactor most of our code in a very very 'not drupal way' and create very large php files, I was hoping to find a better solution.

By a rare chance of good fortune i came to learn about realpath_cache_size. Once I changed the foolish default to a reasonable 1M in php.ini, I lost most of the lstat() calls and over 10 seconds of processing time.

[user@host ~]# cat strace.2.single | awk '{printf " " $1 "\n " $2}' |sed 1d | sed \$d |awk '{printf $2 "+"}'  | sed s/.$/\\n/ | bc
9.752309
[user@host ~]# cat strace.2.single | awk '{printf " " $1 "\n " $2}' |sed 1d | sed \$d | fgrep lstat | awk '{printf $2 "+"}'  | sed s/.$/\\n/ | bc
.040935

Here is what to do in php.ini

; ...php.ini...
; Determines the size of the realpath cache to be used by PHP. This value should
; be increased on systems where PHP opens many files to reflect the quantity of
; the file operations performed.
 realpath_cache_size=1M

; Duration of time, in seconds for which to cache realpath information for a given
; file or directory. For systems with rarely changing files, consider increasing this
; value.
realpath_cache_ttl=300

For normal pages under normal load I was able to get a 10%-25% performance improvment. I think that's quite a bit for a configuration change.

MYSQL Query Optimization: Avoiding ORs

So, you've probably heard that using ORs in your queries is heavy and should be avoided when possible. Here is a live example. We had the following query running on a medium sized table in MYSQL (around 200K rows):

SELECT count(*)  FROM interactions p
   WHERE (
       (p.employer = 69 AND p.flag1 = 1)
       OR
       (p.employee = 69 AND p.flag2 = 0)
       )

Let's think of interactions as a table holding the interaction between employers and employees, and this query should tell the user the total number of interactions where user number 69 is involved.

The query looked pretty innoccent on an idle MYSQL server taking around 200ms, but when the server got busy the query execution time was reaching 5-6 seconds.

Altough we did have indexes on interactions.employer and interactions. employee doing EXPLAIN showed that MYSQL was not using them.

After some digging and fiddling and trying we ended up with:

SELECT count(*) as count FROM (
   SELECT 1  FROM interactions p
       WHERE (p.employer = 69 AND p.flag1 = 1)
   UNION ALL
   SELECT 1  FROM privatemsg p
       WHERE (p.employee = 69 AND p.flag2 = 0)
) t2

This query took on the busy server less then 250 milliseconds and less then 80ms on the idle server. Doing EXPLAIN showed that MYSQL was doing two queries, and using the correct index on each one.

After some more digging we noticed that if we EXPLAIN the original query on the idle server the optimizer occasionally converts it to a UNION, but for some reason this did not always happen and in any case took about twice the time then the UNION query.

To sum up the results here is a simple table

Query type	Server activity	Query Time
Using OR	Idle	200ms
Using OR	Busy	5500ms
Using UNION	Idle	78ms
Using UNION	Busy	189ms

Conclusion: always consider alternatives to OR, but make sure you check them well against real-time examples.

A Further Note: When timing queries in MYSQL alway use the optimizer hint /*! SQL_NO_CACHE */ to make sure you are not getting results from the query cache (if you have one set up).