Shulou(Shulou.com)06/01 Report--

Make a brief record for later analysis

First, problems

A friend @ asked me why I was slow in 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 | 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 | 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 | +-- +-+ + II. Previous knowledge

Because the optimizer part didn't take a close look at it, but recorded some stages of the call interface.

Starting:lex+yacc syntax semantic parsing, get parsing tree checking permissions: authority check Opening tables: open the table to do a good table cache, do a good job with the innodb table physical file association, while adding MDL LOCK main function open_tablesinit: statement to do the first optimization call function SELECT_LEX::prepare and st_select_lex::prepareSystem lock: the main function handler::ha_external_lock, before the implementation of myisam and other engines of the mysql layer table lock, innodb as a shared table lock.

The following three stages correspond to logical and physical optimization execution plan generation: optimizing: SELECT_LEX::optimize- > JOIN::optimize call, statistics: JOIN::make_join_plan call, preparing: make_join_select call

So it's still weird.

Third, stack frame

When a friend prints the stack frame, the problem is found, but the actual data access phase of count (*) is advanced as follows:

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, nasty 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, nasty 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, nasty 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, nasty 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\", 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

You can take a look. In fact, here we can see that we have reached the innodb layer and are reading data. This stage is unexpectedly transferred by optimizing, of course, it is also in the optimizing stage.

Fourth, the source code calls into one, opt_sum_query part 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 is called here. Don't optimize count () * / const_result= 0; continue;} is_exact_count= 1; / / count is now exact}}

Author Wechat: gp_22389860

Welcome to subscribe "Shulou Technology Information " to get latest news, interesting things and hot topics in the IT industry, and controls the hottest and latest Internet news, technology news and IT industry trends.