MySQL索引选择不正确并详细解析OPTIMIZER_TRACE格式

一 表结构如下: 

CREATE TABLE t_audit_operate_log (
  Fid bigint(16) AUTO_INCREMENT,
  Fcreate_time int(10) unsigned NOT NULL DEFAULT '0',
  Fuser varchar(50) DEFAULT '',
  Fip bigint(16) DEFAULT NULL,
  Foperate_object_id bigint(20) DEFAULT '0',
  PRIMARY KEY (Fid),
  KEY indx_ctime (Fcreate_time),
  KEY indx_user (Fuser),
  KEY indx_objid (Foperate_object_id),
  KEY indx_ip (Fip)
) ENGINE=InnoDB DEFAULT CHARSET=utf8;

执行查询:

mysql> explain select count(*) from t_audit_operate_log where Fuser='XX@XX.com' and Fcreate_time>=1407081600 and Fcreate_time<=1407427199G

*************************** 1. row ***************************

id: 1

select_type: SIMPLE

table: t_audit_operate_log

type: ref

possible_keys: indx_ctime,indx_user

key: indx_user

key_len: 153

ref: const

rows: 2007326

Extra: Using where

发现,使用了一个不合适的索引, 不是很理想，于是改成指定索引：

mysql> explain select count(*) from t_audit_operate_log use index(indx_ctime) where Fuser='CY6016@cyou-inc.com' and Fcreate_time>=1407081600 and Fcreate_time<=1407427199G

*************************** 1. row ***************************

id: 1

select_type: SIMPLE

table: t_audit_operate_log

type: range

possible_keys: indx_ctime

key: indx_ctime

key_len: 5

ref: NULL

rows: 670092

Extra: Using where

实际执行耗时，后者比前者快了接近10

问题: 很奇怪，优化器为何不选择使用 indx_ctime 索引，而选择了明显会扫描更多行的 indx_user 索引。

分析2个索引的数据量如下:  两个条件的唯一性对比：

select count(*) from t_audit_operate_log where Fuser='XX@XX.com';
+----------+
| count(*) |
+----------+
| 1238382 | 
+----------+

select count(*) from t_audit_operate_log where Fcreate_time>=1407254400 and Fcreate_time<=1407427199;
+----------+
| count(*) |
+----------+
| 198920 | 
+----------+

显然,使用索引indx_ctime好于indx_user,但MySQL却选择了indx_user. 为什么?

于是,使用 OPTIMIZER_TRACE进一步探索.

二  OPTIMIZER_TRACE的过程说明

以本处事例简要说明OPTIMIZER_TRACE的过程.

查看OPTIMIZER_TRACE方法：

1.set optimizer_trace='enabled=on';    --- 开启trace

2.set optimizer_trace_max_mem_size=1000000;    --- 设置trace大小

3.set end_markers_in_json=on;    --- 增加trace中注释

4.select * from information_schema.optimizer_traceG;

