MySQL 主键范围查找问题

背景:

今天遇到一个主键范围查找的情况:

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越往后越慢主要受到了其他几张关联表的影响。对于数据在磁盘上怎么分布的,有机会得去好好的学习下。

 

posted @ 2014-06-19 18:27  jyzhou  阅读(4659)  评论(0编辑  收藏  举报