slow query sorting result - sending data
Posted by: Hugo Rodriguez
Date: April 28, 2015 07:27PM
Date: April 28, 2015 07:27PM
I have a big performance issue when executing a simple query.
The query is very slow the first time it is executed.
In profile you can see high values in the "CONTEXT_VOLUNTARY, CONTEXT_INVOLUNTARY, BLOCK_OPS_IN, BLOCK_OPS_OUT" columns for the status "sorting result" or "sending data".
Table information:
SHOW CREATE TABLE tableTest;
Table;Create Table
tableTest;CREATE TABLE `tableTest` (
`field_1` varchar(128) NOT NULL,
`field_2` smallint(6) NOT NULL,
`field_3` varchar(128) NOT NULL,
`field_4` datetime default NULL,
`field_5` datetime default NULL,
`field_6` varchar(4) default NULL,
`field_7` varchar(32) default NULL,
`field_8` varchar(128) default NULL,
`field_9` varchar(128) default NULL,
`field_10` varchar(128) default NULL,
`field_11` varchar(128) default NULL,
`field_12` varchar(5) default NULL,
`field_13` varchar(20) default NULL,
`field_14` varchar(8) default NULL,
`field_15` varchar(8) default NULL,
`field_16` varchar(20) default NULL,
`field_17` varchar(8) default NULL,
`field_18` varchar(8) default NULL,
`field_19` varchar(12) default NULL,
`field_20` varchar(12) default NULL,
`field_21` varchar(12) default NULL,
`field_22` varchar(12) default NULL,
`field_23` varchar(7) default NULL,
`field_24` varchar(18) default NULL,
`field_25` varchar(4) default NULL,
`field_26` varchar(6144) default NULL,
`field_27` varchar(6144) default NULL,
KEY `i_tableTest_UPD` (`field_1`,`field_2`,`field_3`,`field_9`,`field_8`,`field_7`,`field_10`,`field_11`),
KEY `i_tableTest_SEL` (`field_7`,`field_11`,`field_8`,`field_9`,`field_12`),
KEY `i_tableTest_o1` (`field_1.`,`field_2`,`field_3`,`field_7`,`field_11`,`field_9`,`field_8`,`field_10`),
KEY `i_tableTest_o2` (`field_1`,`field_2`,`field_3`,`field_7`,`field_11`,`field_9`,`field_8`,`field_12`)
) ENGINE=InnoDB DEFAULT CHARSET=latin1
SHOW TABLE STATUS LIKE 'tableTest';
Name;Engine;Version;Row_format;Rows;Avg_row_length;Data_length;Max_data_length;Index_length;Data_free;Auto_increment;Create_time;Update_time;Check_time;Collation;Checksum;Create_options;Comment
tableTest;InnoDB;10;Compact;11557005;2027;23426318336;0;4000464896;0;\N;2014-10-27 18:48:06;\N;\N;latin1_swedish_ci;\N;;InnoDB free: 273408 kB
Variables:
SHOW VARIABLES LIKE "%version%";
Variable_name;Value
protocol_version;10
version;5.0.67
version_comment;SUSE MySQL RPM
version_compile_machine;x86_64
version_compile_os;suse-linux-gnu
SHOW VARIABLES LIKE '%_buffer_%';
Variable_name;Value
bulk_insert_buffer_size;8388608
innodb_buffer_pool_awe_mem_mb;0
innodb_buffer_pool_size;268435456
innodb_log_buffer_size;1048576
join_buffer_size;671088640
key_buffer_size;671088640
myisam_sort_buffer_size;8388608
net_buffer_length;16384
preload_buffer_size;32768
read_buffer_size;268435456
read_rnd_buffer_size;262144
sort_buffer_size;536870912
SHOW VARIABLES LIKE '%query_cache%';
Variable_name;Value
have_query_cache;YES
query_cache_limit;1048576
query_cache_min_res_unit;4096
query_cache_size;0
query_cache_type;ON
query_cache_wlock_invalidate;OFF
Memory:
free -m
total used free shared buffers cached
Mem: 14343 14270 73 0 193 10197
-/+ buffers/cache: 3879 10464
Swap: 0 0 0
Well, the test is the next:
First time query
SELECT
field_6,
field_7,
field_8,
field_9,
field_20,
field_13,
field_14,
field_15,
field_16,
field_17,
field_18,
field_23,
field_24,
field_19
FROM tableTest
WHERE (field_7 = '210010'
OR field_7 = '210020'
OR field_7 = '500001'
OR field_7 = '500002'
OR field_7 = '230010'
OR field_7 = '230020'
OR field_7 = '590001'
OR field_7 = '590002'
OR field_7 = '660000'
OR field_7 = '670000')
AND field_11 = 'XXX'
AND ((field_9 = '20150427'
AND field_8 > '152201')
OR (field_9 > '20150427'))
AND field_12 = '000'
ORDER BY field_9, field_8, field_6 ASC;
/* Affected rows: 0 Filas encontradas: 62 Advertencias: 0 Duración para 1 query: 00:02:40 */
EXPLAIN query1;
id;select_type;table;type;possible_keys;key;key_len;ref;rows;Extra
1;SIMPLE;tableTest;range;i_tableTest_SEL;i_tableTest_SEL;166;\N;35219;Using where; Using filesort
SHOW PROFILE ALL FOR query 1;
Status;Duration;CPU_user;CPU_system;Context_voluntary;Context_involuntary;Block_ops_in;Block_ops_out;Messages_sent;Messages_received;Page_faults_major;Page_faults_minor;Swaps;Source_function;Source_file;Source_line
starting;0.000123;0.000000;0.000000;0;0;0;0;0;0;0;0;0;\N;\N;\N
Opening tables;0.000067;0.000000;0.000000;0;0;0;0;0;0;0;0;0;open_tables;../../sql/sql_base.c;2661
System lock;0.000044;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_lock_tables;../../sql/lock.cc;153
Table lock;0.000044;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_lock_tables;../../sql/lock.cc;163
init;0.000090;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_select;../../sql/sql_select;2261
optimizing;0.000062;0.000000;0.000000;0;0;0;0;0;0;0;0;0;optimize;../../sql/sql_select;749
statistics;0.007664;0.000000;0.000000;2;0;64;0;0;0;0;0;0;optimize;../../sql/sql_select;902
preparing;0.000066;0.000000;0.000000;0;0;0;0;0;0;0;0;0;optimize;../../sql/sql_select;912
executing;0.000043;0.000000;0.000000;0;0;0;0;0;0;0;0;0;exec;../../sql/sql_select;1581
Sorting result;160.667493;2.924183;0.584037;25636;1597;1116448;35112;0;0;0;1416;0;exec;../../sql/sql_select;1977
Sending data;0.000319;0.000000;0.000000;0;0;0;0;0;0;0;0;0;exec;../../sql/sql_select;2101
end;0.000057;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_select;../../sql/sql_select;2306
end;0.000043;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_select;../../sql/sql_select;2308
query end;0.000040;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_execute_command;../../sql/sql_parse.;5276
freeing items;0.000057;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_parse;../../sql/sql_parse.;6279
closing tables;0.000045;0.000000;0.000000;0;0;0;0;0;0;0;0;0;dispatch_command;../../sql/sql_parse.;2237
logging slow query;0.000039;0.000000;0.000000;0;0;0;0;0;0;0;0;0;log_slow_statement;../../sql/sql_parse.;2295
logging slow query;0.000039;0.000000;0.000000;0;0;0;0;0;0;0;0;0;log_slow_statement;../../sql/sql_parse.;2305
cleaning up;0.000042;0.000000;0.000000;0;0;0;0;0;0;0;0;0;dispatch_command;../../sql/sql_parse.;2260
Slow sorting result phase
Second time same query
SELECT
field_6,
field_7,
field_8,
field_9,
field_20,
field_13,
field_14,
field_15,
field_16,
field_17,
field_18,
field_23,
field_24,
field_19
FROM tableTest
WHERE (field_7 = '210010'
OR field_7 = '210020'
OR field_7 = '500001'
OR field_7 = '500002'
OR field_7 = '230010'
OR field_7 = '230020'
OR field_7 = '590001'
OR field_7 = '590002'
OR field_7 = '660000'
OR field_7 = '670000')
AND field_11 = 'XXX'
AND ((field_9 = '20150427'
AND field_8 > '152201')
OR (field_9 > '20150427'))
AND field_12 = '000'
ORDER BY field_9, field_8, field_6 ASC;
/* Affected rows: 0 Filas encontradas: 62 Advertencias: 0 Duración para 1 query: 2,075 sec. */
EXPLAIN query2;
id;select_type;table;type;possible_keys;key;key_len;ref;rows;Extra
1;SIMPLE;tableTest;range;i_tableTest_SEL;i_tableTest_SEL;166;\N;35219;Using where; Using filesort
SHOW PROFILE ALL FOR query 2;
Status;Duration;CPU_user;CPU_system;Context_voluntary;Context_involuntary;Block_ops_in;Block_ops_out;Messages_sent;Messages_received;Page_faults_major;Page_faults_minor;Swaps;Source_function;Source_file;Source_line
starting;0.000124;0.000000;0.000000;0;0;0;0;0;0;0;0;0;\N;\N;\N
Opening tables;0.000053;0.000000;0.000000;0;0;0;0;0;0;0;0;0;open_tables;../../sql/sql_base.c;2661
System lock;0.000043;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_lock_tables;../../sql/lock.cc;153
Table lock;0.000046;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_lock_tables;../../sql/lock.cc;163
init;0.000090;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_select;../../sql/sql_select;2261
optimizing;0.000064;0.000000;0.000000;0;0;0;0;0;0;0;0;0;optimize;../../sql/sql_select;749
statistics;0.000756;0.000000;0.000000;0;0;0;0;0;0;0;0;0;optimize;../../sql/sql_select;902
preparing;0.000068;0.000000;0.000000;0;0;0;0;0;0;0;0;0;optimize;../../sql/sql_select;912
executing;0.000044;0.000000;0.000000;0;0;0;0;0;0;0;0;0;exec;../../sql/sql_select;1581
Sorting result;2.079908;1.264079;0.268016;171;165;1168;88;0;0;0;1261;0;exec;../../sql/sql_select;1977
Sending data;0.000343;0.000000;0.000000;0;0;0;0;0;0;0;0;0;exec;../../sql/sql_select;2101
end;0.000049;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_select;../../sql/sql_select;2306
end;0.000050;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_select;../../sql/sql_select;2308
query end;0.000042;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_execute_command;../../sql/sql_parse.;5276
freeing items;0.000058;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_parse;../../sql/sql_parse.;6279
closing tables;0.000045;0.000000;0.000000;0;0;0;0;0;0;0;0;0;dispatch_command;../../sql/sql_parse.;2237
logging slow query;0.000040;0.000000;0.000000;0;0;0;0;0;0;0;0;0;log_slow_statement;../../sql/sql_parse.;2295
cleaning up;0.000042;0.000000;0.000000;0;0;0;0;0;0;0;0;0;dispatch_command;../../sql/sql_parse.;2260
The query is faster than the first time.
Aditional test:
Query without order by (changing a value on the where conditions)
SELECT
field_6,
field_7,
field_8,
field_9,
field_20,
field_13,
field_14,
field_15,
field_16,
field_17,
field_18,
field_23,
field_24,
field_19
FROM tableTest
WHERE (field_7 = '210010'
OR field_7 = '210020'
OR field_7 = '500001'
OR field_7 = '500002'
OR field_7 = '230010'
OR field_7 = '230020'
OR field_7 = '590001'
OR field_7 = '590002'
OR field_7 = '660000'
OR field_7 = '670000')
AND field_11 = 'ZZZ'
AND ((field_9 = '20150427'
AND field_8 > '152201')
OR (field_9 > '20150427'))
AND field_12 = '000';
/* Affected rows: 0 Filas encontradas: 55 Advertencias: 0 Duración para 1 query: 00:01:39 */
EXPLAIN query3;
id;select_type;table;type;possible_keys;key;key_len;ref;rows;Extra
1;SIMPLE;tableTest;range;i_tableTest_SEL;i_tableTest_SEL;166;\N;31363;Using where
SHOW PROFILE ALL FOR query 3;
Status;Duration;CPU_user;CPU_system;Context_voluntary;Context_involuntary;Block_ops_in;Block_ops_out;Messages_sent;Messages_received;Page_faults_major;Page_faults_minor;Swaps;Source_function;Source_file;Source_line
starting;0.000125;0.000000;0.000000;0;0;0;0;0;0;0;0;0;\N;\N;\N
Opening tables;0.000053;0.000000;0.000000;0;0;0;0;0;0;0;0;0;open_tables;../../sql/sql_base.c;2661
System lock;0.000042;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_lock_tables;../../sql/lock.cc;153
Table lock;0.000044;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_lock_tables;../../sql/lock.cc;163
init;0.000088;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_select;../../sql/sql_select;2261
optimizing;0.000063;0.000000;0.000000;0;0;0;0;0;0;0;0;0;optimize;../../sql/sql_select;749
statistics;0.054307;0.004000;0.000000;7;0;448;0;0;0;0;0;0;optimize;../../sql/sql_select;902
preparing;0.000133;0.000000;0.000000;0;0;0;0;0;0;0;0;0;optimize;../../sql/sql_select;912
executing;0.000043;0.000000;0.000000;0;0;0;0;0;0;0;0;0;exec;../../sql/sql_select;1581
Sending data;99.489397;1.748109;0.336021;15440;156;731328;16312;0;0;0;51;0;exec;../../sql/sql_select;2101
end;0.000191;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_select;../../sql/sql_select;2306
end;0.000041;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_select;../../sql/sql_select;2308
query end;0.000040;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_execute_command;../../sql/sql_parse.;5276
freeing items;0.000053;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_parse;../../sql/sql_parse.;6279
closing tables;0.000044;0.000000;0.000000;0;0;0;0;0;0;0;0;0;dispatch_command;../../sql/sql_parse.;2237
logging slow query;0.000039;0.000000;0.000000;0;0;0;0;0;0;0;0;0;log_slow_statement;../../sql/sql_parse.;2295
logging slow query;0.000039;0.000000;0.000000;0;0;0;0;0;0;0;0;0;log_slow_statement;../../sql/sql_parse.;2305
cleaning up;0.000041;0.000000;0.000000;0;0;0;0;0;0;0;0;0;dispatch_command;../../sql/sql_parse.;2260
Slow sending data phase.
Thanks,
Hugh
The query is very slow the first time it is executed.
In profile you can see high values in the "CONTEXT_VOLUNTARY, CONTEXT_INVOLUNTARY, BLOCK_OPS_IN, BLOCK_OPS_OUT" columns for the status "sorting result" or "sending data".
Table information:
SHOW CREATE TABLE tableTest;
Table;Create Table
tableTest;CREATE TABLE `tableTest` (
`field_1` varchar(128) NOT NULL,
`field_2` smallint(6) NOT NULL,
`field_3` varchar(128) NOT NULL,
`field_4` datetime default NULL,
`field_5` datetime default NULL,
`field_6` varchar(4) default NULL,
`field_7` varchar(32) default NULL,
`field_8` varchar(128) default NULL,
`field_9` varchar(128) default NULL,
`field_10` varchar(128) default NULL,
`field_11` varchar(128) default NULL,
`field_12` varchar(5) default NULL,
`field_13` varchar(20) default NULL,
`field_14` varchar(8) default NULL,
`field_15` varchar(8) default NULL,
`field_16` varchar(20) default NULL,
`field_17` varchar(8) default NULL,
`field_18` varchar(8) default NULL,
`field_19` varchar(12) default NULL,
`field_20` varchar(12) default NULL,
`field_21` varchar(12) default NULL,
`field_22` varchar(12) default NULL,
`field_23` varchar(7) default NULL,
`field_24` varchar(18) default NULL,
`field_25` varchar(4) default NULL,
`field_26` varchar(6144) default NULL,
`field_27` varchar(6144) default NULL,
KEY `i_tableTest_UPD` (`field_1`,`field_2`,`field_3`,`field_9`,`field_8`,`field_7`,`field_10`,`field_11`),
KEY `i_tableTest_SEL` (`field_7`,`field_11`,`field_8`,`field_9`,`field_12`),
KEY `i_tableTest_o1` (`field_1.`,`field_2`,`field_3`,`field_7`,`field_11`,`field_9`,`field_8`,`field_10`),
KEY `i_tableTest_o2` (`field_1`,`field_2`,`field_3`,`field_7`,`field_11`,`field_9`,`field_8`,`field_12`)
) ENGINE=InnoDB DEFAULT CHARSET=latin1
SHOW TABLE STATUS LIKE 'tableTest';
Name;Engine;Version;Row_format;Rows;Avg_row_length;Data_length;Max_data_length;Index_length;Data_free;Auto_increment;Create_time;Update_time;Check_time;Collation;Checksum;Create_options;Comment
tableTest;InnoDB;10;Compact;11557005;2027;23426318336;0;4000464896;0;\N;2014-10-27 18:48:06;\N;\N;latin1_swedish_ci;\N;;InnoDB free: 273408 kB
Variables:
SHOW VARIABLES LIKE "%version%";
Variable_name;Value
protocol_version;10
version;5.0.67
version_comment;SUSE MySQL RPM
version_compile_machine;x86_64
version_compile_os;suse-linux-gnu
SHOW VARIABLES LIKE '%_buffer_%';
Variable_name;Value
bulk_insert_buffer_size;8388608
innodb_buffer_pool_awe_mem_mb;0
innodb_buffer_pool_size;268435456
innodb_log_buffer_size;1048576
join_buffer_size;671088640
key_buffer_size;671088640
myisam_sort_buffer_size;8388608
net_buffer_length;16384
preload_buffer_size;32768
read_buffer_size;268435456
read_rnd_buffer_size;262144
sort_buffer_size;536870912
SHOW VARIABLES LIKE '%query_cache%';
Variable_name;Value
have_query_cache;YES
query_cache_limit;1048576
query_cache_min_res_unit;4096
query_cache_size;0
query_cache_type;ON
query_cache_wlock_invalidate;OFF
Memory:
free -m
total used free shared buffers cached
Mem: 14343 14270 73 0 193 10197
-/+ buffers/cache: 3879 10464
Swap: 0 0 0
Well, the test is the next:
First time query
SELECT
field_6,
field_7,
field_8,
field_9,
field_20,
field_13,
field_14,
field_15,
field_16,
field_17,
field_18,
field_23,
field_24,
field_19
FROM tableTest
WHERE (field_7 = '210010'
OR field_7 = '210020'
OR field_7 = '500001'
OR field_7 = '500002'
OR field_7 = '230010'
OR field_7 = '230020'
OR field_7 = '590001'
OR field_7 = '590002'
OR field_7 = '660000'
OR field_7 = '670000')
AND field_11 = 'XXX'
AND ((field_9 = '20150427'
AND field_8 > '152201')
OR (field_9 > '20150427'))
AND field_12 = '000'
ORDER BY field_9, field_8, field_6 ASC;
/* Affected rows: 0 Filas encontradas: 62 Advertencias: 0 Duración para 1 query: 00:02:40 */
EXPLAIN query1;
id;select_type;table;type;possible_keys;key;key_len;ref;rows;Extra
1;SIMPLE;tableTest;range;i_tableTest_SEL;i_tableTest_SEL;166;\N;35219;Using where; Using filesort
SHOW PROFILE ALL FOR query 1;
Status;Duration;CPU_user;CPU_system;Context_voluntary;Context_involuntary;Block_ops_in;Block_ops_out;Messages_sent;Messages_received;Page_faults_major;Page_faults_minor;Swaps;Source_function;Source_file;Source_line
starting;0.000123;0.000000;0.000000;0;0;0;0;0;0;0;0;0;\N;\N;\N
Opening tables;0.000067;0.000000;0.000000;0;0;0;0;0;0;0;0;0;open_tables;../../sql/sql_base.c;2661
System lock;0.000044;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_lock_tables;../../sql/lock.cc;153
Table lock;0.000044;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_lock_tables;../../sql/lock.cc;163
init;0.000090;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_select;../../sql/sql_select;2261
optimizing;0.000062;0.000000;0.000000;0;0;0;0;0;0;0;0;0;optimize;../../sql/sql_select;749
statistics;0.007664;0.000000;0.000000;2;0;64;0;0;0;0;0;0;optimize;../../sql/sql_select;902
preparing;0.000066;0.000000;0.000000;0;0;0;0;0;0;0;0;0;optimize;../../sql/sql_select;912
executing;0.000043;0.000000;0.000000;0;0;0;0;0;0;0;0;0;exec;../../sql/sql_select;1581
Sorting result;160.667493;2.924183;0.584037;25636;1597;1116448;35112;0;0;0;1416;0;exec;../../sql/sql_select;1977
Sending data;0.000319;0.000000;0.000000;0;0;0;0;0;0;0;0;0;exec;../../sql/sql_select;2101
end;0.000057;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_select;../../sql/sql_select;2306
end;0.000043;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_select;../../sql/sql_select;2308
query end;0.000040;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_execute_command;../../sql/sql_parse.;5276
freeing items;0.000057;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_parse;../../sql/sql_parse.;6279
closing tables;0.000045;0.000000;0.000000;0;0;0;0;0;0;0;0;0;dispatch_command;../../sql/sql_parse.;2237
logging slow query;0.000039;0.000000;0.000000;0;0;0;0;0;0;0;0;0;log_slow_statement;../../sql/sql_parse.;2295
logging slow query;0.000039;0.000000;0.000000;0;0;0;0;0;0;0;0;0;log_slow_statement;../../sql/sql_parse.;2305
cleaning up;0.000042;0.000000;0.000000;0;0;0;0;0;0;0;0;0;dispatch_command;../../sql/sql_parse.;2260
Slow sorting result phase
Second time same query
SELECT
field_6,
field_7,
field_8,
field_9,
field_20,
field_13,
field_14,
field_15,
field_16,
field_17,
field_18,
field_23,
field_24,
field_19
FROM tableTest
WHERE (field_7 = '210010'
OR field_7 = '210020'
OR field_7 = '500001'
OR field_7 = '500002'
OR field_7 = '230010'
OR field_7 = '230020'
OR field_7 = '590001'
OR field_7 = '590002'
OR field_7 = '660000'
OR field_7 = '670000')
AND field_11 = 'XXX'
AND ((field_9 = '20150427'
AND field_8 > '152201')
OR (field_9 > '20150427'))
AND field_12 = '000'
ORDER BY field_9, field_8, field_6 ASC;
/* Affected rows: 0 Filas encontradas: 62 Advertencias: 0 Duración para 1 query: 2,075 sec. */
EXPLAIN query2;
id;select_type;table;type;possible_keys;key;key_len;ref;rows;Extra
1;SIMPLE;tableTest;range;i_tableTest_SEL;i_tableTest_SEL;166;\N;35219;Using where; Using filesort
SHOW PROFILE ALL FOR query 2;
Status;Duration;CPU_user;CPU_system;Context_voluntary;Context_involuntary;Block_ops_in;Block_ops_out;Messages_sent;Messages_received;Page_faults_major;Page_faults_minor;Swaps;Source_function;Source_file;Source_line
starting;0.000124;0.000000;0.000000;0;0;0;0;0;0;0;0;0;\N;\N;\N
Opening tables;0.000053;0.000000;0.000000;0;0;0;0;0;0;0;0;0;open_tables;../../sql/sql_base.c;2661
System lock;0.000043;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_lock_tables;../../sql/lock.cc;153
Table lock;0.000046;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_lock_tables;../../sql/lock.cc;163
init;0.000090;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_select;../../sql/sql_select;2261
optimizing;0.000064;0.000000;0.000000;0;0;0;0;0;0;0;0;0;optimize;../../sql/sql_select;749
statistics;0.000756;0.000000;0.000000;0;0;0;0;0;0;0;0;0;optimize;../../sql/sql_select;902
preparing;0.000068;0.000000;0.000000;0;0;0;0;0;0;0;0;0;optimize;../../sql/sql_select;912
executing;0.000044;0.000000;0.000000;0;0;0;0;0;0;0;0;0;exec;../../sql/sql_select;1581
Sorting result;2.079908;1.264079;0.268016;171;165;1168;88;0;0;0;1261;0;exec;../../sql/sql_select;1977
Sending data;0.000343;0.000000;0.000000;0;0;0;0;0;0;0;0;0;exec;../../sql/sql_select;2101
end;0.000049;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_select;../../sql/sql_select;2306
end;0.000050;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_select;../../sql/sql_select;2308
query end;0.000042;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_execute_command;../../sql/sql_parse.;5276
freeing items;0.000058;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_parse;../../sql/sql_parse.;6279
closing tables;0.000045;0.000000;0.000000;0;0;0;0;0;0;0;0;0;dispatch_command;../../sql/sql_parse.;2237
logging slow query;0.000040;0.000000;0.000000;0;0;0;0;0;0;0;0;0;log_slow_statement;../../sql/sql_parse.;2295
cleaning up;0.000042;0.000000;0.000000;0;0;0;0;0;0;0;0;0;dispatch_command;../../sql/sql_parse.;2260
The query is faster than the first time.
Aditional test:
Query without order by (changing a value on the where conditions)
SELECT
field_6,
field_7,
field_8,
field_9,
field_20,
field_13,
field_14,
field_15,
field_16,
field_17,
field_18,
field_23,
field_24,
field_19
FROM tableTest
WHERE (field_7 = '210010'
OR field_7 = '210020'
OR field_7 = '500001'
OR field_7 = '500002'
OR field_7 = '230010'
OR field_7 = '230020'
OR field_7 = '590001'
OR field_7 = '590002'
OR field_7 = '660000'
OR field_7 = '670000')
AND field_11 = 'ZZZ'
AND ((field_9 = '20150427'
AND field_8 > '152201')
OR (field_9 > '20150427'))
AND field_12 = '000';
/* Affected rows: 0 Filas encontradas: 55 Advertencias: 0 Duración para 1 query: 00:01:39 */
EXPLAIN query3;
id;select_type;table;type;possible_keys;key;key_len;ref;rows;Extra
1;SIMPLE;tableTest;range;i_tableTest_SEL;i_tableTest_SEL;166;\N;31363;Using where
SHOW PROFILE ALL FOR query 3;
Status;Duration;CPU_user;CPU_system;Context_voluntary;Context_involuntary;Block_ops_in;Block_ops_out;Messages_sent;Messages_received;Page_faults_major;Page_faults_minor;Swaps;Source_function;Source_file;Source_line
starting;0.000125;0.000000;0.000000;0;0;0;0;0;0;0;0;0;\N;\N;\N
Opening tables;0.000053;0.000000;0.000000;0;0;0;0;0;0;0;0;0;open_tables;../../sql/sql_base.c;2661
System lock;0.000042;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_lock_tables;../../sql/lock.cc;153
Table lock;0.000044;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_lock_tables;../../sql/lock.cc;163
init;0.000088;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_select;../../sql/sql_select;2261
optimizing;0.000063;0.000000;0.000000;0;0;0;0;0;0;0;0;0;optimize;../../sql/sql_select;749
statistics;0.054307;0.004000;0.000000;7;0;448;0;0;0;0;0;0;optimize;../../sql/sql_select;902
preparing;0.000133;0.000000;0.000000;0;0;0;0;0;0;0;0;0;optimize;../../sql/sql_select;912
executing;0.000043;0.000000;0.000000;0;0;0;0;0;0;0;0;0;exec;../../sql/sql_select;1581
Sending data;99.489397;1.748109;0.336021;15440;156;731328;16312;0;0;0;51;0;exec;../../sql/sql_select;2101
end;0.000191;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_select;../../sql/sql_select;2306
end;0.000041;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_select;../../sql/sql_select;2308
query end;0.000040;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_execute_command;../../sql/sql_parse.;5276
freeing items;0.000053;0.000000;0.000000;0;0;0;0;0;0;0;0;0;mysql_parse;../../sql/sql_parse.;6279
closing tables;0.000044;0.000000;0.000000;0;0;0;0;0;0;0;0;0;dispatch_command;../../sql/sql_parse.;2237
logging slow query;0.000039;0.000000;0.000000;0;0;0;0;0;0;0;0;0;log_slow_statement;../../sql/sql_parse.;2295
logging slow query;0.000039;0.000000;0.000000;0;0;0;0;0;0;0;0;0;log_slow_statement;../../sql/sql_parse.;2305
cleaning up;0.000041;0.000000;0.000000;0;0;0;0;0;0;0;0;0;dispatch_command;../../sql/sql_parse.;2260
Slow sending data phase.
Thanks,
Hugh
Subject
Views
Written By
Posted
Sorry, you can't reply to this topic. It has been closed.
Content reproduced on this site is the property of the respective copyright holders. It is not reviewed in advance by Oracle and does not necessarily represent the opinion of Oracle or any other party.