# Create a sandbox with the slow log enabled in a table and logging everything. $ dbdeployer deploy single mysql_8.0.26 -c "slow_query_log = ON" -c "log_output = 'TABLE'" -c "long_query_time = 0" # Initialize data. $ ./use <<< "create database test_jfg" $ zcat ~/tmp/t.sql.gz | ./use test_jfg # Get in a mysql client. $ ./use test_jfg # Show the structure of the table we are querying. mysql [localhost:5735] {msandbox} (test_jfg) > show create table t\G *************************** 1. row *************************** Table: t Create Table: CREATE TABLE `t` ( `customerId` int(10) unsigned NOT NULL, `type` varchar(20) CHARACTER SET ascii COLLATE ascii_bin NOT NULL, `requestedAt` bigint(20) unsigned NOT NULL, `active` tinyint(1) NOT NULL DEFAULT '1', `completedAt` bigint(20) unsigned DEFAULT NULL, `c` char(10) DEFAULT NULL, PRIMARY KEY (`customerId`,`type`,`requestedAt`), KEY `type` (`type`,`customerId`,`active`) ) ENGINE=InnoDB DEFAULT CHARSET=latin1 1 row in set (0.00 sec) # Get the number of rows matching type = '0-52'. mysql [localhost:5735] {msandbox} (test_jfg) > select count(*) from t where type = '0-52'; +----------+ | count(*) | +----------+ | 38743 | +----------+ 1 row in set (0.01 sec) # Truncate the slow log and performance_schema.events_statements_summary_by_digest for easier querying. mysql [localhost:5735] {msandbox} (test_jfg) > truncate mysql.slow_log; truncate performance_schema.events_statements_summary_by_digest; Query OK, 0 rows affected (0.00 sec) Query OK, 0 rows affected (0.00 sec) # Do a query served by the index, but where we still need to scan many rows because the 2nd field of the index is not in the where-clause but the 3rd is, pager set to avoid printing the rows returned. mysql [localhost:5735] {msandbox} (test_jfg) > flush status; pager cat > /dev/null; select type, customerId, active, requestedAt from t where type = '0-52' and active = 1; pager; show status like "Handler_read%"; Query OK, 0 rows affected (0.01 sec) PAGER set to 'cat > /dev/null' 3 rows in set (0.01 sec) Default pager wasn't set, using stdout. +-----------------------+-------+ | Variable_name | Value | +-----------------------+-------+ | Handler_read_first | 0 | | Handler_read_key | 1 | | Handler_read_last | 0 | | Handler_read_next | 38743 | | Handler_read_prev | 0 | | Handler_read_rnd | 0 | | Handler_read_rnd_next | 0 | +-----------------------+-------+ 7 rows in set (0.00 sec) # So we can see that the query above scanned 38743 rows, which is expected with the select count(*) above. The slow log and p_s are giving us the same thing. mysql [localhost:5735] {msandbox} (test_jfg) > select rows_sent, rows_examined, sql_text from mysql.slow_log where sql_text like '%where type % and active%'; +-----------+---------------+----------------------------------------------------------------------------------------+ | rows_sent | rows_examined | sql_text | +-----------+---------------+----------------------------------------------------------------------------------------+ | 3 | 38743 | select type, customerId, active, requestedAt from t where type = '0-52' and active = 1 | +-----------+---------------+----------------------------------------------------------------------------------------+ 1 row in set (0.00 sec) mysql [localhost:5735] {msandbox} (test_jfg) > select DIGEST_TEXT, SUM_ROWS_SENT, SUM_ROWS_EXAMINED from performance_schema.events_statements_summary_by_digest WHERE DIGEST_TEXT like '%WHERE TYPE = %'; +-------------------------------------------------------------------------------------------------+---------------+-------------------+ | DIGEST_TEXT | SUM_ROWS_SENT | SUM_ROWS_EXAMINED | +-------------------------------------------------------------------------------------------------+---------------+-------------------+ | SELECT TYPE , `customerId` , `active` , `requestedAt` FROM `t` WHERE TYPE = ? AND `active` = ? | 3 | 38743 | +-------------------------------------------------------------------------------------------------+---------------+-------------------+ 1 row in set (0.00 sec) # Let's truncate the slow log and p_s table, and redo everything but with select *, and we get a surprising rows_examined. mysql [localhost:5735] {msandbox} (test_jfg) > truncate mysql.slow_log; truncate performance_schema.events_statements_summary_by_digest; flush status; pager cat > /dev/null; select * from t where type = '0-52' and active = 1; pager; show status like "Handler_read%"; select rows_sent, rows_examined, sql_text from mysql.slow_log where sql_text like '%where type%and active%'; select DIGEST_TEXT, SUM_ROWS_SENT, SUM_ROWS_EXAMINED from performance_schema.events_statements_summary_by_digest WHERE DIGEST_TEXT like '%WHERE TYPE = %'; Query OK, 0 rows affected (0.00 sec) Query OK, 0 rows affected (0.00 sec) Query OK, 0 rows affected (0.00 sec) PAGER set to 'cat > /dev/null' 3 rows in set (0.01 sec) Default pager wasn't set, using stdout. +-----------------------+-------+ | Variable_name | Value | +-----------------------+-------+ | Handler_read_first | 0 | | Handler_read_key | 1 | | Handler_read_last | 0 | | Handler_read_next | 3 | | Handler_read_prev | 0 | | Handler_read_rnd | 0 | | Handler_read_rnd_next | 0 | +-----------------------+-------+ 7 rows in set (0.00 sec) +-----------+---------------+----------------------------------------------------+ | rows_sent | rows_examined | sql_text | +-----------+---------------+----------------------------------------------------+ | 3 | 3 | select * from t where type = '0-52' and active = 1 | +-----------+---------------+----------------------------------------------------+ 1 row in set (0.00 sec) +----------------------------------------------------+---------------+-------------------+ | DIGEST_TEXT | SUM_ROWS_SENT | SUM_ROWS_EXAMINED | +----------------------------------------------------+---------------+-------------------+ | SELECT * FROM `t` WHERE TYPE = ? AND `active` = ? | 3 | 3 | +----------------------------------------------------+---------------+-------------------+ 1 row in set (0.00 sec) # I do not understand how a query with select * can scan less rows than a query returning the fields of a covering index. Both explains below, the Extra is a little different, but rows are the same. mysql [localhost:5735] {msandbox} (test_jfg) > explain select type, customerId, active, requestedAt from t where type = '0-52' and active = 1; +----+-------------+-------+------------+------+---------------+------+---------+-------+-------+----------+--------------------------+ | id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra | +----+-------------+-------+------------+------+---------------+------+---------+-------+-------+----------+--------------------------+ | 1 | SIMPLE | t | NULL | ref | type | type | 22 | const | 35549 | 10.00 | Using where; Using index | +----+-------------+-------+------------+------+---------------+------+---------+-------+-------+----------+--------------------------+ 1 row in set, 1 warning (0.00 sec) mysql [localhost:5735] {msandbox} (test_jfg) > explain select * from t where type = '0-52' and active = 1; +----+-------------+-------+------------+------+---------------+------+---------+-------+-------+----------+-----------------------+ | id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra | +----+-------------+-------+------------+------+---------------+------+---------+-------+-------+----------+-----------------------+ | 1 | SIMPLE | t | NULL | ref | type | type | 22 | const | 35549 | 10.00 | Using index condition | +----+-------------+-------+------------+------+---------------+------+---------+-------+-------+----------+-----------------------+ 1 row in set, 1 warning (0.00 sec) # If we look at what InnoDB is reporting in Innodb_rows_read, we see results that are consistent with rows_examined above, which makes me think this is an InnoDB bug. mysql [localhost:5735] {msandbox} (test_jfg) > show global status like 'Innodb_rows_read'; pager cat > /dev/null; select type, customerId, active, requestedAt from t where type = '0-52' and active = 1; pager; show global status like 'Innodb_rows_read'; +------------------+-------+ | Variable_name | Value | +------------------+-------+ | Innodb_rows_read | 77497 | +------------------+-------+ 1 row in set (0.00 sec) PAGER set to 'cat > /dev/null' 3 rows in set (0.02 sec) Default pager wasn't set, using stdout. +------------------+--------+ | Variable_name | Value | +------------------+--------+ | Innodb_rows_read | 116240 | +------------------+--------+ 1 row in set (0.00 sec) mysql [localhost:5735] {msandbox} (test_jfg) > show global status like 'Innodb_rows_read'; pager cat > /dev/null; select * from t where type = '0-52' and active = 1; pager; show global status like 'Innodb_rows_read'; +------------------+--------+ | Variable_name | Value | +------------------+--------+ | Innodb_rows_read | 116240 | +------------------+--------+ 1 row in set (0.00 sec) PAGER set to 'cat > /dev/null' 3 rows in set (0.01 sec) Default pager wasn't set, using stdout. +------------------+--------+ | Variable_name | Value | +------------------+--------+ | Innodb_rows_read | 116243 | +------------------+--------+ 1 row in set (0.00 sec) # When comparing the performance of the two queries, it looks like the select * is 33% faster than selecting the fields of the index, which I do not explain, but not to the point of scanning 10,000 less rows (I did the comparison a few times, and the results are all similar). $ n=1000; time yes "select type, customerId, active, requestedAt from t where type = '0-52' and active = 1;" | head -n $n | ./use test_jfg > /dev/null; time yes "select * from t where type = '0-52' and active = 1;" | head -n $n | ./use test_jfg > /dev/null real 0m17.461s user 0m0.088s sys 0m0.033s real 0m8.701s user 0m0.087s sys 0m0.017s