Bug #95824 Optimizer trace prints ranges incorrectly for multi-part keys
Submitted: 15 Jun 2019 11:07 Modified: 16 Jun 2019 5:57
Reporter: Sergei Petrunia Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Optimizer Severity:S3 (Non-critical)
Version:5.7.26,8.0.16 OS:Any
Assigned to: CPU Architecture:Any

[15 Jun 2019 11:07] Sergei Petrunia
Description:
BUG#95823 shows a similar issue in EXPLAIN FORMAT=JSON. Now, let's look how some multi-part ranges are printed into the optimizer trace.

How to repeat:
##
## Using the same dataset as in BUG#95823:
##
create table ten(a int primary key);
insert into ten values (0),(1),(2),(3),(4),(5),(6),(7),(8),(9);
create table one_k(a int primary key);
insert into one_k select A.a + B.a* 10 + C.a * 100 from ten A, ten B, ten C;

create table t1 (start_date date, end_date date, filler char(100), key(start_date, end_date));
insert into t1 select date_add(now(), interval a day), date_add(now(), interval (a+7) day), 'data' from one_k;

## The test
mysql> set optimizer_trace=1;                                                                                                                                           Query OK, 0 rows affected (0.00 sec)

mysql> explain select * from t1 force index(start_date) where start_date >= '2019-02-10' and end_date <'2019-04-01';
+----+-------------+-------+------------+-------+---------------+------------+---------+------+------+----------+-----------------------+
| id | select_type | table | partitions | type  | possible_keys | key        | key_len | ref  | rows | filtered | Extra                 |
+----+-------------+-------+------------+-------+---------------+------------+---------+------+------+----------+-----------------------+
|  1 | SIMPLE      | t1    | NULL       | range | start_date    | start_date | 8       | NULL | 1000 |    33.33 | Using index condition |
+----+-------------+-------+------------+-------+---------------+------------+---------+------+------+----------+-----------------------+

mysql> select * from information_schema.optimizer_trace\G
...
                  "analyzing_range_alternatives": {
                    "range_scan_alternatives": [
                      {
                        "index": "start_date",
                        "ranges": [
                          "0x4ac60f <= start_date"
                        ],
                        "index_dives_for_eq_ranges": true,
                        "rowid_ordered": false,
                        "using_mrr": false,
                        "index_only": false,
                        "rows": 1000,
                        "cost": 350.26,
                        "chosen": true
                      }
                    ],

... and the same below:

                  "chosen_range_access_summary": {
                    "range_access_plan": {
                      "type": "range_scan",
                      "index": "start_date",
                      "rows": 1000,
                      "ranges": [
                        "0x4ac60f <= start_date"
                      ]

This shows just one key part, while the EXPLAIN says that two keyparts are used.  0x4ac60f is the date value that's printed as hex, this is probably a topic for another bug.

Note that the server codebase actually contains the code that prints the ranges correctly. Re-start the server with --debug,  re-run the above, and look into /tmp/mysqld.trace:

T@9: | | | | | | | | | | >print_quick
quick range select, key start_date, length: 8
  2019-02-10/NULL < X
other_keys: 0x0:
T@9: | | | | | | | | | | <print_quick 15354
[16 Jun 2019 5:57] Umesh Shastry
Hello Sergei,

Thank you for the report and test case.
Verified as described.

regards,
Umesh