{
  "steps": [
    {
      "join_preparation": {  ---优化准备工作
        "select#": 1,
        "steps": [
          {
            "expanded_query": "/* select#1 */ select count(0) AS `count(*)` from `t_audit_operate_log` where ((`t_audit_operate_log`.`Fuser` = 'XX@XX.com') and (`t_audit_operate_log`.`Fcreate_time` >= 1407081600) and (`t_audit_operate_log`.`Fcreate_time` <= 1407427199))"
          }
        ] /* steps */
      } /* join_preparation */
    },
    {
      "join_optimization": {  ---优化工作的主要阶段,包括逻辑优化和物理优化两个阶段
        "select#": 1,
        "steps": [  ---优化工作的主要阶段, 逻辑优化阶段
          {
            "condition_processing": {  ---逻辑优化,条件化简
              "condition": "WHERE",
              "original_condition": "((`t_audit_operate_log`.`Fuser` = 'XX@XX.com') and (`t_audit_operate_log`.`Fcreate_time` >= 1407081600) and (`t_audit_operate_log`.`Fcreate_time` <= 1407427199))",
              "steps": [
                {
                  "transformation": "equality_propagation",  ---逻辑优化,条件化简,等式处理
                  "resulting_condition": "((`t_audit_operate_log`.`Fuser` = 'XX@XX.com') and (`t_audit_operate_log`.`Fcreate_time` >= 1407081600) and (`t_audit_operate_log`.`Fcreate_time` <= 1407427199))"
                },
                {
                  "transformation": "constant_propagation",  ---逻辑优化,条件化简,常量处理
                  "resulting_condition": "((`t_audit_operate_log`.`Fuser` = 'XX@XX.com') and (`t_audit_operate_log`.`Fcreate_time` >= 1407081600) and (`t_audit_operate_log`.`Fcreate_time` <= 1407427199))"
                },
                {
                  "transformation": "trivial_condition_removal",  ---逻辑优化,条件化简,条件去除
                  "resulting_condition": "((`t_audit_operate_log`.`Fuser` = 'XX@XX.com') and (`t_audit_operate_log`.`Fcreate_time` >= 1407081600) and (`t_audit_operate_log`.`Fcreate_time` <= 1407427199))"
                }
              ] /* steps */
            } /* condition_processing */
          },  ---逻辑优化,条件化简,结束
          {
            "table_dependencies": [  ---逻辑优化, 找出表之间的相互依赖关系. 非直接可用的优化方式. 
              {
                "table": "`t_audit_operate_log`",
                "row_may_be_null": false,
                "map_bit": 0,
                "depends_on_map_bits": [
                ] /* depends_on_map_bits */
              }
            ] /* table_dependencies */
          },
          {
            "ref_optimizer_key_uses": [   ---逻辑优化,  找出备选的索引
              {
                "table": "`t_audit_operate_log`",
                "field": "Fuser",
                "equals": "'XX@XX.com'",
                "null_rejecting": false
              }
            ] /* ref_optimizer_key_uses */
          },
          {
            "rows_estimation": [   ---逻辑优化, 估算每个表的元组个数. 单表上进行全表扫描和索引扫描的代价估算. 每个索引都估算索引扫描代价
              {
                "table": "`t_audit_operate_log`",
                "range_analysis": {
                  "table_scan": {---逻辑优化, 估算每个表的元组个数. 单表上进行全表扫描的代价
                    "rows": 8150516,
                    "cost": 1.73e6
                  } /* table_scan */,
                  "potential_range_indices": [ ---逻辑优化, 列出备选的索引. 后续版本字符串变为potential_range_indexes
                    {
                      "index": "PRIMARY",---逻辑优化, 本行表明主键索引不可用
                      "usable": false,
                      "cause": "not_applicable"
                    },
                    {
                      "index": "indx_ctime",---逻辑优化, 索引indx_ctime
                      "usable": true,
                      "key_parts": [
                        "Fcreate_time",
                        "Fid"
                      ] /* key_parts */
                    },
                    {
                      "index": "indx_user",---逻辑优化, 索引indx_user
                      "usable": true,
                      "key_parts": [
                        "Fuser",
                        "Fid"
                      ] /* key_parts */
                    },
                    {
                      "index": "indx_objid",---逻辑优化, 索引
                      "usable": false,
                      "cause": "not_applicable"
                    },
                    {
                      "index": "indx_ip",---逻辑优化, 索引
                      "usable": false,
                      "cause": "not_applicable"
                    }
                  ] /* potential_range_indices */,
                  "setup_range_conditions": [ ---逻辑优化, 如果有可下推的条件,则带条件考虑范围查询
                  ] /* setup_range_conditions */,
                  "group_index_range": {---逻辑优化, 如带有GROUPBY或DISTINCT,则考虑是否有索引可优化这种操作. 并考虑带有MIN/MAX的情况
                    "chosen": false,
                    "cause": "not_group_by_or_distinct"
                  } /* group_index_range */,
                  "analyzing_range_alternatives": {---逻辑优化,开始计算每个索引做范围扫描的花费(等值比较是范围扫描的特例)
                    "range_scan_alternatives": [
                      {
                        "index": "indx_ctime", ---[A]
                        "ranges": [
                          "1407081600 <= Fcreate_time <= 1407427199"
                        ] /* ranges */,
                        "index_dives_for_eq_ranges": true,
                        "rowid_ordered": false,
                        "using_mrr": true,
                        "index_only": false,
                        "rows": 688362,
                        "cost": 564553, ---逻辑优化,这个索引的代价最小
                        "chosen": true ---逻辑优化,这个索引的代价最小,被选中. (比前面的table_scan 和其他索引的代价都小)
                      },
                      {
                        "index": "indx_user",
                        "ranges": [
                          "XX@XX.com <= Fuser <= XX@XX.com"
                        ] /* ranges */,
                        "index_dives_for_eq_ranges": true,
                        "rowid_ordered": true,
                        "using_mrr": true,
                        "index_only": false,
                        "rows": 1945894,
                        "cost": 1.18e6,
                        "chosen": false,
                        "cause": "cost"
                      }
                    ] /* range_scan_alternatives */,
                    "analyzing_roworder_intersect": {
                      "usable": false,
                      "cause": "too_few_roworder_scans"
                    } /* analyzing_roworder_intersect */
                  } /* analyzing_range_alternatives */,---逻辑优化,开始计算每个索引做范围扫描的花费. 这项工作结算
                  "chosen_range_access_summary": {---逻辑优化,开始计算每个索引做范围扫描的花费. 总结本阶段最优的.
                    "range_access_plan": {
                      "type": "range_scan",
                      "index": "indx_ctime",
                      "rows": 688362,
                      "ranges": [
                        "1407081600 <= Fcreate_time <= 1407427199"
                      ] /* ranges */
                    } /* range_access_plan */,
                    "rows_for_plan": 688362,
                    "cost_for_plan": 564553,
                    "chosen": true    -- 这里看到的cost和rows都比 indx_user 要来的小很多---这个和[A]处是一样的,是信息汇总.
                  } /* chosen_range_access_summary */
                } /* range_analysis */
              }
            ] /* rows_estimation */ ---逻辑优化, 估算每个表的元组个数. 行估算结束
          },
          {
            "considered_execution_plans": [ ---物理优化, 开始多表连接的物理优化计算
              {
                "plan_prefix": [
                ] /* plan_prefix */,
                "table": "`t_audit_operate_log`",
                "best_access_path": {
                  "considered_access_paths": [
                    {
                      "access_type": "ref", ---物理优化, 计算indx_user索引上使用ref方查找的花费,
                      "index": "indx_user",
                      "rows": 1.95e6,
                      "cost": 683515,
                      "chosen": true
                    }, ---物理优化, 本应该比较所有的可用索引,即打印出多个格式相同的但索引名不同的内容,这里却没有。推测是bug--没有遍历每一个索引.
                    {
                      "access_type": "range",---物理优化,猜测对应的是indx_time（没有实例可进行调试，对比5.7的跟踪信息猜测而得）
                      "rows": 516272,
                      "cost": 702225,---物理优化，代价大于了ref方式的683515，所以没有被选择
                      "chosen": false   -- cost比上面看到的增加了很多，但rows没什么变化 ---物理优化，此索引没有被选择
                    }
                  ] /* considered_access_paths */
                } /* best_access_path */,
                "cost_for_plan": 683515, ---物理优化，汇总在best_access_path 阶段得到的结果
                "rows_for_plan": 1.95e6,
                "chosen": true   -- cost比上面看到的竟然小了很多？虽然rows没啥变化  ---物理优化，汇总在best_access_path 阶段得到的结果
              }
            ] /* considered_execution_plans */
          },
          {
            "attaching_conditions_to_tables": {---逻辑优化，尽量把条件绑定到对应的表上
              } /* attaching_conditions_to_tables */
          },
          {
            "refine_plan": [
              {
                "table": "`t_audit_operate_log`",---逻辑优化，下推索引条件"pushed_index_condition"；其他条件附加到表上做为过滤条件"table_condition_attached"
              }
            ] /* refine_plan */
          }
        ] /* steps */
      } /* join_optimization */ ---逻辑优化和物理优化结束
    },
    {
      "join_explain": {} /* join_explain */
    }
  ] /* steps */

可以看到，即便是一条非常简单的SQL，也会打印出很冗长的查询计划。

 

当然你也可以把查询计划导入到文件中去，例如导入到一个命名为xx.trace的文件，然后用JSON阅读器来查看     

 

SELECT TRACE INTO DUMPFILE “xx.trace” FROM INFORMATION_SCHEMA.OPTIMIZER_TRACE;

 

官方文档给出了一个不错的例子，比这里的这个要复杂多了，有兴趣的同学可自行翻阅：http://dev.mysql.com/doc/internals/en/tracing-example.html

 

 

之前也写过博客，提及到optimizer trace的相关选项（http://mysqllover.com/?p=470 ）：

 

optimizer_trace有两个字段：

“enabled=on,one_line=off” ,可以通过set 进行字符串更新，前者表示打开optimizer_trace，后者表示打印的查询计划是否以一行显示，还是以json树的形式显示

我们可以在session级别来设这这个参数。

 

默认optimizer_trace_limit值为1，因此只会保存一条记录。这个设置需要重连session才能生效，另外一个变量optimizer_trace_offset通常与之配合使用，默认值为-1

 

例如，offset=-1, limit=1将显示最近一次trace

offset=-2,limit=1将显示最近的前一个trace。

offset=-5,limit=5 将最近的5次trace打印出来

 总的来说：

当offset大于0时，则会显示老的从offset开始的limit个trace，也就是说，新的trace没有记下来。

当offset小于0时，则会显示最新的-offset开始的limit个trace，也就是说，只显示新的trace

 注意重设变量会导致trace被清空

另外由于trace数据是存储在内存中的，因此还需要设置optimizer_trace_max_mem_size来限制内存的使用量，否则意外的设置可能导致内存爆掉。这是session级别，不应该设置的过大

 

optimizer_trace_limit和optimizer_trace_offset也影响占用内存大小，但不应该超过OPTIMIZER_TRACE_MAX_MEM_SIZE

 

 

另外，还有个参数optimizer_trace_features，可以控制打印到查询计划树的项，默认情况下是全部打开的，如下：

 

mysql> show variables like ‘optimizer_trace_features';

+————————–+—————————————————————————-+

| Variable_name            | Value                                                                      |

+————————–+—————————————————————————-+

| optimizer_trace_features | greedy_search=on,range_optimizer=on,dynamic_range=on,repeated_subselect=on |

+————————–+—————————————————————————-+

1 row in set (0.00 sec)

 

如果你不关心某些查询计划选项，可以将其关闭掉，只打印你关注的，这样可以减小查询计划树的输出，让其更可读一点。

 

greedy_search：对于有N个表的join操作，可能产生N的阶乘的查询计划路径；

range_optimizer：range优化

dynamic_range：dynamic range optimizer（也就是”range checked  for each row”，每个外部列会执行一次range optimizer）；如果关闭该选项的话，只有第一次调用JOIN_TAB::SQL_SELECT才被跟踪

repeated_subselect：子查询，如果关闭的话，只有第一次调用Item_subselect 才被跟踪

 

—————————————————-

TODO PLAN：增加阈值（读取的行数，或者执行的时间），超过阈值时，自动将trace导入到某个文件中，这样可以便于在线debug

 

参考：

 

http://dev.mysql.com/doc/internals/en/optimizer-features-to-trace.html

 

http://dev.mysql.com/doc/internals/en/system-variables-controlling-trace.html

 

http://guilhembichot.blogspot.com/2011/09/optimizer-tracing-how-to-configure-it.html

http://jorgenloland.blogspot.com/2011/10/optimizer-tracing-query-execution-plan.html