Details
-
Bug
-
Status: Done
-
Medium
-
Resolution: Fixed
-
8.0.12-2rc1, Not 5.7.x
-
None
Description
I have executed some query in 8.0.12 which creates an in memory temp table, this is what I got in the slow query log:
# Time: 2018-11-07T13:48:48.299425Z # User@Host: root[root] @ localhost [] Id: 14 # Schema: sbtest Last_errno: 0 Killed: 0 # Query_time: 6.121805 Lock_time: 0.000347 Rows_sent: 2437104 Rows_examined: 8437104 Rows_affected: 0 # Bytes_sent: 484748639 Tmp_tables: 1 Tmp_disk_tables: 1 Tmp_table_sizes: 0 # Full_scan: Yes Full_join: No Tmp_table: Yes Tmp_table_on_disk: No # Filesort: No Filesort_on_disk: No Merge_passes: 0 SET timestamp=1541598528; select * from sbtest1 where k>70000 union select * from sbtest2 where k>70000;
Comment:
1. Tmp_disk_tables is 1 here (notice Tmp_table_on_disk in the line below that one is "No" which is inconsistent) - it should be 0 here.
2. Tmp_table_sizes is 0 and I think it should be calculated regardless if temp table is created on disk or in memory.
Here's info from performance schema for this query:
select * from performance_schema.events_statements_current\G;
*************************** 2. row ***************************
THREAD_ID: 86
EVENT_ID: 203
END_EVENT_ID: NULL
EVENT_NAME: statement/sql/select
SOURCE: init_net_server_extension.cc:95
TIMER_START: 10970180946953000
TIMER_END: 10972287135089000
TIMER_WAIT: 2106188136000
LOCK_TIME: 261000000
SQL_TEXT: select * from sbtest1 where k>70000 union select * from sbtest2 where k>70000
DIGEST: ae298ff66e9c8fca13309c4b62e81417afe55c46c1f417de2f123d10f45ab6cb
DIGEST_TEXT: SELECT * FROM `sbtest1` WHERE `k` > ? UNION SELECT * FROM `sbtest2` WHERE `k` > ?
CURRENT_SCHEMA: sbtest
OBJECT_TYPE: NULL
OBJECT_SCHEMA: NULL
OBJECT_NAME: NULL
OBJECT_INSTANCE_BEGIN: NULL
MYSQL_ERRNO: 0
RETURNED_SQLSTATE: NULL
MESSAGE_TEXT: NULL
ERRORS: 0
WARNINGS: 0
ROWS_AFFECTED: 0
ROWS_SENT: 0
ROWS_EXAMINED: 0
CREATED_TMP_DISK_TABLES: 0
CREATED_TMP_TABLES: 1
SELECT_FULL_JOIN: 0
SELECT_FULL_RANGE_JOIN: 0
SELECT_RANGE: 0
SELECT_RANGE_CHECK: 0
SELECT_SCAN: 3
SORT_MERGE_PASSES: 0
SORT_RANGE: 0
SORT_ROWS: 0
SORT_SCAN: 0
NO_INDEX_USED: 1
NO_GOOD_INDEX_USED: 0
NESTING_EVENT_ID: NULL
NESTING_EVENT_TYPE: NULL
NESTING_EVENT_LEVEL: 0
CREATED_TMP_TABLES is 1, but CREATED_TMP_DISK_TABLES is 0
PS 5.7.23 with in memory temp table:
# Time: 2018-11-07T15:52:20.869794Z # User@Host: root[root] @ localhost [] Id: 5 # Schema: sbtest Last_errno: 0 Killed: 0 # Query_time: 0.096984 Lock_time: 0.000140 Rows_sent: 99999 Rows_examined: 299997 Rows_affected: 0 # Bytes_sent: 988930 Tmp_tables: 1 Tmp_disk_tables: 0 Tmp_table_sizes: 1663184 # QC_Hit: No Full_scan: Yes Full_join: No Tmp_table: Yes Tmp_table_on_disk: No # Filesort: No Filesort_on_disk: No Merge_passes: 0 SET timestamp=1541605940; select id from sbtest1 where id<100000 union select id from sbtest2 where id<100000;
Tmp_disk_tables is 0 here, but Tmp_table_sizes is calculated which I think it should be (so 5.7 seems fine here).
PS 8.0.12 with on disk temp table:
# Time: 2018-11-07T15:42:27.934851Z # User@Host: root[root] @ localhost [] Id: 11 # Schema: sbtest Last_errno: 0 Killed: 0 # Query_time: 18.682736 Lock_time: 0.000502 Rows_sent: 2437104 Rows_examined: 8437104 Rows_affected: 0 # Bytes_sent: 487185771 Tmp_tables: 1 Tmp_disk_tables: 1 Tmp_table_sizes: 16384 # Full_scan: Yes Full_join: No Tmp_table: Yes Tmp_table_on_disk: Yes # Filesort: No Filesort_on_disk: No Merge_passes: 0 use sbtest; SET timestamp=1541605347; select * from sbtest1 where k>70000 union select * from sbtest2 where k>70000;
You can see that Tmp_disk_tables is 1 here and Tmp_table_sizes is also calculated - so I would conclude that this affects only queries which create in memory temp tables.
Just for reference PS 5.7.23 with on disk temp table:
# Time: 2018-11-07T14:23:12.540917Z # User@Host: root[root] @ localhost [] Id: 4 # Schema: sbtest Last_errno: 0 Killed: 0 # Query_time: 8.320551 Lock_time: 0.000114 Rows_sent: 2437104 Rows_examined: 8437104 Rows_affected: 0 # Bytes_sent: 484748639 Tmp_tables: 1 Tmp_disk_tables: 1 Tmp_table_sizes: 16384 # QC_Hit: No Full_scan: Yes Full_join: No Tmp_table: Yes Tmp_table_on_disk: Yes # Filesort: No Filesort_on_disk: No Merge_passes: 0 SET timestamp=1541600592; select * from sbtest1 where k>70000 union select * from sbtest2 where k>70000;
Also notice that upstream in 8.0.14 adds a new variable to control format of slow query log:
https://dev.mysql.com/doc/refman/8.0/en/server-system-variables.html#sysvar_log_slow_extra
https://dev.mysql.com/doc/refman/8.0/en/slow-query-log.html#slow-query-log-contents
and it will include some of the stuff that we already have and some more so this will be fun all around.
STEPS TO REPRODUCE:
### PREPARE ### set global log_slow_verbosity='standard'; set global long_query_time=0; set global slow_query_log=ON; ### REPRODUCE ON DISK TEMP TABLE WITHIN QUERY: ### create table t1 (a int, b blob, key k_b(b(64))); create table t2 (a int, b blob, key k_b(b(64))); insert into t1 values (1,"aaa"),(2,"bbb"),(3,"ccc"); insert into t2 values (1,"aaa"),(2,"bbb"),(3,"ccc"); select * from t1 union select * from t2; ### REPRODUCE IN MEMORY TEMP TABLE WITHIN QUERY: ### create table t3 (a int); create table t4 (a int); insert into t3 values (1),(2),(3); insert into t4 values (1),(2),(3); select * from t3 union select * from t4;
