mysql> SHOW PROFILES;
+----------+------------+------------------------------------------------------------------------------------------------------------------------------+
| Query_ID | Duration | Query |
+----------+------------+------------------------------------------------------------------------------------------------------------------------------+
| 5 | 0.98439500 | SELECT DISTINCT smw_namespace, smw_title, smw_iw FROM `smw_rels2`,`smw_ids` WHERE p_id='8979' AND o_id=smw_id LIMIT 1000 |
| 6 | 0.23709100 | SELECT smw_namespace, smw_title, smw_iw FROM `smw_rels2`,`smw_ids` WHERE p_id='8979' AND o_id=smw_id LIMIT 1000 |
+----------+------------+------------------------------------------------------------------------------------------------------------------------------+
6 rows in set (0.00 sec)
mysql> SHOW PROFILE FOR QUERY 6;
+--------------------------------+----------+
| Status | Duration |
+--------------------------------+----------+
| starting | 0.000013 |
| checking query cache for query | 0.000056 |
| Opening tables | 0.000028 |
| System lock | 0.000017 |
| Table lock | 0.000047 |
| init | 0.000017 |
| optimizing | 0.000018 |
| statistics | 0.000261 |
| preparing | 0.000014 |
| executing | 0.000002 |
| Sending data | 0.236548 |
| end | 0.000008 |
| query end | 0.000004 |
| freeing items | 0.000040 |
| storing result in query cache | 0.000012 |
| logging slow query | 0.000002 |
| cleaning up | 0.000004 |
+--------------------------------+----------+
17 rows in set (0.00 sec)
mysql> SHOW PROFILE FOR QUERY 5;
+--------------------------------+----------+
| Status | Duration |
+--------------------------------+----------+
| starting | 0.000012 |
| checking query cache for query | 0.000061 |
| Opening tables | 0.000020 |
| System lock | 0.000015 |
| Table lock | 0.000045 |
| init | 0.000016 |
| optimizing | 0.000014 |
| statistics | 0.000229 |
| preparing | 0.000013 |
| Creating tmp table | 0.000038 |
| executing | 0.000003 |
| Copying to tmp table | 0.983473 |
| Sending data | 0.000351 |
| end | 0.000004 |
| removing tmp table | 0.000048 |
| end | 0.000004 |
| query end | 0.000004 |
| freeing items | 0.000025 |
| storing result in query cache | 0.000012 |
| logging slow query | 0.000001 |
| cleaning up | 0.000007 |
+--------------------------------+----------+
21 rows in set (0.00 sec)
第5,6条,只有一个DISTINCT不一样。5用到了临时表进行数据去重。
获取的数据都是一样的,SENDING DATA如果是发送数据到客户端这样话,就没办法解释为什么5,6的SENDING DATA时间相差这么巨大。往上再看一布操作耗时比较长的过程都是在executing后面。
看到一个外国人问的这个问题,他说SENDING DATA后面的时间其实是executing的。从上面看来,没个参数项后面的值,代表的是此参数项前面那个参数项的执行时间,这样理解才说得通。请斑竹指正。
+----------+------------+------------------------------------------------------------------------------------------------------------------------------+
| Query_ID | Duration | Query |
+----------+------------+------------------------------------------------------------------------------------------------------------------------------+
| 5 | 0.98439500 | SELECT DISTINCT smw_namespace, smw_title, smw_iw FROM `smw_rels2`,`smw_ids` WHERE p_id='8979' AND o_id=smw_id LIMIT 1000 |
| 6 | 0.23709100 | SELECT smw_namespace, smw_title, smw_iw FROM `smw_rels2`,`smw_ids` WHERE p_id='8979' AND o_id=smw_id LIMIT 1000 |
+----------+------------+------------------------------------------------------------------------------------------------------------------------------+
6 rows in set (0.00 sec)
mysql> SHOW PROFILE FOR QUERY 6;
+--------------------------------+----------+
| Status | Duration |
+--------------------------------+----------+
| starting | 0.000013 |
| checking query cache for query | 0.000056 |
| Opening tables | 0.000028 |
| System lock | 0.000017 |
| Table lock | 0.000047 |
| init | 0.000017 |
| optimizing | 0.000018 |
| statistics | 0.000261 |
| preparing | 0.000014 |
| executing | 0.000002 |
| Sending data | 0.236548 |
| end | 0.000008 |
| query end | 0.000004 |
| freeing items | 0.000040 |
| storing result in query cache | 0.000012 |
| logging slow query | 0.000002 |
| cleaning up | 0.000004 |
+--------------------------------+----------+
17 rows in set (0.00 sec)
mysql> SHOW PROFILE FOR QUERY 5;
+--------------------------------+----------+
| Status | Duration |
+--------------------------------+----------+
| starting | 0.000012 |
| checking query cache for query | 0.000061 |
| Opening tables | 0.000020 |
| System lock | 0.000015 |
| Table lock | 0.000045 |
| init | 0.000016 |
| optimizing | 0.000014 |
| statistics | 0.000229 |
| preparing | 0.000013 |
| Creating tmp table | 0.000038 |
| executing | 0.000003 |
| Copying to tmp table | 0.983473 |
| Sending data | 0.000351 |
| end | 0.000004 |
| removing tmp table | 0.000048 |
| end | 0.000004 |
| query end | 0.000004 |
| freeing items | 0.000025 |
| storing result in query cache | 0.000012 |
| logging slow query | 0.000001 |
| cleaning up | 0.000007 |
+--------------------------------+----------+
21 rows in set (0.00 sec)
第5,6条,只有一个DISTINCT不一样。5用到了临时表进行数据去重。
获取的数据都是一样的,SENDING DATA如果是发送数据到客户端这样话,就没办法解释为什么5,6的SENDING DATA时间相差这么巨大。往上再看一布操作耗时比较长的过程都是在executing后面。
看到一个外国人问的这个问题,他说SENDING DATA后面的时间其实是executing的。从上面看来,没个参数项后面的值,代表的是此参数项前面那个参数项的执行时间,这样理解才说得通。请斑竹指正。
这个代表的意思应该是:从 executing开始到Copying to tmp table结束,这个时间段的长度。这样才好解释。不知道对不对。
The thread is processing rows for a SELECT statement and also is sending data to the client.我的理解是,一句SELECT,相关的WHERE/GROUP BY/HAVING都已经OK了,现在正在组织这个结果集的每行的数据,并将这个结果集发送给客户端。组织结果集和发送数据都属于sending data。你的distinct这句导致了需要把所有非distinct的结果集导入临时表(内存不够,继而导入了tmp table),然后在内存中processing rows,选择不重复的行,返回给客户。因此这个sending data过程包括在临时表中筛选的过程。
内存临时表中processing rows”不过,Because operations occurring during this this state tend to perform large amounts of disk access (reads), it is often the longest-running state over the lifetime of a given query.