Same execution path, data and schematics; different query times

Question

We have noticed some inconsistencies in our MySQL performance for query times that we feel cannot be explained by just server load. Some queries seem to be much efficient than others, despite having a similar setup.

Edit: Since opening this question, our database crashed (for unknown reasons at this moment, RDS teams are investigating), and after a reboot the issue is no longer reproducible and the queries are the same speed. I still would like to know what was wrong because the issue may come back, but perhaps we will never find out...

Continue original question: To test this, I made a near-copy of a table. The performance (query time) against the copied table is dramatically worse than the source, despite the same execution path, same data, and very similar table schematics.

In this example, we have the following 3 tables:

offers_clicks
offers
offers_new

"offers_new" is a test table that has a limited number of field (only "id" and 'status" fields), but is otherwise having the same structure as "offers" table (which is also having "id" and "status" field, but also many other fields). Here are the table schematics:

Offers Table:

| offers | CREATE TABLE `offers` (
  `id` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `status` tinyint(4) NOT NULL DEFAULT '0',
  `user_id` int(11) NOT NULL DEFAULT '0',
.....many_other_fields.....
  KEY `ix_public_view_key` (`public_view_key`),
  FULLTEXT KEY `name` (`name`,`internal_name`)
) ENGINE=InnoDB AUTO_INCREMENT=18425582 DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci |

Offers New table:

| offers_new | CREATE TABLE `offers_new` (
  `id` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `status` tinyint(4) NOT NULL DEFAULT '0',
  PRIMARY KEY (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=18423831 DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci |

We then did an INSERT SELECT from "offers" table to "offers_new" table:

INSERT INTO offers_new (id, status) SELECT id, status FROM offers;

After this, we started to run some test queries. As you can see, the query times to "offers_new" table is about 10 times slower than "offers" table.

mysql> SELECT COUNT(*) FROM offers_clicks, offers_new WHERE offers_new.id = offers_clicks.offer_id AND offers_clicks.date > '2019-05-30 00:00:00' and offers_clicks.date < '2019-05-30 01:00:00';
+----------+
| COUNT(*) |
+----------+
|    15472 |
+----------+
1 row in set (26.04 sec)

mysql> SELECT COUNT(*) FROM offers_clicks, offers WHERE offers.id  = offers_clicks.offer_id AND offers_clicks.date > '2019-05-30 00:00:00' and offers_clicks.date < '2019-05-30 01:00:00';
+----------+
| COUNT(*) |
+----------+
|    15472 |
+----------+
1 row in set (2.90 sec)

mysql> SELECT COUNT(*) FROM offers_clicks, offers_new WHERE offers_new.id = offers_clicks.offer_id AND offers_clicks.date > '2019-05-30 00:00:00' and offers_clicks.date < '2019-05-30 01:00:00';
+----------+
| COUNT(*) |
+----------+
|    15472 |
+----------+
1 row in set (28.07 sec)

mysql> SELECT COUNT(*) FROM offers_clicks, offers WHERE offers.id  = offers_clicks.offer_id AND offers_clicks.date > '2019-05-30 00:00:00' and offers_clicks.date < '2019-05-30 01:00:00';
+----------+
| COUNT(*) |
+----------+
|    15472 |
+----------+
1 row in set (2.26 sec)

Please note that the execution path is exactly the same for both queries:

mysql> explain SELECT COUNT(*) FROM offers_clicks, offers_new WHERE offers_new.id = offers_clicks.offer_id AND offers_clicks.date > '2019-05-30 00:00:00' and offers_clicks.date < '2019-05-30 01:00:00';
+----+-------------+---------------+-----------------------------------------------------------------------+--------+--------------------+---------+---------+--------------------------------------------+-------+----------+-----------------------+
| id | select_type | table         | partitions                                                            | type   | possible_keys      | key     | key_len | ref                                        | rows  | filtered | Extra                 |
+----+
|  1 | SIMPLE      | offers_clicks | p0,p1,p2,p3,p4,p5,p6,p7,p8,p9,p10,p11,p12,p13,p14,p15,p16,p17,p18,p19 | range  | pts_id,date,date_2 | date    | 5       | NULL                                       | 15472 |   100.00 | Using index condition |
|  1 | SIMPLE      | offers_new    | NULL                                                                  | eq_ref | PRIMARY            | PRIMARY | 4       | dejong_pointstoshop.offers_clicks.offer_id |     1 |   100.00 | Using index           |
+----+
2 rows in set, 1 warning (0.00 sec)

mysql> explain SELECT COUNT(*) FROM offers_clicks, offers WHERE offers.id = offers_clicks.offer_id AND offers_clicks.date > '2019-05-30 00:00:00' and offers_clicks.date < '2019-05-30 01:00:00';
+----+-------------+---------------+-----------------------------------------------------------------------+--------+--------------------+---------+---------+--------------------------------------------+-------+----------+-----------------------+
| id | select_type | table         | partitions                                                            | type   | possible_keys      | key     | key_len | ref                                        | rows  | filtered | Extra                 |
+----+-------------+---------------+-----------------------------------------------------------------------+--------+--------------------+---------+---------+--------------------------------------------+-------+----------+-----------------------+
|  1 | SIMPLE      | offers_clicks | p0,p1,p2,p3,p4,p5,p6,p7,p8,p9,p10,p11,p12,p13,p14,p15,p16,p17,p18,p19 | range  | pts_id,date,date_2 | date    | 5       | NULL                                       | 15472 |   100.00 | Using index condition |
|  1 | SIMPLE      | offers        | NULL                                                                  | eq_ref | PRIMARY            | PRIMARY | 4       | dejong_pointstoshop.offers_clicks.offer_id |     1 |   100.00 | Using index           |
+----+-------------+---------------+-----------------------------------------------------------------------+--------+--------------------+---------+---------+--------------------------------------------+-------+----------+-----------------------+
2 rows in set, 1 warning (0.00 sec)

Steps we have taken after this:

We reached out to our host, AWS, to see if there are any issues with our RDS setup. They reported they cannot find anything wrong and claim it must be something wrong with MySQL
We ran profiling to see what happens internally. We don't see swapping, major page faults (only minor) or other things that could explain the differences. I have attached the data at the bottom of this topic.
We made sure to optimize the table to make sure there was no bad fragmenting of the table somehow, even though that seemed unlikely on a new table.
We tried to ensure that "offers_new" table was "warm" by loading the query several times before timing it
We ran those queries in our staging environment and saw performance being equal ("offers_new" table is slightly faster, perhaps due to having fewer fields)

We are using MySQL 8.0.15

It is worth noting that our production system is under high CPU load. However, this should not explain different query times for queries that are pretty much identical. We ran it dozens of times now with he same results.

It is also worth noting that "offers" table is a production table, so it's being updated / queried against frequently. "offers_new", which is the slow table, is not.

Edits based on comments:

ANSI JOIN has same results
Just like one commenter, we thought that perhaps something was not in memory for "offers_new". After all, "offers_new" is not used in production, and "offers" is. However, profiling shows "Page_faults_major" at 0 for both queries. While our understanding is fairly limited in this area, we believe that this means the data was loaded from memory and not disk.
One commenter asked us to run a COUNT on just "offers" and "offers_new" tables. Here are the results:

mysql> SELECT COUNT(*) FROM offers_new;
+----------+
| COUNT(*) |
+----------+
|  5093127 |
+----------+
1 row in set (0.13 sec)

mysql> SELECT COUNT(*) FROM offers;
+----------+
| COUNT(*) |
+----------+
|  5107742 |
+----------+
1 row in set (2.54 sec)

The counts are very close. Offers is a live table, so since my tests yesterday, new entries have been added to the table. The counts are still close though. Interestingly, the COUNT(*) on "offers_new" is significantly faster than "offers", so the opposite from the query results we made this question about! Count on "offers_new" is about 0.1/0.2 seconds, count on "offers" table is a few seconds (ranges between 2-6s). I ran it about 10 times each to make sure it wasn't just server load, and it was consistently slower. I assume that this has something to do with the number of columns which is much higher for "offers" table. Either way, it's interesting to see the opposite results of the other query...

Here is the profiling:

mysql> SHOW PROFILES;
+----------+-------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Query_ID | Duration    | Query                                                                                                                                                                                     |
+---+
|        1 | 26.03997750 | SELECT COUNT(*) FROM offers_clicks, offers_new WHERE offers_new.id = offers_clicks.offer_id AND offers_clicks.date > '2019-05-30 00:00:00' and offers_clicks.date < '2019-05-30 01:00:00' |
|        2 |  2.89890600 | SELECT COUNT(*) FROM offers_clicks, offers WHERE offers.id = offers_clicks.offer_id AND offers_clicks.date > '2019-05-30 00:00:00' and offers_clicks.date < '2019-05-30 01:00:00'         |
|        3 | 28.07228225 | SELECT COUNT(*) FROM offers_clicks, offers_new WHERE offers_new.id = offers_clicks.offer_id AND offers_clicks.date > '2019-05-30 00:00:00' and offers_clicks.date < '2019-05-30 01:00:00' |
|        4 |  2.25160675 | SELECT COUNT(*) FROM offers_clicks, offers WHERE offers.id = offers_clicks.offer_id AND offers_clicks.date > '2019-05-30 00:00:00' and offers_clicks.date < '2019-05-30 01:00:00'         |
+----------+-------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
4 rows in set, 1 warning (0.00 sec)

mysql> 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.000364 |   0.016000 |   0.000000 |                 3 |                   3 |            0 |             0 |             0 |                 0 |                 0 |                 1 |     0 | NULL                    | NULL                 |        NULL |
| Executing hook on transaction  |  0.000134 |   0.008000 |   0.000000 |                 6 |                   2 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | launch_hook_trans_begin | rpl_handler.cc       |        1100 |
| starting                       |  0.000128 |   0.008000 |   0.000000 |                 2 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | launch_hook_trans_begin | rpl_handler.cc       |        1102 |
| checking permissions           |  0.000173 |   0.008000 |   0.000000 |                 3 |                   2 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | check_access            | sql_authorization.cc |        1899 |
| checking permissions           |  0.000182 |   0.012000 |   0.000000 |                65 |                  33 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | check_access            | sql_authorization.cc |        1899 |
| Opening tables                 |  0.003432 |   0.176000 |   0.012000 |               556 |                 224 |            0 |             0 |             0 |                 0 |                 0 |                20 |     0 | open_tables             | sql_base.cc          |        5586 |
| init                           |  0.000235 |   0.012000 |   0.000000 |                25 |                  20 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | execute                 | sql_select.cc        |         555 |
| System lock                    |  0.000151 |   0.008000 |   0.000000 |                62 |                  17 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_lock_tables       | lock.cc              |         332 |
| optimizing                     |  0.000171 |   0.008000 |   0.000000 |                32 |                   9 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | optimize                | sql_optimizer.cc     |         212 |
| statistics                     |  0.001255 |   0.068000 |   0.000000 |               230 |                 125 |            0 |            24 |             0 |                 0 |                 0 |                 0 |     0 | optimize                | sql_optimizer.cc     |         425 |
| preparing                      |  0.000166 |   0.012000 |   0.000000 |                43 |                  19 |            0 |             0 |             0 |                 0 |                 0 |                10 |     0 | optimize                | sql_optimizer.cc     |         499 |
| executing                      |  0.000134 |   0.004000 |   0.000000 |                27 |                  16 |            0 |             0 |             0 |                 0 |                 0 |                10 |     0 | exec                    | sql_executor.cc      |         197 |
| Sending data                   | 26.032492 | 999.999999 |  67.940000 |           5361975 |             1420548 |       227416 |       1584568 |             0 |                 0 |                 0 |            299459 |     0 | exec                    | sql_executor.cc      |         273 |
| end                            |  0.000325 |   0.012000 |   0.000000 |                 7 |                   0 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | execute                 | sql_select.cc        |         608 |
| query end                      |  0.000115 |   0.004000 |   0.000000 |                11 |                   9 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_execute_command   | sql_parse.cc         |        4581 |
| waiting for handler commit     |  0.000118 |   0.008000 |   0.000000 |                34 |                  13 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | ha_commit_trans         | handler.cc           |        1533 |
| closing tables                 |  0.000118 |   0.004000 |   0.000000 |                23 |                   2 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_execute_command   | sql_parse.cc         |        4627 |
| freeing items                  |  0.000163 |   0.008000 |   0.000000 |                 4 |                   1 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_parse             | sql_parse.cc         |        5256 |
| cleaning up                    |  0.000125 |   0.008000 |   0.000000 |                 5 |                   1 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | dispatch_command        | sql_parse.cc         |        2108 |
+---+
19 rows in set, 1 warning (0.00 sec)

mysql> 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.000364 |   0.012000 |   0.000000 |                41 |                  24 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | NULL                    | NULL                 |        NULL |
| Executing hook on transaction  | 0.000137 |   0.008000 |   0.000000 |                40 |                  12 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | launch_hook_trans_begin | rpl_handler.cc       |        1100 |
| starting                       | 0.000135 |   0.004000 |   0.000000 |                21 |                   6 |            0 |            16 |             0 |                 0 |                 0 |                 2 |     0 | launch_hook_trans_begin | rpl_handler.cc       |        1102 |
| checking permissions           | 0.000124 |   0.008000 |   0.000000 |                26 |                   7 |            0 |            16 |             0 |                 0 |                 0 |                 2 |     0 | check_access            | sql_authorization.cc |        1899 |
| checking permissions           | 0.000139 |   0.008000 |   0.000000 |                19 |                   9 |           32 |            24 |             0 |                 0 |                 0 |                 4 |     0 | check_access            | sql_authorization.cc |        1899 |
| Opening tables                 | 0.000152 |   0.004000 |   0.000000 |                30 |                  14 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | open_tables             | sql_base.cc          |        5586 |
| init                           | 0.000125 |   0.004000 |   0.008000 |                25 |                  19 |            0 |             0 |             0 |                 0 |                 0 |                 1 |     0 | execute                 | sql_select.cc        |         555 |
| System lock                    | 0.000237 |   0.004000 |   0.004000 |                26 |                  15 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_lock_tables       | lock.cc              |         332 |
| optimizing                     | 0.000150 |   0.008000 |   0.000000 |                24 |                   7 |            0 |             0 |             0 |                 0 |                 0 |                 4 |     0 | optimize                | sql_optimizer.cc     |         212 |
| statistics                     | 0.001082 |   0.048000 |   0.004000 |               192 |                  59 |            0 |             0 |             0 |                 0 |                 0 |                17 |     0 | optimize                | sql_optimizer.cc     |         425 |
| preparing                      | 0.000162 |   0.008000 |   0.000000 |                19 |                  22 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | optimize                | sql_optimizer.cc     |         499 |
| executing                      | 0.000136 |   0.008000 |   0.000000 |                33 |                  32 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | exec                    | sql_executor.cc      |         197 |
| Sending data                   | 2.894895 | 120.524000 |   6.512000 |            551014 |              158606 |        43632 |        125120 |             0 |                 0 |                 0 |             34154 |     0 | exec                    | sql_executor.cc      |         273 |
| end                            | 0.000359 |   0.012000 |   0.000000 |                28 |                  27 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | execute                 | sql_select.cc        |         608 |
| query end                      | 0.000130 |   0.004000 |   0.004000 |                51 |                  33 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | mysql_execute_command   | sql_parse.cc         |        4581 |
| waiting for handler commit     | 0.000135 |   0.004000 |   0.000000 |                58 |                   9 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | ha_commit_trans         | handler.cc           |        1533 |
| closing tables                 | 0.000144 |   0.008000 |   0.000000 |                27 |                  15 |            0 |            16 |             0 |                 0 |                 0 |                 2 |     0 | mysql_execute_command   | sql_parse.cc         |        4627 |
| freeing items                  | 0.000165 |   0.008000 |   0.000000 |                23 |                   4 |            0 |             8 |             0 |                 0 |                 0 |                 3 |     0 | mysql_parse             | sql_parse.cc         |        5256 |
| cleaning up                    | 0.000137 |   0.008000 |   0.000000 |                 6 |                   3 |            0 |             0 |             0 |                 0 |                 0 |                 0 |     0 | dispatch_command        | sql_parse.cc         |        2108 |
+---+
19 rows in set, 1 warning (0.00 sec)

mysql> show create table offers \G
*************************** 1. row ***************************
       Table: offers
Create Table: CREATE TABLE `offers` (
  `id` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `status` tinyint(4) NOT NULL DEFAULT '0',
  `field_a` int(11) NOT NULL DEFAULT '0',
  `field_b` text COLLATE utf8_unicode_ci NOT NULL,
  `field_c` varchar(150) COLLATE utf8_unicode_ci NOT NULL,
  `field_d` text COLLATE utf8_unicode_ci NOT NULL,
  `field_e` text COLLATE utf8_unicode_ci NOT NULL,
  `field_f` text COLLATE utf8_unicode_ci,
  `field_g` varchar(64) CHARACTER SET utf8 DEFAULT NULL,
  `field_h` text COLLATE utf8_unicode_ci,
  `field_i` mediumint(9) NOT NULL DEFAULT '0',
  `field_j` varchar(100) COLLATE utf8_unicode_ci NOT NULL DEFAULT '0',
  `field_k` varchar(100) COLLATE utf8_unicode_ci DEFAULT NULL,
  `field_l` decimal(10,4) NOT NULL,
  `field_m` decimal(10,4) NOT NULL DEFAULT '0.0000',
  `field_n` decimal(10,4) NOT NULL DEFAULT '0.0000',
  `field_o` decimal(10,4) NOT NULL DEFAULT '0.0000',
  `field_p` decimal(5,2) NOT NULL DEFAULT '0.00',
  `field_q` text COLLATE utf8_unicode_ci NOT NULL,
  `field_r` text COLLATE utf8_unicode_ci NOT NULL,
  `field_s` int(11) NOT NULL,
  `field_t` mediumint(9) NOT NULL DEFAULT '0',
  `field_u` tinyint(4) NOT NULL DEFAULT '0',
  `field_v` tinyint(4) NOT NULL DEFAULT '0',
  `field_w` tinyint(4) NOT NULL DEFAULT '0',
  `field_x` tinyint(4) NOT NULL,
  `field_y` tinyint(4) DEFAULT NULL,
  `field_z` tinyint(4) NOT NULL DEFAULT '0',
  `field_aa` tinyint(1) NOT NULL DEFAULT '0',
  `field_ab` tinyint(1) NOT NULL,
  `field_ac` tinyint(4) NOT NULL,
  `field_ad` tinyint(1) NOT NULL DEFAULT '0',
  `field_ae` tinyint(1) NOT NULL,
  `field_af` int(10) unsigned DEFAULT '0',
  `field_ag` int(10) unsigned NOT NULL,
  `field_ah` int(10) unsigned NOT NULL,
  `field_ai` int(11) NOT NULL,
  `field_aj` tinyint(1) NOT NULL DEFAULT '0',
  `field_ak` decimal(6,3) DEFAULT '0.000',
  `field_al` tinyint(1) NOT NULL,
  `field_am` decimal(8,3) NOT NULL,
  `field_an` decimal(8,3) NOT NULL,
  `field_ao` decimal(5,2) NOT NULL,
  `field_ap` decimal(8,3) NOT NULL,
  `field_aq` tinyint(3) unsigned DEFAULT NULL,
  `field_ar` int(11) NOT NULL,
  `field_as` mediumint(9) NOT NULL DEFAULT '0',
  `field_at` mediumint(9) NOT NULL,
  `field_au` mediumint(9) NOT NULL,
  `field_av` mediumint(9) NOT NULL,
  `field_aw` mediumint(9) NOT NULL,
  `field_ax` mediumint(9) NOT NULL DEFAULT '8388607',
  `field_ay` datetime NOT NULL DEFAULT '0000-00-00 00:00:00',
  `field_az` tinyint(1) NOT NULL DEFAULT '0',
  `field_ba` smallint(5) unsigned DEFAULT NULL,
  `field_bb` tinyint(1) NOT NULL DEFAULT '0',
  `field_bc` tinyint(1) NOT NULL DEFAULT '0',
  `field_bd` tinyint(1) NOT NULL DEFAULT '1',
  `field_be` tinyint(1) NOT NULL,
  `field_bf` datetime NOT NULL DEFAULT '0000-00-00 00:00:00',
  `field_bg` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP,
  `field_bh` tinyint(1) NOT NULL DEFAULT '0',
  `field_bi` text COLLATE utf8_unicode_ci NOT NULL,
  `field_bj` tinyint(1) NOT NULL DEFAULT '0',
  `field_bk` date DEFAULT NULL,
  `field_bl` date DEFAULT NULL,
  `field_bm` varchar(20) COLLATE utf8_unicode_ci NOT NULL DEFAULT '',
  `field_bn` varchar(40) COLLATE utf8_unicode_ci NOT NULL DEFAULT '',
  `field_bo` tinyint(1) NOT NULL DEFAULT '0',
  `field_bp` varchar(255) COLLATE utf8_unicode_ci NOT NULL,
  `field_bq` smallint(5) unsigned DEFAULT NULL,
  `field_br` tinyint(3) unsigned NOT NULL DEFAULT '0',
  `field_bs` decimal(10,6) DEFAULT NULL,
  `field_bt` decimal(10,6) DEFAULT NULL,
  `field_bu` tinyint(1) NOT NULL DEFAULT '0',
  `field_bv` tinyint(1) NOT NULL DEFAULT '0',
  `field_bw` tinyint(1) NOT NULL DEFAULT '0',
  `field_bx` tinyint(1) NOT NULL DEFAULT '0',
  `field_by` tinyint(1) NOT NULL DEFAULT '0',
  `field_bz` datetime DEFAULT NULL,
  `field_ca` datetime DEFAULT NULL,
  `field_cb` datetime DEFAULT NULL,
  `field_cc` varchar(50) COLLATE utf8_unicode_ci DEFAULT NULL,
  `field_cd` datetime DEFAULT NULL,
  `field_ce` varchar(155) COLLATE utf8_unicode_ci NOT NULL DEFAULT '',
  `field_cf` int(11) DEFAULT NULL,
  `field_cg` decimal(10,4) NOT NULL DEFAULT '0.0000',
  `field_ch` tinyint(1) NOT NULL DEFAULT '0',
  `field_ci` decimal(5,4) NOT NULL DEFAULT '0.0000',
  `field_cj` mediumint(9) NOT NULL DEFAULT '0',
  `field_ck` datetime DEFAULT NULL,
  `field_cl` tinyint(1) NOT NULL DEFAULT '0',
  `field_cm` datetime DEFAULT NULL,
  `field_cn` smallint(5) unsigned NOT NULL DEFAULT '0',
  `field_co` smallint(5) unsigned NOT NULL DEFAULT '0',
  `field_cp` tinyint(1) NOT NULL DEFAULT '0',
  `field_cq` tinyint(1) NOT NULL DEFAULT '0',
  `field_cr` tinyint(1) NOT NULL DEFAULT '0',
  `field_cs` tinyint(1) NOT NULL DEFAULT '0',
  `field_ct` tinyint(1) NOT NULL DEFAULT '0',
  `field_cu` tinyint(1) NOT NULL DEFAULT '0',
  `field_cv` tinyint(1) NOT NULL DEFAULT '0',
  `field_cw` tinyint(1) NOT NULL DEFAULT '0',
  `field_cx` decimal(5,2) NOT NULL,
  `field_cy` tinyint(1) NOT NULL DEFAULT '0',
  `field_cz` tinyint(1) NOT NULL DEFAULT '0',
  `field_da` int(11) NOT NULL DEFAULT '0',
  `field_db` tinyint(1) NOT NULL DEFAULT '0',
  `field_dc` varchar(255) COLLATE utf8_unicode_ci NOT NULL DEFAULT '',
  `field_dd` tinyint(3) unsigned DEFAULT NULL,
  `field_de` tinyint(1) DEFAULT '0',
  `field_df` datetime DEFAULT NULL,
  `field_dg` tinyint(1) NOT NULL DEFAULT '0',
  `field_dh` tinyint(1) NOT NULL DEFAULT '0',
  `⁠⁠⁠⁠field_di` bigint(20) DEFAULT NULL,
  `field_dj` datetime DEFAULT NULL,
  `field_dk` tinyint(1) NOT NULL DEFAULT '0',
  `field_dl` int(1) DEFAULT NULL,
  `field_dm` tinyint(1) NOT NULL DEFAULT '0',
  `field_dn` int(11) NOT NULL DEFAULT '0',
  `field_do` tinyint(1) NOT NULL DEFAULT '0',
  `field_dp` tinyint(3) unsigned NOT NULL DEFAULT '0',
  `field_dq` int(11) NOT NULL DEFAULT '0',
  `field_dr` json DEFAULT NULL,
  `field_ds` int(11) NOT NULL DEFAULT '0',
  `field_dt` datetime DEFAULT NULL,
  `field_du` tinyint(1) NOT NULL DEFAULT '0',
  `field_dv` json NOT NULL,
  `field_dw` decimal(8,5) DEFAULT '0.00000',
  `field_dx` tinyint(1) NOT NULL DEFAULT '0',
  `field_dy` smallint(6) NOT NULL DEFAULT '14',
  PRIMARY KEY (`id`),
  UNIQUE KEY `field_i_field_j` (`field_i`,`field_j`),
  UNIQUE KEY `field_j_field_i` (`field_k`,`field_i`),
  KEY `status_field_bf` (`status`,`field_bf`),
  KEY `field_bm` (`field_bm`),
  KEY `status_field_i_field_bo` (`status`,`field_i`,`field_bo`),
  KEY `field_j` (`field_j`),
  KEY `field_bz` (`field_bz`),
  KEY `field_br` (`field_br`),
  KEY `field_bh` (`field_bh`),
  KEY `field_ba` (`field_ba`),
  KEY `field_cm` (`status`,`field_cm`),
  KEY `field_cc` (`field_cc`),
  KEY `field_i_field_cc` (`field_i`,`field_cc`),
  KEY `field_g` (`field_g`),
  FULLTEXT KEY `field_c` (`field_c`,`field_ce`)
) ENGINE=InnoDB AUTO_INCREMENT=18425582 DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci

Very strange, the only significant difference in the profiles is in "Sending data". But all it's sending is a count, which shouldn't take much time at all. — Barmar, May 31 '19 at 15:27
Here's another question about anomalous "Sending data" times: https://stackoverflow.com/questions/863447/mysql-slow-sending-data-phase — Barmar, May 31 '19 at 15:29
The label "Sending Data" is a bit confusing in MySQL. It basically is reading/processing the data. This is where MySQL tends to spend most of it's time, especially if you are missing something like an index. I think that in this case the join requires a fair amount of context switching because of the 15472 rows to join. This takes CPU. Since our server is seeing high CPU usage, the Sending Data step is fairly slow. However, this does not explain why one query is 10 times slower than the other with the same data, since it follows the same plan, has the same data to read, etc. — Mathijs de Jong, May 31 '19 at 15:46
It could just be that the index for the production table is in memory because it's being used frequently, but the index for the new table is not so it has to be read from disk. — Barmar, May 31 '19 at 15:54
I was thinking the same thing, except that "Page_faults_major" is 0 which suggests that everything is in memory. I could be wrong though, as my expertise of MySQL in this area is reaching its limits. — Mathijs de Jong, May 31 '19 at 16:11
The difference is in page_faults_minor. I'm not sure what the difference is. — Barmar, May 31 '19 at 16:16
Did you try to compare `SELECT COUNT(*) FROM offers_new` vs `SELECT COUNT(*) FROM offers`? — Paul Spiegel, May 31 '19 at 16:18
Found this: https://www.quora.com/What-is-difference-between-Page_faults_minor-Page_faults_mizor-and-Block-IO-in-MySQL but I don't understand why a minor page fault would actually increase query time. — Barmar, May 31 '19 at 16:18
It shouldn't make a difference, but please learn to use ANSI JOIN instead of cross products. — Barmar, May 31 '19 at 16:39
Paul, counts are nearly the same (slight difference in count now because offers is a live table). Interestingly, the COUNT(*) on "offers_new" is significantly faster than "offers", so the opposite from the query above! Count on "offers_new" is 0.1 second, count on offers table is a few seconds (ranges between 2-6s). I ran it about 10 times each to make sure it wasn't just server load, and it was consistently slower. Now I'm even more confused... Barmar, agreed. :-) I actually use ANSI JOIN in production. I just used this for this example. I just ran an ANSI JOIN and results were the same. — Mathijs de Jong, May 31 '19 at 16:54
Several other columns in the Sending Data row are also 10x in query 1. — Barmar, May 31 '19 at 23:34
Please post TEXT results of A) SHOW INDEX FROM offers; B) SHOW INDEX FROM offers_new; C) SHOW CREATE TABLE offers; D) SHOW CREATE TABLE offers_new; — Wilson Hauck, Jun 01 '19 at 12:00
Please provide `SHOW TABLE STATUS` for each of the 3 tables; I need to see the sizes. Does `offers` have `PRIMARY KEY(id)`; it does not show. Notice how the partitioning does not help performance (and probably hurts a little); please provide `SHOW CREATE TABLE` showing the partitioning and explain why you used the form of partition that it has. — Rick James, Jun 03 '19 at 22:36
@Barmar - I find that `Sending data` (or one or two other things) always hold nearly all the time. Hence I find Profiling _useless_. — Rick James, Jun 03 '19 at 22:50
@MathijsdeJong - If MySQL exceeds the memory available, it can incur "page faults". However, the performance becomes really terrible. This is only 10x slower, so I don't think it is page faults. And AWS does a reasonable job of tuning their servers to avoid such. — Rick James, Jun 03 '19 at 22:53
@MathijsdeJong - There _may_ be an `Innodb_...` metric (see `SHOW GLOBAL STATUS`) that shows the blocks read, but that metric is quite cluttered with other stuff to trust. — Rick James, Jun 03 '19 at 22:54
@MathijsdeJong - Assuming the Query cache is not turned on, usually running a query twice and using the second timing is sufficient. When you ran 10 times, did you see one time for the first, then approximately the same for the others? — Rick James, Jun 03 '19 at 23:25
I like [_this_](https://stackoverflow.com/a/10347999/1766831) description of **Sending data**. — Rick James, Jun 03 '19 at 23:37
Was the new table analyzed? What are the results if SQL_NO_CACHE hint is used for both queries? — fifonik, Jun 04 '19 at 01:04
It is not really to the question directly, but I'd try to add composite index (date, offer_id) on offers_clicks — fifonik, Jun 04 '19 at 01:18
Some answers: Offers has primary key on id. I will post full schematics. Yes, table was analyzed. There is no query cache enabled. The index paths is the same on both queries, and therefore different indexes should not matter. The offers_clicks table is partitioned by user_id. To clarify, I'm not looking to optimize these queries, as they are written exclusively to show a test case that in my opinion should show same speed. They are not production queries. The first time is usually slower, which is when it shows major page faults. Follow up queries are usually fast. — Mathijs de Jong, Jun 04 '19 at 16:50
Unfortunately, our database crashed this morning out of the blue (RDS internal team is investigating it). After this reboot, both queries have identical speed ("offers_new" in fact is now just slightly faster than "offers", but that's probably because of fewer overall fields and makes sense). So whatever was wrong before, the test case may be lost :( — Mathijs de Jong, Jun 04 '19 at 16:51
I added the schematics for the full offers table, anonomized. Although I don't believe this should materially change the query. Maybe it could make things a bit slower due to the many fields, but not faster as we experienced before. — Mathijs de Jong, Jun 04 '19 at 18:29
`SQL_NO_CACHE` says not to use the "Query cache"; this is totally independent of the "buffer pool". When the QC is involved, the time for a select is about 1ms, regardless of how complex it is -- so the timing is not useful. — Rick James, Jun 04 '19 at 19:35
Rick. Sorry if I wasn't clear, but I meant to say that query cache is disabled on our server, so SQL_NO_CACHE has no effect. — Mathijs de Jong, Jun 05 '19 at 00:02

Rick James · Answer 1 · 2019-06-04T19:39:57.770

A guess (pending more information requested in Comments)...

innodb_buffer_pool_size is smaller than the Data_length (see SHOW TABLE SIZE offers), and the 15K rows are scattered around the table. This could lead to hitting the disk instead of finding the desired id in the cache (buffer_pool).
The ratio of about 10:1, as exemplified by both pairs of runs, is what I have seen many times in comparing a query that hits the disk versus runs in cache.

A partial solution may be to increase the buffer_pool. However, since you are using a Cloud service, the only way to do that increase may be to pay for bigger RAM.

An alternative may be to force or trick it into using a different index. But first I need to see the rest of the indexes, plus the datatypes of the indexed columns.

Meanwhile, I would really like to critique offers_clicks; what is the partition key?

On to another approach... Is this a common query? It seems to be "how many clicks happened in the hour?"

Why does it need to look at offers at all? Can't it get the right answer from SELECT COUNT(*) FROM offers_clicks WHERE date ...?

If you do need the JOIN, then let's talk about building and maintaining a summary table that holds the counts for every hour.

Side issues

FROM offers_clicks, offers
WHERE offers.id = offers_clicks.offer_id AND offers_clicks.date

should be written

FROM offers_clicks
JOIN offers  ON offers.id = offers_clicks.offer_id  -- how the tables relate
WHERE offers_clicks.date ...

The former is the old "commalist" style of JOIN, the latter is the preferred syntax. The two syntaxes generate identical code, so this is not a performance issue. The former looks like a "cross join", but the WHERE makes it effectively not.

Also... This is only 3599 seconds, not a full hour. The convention is to include the first midnight.

    date > '2019-05-30 00:00:00'
and date < '2019-05-30 01:00:00'

I prefer this style since it avoids leap year issues, etc:

    date >= '2019-05-30 00:00:00'
and date  < '2019-05-30 00:00:00' + INTERVAL 1 HOUR

Page faults...

When a program (MySQL or any other) has allocated more memory (RAM) than the Operating System is willing to give it, some pages (usually 4KB in size) are "swapped" out to disk. When a page is referenced by the program, a "page fault" occurs. This is a hardware interrupt that says "panic! the page you asked for is no in RAM". Then the OS steps in to copy that page back into RAM so the program can continue.

InnoDB would much prefer to lay out a lot of RAM, then have free access to all of it whenever it likes. That is, InnoDB pretends that page faults will never occur. Hence, page faults hurt performance a lot. Do not configure MySQL to use "too much" RAM, else you get into page faults.

InnoDB does need to swap blocks of data and indexes (and table definitions, etc) into RAM and free up space for other blocks. But InnoDB is carefully designed and coded to minimize this. The "buffer pool" is a large chunk of RAM that InnoDB uses as an LRU (Least Recently Used) cache of its 16KB blocks. That is probably what is slowing down the processing, not the CPU, not page faults, etc. (I await some info so I can confirm this.)

The first time is usually slower, which is when it shows major page faults. Follow up queries are usually fast.

That means that there was I/O to bring in pages needed for the query (page fault major). Then subsequent queries could be run without I/O (faster).

And, since offers is much bigger, there would be more I/O. However, that is the opposite of what you are seeing.

If it were hitting the disk, wouldn't that show up in Major Page Faults? — Barmar, Jun 03 '19 at 22:56
@Barmar - No. InnoDB did not find it in the buffer_pool, so it issued a 16KB read from the data BTree (or index BTree). — Rick James, Jun 03 '19 at 23:02
Hey, I have some comments. 1) This is not a production query, this is only made to illustrate a problem we were having with our data. I appreciate your feedback, but fortunately, the production query won't have these issues. 2) The data length of offers table is about 6GB, innodb buffer is 414GB. Offers_new table is 0.14GB (because it has fewer fields). — Mathijs de Jong, Jun 04 '19 at 18:39
3) Even the smallest query on the smallest of tables in our table still shows page_faults_minor. According to a quora topic, minor page faults are pulled from memory; they are just not owned by the process. This information may be incorrect though. : https://www.quora.com/What-is-difference-between-Page_faults_minor-Page_faults_mizor-and-Block-IO-in-MySQL — Mathijs de Jong, Jun 04 '19 at 18:41
4) I wanted to make sure that you saw my comment that our database crashed this morning out of the blue (RDS internal team is investigating it). After this reboot, both queries have identical speed ("offers_new" in fact is now just slightly faster than "offers", but that's probably because of fewer overall fields and makes sense). So whatever was wrong before, the test case may be lost :( — Mathijs de Jong, Jun 04 '19 at 18:46
@MathijsdeJong - You have 0.5 terabyte of RAM? No other big tables? What about the page_faults_minor after the reboot? — Rick James, Jun 04 '19 at 18:53
Correct. :-) We have plenty of large tables. The total size of all our data+index combined is about 1.5TB, but not all data is active so I don't think everything has to be loaded in memory all the time. I'm not sure how that works though, but I assume that MySQL has the ability to add only portions of a table/index into memory? — Mathijs de Jong, Jun 04 '19 at 19:15
@MathijsdeJong - The "buffer pool" is a cache of the blocks of data and indexes. Each 16KB block comes and goes as needed. So, if you run those queries a second time _before some huge table bumps them out of cache_, the queries should be performed without any I/O. The tables/indexes in question are small enough to fit in the cache (until bumped out). (I don't understand "page fault minor" enough to explain how it is involved.) — Rick James, Jun 04 '19 at 19:33
Thank you for your help! I believe your answer is centralized around memory but I'm not sure that is the problem. While I agree that this was also my first go-to explanation, "Profiling" ran on the queries indicates no major page faults, only minor, which suggests it's in memory (if we believe the Quora answer). Also, when running both queries multiple times after each other, one continued to be the slow one (after server reboot they are the same). The fact that a reboot fixed this makes me wonder whether there are some hardware issues, some RDS issues, or some MySQL 8 bug. — Mathijs de Jong, Jun 05 '19 at 00:12

Same execution path, data and schematics; different query times

1 Answers1