发现瓶颈 - Profiling(程序剖析) - 剖析执行语句

剖析执行语句

结合FLUSH STATUS和SHOW SESSION STATUS对于查看语句执行和批量语句来说是非常有用的。这是优化语句的最佳方法。

 

让我们来看一个例子，首先，执行FLUSH STATUS把当前会话状态变量清零，因此你可以知道MySQL执行这个语句做了多少的工作。

 

mysql> FLUSH STATUS;

 

接下来，执行语句，我们添加了一个参数叫SQL_NO_CACHE。所以MySQL执行的语句并不是缓存所提供的。

 

 

mysql> SELECT SQL_NO_CACHE film_actor.actor_id, COUNT(*)

-> FROM sakila.film_actor

-> INNER JOIN sakila.actor USING(actor_id)

-> GROUP BY film_actor.actor_id

-> ORDER BY COUNT(*) DESC;

...

200 rows in set (0.18 sec)

 

 

这个查询语句返回了200行。但是它真正的做了什么？SHOW STATUS可以更深入的查看。首先，让我们看看服务器所提供查询计划（query plan）的类型.

 

mysql> SHOW SESSION STATUS LIKE 'Select%';

+------------------------+-------+

 

| Variable_name | Value |

+------------------------+-------+

| Select_full_join | 0 |

| Select_full_range_join | 0 |

| Select_range | 0 |

| Select_range_check | 0 |

| Select_scan | 2 |

+------------------------+-------+

 

 

看起来MySQL做了个全表扫描。如果这个语句调用了多个表。一些变量就大于0了。比如，如果MySQL对后面的表使用了范围扫描去查找匹配的行，Select_full_range_join就会有值了。我们甚至可以查看底层存储引擎操作语句的表现。

 

 

mysql> SHOW SESSION STATUS LIKE 'Handler%';

+----------------------------+-------+

| Variable_name | Value |

+----------------------------+-------+

| Handler_commit | 0 |

| Handler_delete | 0 |

| Handler_discover | 0 |

| Handler_prepare | 0 |

| Handler_read_first | 1 |

| Handler_read_key | 5665 |

| Handler_read_next | 5662 |

| Handler_read_prev | 0 |

| Handler_read_rnd | 200 |

| Handler_read_rnd_next | 207 |

| Handler_rollback | 0 |

| Handler_savepoint | 0 |

| Handler_savepoint_rollback | 0 |

| Handler_update | 5262 |

| Handler_write | 219 |

+----------------------------+-------+

 

 

"read"的值很高，说明了MySQL为了满足这个查询，扫描了不止一张表。正常来讲，如果MySQL仅仅扫描一张表的话，Handler_read_rnd_next值会非常高，以及Handler_read_rnd应该为0。

 

这个例子中，很多非0的值说明了MySQL肯定只用了临时表去满足不同的GROUP BY和ORDER BY条件。这就是Handler_write和Handler_update是非0值的原因：MySQL可能写入了一个临时表，对它扫描和排序以及再次扫描输出排序后的结果。让我们看看MySQL对排序结果做了什么。

 

 

mysql> SHOW SESSION STATUS LIKE 'Sort%';

+-------------------+-------+

| Variable_name | Value |

+-------------------+-------+

 

| Sort_merge_passes | 0 |

| Sort_range | 0 |

| Sort_rows | 200 |

| Sort_scan | 1 |

+-------------------+-------+

 

 

像我们想的一样，MySQL使用扫描了一个包含每条输出语句的临时表的方法对行进行了排序。如果这个值超过了200.我们就怀疑可能在语句执行的时候，它对另外一些进行了排序。我们也可以查看MySQL创建了多少张临时表。

 

 

 

mysql> SHOW SESSION STATUS LIKE 'Created%';

+-------------------------+-------+

| Variable_name | Value |

+-------------------------+-------+

| Created_tmp_disk_tables | 0 |

| Created_tmp_files | 0 |

| Created_tmp_tables | 5 |

+-------------------------+-------+

 

 

看到语句并不需要使用硬盘创建临时表，这是非常好的。因为使用硬盘会非常慢。但是也会有些疑惑，仅仅为了一个执行语句需要创建5个临时表么？

 

事实上，这个语句仅需要一个临时表。其实这是个假象，到底怎么回事？我们运行这个例子的环境为MySQL5.0.45，以及在MySQL5.0中使用SHOW STATUS实际上从INFORMATION_SCHEMA表中查询数据。我们称为观测语句的消耗。这回造成一些偏差。你可以再次运行SHOW STATUS 。

 

 

mysql> SHOW SESSION STATUS LIKE 'Created%';

+-------------------------+-------+

| Variable_name | Value |

+-------------------------+-------+

| Created_tmp_disk_tables | 0 |

| Created_tmp_files | 0 |

| Created_tmp_tables | 6 |

+-------------------------+-------+

 

 

注意这个值又增加了。Handler和其他变量也相应的被影响了。你的结果受影响的程度和MySQL版本有关系。

 

在MySQL4.1和较早的版本中，你也可以使用相同的过程-FLUSH STATUS,执行语句，运行SHOW STATUS.你仅仅需要的是一个空闲的服务器，因为在老版本中这些变量都是全局的。因此这些值可能会被其他的一些处理所改变。

 

为了降低由SHOW STATUS所造成了误差，最好的方法是运行两次，然后从第一次中减去第二次的结果。然后你再减去SHOW STATUS的消耗得到执行语句的正确结果。为了得到准确的结果，你也需要知道变量的作用范围，因此能知道哪些是观测语句造成的消耗。一些范围是每个会话的（per-session）,一些是全局的（global）.你可以用mk-query-profiler去自动化这些复杂的过程。

 

在MySQL连接的代码中，你可以整合这个自动化剖析。当程序剖析开启的时候，这个连接会在每个语句执行之前执行FLUSH STATUS以及在这之后记录日志。可选择的是，你可以对每页（per-page）进行程序剖析而不是每条执行语句。在语句执行的时候，每个策略都对得知MySQL的工作量非常有用。