背景:
今天遇到一个主键范围查找的情况:
select ... from tb left join tb1 on ... where tb.id between 0 and 10000
id是主键,每次取10000。上面的这个查询id范围越往后面消耗的时间越久。通过id自增主键去查找数据应该不会出现这个现象的。以前都没有注意这个奇怪的现象,现在就好好分析下。
知识点:
索引的根节点到子节点的距离是一样的,根节点包含指向子节点的指针,存储引擎通过指针来查找数据。所以通过索引查找他们的消耗是一样的。
测试:
1:SQL结构:
explain select sql_no_cache post.id, post.root, post.boardId, post.postTime, post.subject, post.file, body.body, post.userId, post.click, post.child, post.type, post.rating, post.votes, topic.approved, topic.archived, topic.reply, user.status from j_post as post left join j_post_body as body on post.id = body.id left join j_topic as topic on post.id=topic.id left join j_user as user on user.id=post.userId where post.id between 1090000 and 1100000; +----+-------------+-------+--------+---------------+---------+---------+------------------+-------+-------------+ | id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra | +----+-------------+-------+--------+---------------+---------+---------+------------------+-------+-------------+ | 1 | SIMPLE | post | range | PRIMARY | PRIMARY | 4 | NULL | 17876 | Using where | | 1 | SIMPLE | body | eq_ref | PRIMARY | PRIMARY | 4 | jute.post.id | 1 | | | 1 | SIMPLE | topic | eq_ref | PRIMARY | PRIMARY | 4 | jute.post.id | 1 | | | 1 | SIMPLE | user | eq_ref | PRIMARY | PRIMARY | 4 | jute.post.userId | 1 | | +----+-------------+-------+--------+---------------+---------+---------+------------------+-------+-------------+
执行的状况:
1090000 and 1100000 >show profile cpu,block io for query 1; +----------------------+----------+----------+------------+--------------+---------------+ | Status | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out | +----------------------+----------+----------+------------+--------------+---------------+ | starting | 0.000156 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000008 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000004 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000004 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000008 | 0.000000 | 0.000000 | 0 | 0 | | Opening tables | 0.000062 | 0.000000 | 0.000000 | 0 | 0 | | System lock | 0.000017 | 0.000000 | 0.000000 | 0 | 0 | | init | 0.000068 | 0.000000 | 0.000000 | 0 | 0 | | optimizing | 0.000021 | 0.000000 | 0.000000 | 0 | 0 | | statistics | 0.001326 | 0.004001 | 0.000000 | 0 | 0 | | preparing | 0.000030 | 0.000000 | 0.000000 | 0 | 0 | | executing | 0.000006 | 0.000000 | 0.000000 | 0 | 0 | | Sending data | 0.640303 | 0.384024 | 0.028001 | 0 | 0 | | end | 0.000020 | 0.000000 | 0.000000 | 0 | 0 | | query end | 0.000008 | 0.000000 | 0.000000 | 0 | 0 | | closing tables | 0.000016 | 0.000000 | 0.000000 | 0 | 0 | | freeing items | 0.000026 | 0.000000 | 0.000000 | 0 | 0 | | logging slow query | 0.000006 | 0.000000 | 0.000000 | 0 | 0 | | cleaning up | 0.000008 | 0.000000 | 0.000000 | 0 | 0 | +----------------------+----------+----------+------------+--------------+---------------+ 19 rows in set (0.01 sec) 21000000 and 21010000 >show profile cpu,block io for query 2; +----------------------+----------+----------+------------+--------------+---------------+ | Status | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out | +----------------------+----------+----------+------------+--------------+---------------+ | starting | 0.000161 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000010 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000004 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000005 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000008 | 0.000000 | 0.000000 | 0 | 0 | | Opening tables | 0.000042 | 0.000000 | 0.000000 | 0 | 0 | | System lock | 0.000015 | 0.000000 | 0.000000 | 0 | 0 | | init | 0.000065 | 0.000000 | 0.000000 | 0 | 0 | | optimizing | 0.000022 | 0.000000 | 0.000000 | 0 | 0 | | statistics | 0.017431 | 0.000000 | 0.000000 | 144 | 0 | | preparing | 0.000031 | 0.000000 | 0.000000 | 0 | 0 | | executing | 0.000006 | 0.000000 | 0.000000 | 0 | 0 | | Sending data | 3.228074 | 0.696043 | 0.164010 | 45936 | 0 | | end | 0.000020 | 0.000000 | 0.000000 | 0 | 0 | | query end | 0.000009 | 0.000000 | 0.000000 | 0 | 0 | | closing tables | 0.000018 | 0.000000 | 0.000000 | 0 | 0 | | freeing items | 0.000052 | 0.000000 | 0.000000 | 0 | 0 | | logging slow query | 0.000008 | 0.000000 | 0.000000 | 0 | 0 | | cleaning up | 0.000009 | 0.000000 | 0.000000 | 0 | 0 | +----------------------+----------+----------+------------+--------------+---------------+ 19 rows in set (0.01 sec) 26000000 and 26010000 >show profile cpu,block io for query 3; +----------------------+----------+----------+------------+--------------+---------------+ | Status | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out | +----------------------+----------+----------+------------+--------------+---------------+ | starting | 0.000146 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000008 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000004 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000004 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000007 | 0.000000 | 0.000000 | 0 | 0 | | Opening tables | 0.000042 | 0.000000 | 0.000000 | 0 | 0 | | System lock | 0.000015 | 0.000000 | 0.000000 | 0 | 0 | | init | 0.000065 | 0.000000 | 0.000000 | 0 | 0 | | optimizing | 0.000021 | 0.000000 | 0.000000 | 0 | 0 | | statistics | 0.013855 | 0.004000 | 0.000000 | 392 | 0 | | preparing | 0.000064 | 0.000000 | 0.000000 | 0 | 0 | | executing | 0.000009 | 0.000000 | 0.000000 | 0 | 0 | | Sending data | 4.075430 | 0.676042 | 0.140009 | 82288 | 0 | | end | 0.000021 | 0.000000 | 0.000000 | 0 | 0 | | query end | 0.000010 | 0.000000 | 0.000000 | 0 | 0 | | closing tables | 0.000019 | 0.000000 | 0.000000 | 0 | 0 | | freeing items | 0.000050 | 0.000000 | 0.000000 | 0 | 0 | | logging slow query | 0.000007 | 0.000000 | 0.000000 | 0 | 0 | | cleaning up | 0.000009 | 0.000000 | 0.000000 | 0 | 0 | +----------------------+----------+----------+------------+--------------+---------------+ 19 rows in set (0.03 sec) 6000000 and 6010000 >show profile cpu,block io for query 4; +----------------------+----------+----------+------------+--------------+---------------+ | Status | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out | +----------------------+----------+----------+------------+--------------+---------------+ | starting | 0.000164 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000008 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000004 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000005 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000008 | 0.000000 | 0.000000 | 0 | 0 | | Opening tables | 0.000041 | 0.000000 | 0.000000 | 0 | 0 | | System lock | 0.000015 | 0.000000 | 0.000000 | 0 | 0 | | init | 0.000064 | 0.000000 | 0.000000 | 0 | 0 | | optimizing | 0.000021 | 0.000000 | 0.000000 | 0 | 0 | | statistics | 0.013467 | 0.004000 | 0.000000 | 392 | 0 | | preparing | 0.000032 | 0.000000 | 0.000000 | 0 | 0 | | executing | 0.000006 | 0.000000 | 0.000000 | 0 | 0 | | Sending data | 1.345275 | 0.476030 | 0.084005 | 19848 | 0 | | end | 0.000021 | 0.000000 | 0.000000 | 0 | 0 | | query end | 0.000042 | 0.000000 | 0.000000 | 0 | 0 | | closing tables | 0.000022 | 0.000000 | 0.000000 | 0 | 0 | | freeing items | 0.000058 | 0.000000 | 0.000000 | 0 | 0 | | logging slow query | 0.000015 | 0.000000 | 0.000000 | 0 | 0 | | cleaning up | 0.000012 | 0.000000 | 0.000000 | 0 | 0 | +----------------------+----------+----------+------------+--------------+---------------+ 19 rows in set (0.02 sec) 27000000 and 27010000 >show profile cpu,block io for query 5; +----------------------+----------+----------+------------+--------------+---------------+ | Status | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out | +----------------------+----------+----------+------------+--------------+---------------+ | starting | 0.000144 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000007 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000004 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000004 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000007 | 0.000000 | 0.000000 | 0 | 0 | | Opening tables | 0.000041 | 0.000000 | 0.000000 | 0 | 0 | | System lock | 0.000016 | 0.000000 | 0.000000 | 0 | 0 | | init | 0.000065 | 0.000000 | 0.000000 | 0 | 0 | | optimizing | 0.000021 | 0.000000 | 0.000000 | 0 | 0 | | statistics | 0.011399 | 0.000000 | 0.000000 | 208 | 0 | | preparing | 0.000032 | 0.000000 | 0.000000 | 0 | 0 | | executing | 0.000006 | 0.000000 | 0.000000 | 0 | 0 | | Sending data | 3.157346 | 0.616038 | 0.176011 | 71840 | 0 | | end | 0.000021 | 0.000000 | 0.000000 | 0 | 0 | | query end | 0.000054 | 0.000000 | 0.000000 | 0 | 0 | | closing tables | 0.000020 | 0.000000 | 0.000000 | 0 | 0 | | freeing items | 0.000056 | 0.000000 | 0.000000 | 0 | 0 | | logging slow query | 0.000007 | 0.000000 | 0.000000 | 0 | 0 | | cleaning up | 0.000027 | 0.000000 | 0.000000 | 0 | 0 | +----------------------+----------+----------+------------+--------------+---------------+ 19 rows in set (0.02 sec)
从上面的结果可以看出越往后,消耗的时间越久。
这个和知识点里说的不一样,为什么出现这个情况?先从另一方面看:上面是连表查询,很可能出现问题的不是使用主键id的这个表。那就开始用单表看看,会是怎么样的情况。
2:SQL结构
explain select sql_no_cache post.id, post.root, post.boardId, post.postTime, post.subject, post.file, post.userId, post.click, post.child, post.type, post.rating, post.votes from jute_post as post where post.id between 1090000 and 1100000; +----+-------------+-------+-------+---------------+---------+---------+------+-------+-------------+ | id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra | +----+-------------+-------+-------+---------------+---------+---------+------+-------+-------------+ | 1 | SIMPLE | post | range | PRIMARY | PRIMARY | 4 | NULL | 17876 | Using where | +----+-------------+-------+-------+---------------+---------+---------+------+-------+-------------+
执行状况:
1090000 and 1100000 +----------------------+----------+----------+------------+--------------+---------------+ | Status | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out | +----------------------+----------+----------+------------+--------------+---------------+ | starting | 0.000164 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000013 | 0.000000 | 0.000000 | 0 | 0 | | Opening tables | 0.174908 | 0.012001 | 0.004000 | 1720 | 0 | | System lock | 0.000046 | 0.000000 | 0.000000 | 0 | 0 | | init | 0.000066 | 0.000000 | 0.000000 | 0 | 0 | | optimizing | 0.000033 | 0.000000 | 0.000000 | 0 | 0 | | statistics | 0.001264 | 0.004000 | 0.000000 | 0 | 0 | | preparing | 0.000040 | 0.000000 | 0.000000 | 0 | 0 | | executing | 0.000007 | 0.000000 | 0.000000 | 0 | 0 | | Sending data | 0.057492 | 0.052004 | 0.004000 | 16 | 0 | | end | 0.000026 | 0.000000 | 0.000000 | 0 | 0 | | query end | 0.000010 | 0.000000 | 0.000000 | 0 | 0 | | closing tables | 0.000013 | 0.000000 | 0.000000 | 0 | 0 | | freeing items | 0.000023 | 0.000000 | 0.000000 | 0 | 0 | | logging slow query | 0.000005 | 0.000000 | 0.000000 | 0 | 0 | | cleaning up | 0.000006 | 0.000000 | 0.000000 | 0 | 0 | +----------------------+----------+----------+------------+--------------+---------------+ 21000000 and 21010000 +----------------------+----------+----------+------------+--------------+---------------+ | Status | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out | +----------------------+----------+----------+------------+--------------+---------------+ | starting | 0.000101 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000011 | 0.000000 | 0.000000 | 0 | 0 | | Opening tables | 0.000025 | 0.000000 | 0.000000 | 0 | 0 | | System lock | 0.000029 | 0.000000 | 0.000000 | 0 | 0 | | init | 0.000044 | 0.000000 | 0.000000 | 0 | 0 | | optimizing | 0.000013 | 0.000000 | 0.000000 | 0 | 0 | | statistics | 0.007977 | 0.000000 | 0.000000 | 32 | 0 | | preparing | 0.000024 | 0.000000 | 0.000000 | 0 | 0 | | executing | 0.000005 | 0.000000 | 0.000000 | 0 | 0 | | Sending data | 0.083919 | 0.068004 | 0.004001 | 288 | 0 | | end | 0.000021 | 0.000000 | 0.000000 | 0 | 0 | | query end | 0.000009 | 0.000000 | 0.000000 | 0 | 0 | | closing tables | 0.000012 | 0.000000 | 0.000000 | 0 | 0 | | freeing items | 0.000021 | 0.000000 | 0.000000 | 0 | 0 | | logging slow query | 0.000005 | 0.000000 | 0.000000 | 0 | 0 | | cleaning up | 0.000006 | 0.000000 | 0.000000 | 0 | 0 | +----------------------+----------+----------+------------+--------------+---------------+ 26000000 and 26010000 +----------------------+----------+----------+------------+--------------+---------------+ | Status | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out | +----------------------+----------+----------+------------+--------------+---------------+ | starting | 0.000102 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000011 | 0.000000 | 0.000000 | 0 | 0 | | Opening tables | 0.000025 | 0.000000 | 0.000000 | 0 | 0 | | System lock | 0.000015 | 0.000000 | 0.000000 | 0 | 0 | | init | 0.000043 | 0.000000 | 0.000000 | 0 | 0 | | optimizing | 0.000012 | 0.000000 | 0.000000 | 0 | 0 | | statistics | 0.001315 | 0.000000 | 0.000000 | 0 | 0 | | preparing | 0.000023 | 0.000000 | 0.000000 | 0 | 0 | | executing | 0.000005 | 0.000000 | 0.000000 | 0 | 0 | | Sending data | 0.083872 | 0.068004 | 0.004000 | 48 | 0 | | end | 0.000021 | 0.000000 | 0.000000 | 0 | 0 | | query end | 0.000008 | 0.000000 | 0.000000 | 0 | 0 | | closing tables | 0.000013 | 0.000000 | 0.000000 | 0 | 0 | | freeing items | 0.000024 | 0.000000 | 0.000000 | 0 | 0 | | logging slow query | 0.000011 | 0.000000 | 0.000000 | 0 | 0 | | cleaning up | 0.000006 | 0.000000 | 0.000000 | 0 | 0 | +----------------------+----------+----------+------------+--------------+---------------+ 6000000 and 6010000 +----------------------+----------+----------+------------+--------------+---------------+ | Status | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out | +----------------------+----------+----------+------------+--------------+---------------+ | starting | 0.000082 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000026 | 0.000000 | 0.000000 | 0 | 0 | | Opening tables | 0.000021 | 0.000000 | 0.000000 | 0 | 0 | | System lock | 0.000011 | 0.000000 | 0.000000 | 0 | 0 | | init | 0.000032 | 0.000000 | 0.000000 | 0 | 0 | | optimizing | 0.000009 | 0.000000 | 0.000000 | 0 | 0 | | statistics | 0.000753 | 0.000000 | 0.004000 | 0 | 0 | | preparing | 0.000017 | 0.000000 | 0.000000 | 0 | 0 | | executing | 0.000004 | 0.000000 | 0.000000 | 0 | 0 | | Sending data | 0.057981 | 0.036003 | 0.000000 | 40 | 0 | | end | 0.000018 | 0.000000 | 0.000000 | 0 | 0 | | query end | 0.000010 | 0.000000 | 0.000000 | 0 | 0 | | closing tables | 0.000010 | 0.000000 | 0.000000 | 0 | 0 | | freeing items | 0.007655 | 0.000000 | 0.000000 | 0 | 0 | | logging slow query | 0.000007 | 0.000000 | 0.000000 | 0 | 0 | | cleaning up | 0.000005 | 0.000000 | 0.000000 | 0 | 0 | +----------------------+----------+----------+------------+--------------+---------------+ 27000000 and 27010000 +----------------------+----------+----------+------------+--------------+---------------+ | Status | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out | +----------------------+----------+----------+------------+--------------+---------------+ | starting | 0.000103 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000011 | 0.000000 | 0.000000 | 0 | 0 | | Opening tables | 0.000025 | 0.000000 | 0.000000 | 0 | 0 | | System lock | 0.000015 | 0.000000 | 0.000000 | 0 | 0 | | init | 0.000043 | 0.000000 | 0.000000 | 0 | 0 | | optimizing | 0.000013 | 0.000000 | 0.000000 | 0 | 0 | | statistics | 0.008353 | 0.000000 | 0.004001 | 8 | 0 | | preparing | 0.000025 | 0.000000 | 0.000000 | 0 | 0 | | executing | 0.000006 | 0.000000 | 0.000000 | 0 | 0 | | Sending data | 0.071468 | 0.060004 | 0.004000 | 64 | 0 | | end | 0.000022 | 0.000000 | 0.000000 | 0 | 0 | | query end | 0.000009 | 0.000000 | 0.000000 | 0 | 0 | | closing tables | 0.000013 | 0.000000 | 0.000000 | 0 | 0 | | freeing items | 0.000020 | 0.000000 | 0.000000 | 0 | 0 | | logging slow query | 0.000005 | 0.000000 | 0.000000 | 0 | 0 | | cleaning up | 0.000006 | 0.000000 | 0.000000 | 0 | 0 | +----------------------+----------+----------+------------+--------------+---------------+
发现上面执行时候消耗都差不多,验证了知识点里的内容。
总结:
上面的测试数据都是在磁盘上,没有预热的,所以和BP无关。通过1和2的测试对比得知:越往后越慢的问题在于Join,多表查出来不一样的时间,应该是跟数据在磁盘分布有关。id越往后越慢主要受到了其他几张关联表的影响。对于数据在磁盘上怎么分布的,有机会得去好好的学习下。