MySQL：COUNT(*) profile optimizing阶段慢

简单记录一下，以供后面分析

一、问题

一个朋友@问心问我为什么在optimizing 阶段会慢

Mysql> show profiles; 
+----------+------------+----------------------------------------+| Query_ID | Duration   | Query                                  |+----------+------------+----------------------------------------+|        1 | 0.00399900 | SHOW VARIABLES LIKE '%profiling%'      ||        2 | 6.62358725 | select count(*) from cw_base_snap_flow |+----------+------------+----------------------------------------+2 rows in set, 1 warning (0.00 sec)
mysql> show profile block io,cpu for query 2;
+----------------------+----------+-----------+------------+--------------+---------------+| Status               | Duration | CPU_user  | CPU_system | Block_ops_in | Block_ops_out |
+----------------------+----------+-----------+------------+--------------+---------------+
| starting             | 0.000073 |  0.000112 |   0.000004 |            0 |             0 || checking permissions | 0.000012 |  0.000022 |   0.000002 |            0 |             0 |
| Opening tables       | 0.000033 |  0.000063 |   0.000003 |            0 |             0 || init                 | 0.000017 |  0.000032 |   0.000002 |            0 |             0 |
| System lock          | 0.000018 |  0.000033 |   0.000002 |            0 |             0 || optimizing           | 6.623237 | 17.625023 |   2.907697 |        22520 |         63424 |
| executing            | 0.000040 |  0.000053 |   0.000004 |            0 |             0 || end                  | 0.000011 |  0.000019 |   0.000001 |            0 |             0 |
| query end            | 0.000014 |  0.000028 |   0.000000 |            0 |             0 || closing tables       | 0.000015 |  0.000028 |   0.000002 |            0 |             0 |
| freeing items        | 0.000023 |  0.000042 |   0.000003 |            0 |             0 || logging slow query   | 0.000070 |  0.000133 |   0.000007 |            0 |             8 |
| cleaning up          | 0.000027 |  0.000051 |   0.000003 |            0 |             0 |+----------------------+----------+-----------+------------+--------------+---------------+

二、以前的认识

因为优化器部分没有怎么仔细看过但记录了一些阶段的调入接口

• starting:lex+yacc 语法语义解析,得到解析树
• checking permissions:权限检查
• Opening tables:打开表做好table cache，做好和innodb表物理文件的关联，同时加MDL LOCK 主要函数open_tables
• init:语句做首次优化 调入函数SELECT_LEX::prepare及st_select_lex::prepare
• System lock:主要函数handler::ha_external_lock，之前会实现myisam等引擎的mysql层表锁，innodb做共享表锁。
  下面三个阶段对应 逻辑物理优化执行计划生成：
• optimizing: SELECT_LEX::optimize->JOIN::optimize 调入，
• statistics: JOIN::make_join_plan调入，
• preparing: make_join_select 调入

所以还是比较奇怪

三、栈帧

放朋友打印了一下栈帧才发现问题，居然count(*)的实际数据访问阶段提前了如下：

