MySQL：COUNT(*)profileoptimizing阶段慢

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

创新互联公司坚持“要么做到，要么别承诺”的工作理念，服务领域包括：成都做网站、网站建设、外贸营销网站建设、企业官网、英文网站、手机端网站、网站推广等服务，满足客户于互联网时代的七里河网站设计、移动媒体设计的需求，帮助企业找到有效的互联网解决方案。努力成为您成熟可靠的网络建设合作伙伴！

一、问题

一个朋友@问心问我为什么在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=, buf=, offset=, n=) 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=) 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=, 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=, 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=, mtr=) 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=, match_mode=) 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=) 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=) 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 the expr in COUNT(expr) can never be null we can change this
          to the number of rows in the tables if this number is exact and
          there are no outer joins.
          Don't apply this optimization when there is a FORCE INDEX on any of
          the tables.
        */
        if (!conds && !((Item_sum_count*) item)->get_arg(0)->maybe_null &&
            !outer_tables && maybe_exact_count && !force_index)
        {          if (!is_exact_count)
          {            /*
              We will skip calling record count for explain query,
          since it might take long time to compute.
            */
            if (!thd->lex->describe &&
                (count= get_exact_record_count(tables)) == ULLONG_MAX) //这里调用了get_exact_record_count
            {              /* Error from handler in counting rows. Don't optimize count() */
              const_result= 0;              continue;
            }
            is_exact_count= 1;                  // count is now exact
          }
        }

作者微信：gp_22389860

网页标题：MySQL：COUNT(*)profileoptimizing阶段慢
网站路径：http://mswzjz.cn/article/iepjjh.html