Thread 1 (process 33641):#0  0x00007f20e284ca93 in pread64 () from /lib64/libpthread.so.0#1  0x00000000010649c3 in os_file_io (in_type=..., file=56, buf=0x7f20b2a08000, n=16384, offset=4458364928, err=0x7f1f2de82a9c) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/storage/innobase/os/os0file.cc:5423#2  0x0000000001065221 in os_file_pread (err=0x7f1f2de82a9c, offset=4458364928, n=16384, buf=0x7f20b2a08000, file=56, type=...) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/storage/innobase/os/os0file.cc:5601#3  os_file_read_page (type=..., file=56, buf=0x7f20b2a08000, offset=4458364928, n=16384, o=0x0, exit_on_err=true) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/storage/innobase/os/os0file.cc:5640#4  0x0000000001065767 in os_file_read_func (type=..., file=<optimized out>, buf=<optimized out>, offset=<optimized out>, n=<optimized out>) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/storage/innobase/os/os0file.cc:6033#5  0x00000000012056eb in pfs_os_aio_func (src_line=5758, m2=0x7f20ae782388, m1=0xc9235e8, read_only=false, n=16384, offset=4458364928, buf=0x7f20b2a08000, file=56, name=0xc9236b8 "./bat/cw_base_snap_flow.ibd", mode=24, type=..., src_file=<optimized out>) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/storage/innobase/include/os0file.ic:252#6  fil_io (type=..., sync=true, page_id=..., page_size=..., byte_offset=139771890905024, len=16384, buf=0x7f20b2a08000, message=0x7f20ae782388) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/storage/innobase/fil/fil0fil.cc:5758#7  0x00000000011bd2b2 in buf_read_page_low (err=0x7f1f2de833ac, sync=true, type=0, mode=<optimized out>, page_id=..., page_size=..., unzip=false) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/storage/innobase/buf/buf0rea.cc:183#8  0x00000000011bdd20 in buf_read_page (page_id=..., page_size=...) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/storage/innobase/buf/buf0rea.cc:406#9  0x000000000119c9eb in buf_page_get_gen (page_id=..., page_size=..., rw_latch=1, guess=<optimized out>, mode=10, file=0x15fe390 "/export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/storage/innobase/btr/btr0pcur.cc", line=448, mtr=0x7f1f2de837f0, dirty_with_no_latch=false) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/storage/innobase/buf/buf0buf.cc:4180#10 0x0000000001185841 in btr_block_get_func (mtr=0x7f1f2de837f0, line=448, file=0x15fe390 "/export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/storage/innobase/btr/btr0pcur.cc", mode=1, page_size=..., page_id=...) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/storage/innobase/include/btr0btr.ic:63#11 btr_pcur_move_to_next_page (cursor=0x7f1e18271c40, mtr=0x7f1f2de837f0) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/storage/innobase/btr/btr0pcur.cc:448#12 0x00000000010dfc22 in btr_pcur_move_to_next (cursor=<optimized out>, mtr=<optimized out>) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/storage/innobase/include/btr0pcur.ic:360#13 0x00000000010e5019 in row_search_mvcc (buf=0x7f1e18221768 "@\027\"\030\036\177", mode=PAGE_CUR_G, prebuilt=0x7f1e18271a48, match_mode=0, direction=1) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/storage/innobase/row/row0sel.cc:5872
#14 0x00000000010c3960 in row_search_for_mysql (direction=1, prebuilt=0x7f1e18271a48, buf=0x7f1e18221768 "@\027\"\030\036\177", mode=<optimized out>, match_mode=<optimized out>) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/storage/innobase/include/row0sel.ic:139#15 row_scan_index_for_mysql (prebuilt=0x7f1e18271a48, index=0x7f1ec01ad8d8, check_keys=false, n_rows=0x7f1f2de86438) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/storage/innobase/row/row0mysql.cc:5896#16 0x0000000000ff815b in ha_innobase::records (this=0x7f1e1826da90, num_rows=0x7f1f2de87200) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/storage/innobase/handler/ha_innodb.cc:13280#17 0x0000000000e4e0ee in ha_records (num_rows=0x7f1f2de87200, this=0x7f1e1826da90) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/sql/handler.h:2668#18 get_exact_record_count (tables=<optimized out>) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/sql/opt_sum.cc:84#19 opt_sum_query (thd=0x7f1e18012170, tables=0x7f1e180016a8, all_fields=..., conds=0x0) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/sql/opt_sum.cc:347#20 0x0000000000ceba8f in JOIN::optimize (this=0x7f1e18001db8) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/sql/sql_optimizer.cc:293#21 0x0000000000d301d2 in st_select_lex::optimize (this=0x7f1e18000940, thd=0x7f1e18012170) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/sql/sql_select.cc:1009#22 0x0000000000d3046f in handle_query (thd=0x7f1e18012170, lex=0x7f1e180142b8, result=0x7f1e18001ce8, added_options=1, removed_options=0) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/sql/sql_select.cc:164#23 0x0000000000cf1cc3 in execute_sqlcom_select (thd=0x7f1e18012170, all_tables=<optimized out>) at /export/home/pb2/build/sb_0-19699473-1468327072.46/mysql-5.7.14/sql/sql_parse.cc:5143

大家可以看看。实际上这里我们可以看到已经到了innodb层并且在读取数据了。这个阶段居然是optimizing调入的，当然也就在optimizing阶段了。

四、源码调入

一、opt_sum_query 部分

case Item_sum::COUNT_FUNC:        
        if (!conds && !((Item_sum_count*) item)->get_arg(0)->maybe_null &&
            !outer_tables && maybe_exact_count && !force_index)
        {          if (!is_exact_count)
          {            
            if (!thd->lex->describe &&
                (count= get_exact_record_count(tables)) == ULLONG_MAX) //这里调用了get_exact_record_count
            {              
              const_result= 0;              continue;
            }
            is_exact_count= 1;                  // count is now exact
          }
        }

作者微信：gp_22389860