Tidb: Plan binding evolution rejecting improved plans

Created on 12 Oct 2020  路  17Comments  路  Source: pingcap/tidb

Description

Bug Report

Please answer these questions before submitting your issue. Thanks!

1. Minimal reproduce step (Required)

Consider the following test case:

DROP TABLE IF EXISTS t1;
CREATE TABLE t1 (
 pk VARBINARY(36) NOT NULL PRIMARY KEY,
 b BIGINT NOT NULL,
 c BIGINT NOT NULL,
 pad VARBINARY(2048),
 INDEX (b)
);
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM dual;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
SELECT SLEEP(2);
ANALYZE TABLE t1;
SELECT SLEEP(2);

SELECT * FROM t1 WHERE b = 2 AND c = 123412;
SELECT * FROM t1 WHERE b = 3 AND c = 392812;
SELECT * FROM t1 WHERE b = 4 AND c = 932932;
DROP GLOBAL BINDING FOR SELECT * FROM t1 WHERE b = 3 AND c = 321210; -- drop incase this example is run twice
SHOW GLOBAL BINDINGS;
ADMIN CAPTURE BINDINGS;
SHOW GLOBAL BINDINGS;

EXPLAIN SELECT * FROM t1 WHERE b = 4 AND c = 3921228;
ALTER TABLE t1 ADD INDEX (c);
SELECT SLEEP(2);
ANALYZE TABLE t1;
SELECT SLEEP(2);
EXPLAIN SELECT * FROM t1 WHERE b = 1 AND c = 275628;

SELECT SLEEP(10); -- allow background work from alter table etc to settle

SET tidb_evolve_plan_baselines = 1;
SELECT SLEEP(2);
SELECT * FROM t1 WHERE b = 2 AND c = 3924541;

SHOW GLOBAL BINDINGS;
SELECT SLEEP(1);
SHOW GLOBAL BINDINGS;
SELECT SLEEP(10);
SHOW GLOBAL BINDINGS;

2. What did you expect to see? (Required)

The new plan is faster, and should be accepted. Here is the output from EXPLAIN ANALYZE:

mysql> explain analyze SELECT /*+ use_index(@`sel_1` `test`.`t1` `b`)*/ * FROM `t1` WHERE `b`=2 AND `c`=123412;
+-------------------------------+-----------+---------+-----------+----------------------+--------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------+----------------------+------+
| id                            | estRows   | actRows | task      | access object        | execution info                                                                                                                             | operator info                 | memory               | disk |
+-------------------------------+-----------+---------+-----------+----------------------+--------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------+----------------------+------+
| IndexLookUp_8                 | 0.20      | 0       | root      |                      | time:457.133993ms, loops:1, cop_task: {num: 1, max:495.556碌s, proc_keys: 0, rpc_num: 1, rpc_time: 469.706碌s, copr_cache_hit_ratio: 1.00}   |                               | 6.245874404907227 MB | N/A  |
| 鈹溾攢IndexRangeScan_5(Build)     | 128139.00 | 128389  | cop[tikv] | table:t1, index:b(b) | time:52ms, loops:130                                                                                                                       | range:[2,2], keep order:false | N/A                  | N/A  |
| 鈹斺攢Selection_7(Probe)          | 0.20      | 0       | cop[tikv] |                      | time:0ns, loops:0                                                                                                                          | eq(test.t1.c, 123412)         | N/A                  | N/A  |
|   鈹斺攢TableRowIDScan_6          | 128139.00 | 0       | cop[tikv] | table:t1             | time:0ns, loops:0                                                                                                                          | keep order:false              | N/A                  | N/A  |
+-------------------------------+-----------+---------+-----------+----------------------+--------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------+----------------------+------+
4 rows in set (0.46 sec)

mysql> explain analyze SELECT /*+ use_index(@`sel_1` `test`.`t1` `c`)*/ * FROM `test`.`t1` WHERE `b`=2 AND `c`=3924541;
+-------------------------------+---------+---------+-----------+----------------------+------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------------------+-----------+------+
| id                            | estRows | actRows | task      | access object        | execution info                                                                                                                           | operator info                             | memory    | disk |
+-------------------------------+---------+---------+-----------+----------------------+------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------------------+-----------+------+
| IndexLookUp_8                 | 0.00    | 0       | root      |                      | time:706.484碌s, loops:1, cop_task: {num: 1, max:595.214碌s, proc_keys: 0, rpc_num: 1, rpc_time: 564.225碌s, copr_cache_hit_ratio: 0.00}    |                                           | 185 Bytes | N/A  |
| 鈹溾攢IndexRangeScan_5(Build)     | 0.00    | 0       | cop[tikv] | table:t1, index:c(c) | time:0s, loops:1                                                                                                                         | range:[3924541,3924541], keep order:false | N/A       | N/A  |
| 鈹斺攢Selection_7(Probe)          | 0.00    | 0       | cop[tikv] |                      | time:0ns, loops:0                                                                                                                        | eq(test.t1.b, 2)                          | N/A       | N/A  |
|   鈹斺攢TableRowIDScan_6          | 0.00    | 0       | cop[tikv] | table:t1             | time:0ns, loops:0                                                                                                                        | keep order:false                          | N/A       | N/A  |
+-------------------------------+---------+---------+-----------+----------------------+------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------------------+-----------+------+
4 rows in set (0.00 sec)

3. What did you see instead (Required)

The new plan is rejected:

mysql> SHOW GLOBAL BINDINGS\G
*************************** 1. row ***************************
Original_sql: select * from t1 where b = ? and c = ?
    Bind_sql: SELECT /*+ use_index(@`sel_1` `test`.`t1` `b`)*/ * FROM `t1` WHERE `b`=2 AND `c`=123412
  Default_db: test
      Status: using
 Create_time: 2020-10-12 14:50:09.461
 Update_time: 2020-10-12 14:50:09.461
     Charset: 
   Collation: 
      Source: capture
*************************** 2. row ***************************
Original_sql: select * from t1 where b = ? and c = ?
    Bind_sql: SELECT /*+ use_index(@`sel_1` `test`.`t1` `c`)*/ * FROM `test`.`t1` WHERE `b`=2 AND `c`=3924541
  Default_db: test
      Status: rejected
 Create_time: 2020-10-12 14:50:52.311
 Update_time: 2020-10-12 14:50:55.311
     Charset: utf8
   Collation: utf8_general_ci
      Source: evolve
2 rows in set (0.00 sec)

4. What is your TiDB version? (Required)

mysql> select tidb_version()\G
*************************** 1. row ***************************
tidb_version(): Release Version: v4.0.0-beta.2-1357-g38ecab6a7
Edition: Community
Git Commit Hash: 38ecab6a7c1dde3c9a2ed2713b3a69d63f662b77
Git Branch: master
UTC Build Time: 2020-10-12 12:52:19
GoVersion: go1.13
Race Enabled: false
TiKV Min Version: v3.0.0-60965b006877ca7234adaced7890d7b029ed1306
Check Table Before Drop: false
1 row in set (0.00 sec)

SIG slack channel

#sig-planner

Score

  • 300

Mentor

  • @lzmhhh123
challenge-program difficulteasy severitcritical siplanner statuhelp-wanted typbug
Source
picture nullnotnil

Most helpful comment

OK, I finally made it to understand the root cause. Here is a minimal repro:

CREATE TABLE t1 (
 pk VARBINARY(36) NOT NULL PRIMARY KEY,
 b BIGINT NOT NULL,
 c BIGINT NOT NULL,
 pad VARBINARY(2048),
 INDEX (b),
 INDEX (c)
);

MySQL [test]> create global binding for select * from t1 WHERE b=2 AND c=3924541 using select /*+ use_index(@sel_1 test.t1 b) */ * from t1 WHERE b=2 AND c=3924541;
Query OK, 0 rows affected (0.01 sec)

MySQL [test]> explain SELECT /*+ use_index(@`sel_1` `test`.`t1` `c`)*/ * FROM `test`.`t1` WHERE `b`=2 AND `c`=3924541;
+-------------------------------+---------+-----------+----------------------+---------------------------------------------------------+
| id                            | estRows | task      | access object        | operator info                                           |
+-------------------------------+---------+-----------+----------------------+---------------------------------------------------------+
| IndexLookUp_8                 | 0.01    | root      |                      |                                                         |
| 鈹溾攢IndexRangeScan_5(Build)     | 10.00   | cop[tikv] | table:t1, index:c(c) | range:[3924541,3924541], keep order:false, stats:pseudo |
| 鈹斺攢Selection_7(Probe)          | 0.01    | cop[tikv] |                      | eq(test.t1.b, 2)                                        |
|   鈹斺攢TableRowIDScan_6          | 10.00   | cop[tikv] | table:t1             | keep order:false, stats:pseudo                          |
+-------------------------------+---------+-----------+----------------------+---------------------------------------------------------+
4 rows in set (0.00 sec)

The query SELECT /*+ use_index(@sel_1 test.t1 c) */ * FROM test.t1 WHERE b=2 AND c=3924541 would be normalized as select * from test . t1 where b = ? and c = ?, while the original_sql of the created bind is select * from t1 where b = ? and c = ?, they do not match, so the bind cannot be hit.

picture eurekaka on 21 Oct 2020
👍2

All 17 comments

My dev env has so poor performance that I cannot finish the expensive data insert steps.

Can you build index on c in the CREATE TABLE statement as well, and utilize SQL hint in the first 3 SELECT queries to force using index b(or manually create the SQL binding to use index b)? i.e, the bound plan still uses index b, and we can rule out the impact of DDL on this case.

Also, you can use admin evolve bindings to trigger a round of plan evolution manually, instead of sleep() to wait for the uncertain events.

eurekaka picture eurekaka on 13 Oct 2020

My dev env has so poor performance that I cannot finish the expensive data insert steps.

You should be able to reproduce with half of the insert steps. My machine is very powerful though (128G RAM, NVMe SSD etc.)

Here is the revised test case based on your instructions. Let me know if I missed anything:

DROP TABLE IF EXISTS t1;
CREATE TABLE t1 (
 pk VARBINARY(36) NOT NULL PRIMARY KEY,
 b BIGINT NOT NULL,
 c BIGINT NOT NULL,
 pad VARBINARY(2048),
 INDEX (b),
 INDEX (c)
);
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM dual;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM t1 a JOIN t1 b JOIN t1 c LIMIT 10000;
SELECT SLEEP(2);
ANALYZE TABLE t1;
SELECT SLEEP(2);

SELECT * FROM t1 FORCE INDEX (b) WHERE b = 2 AND c = 123412;
SELECT * FROM t1 FORCE INDEX (b) WHERE b = 3 AND c = 392812;
SELECT * FROM t1 FORCE INDEX (b) WHERE b = 4 AND c = 932932;
DROP GLOBAL BINDING FOR SELECT * FROM t1 WHERE b = 3 AND c = 321210; -- drop incase this example is run twice
SHOW GLOBAL BINDINGS;
ADMIN CAPTURE BINDINGS;
SHOW GLOBAL BINDINGS;

EXPLAIN SELECT * FROM t1 WHERE b = 4 AND c = 3921228;
ALTER TABLE t1 ADD INDEX (c);
SELECT SLEEP(2);
ANALYZE TABLE t1;
SELECT SLEEP(2);
EXPLAIN SELECT * FROM t1 WHERE b = 1 AND c = 275628;

SELECT SLEEP(10); -- allow background work from alter table etc to settle

SET tidb_evolve_plan_baselines = 1;
SELECT SLEEP(2);
SELECT * FROM t1 WHERE b = 2 AND c = 3924541;
admin evolve bindings;

SHOW GLOBAL BINDINGS;
SELECT SLEEP(1);
SHOW GLOBAL BINDINGS;
SELECT SLEEP(10);
SHOW GLOBAL BINDINGS;

The output shows the plan is still rejected:

Original_sql    Bind_sql        Default_db      Status  Create_time     Update_time     Charset Collation       Source
select * from t1 where b = ? and c = ?  SELECT /*+ use_index(@`sel_1` `test`.`t1` `b`)*/ * FROM `t1` WHERE `b`=2 AND `c`=123412 test    using   2020-10-12 22:27:22.690 2020-10-12 22:27:22.690  capture
select * from t1 where b = ? and c = ?  SELECT /*+ use_index(@`sel_1` `test`.`t1` `c`)*/ * FROM `test`.`t1` WHERE `b`=2 AND `c`=3924541 test    rejected        2020-10-12 22:28:09.140 2020-10-12 22:28:12.140   utf8    utf8_general_ci evolve
nullnotnil picture nullnotnil on 13 Oct 2020

I still cannot reproduce your problem. Here is my output:

SELECT * FROM t1 FORCE INDEX (b) WHERE b = 2 AND c = 123412;
SELECT * FROM t1 FORCE INDEX (b) WHERE b = 3 AND c = 392812;
SELECT * FROM t1 FORCE INDEX (b) WHERE b = 4 AND c = 932932;
DROP GLOBAL BINDING FOR SELECT * FROM t1 WHERE b = 3 AND c = 321210; -- drop incase this example is run twice
SHOW GLOBAL BINDINGS;
ADMIN CAPTURE BINDINGS;
SHOW GLOBAL BINDINGS;

SET tidb_evolve_plan_baselines = 1;
SELECT * FROM t1 WHERE b = 2 AND c = 3924541;
admin evolve bindings;

SHOW GLOBAL BINDINGS;

+----------------------------------------+-------------------------------------------------------------------------------------------------+------------+--------+-------------------------+-------------------------+---------+-----------------+---------+
| Original_sql                           | Bind_sql                                                                                        | Default_db | Status | Create_time             | Update_time             | Charset | Collation       | Source  |
+----------------------------------------+-------------------------------------------------------------------------------------------------+------------+--------+-------------------------+-------------------------+---------+-----------------+---------+
| select * from t1 where b = ? and c = ? | SELECT /*+ use_index(@`sel_1` `test`.`t1` `b`)*/ * FROM `t1` WHERE `b`=2 AND `c`=123412         | test       | using  | 2020-10-14 15:55:39.335 | 2020-10-14 15:55:39.335 |         |                 | capture |
| select * from t1 where b = ? and c = ? | SELECT /*+ use_index(@`sel_1` `test`.`t1` `c`)*/ * FROM `test`.`t1` WHERE `b`=2 AND `c`=3924541 | test       | using  | 2020-10-14 15:57:11.137 | 2020-10-14 15:57:14.008 | utf8    | utf8_general_ci | evolve  |
+----------------------------------------+-------------------------------------------------------------------------------------------------+------------+--------+-------------------------+-------------------------+---------+-----------------+---------+
eurekaka picture eurekaka on 14 Oct 2020

/label sig/planner

lhy1024 picture lhy1024 on 16 Oct 2020

Sorry, it took me a could of days to get back. I asked some colleagues to verify to make sure I'm not crazy. It is a flaky issue, but I added some debugging code which helps understand the issue:

diff --git a/bindinfo/handle.go b/bindinfo/handle.go
index a120463db..5e7278f84 100644
--- a/bindinfo/handle.go
+++ b/bindinfo/handle.go
@@ -756,6 +756,10 @@ const (
        // acceptFactor is the factor to decide should we accept the pending verified plan.
        // A pending verified plan will be accepted if it performs at least `acceptFactor` times better than the accepted plans.
        acceptFactor = 1.5
+       // verifyTimeoutFactor is how long to wait to verify the pending plan.
+       // For debugging purposes it is useful to wait a few times longer than the current execution time so that
+       // an informative error can be written to the log.
+       verifyTimeoutFactor = 2.0
        // nextVerifyDuration is the duration that we will retry the rejected plans.
        nextVerifyDuration = 7 * 24 * time.Hour
 )
@@ -808,6 +812,7 @@ func (h *BindHandle) getRunningDuration(sctx sessionctx.Context, db, sql string,
                return time.Since(startTime), nil
        case <-timer.C:
                cancelFunc()
+               logutil.BgLogger().Warn("plan verification timed out", zap.Duration("timeElapsed", time.Since(startTime)))
        }
        <-resultChan
        return -1, nil
@@ -857,7 +862,7 @@ func (h *BindHandle) HandleEvolvePlanTask(sctx sessionctx.Context, adminEvolve b
                return nil
        }
        sctx.GetSessionVars().UsePlanBaselines = true
-       acceptedPlanTime, err := h.getRunningDuration(sctx, db, binding.BindSQL, maxTime)
+       currentPlanTime, err := h.getRunningDuration(sctx, db, binding.BindSQL, maxTime)
        // If we just return the error to the caller, this job will be retried again and again and cause endless logs,
        // since it is still in the bind record. Now we just drop it and if it is actually retryable,
        // we will hope for that we can capture this evolve task again.
@@ -866,16 +871,17 @@ func (h *BindHandle) HandleEvolvePlanTask(sctx sessionctx.Context, adminEvolve b
        }
        // If the accepted plan timeouts, it is hard to decide the timeout for verify plan.
        // Currently we simply mark the verify plan as `using` if it could run successfully within maxTime.
-       if acceptedPlanTime > 0 {
-               maxTime = time.Duration(float64(acceptedPlanTime) / acceptFactor)
+       if currentPlanTime > 0 {
+               maxTime = time.Duration(float64(currentPlanTime) * verifyTimeoutFactor)
        }
        sctx.GetSessionVars().UsePlanBaselines = false
        verifyPlanTime, err := h.getRunningDuration(sctx, db, binding.BindSQL, maxTime)
        if err != nil {
                return h.DropBindRecord(originalSQL, db, &binding)
        }
-       if verifyPlanTime < 0 {
+       if verifyPlanTime == -1 || (float64(verifyPlanTime) * acceptFactor > float64(currentPlanTime)) {
                binding.Status = Rejected
+               logutil.BgLogger().Warn("new plan rejected", zap.Duration("currentPlanTime", currentPlanTime), zap.Duration("verifyPlanTime", verifyPlanTime))
        } else {
                binding.Status = Using
        }

My understanding from rejected executions, is that there is a bug in the recorded time for the current plan in use. i.e. I will get a debug line like this one:

[2020/10/19 15:07:46.525 -06:00] [WARN] [handle.go:884] ["new plan rejected"] [currentPlanTime=1.245585ms] [verifyPlanTime=1.160435ms]

But there is no way that the current plan executes that fast. It should be 300ms+:

mysql> SELECT /*+ use_index(@`sel_1` `test`.`t1` `b`)*/ * FROM `t1` WHERE `b`=2 AND `c`=123412;
Empty set (0.37 sec)

mysql> SELECT /*+ use_index(@`sel_1` `test`.`t1` `b`)*/ * FROM `t1` WHERE `b`=2 AND `c`=123412;
Empty set (0.42 sec)

mysql> SELECT /*+ use_index(@`sel_1` `test`.`t1` `b`)*/ * FROM `t1` WHERE `b`=2 AND `c`=123412;
Empty set (0.39 sec)

mysql> SELECT /*+ use_index(@`sel_1` `test`.`t1` `b`)*/ * FROM `t1` WHERE `b`=2 AND `c`=123412;
Empty set (0.41 sec)

mysql> SELECT /*+ use_index(@`sel_1` `test`.`t1` `b`)*/ * FROM `t1` WHERE `b`=2 AND `c`=123412;
Empty set (0.44 sec)

mysql> SELECT /*+ use_index(@`sel_1` `test`.`t1` `b`)*/ * FROM `t1` WHERE `b`=2 AND `c`=123412;
Empty set (0.39 sec)

mysql> SELECT /*+ use_index(@`sel_1` `test`.`t1` `b`)*/ * FROM `t1` WHERE `b`=2 AND `c`=123412;
Empty set (0.40 sec)

mysql> SELECT /*+ use_index(@`sel_1` `test`.`t1` `b`)*/ * FROM `t1` WHERE `b`=2 AND `c`=123412;
Empty set (0.38 sec)

It is almost as if it is using the timing of the new plan both times.

nullnotnil picture nullnotnil on 19 Oct 2020

~I found the bug. The currentPlanTime may be calculated using the new binding.bindSQL:~ See below

diff --git a/bindinfo/handle.go b/bindinfo/handle.go
index 03757e3da..794cb73a7 100644
--- a/bindinfo/handle.go
+++ b/bindinfo/handle.go
@@ -862,6 +862,7 @@ func (h *BindHandle) HandleEvolvePlanTask(sctx sessionctx.Context, adminEvolve b
                return nil
        }
        sctx.GetSessionVars().UsePlanBaselines = true
+       fmt.Printf("originalSQL: %s, bindsql: %s\n", originalSQL, binding.BindSQL)
        currentPlanTime, err := h.getRunningDuration(sctx, db, binding.BindSQL, maxTime)
        // If we just return the error to the caller, this job will be retried again and again and cause endless logs,
        // since it is still in the bind record. Now we just drop it and if it is actually retryable,

Outputs to my log file:

originalSQL: select * from t1 where b = ? and c = ?, bindsql: SELECT /*+ use_index(@`sel_1` `test`.`t1` `c`)*/ * FROM `test`.`t1` WHERE `b`=2 AND `c`=3924541

Which if I execute in MySQL it does not use the existing binding:

mysql> SELECT /*+ use_index(@`sel_1` `test`.`t1` `c`)*/ * FROM `test`.`t1` WHERE `b`=2 AND `c`=3924541;
Empty set (0.00 sec)

~What it should be evaluating is either the Original_sql (with values inserted), or some variant of the new bindsql with hints refering to the existing plan in use.~ (see below)

nullnotnil picture nullnotnil on 20 Oct 2020

Edit that. It's even simpler. The reason why it doesn't use the existing plan is because of the qualified schema name:

mysql> SELECT /*+ use_index(@`sel_1` `test`.`t1` `c`)*/ * FROM `test`.`t1` WHERE `b`=2 AND `c`=3924541;
Empty set (0.00 sec)

mysql> SELECT /*+ use_index(@`sel_1` `test`.`t1` `c`)*/ * FROM `t1` WHERE `b`=2 AND `c`=3924541;
Empty set (0.39 sec)

In EXPLAIN ANALYZE:

mysql> EXPLAIN ANALYZE SELECT /*+ use_index(@`sel_1` `test`.`t1` `c`)*/ * FROM `t1` WHERE `b`=2 AND `c`=3924541;
+-------------------------------+-----------+---------+-----------+----------------------+--------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------+----------------------+------+
| id                            | estRows   | actRows | task      | access object        | execution info                                                                                                                             | operator info                 | memory               | disk |
+-------------------------------+-----------+---------+-----------+----------------------+--------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------+----------------------+------+
| IndexLookUp_8                 | 0.33      | 0       | root      |                      | time:358.144985ms, loops:1, cop_task: {num: 1, max:573.157碌s, proc_keys: 0, rpc_num: 1, rpc_time: 537.777碌s, copr_cache_hit_ratio: 1.00}   |                               | 6.046115875244141 MB | N/A  |
| 鈹溾攢IndexRangeScan_5(Build)     | 154037.22 | 128190  | cop[tikv] | table:t1, index:b(b) | time:52ms, loops:130                                                                                                                       | range:[2,2], keep order:false | N/A                  | N/A  |
| 鈹斺攢Selection_7(Probe)          | 0.33      | 0       | cop[tikv] |                      | time:0ns, loops:0                                                                                                                          | eq(test.t1.c, 3924541)        | N/A                  | N/A  |
|   鈹斺攢TableRowIDScan_6          | 154037.22 | 0       | cop[tikv] | table:t1             | time:0ns, loops:0                                                                                                                          | keep order:false              | N/A                  | N/A  |
+-------------------------------+-----------+---------+-----------+----------------------+--------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------+----------------------+------+
4 rows in set (0.36 sec)

mysql> EXPLAIN ANALYZE SELECT /*+ use_index(@`sel_1` `test`.`t1` `c`)*/ * FROM `test`.`t1` WHERE `b`=2 AND `c`=3924541;
+-------------------------------+---------+---------+-----------+----------------------+------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------------------+-----------+------+
| id                            | estRows | actRows | task      | access object        | execution info                                                                                                                           | operator info                             | memory    | disk |
+-------------------------------+---------+---------+-----------+----------------------+------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------------------+-----------+------+
| IndexLookUp_8                 | 0.33    | 0       | root      |                      | time:736.776碌s, loops:1, cop_task: {num: 1, max:616.756碌s, proc_keys: 0, rpc_num: 1, rpc_time: 579.446碌s, copr_cache_hit_ratio: 0.00}    |                                           | 183 Bytes | N/A  |
| 鈹溾攢IndexRangeScan_5(Build)     | 1.63    | 0       | cop[tikv] | table:t1, index:c(c) | time:0s, loops:1                                                                                                                         | range:[3924541,3924541], keep order:false | N/A       | N/A  |
| 鈹斺攢Selection_7(Probe)          | 0.33    | 0       | cop[tikv] |                      | time:0ns, loops:0                                                                                                                        | eq(test.t1.b, 2)                          | N/A       | N/A  |
|   鈹斺攢TableRowIDScan_6          | 1.63    | 0       | cop[tikv] | table:t1             | time:0ns, loops:0                                                                                                                        | keep order:false                          | N/A       | N/A  |
+-------------------------------+---------+---------+-----------+----------------------+------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------------------+-----------+------+
4 rows in set (0.00 sec)

So to summarize the root cause:

The new plan being compared to itself and is infrequently 1.5x faster. The reason for the compare-to-self is because the bind_sql in the evolved plan fully qualifies the schema name. This makes it fail to match to the existing binding in place for comparison.

nullnotnil picture nullnotnil on 20 Oct 2020

Did you run those queries in the test database? Here is my output:

MySQL [test]> explain select /*+ use_index(@sel_1 test.t1 c) */ * FROM t1 WHERE b=2 AND c=3924541;
+-------------------------------+---------+-----------+----------------------+---------------------------------------------------------+
| id                            | estRows | task      | access object        | operator info                                           |
+-------------------------------+---------+-----------+----------------------+---------------------------------------------------------+
| IndexLookUp_8                 | 0.01    | root      |                      |                                                         |
| 鈹溾攢IndexRangeScan_5(Build)     | 10.00   | cop[tikv] | table:t1, index:c(c) | range:[3924541,3924541], keep order:false, stats:pseudo |
| 鈹斺攢Selection_7(Probe)          | 0.01    | cop[tikv] |                      | eq(test.t1.b, 2)                                        |
|   鈹斺攢TableRowIDScan_6          | 10.00   | cop[tikv] | table:t1             | keep order:false, stats:pseudo                          |
+-------------------------------+---------+-----------+----------------------+---------------------------------------------------------+
4 rows in set (0.00 sec)

MySQL [test]> explain select * FROM t1 WHERE b=2 AND c=3924541;
+-------------------------------+---------+-----------+----------------------+---------------------------------------------+
| id                            | estRows | task      | access object        | operator info                               |
+-------------------------------+---------+-----------+----------------------+---------------------------------------------+
| IndexLookUp_11                | 0.01    | root      |                      |                                             |
| 鈹溾攢IndexRangeScan_8(Build)     | 10.00   | cop[tikv] | table:t1, index:b(b) | range:[2,2], keep order:false, stats:pseudo |
| 鈹斺攢Selection_10(Probe)         | 0.01    | cop[tikv] |                      | eq(test.t1.c, 3924541)                      |
|   鈹斺攢TableRowIDScan_9          | 10.00   | cop[tikv] | table:t1             | keep order:false, stats:pseudo              |
+-------------------------------+---------+-----------+----------------------+---------------------------------------------+
4 rows in set (0.00 sec)

My TiDB git hash is 106b04ddab7b5aabc42a58f5136565a8c7efb7a5.

eurekaka picture eurekaka on 20 Oct 2020

@eurekaka the output in your query is the same as mine. Note that in the first example, the index c was selected. It should have used the plan binding, as it did in the second query.

I think this will be easiest to debug with https://github.com/pingcap/tidb/pull/18017 - I am going to see if its possible to port this to master.

nullnotnil picture nullnotnil on 20 Oct 2020

With this patch, you should be able to see bindings easier (and not rely on performance data).

Here is a testcase to show the bug:

DROP TABLE IF EXISTS t1;
CREATE TABLE t1 (
 pk VARBINARY(36) NOT NULL PRIMARY KEY,
 b BIGINT NOT NULL,
 c BIGINT NOT NULL,
 pad VARBINARY(2048),
 INDEX (b),
 INDEX (c)
);
INSERT INTO t1 SELECT uuid(), FLOOR(RAND()*5), FLOOR(RAND()*1000000), HEX(RANDOM_BYTES(1000)) FROM dual;
SHOW BINDINGS; -- should be empty

CREATE SESSION BINDING FOR 
SELECT * FROM t1 WHERE b = 2 AND c = 123412
USING
SELECT * FROM t1 FORCE INDEX(b) WHERE b = 2 AND c = 123412;

SHOW BINDINGS; -- should only be one

SELECT * FROM mysql.user; -- the control; should be no bindings
SHOW VARIABLES LIKE 'last_plan_from_binding';

SELECT * FROM t1 WHERE b = 2 AND c = 123412; -- uses a binding
SHOW VARIABLES LIKE 'last_plan_from_binding';

SELECT * FROM mysql.user; -- the control; should be no bindings
SHOW VARIABLES LIKE 'last_plan_from_binding';

SELECT /*+ use_index(@sel_1 test.t1 b) */ * FROM t1 WHERE b=2 AND c=3924541; -- also uses a binding (the def of the binding)
SHOW VARIABLES LIKE 'last_plan_from_binding';

SELECT /*+ use_index(@sel_1 test.t1 c) */ * FROM t1 WHERE b=2 AND c=3924541; -- also uses a binding (despite asking for other index)
SHOW VARIABLES LIKE 'last_plan_from_binding';

SELECT * FROM test.t1 WHERE b = 2 AND c = 123412; -- does not bind
SHOW VARIABLES LIKE 'last_plan_from_binding';

SELECT /*+ use_index(@sel_1 test.t1 b) */ * FROM test.t1 WHERE b=2 AND c=3924541; -- does not bind
SHOW VARIABLES LIKE 'last_plan_from_binding';

SELECT /*+ use_index(@sel_1 test.t1 c) */ * FROM test.t1 WHERE b=2 AND c=3924541; -- does not bind
SHOW VARIABLES LIKE 'last_plan_from_binding';

SELECT * FROM mysql.user; -- the control; should be no bindings
SHOW VARIABLES LIKE 'last_plan_from_binding';

Output:

mysql> SHOW BINDINGS; -- should only be one
+----------------------------------------+------------------------------------------------------------+------------+--------+-------------------------+-------------------------+---------+-----------------+--------+
| Original_sql                           | Bind_sql                                                   | Default_db | Status | Create_time             | Update_time             | Charset | Collation       | Source |
+----------------------------------------+------------------------------------------------------------+------------+--------+-------------------------+-------------------------+---------+-----------------+--------+
| select * from t1 where b = ? and c = ? | SELECT * FROM t1 FORCE INDEX(b) WHERE b = 2 AND c = 123412 | test       | using  | 2020-10-20 11:15:49.401 | 2020-10-20 11:15:49.401 | utf8    | utf8_general_ci | manual |
+----------------------------------------+------------------------------------------------------------+------------+--------+-------------------------+-------------------------+---------+-----------------+--------+
1 row in set (0.00 sec)

mysql> 
mysql> SELECT * FROM mysql.user; -- the control; should be no bindings
+------+------+-----------------------+-------------+-------------+-------------+-------------+-------------+-----------+--------------+------------+-----------------+------------+--------------+------------+-----------------------+------------------+--------------+------------------+----------------+---------------------+--------------------+------------+------------------+------------+--------------+------------------+----------------+----------------+---------------+-------------+-----------+-------------+------------------------+
| Host | User | authentication_string | Select_priv | Insert_priv | Update_priv | Delete_priv | Create_priv | Drop_priv | Process_priv | Grant_priv | References_priv | Alter_priv | Show_db_priv | Super_priv | Create_tmp_table_priv | Lock_tables_priv | Execute_priv | Create_view_priv | Show_view_priv | Create_routine_priv | Alter_routine_priv | Index_priv | Create_user_priv | Event_priv | Trigger_priv | Create_role_priv | Drop_role_priv | Account_locked | Shutdown_priv | Reload_priv | FILE_priv | Config_priv | Create_Tablespace_Priv |
+------+------+-----------------------+-------------+-------------+-------------+-------------+-------------+-----------+--------------+------------+-----------------+------------+--------------+------------+-----------------------+------------------+--------------+------------------+----------------+---------------------+--------------------+------------+------------------+------------+--------------+------------------+----------------+----------------+---------------+-------------+-----------+-------------+------------------------+
| %    | root |                       | Y           | Y           | Y           | Y           | Y           | Y         | Y            | Y          | Y               | Y          | Y            | Y          | Y                     | Y                | Y            | Y                | Y              | Y                   | Y                  | Y          | Y                | Y          | Y            | Y                | Y              | N              | Y             | Y           | Y         | Y           | Y                      |
+------+------+-----------------------+-------------+-------------+-------------+-------------+-------------+-----------+--------------+------------+-----------------+------------+--------------+------------+-----------------------+------------------+--------------+------------------+----------------+---------------------+--------------------+------------+------------------+------------+--------------+------------------+----------------+----------------+---------------+-------------+-----------+-------------+------------------------+
1 row in set (0.00 sec)

mysql> SHOW VARIABLES LIKE 'last_plan_from_binding';
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| last_plan_from_binding | OFF   |
+------------------------+-------+
1 row in set (0.00 sec)

mysql> 
mysql> SELECT * FROM t1 WHERE b = 2 AND c = 123412; -- uses a binding
Empty set (0.01 sec)

mysql> SHOW VARIABLES LIKE 'last_plan_from_binding';
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| last_plan_from_binding | ON    |
+------------------------+-------+
1 row in set (0.00 sec)

mysql> SELECT * FROM mysql.user; -- the control; should be no bindings
+------+------+-----------------------+-------------+-------------+-------------+-------------+-------------+-----------+--------------+------------+-----------------+------------+--------------+------------+-----------------------+------------------+--------------+------------------+----------------+---------------------+--------------------+------------+------------------+------------+--------------+------------------+----------------+----------------+---------------+-------------+-----------+-------------+------------------------+
| Host | User | authentication_string | Select_priv | Insert_priv | Update_priv | Delete_priv | Create_priv | Drop_priv | Process_priv | Grant_priv | References_priv | Alter_priv | Show_db_priv | Super_priv | Create_tmp_table_priv | Lock_tables_priv | Execute_priv | Create_view_priv | Show_view_priv | Create_routine_priv | Alter_routine_priv | Index_priv | Create_user_priv | Event_priv | Trigger_priv | Create_role_priv | Drop_role_priv | Account_locked | Shutdown_priv | Reload_priv | FILE_priv | Config_priv | Create_Tablespace_Priv |
+------+------+-----------------------+-------------+-------------+-------------+-------------+-------------+-----------+--------------+------------+-----------------+------------+--------------+------------+-----------------------+------------------+--------------+------------------+----------------+---------------------+--------------------+------------+------------------+------------+--------------+------------------+----------------+----------------+---------------+-------------+-----------+-------------+------------------------+
| %    | root |                       | Y           | Y           | Y           | Y           | Y           | Y         | Y            | Y          | Y               | Y          | Y            | Y          | Y                     | Y                | Y            | Y                | Y              | Y                   | Y                  | Y          | Y                | Y          | Y            | Y                | Y              | N              | Y             | Y           | Y         | Y           | Y                      |
+------+------+-----------------------+-------------+-------------+-------------+-------------+-------------+-----------+--------------+------------+-----------------+------------+--------------+------------+-----------------------+------------------+--------------+------------------+----------------+---------------------+--------------------+------------+------------------+------------+--------------+------------------+----------------+----------------+---------------+-------------+-----------+-------------+------------------------+
1 row in set (0.00 sec)

mysql> SHOW VARIABLES LIKE 'last_plan_from_binding';
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| last_plan_from_binding | OFF   |
+------------------------+-------+
1 row in set (0.01 sec)

mysql> SELECT /*+ use_index(@sel_1 test.t1 b) */ * FROM t1 WHERE b=2 AND c=3924541; -- also uses a binding (the def of the binding)
Empty set (0.00 sec)

mysql> SHOW VARIABLES LIKE 'last_plan_from_binding';
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| last_plan_from_binding | ON    |
+------------------------+-------+
1 row in set (0.00 sec)

mysql> 
mysql> SELECT /*+ use_index(@sel_1 test.t1 c) */ * FROM t1 WHERE b=2 AND c=3924541; -- also uses a binding (despite asking for other index)
Empty set (0.00 sec)

mysql> SHOW VARIABLES LIKE 'last_plan_from_binding';
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| last_plan_from_binding | ON    |
+------------------------+-------+
1 row in set (0.00 sec)

mysql> SELECT * FROM test.t1 WHERE b = 2 AND c = 123412; -- does not bind
Empty set (0.00 sec)

mysql> SHOW VARIABLES LIKE 'last_plan_from_binding';
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| last_plan_from_binding | OFF   |
+------------------------+-------+
1 row in set (0.01 sec)

mysql> 
mysql> SELECT /*+ use_index(@sel_1 test.t1 b) */ * FROM test.t1 WHERE b=2 AND c=3924541; -- does not bind
Empty set (0.00 sec)

mysql> SHOW VARIABLES LIKE 'last_plan_from_binding';
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| last_plan_from_binding | OFF   |
+------------------------+-------+
1 row in set (0.00 sec)

mysql> 
mysql> SELECT /*+ use_index(@sel_1 test.t1 c) */ * FROM test.t1 WHERE b=2 AND c=3924541; -- does not bind
Empty set (0.00 sec)

mysql> SHOW VARIABLES LIKE 'last_plan_from_binding';
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| last_plan_from_binding | OFF   |
+------------------------+-------+
1 row in set (0.00 sec)

mysql> 
mysql> SELECT * FROM mysql.user; -- the control; should be no bindings
+------+------+-----------------------+-------------+-------------+-------------+-------------+-------------+-----------+--------------+------------+-----------------+------------+--------------+------------+-----------------------+------------------+--------------+------------------+----------------+---------------------+--------------------+------------+------------------+------------+--------------+------------------+----------------+----------------+---------------+-------------+-----------+-------------+------------------------+
| Host | User | authentication_string | Select_priv | Insert_priv | Update_priv | Delete_priv | Create_priv | Drop_priv | Process_priv | Grant_priv | References_priv | Alter_priv | Show_db_priv | Super_priv | Create_tmp_table_priv | Lock_tables_priv | Execute_priv | Create_view_priv | Show_view_priv | Create_routine_priv | Alter_routine_priv | Index_priv | Create_user_priv | Event_priv | Trigger_priv | Create_role_priv | Drop_role_priv | Account_locked | Shutdown_priv | Reload_priv | FILE_priv | Config_priv | Create_Tablespace_Priv |
+------+------+-----------------------+-------------+-------------+-------------+-------------+-------------+-----------+--------------+------------+-----------------+------------+--------------+------------+-----------------------+------------------+--------------+------------------+----------------+---------------------+--------------------+------------+------------------+------------+--------------+------------------+----------------+----------------+---------------+-------------+-----------+-------------+------------------------+
| %    | root |                       | Y           | Y           | Y           | Y           | Y           | Y         | Y            | Y          | Y               | Y          | Y            | Y          | Y                     | Y                | Y            | Y                | Y              | Y                   | Y                  | Y          | Y                | Y          | Y            | Y                | Y              | N              | Y             | Y           | Y         | Y           | Y                      |
+------+------+-----------------------+-------------+-------------+-------------+-------------+-------------+-----------+--------------+------------+-----------------+------------+--------------+------------+-----------------------+------------------+--------------+------------------+----------------+---------------------+--------------------+------------+------------------+------------+--------------+------------------+----------------+----------------+---------------+-------------+-----------+-------------+------------------------+
1 row in set (0.00 sec)

mysql> SHOW VARIABLES LIKE 'last_plan_from_binding';
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| last_plan_from_binding | OFF   |
+------------------------+-------+
1 row in set (0.00 sec)

The bug is caused because the plan captured by plan evolving is using the form which does not bind.

nullnotnil picture nullnotnil on 20 Oct 2020

OK, I finally made it to understand the root cause. Here is a minimal repro:

CREATE TABLE t1 (
 pk VARBINARY(36) NOT NULL PRIMARY KEY,
 b BIGINT NOT NULL,
 c BIGINT NOT NULL,
 pad VARBINARY(2048),
 INDEX (b),
 INDEX (c)
);

MySQL [test]> create global binding for select * from t1 WHERE b=2 AND c=3924541 using select /*+ use_index(@sel_1 test.t1 b) */ * from t1 WHERE b=2 AND c=3924541;
Query OK, 0 rows affected (0.01 sec)

MySQL [test]> explain SELECT /*+ use_index(@`sel_1` `test`.`t1` `c`)*/ * FROM `test`.`t1` WHERE `b`=2 AND `c`=3924541;
+-------------------------------+---------+-----------+----------------------+---------------------------------------------------------+
| id                            | estRows | task      | access object        | operator info                                           |
+-------------------------------+---------+-----------+----------------------+---------------------------------------------------------+
| IndexLookUp_8                 | 0.01    | root      |                      |                                                         |
| 鈹溾攢IndexRangeScan_5(Build)     | 10.00   | cop[tikv] | table:t1, index:c(c) | range:[3924541,3924541], keep order:false, stats:pseudo |
| 鈹斺攢Selection_7(Probe)          | 0.01    | cop[tikv] |                      | eq(test.t1.b, 2)                                        |
|   鈹斺攢TableRowIDScan_6          | 10.00   | cop[tikv] | table:t1             | keep order:false, stats:pseudo                          |
+-------------------------------+---------+-----------+----------------------+---------------------------------------------------------+
4 rows in set (0.00 sec)

The query SELECT /*+ use_index(@sel_1 test.t1 c) */ * FROM test.t1 WHERE b=2 AND c=3924541 would be normalized as select * from test . t1 where b = ? and c = ?, while the original_sql of the created bind is select * from t1 where b = ? and c = ?, they do not match, so the bind cannot be hit.

eurekaka picture eurekaka on 21 Oct 2020
👍2

/assign @rebelice

rebelice picture rebelice on 20 Nov 2020

Since the SQL select * from t1 where b = ? and c = ? could be recognized to different SQL on different DB context. I think the select * from test . t1 where b = ? and c = ? can't hit the binding is reasonable. Should the issue be an enhancement issue?

OK, I finally made it to understand the root cause. Here is a minimal repro:

CREATE TABLE t1 (
 pk VARBINARY(36) NOT NULL PRIMARY KEY,
 b BIGINT NOT NULL,
 c BIGINT NOT NULL,
 pad VARBINARY(2048),
 INDEX (b),
 INDEX (c)
);

MySQL [test]> create global binding for select * from t1 WHERE b=2 AND c=3924541 using select /*+ use_index(@sel_1 test.t1 b) */ * from t1 WHERE b=2 AND c=3924541;
Query OK, 0 rows affected (0.01 sec)

MySQL [test]> explain SELECT /*+ use_index(@`sel_1` `test`.`t1` `c`)*/ * FROM `test`.`t1` WHERE `b`=2 AND `c`=3924541;
+-------------------------------+---------+-----------+----------------------+---------------------------------------------------------+
| id                            | estRows | task      | access object        | operator info                                           |
+-------------------------------+---------+-----------+----------------------+---------------------------------------------------------+
| IndexLookUp_8                 | 0.01    | root      |                      |                                                         |
| 鈹溾攢IndexRangeScan_5(Build)     | 10.00   | cop[tikv] | table:t1, index:c(c) | range:[3924541,3924541], keep order:false, stats:pseudo |
| 鈹斺攢Selection_7(Probe)          | 0.01    | cop[tikv] |                      | eq(test.t1.b, 2)                                        |
|   鈹斺攢TableRowIDScan_6          | 10.00   | cop[tikv] | table:t1             | keep order:false, stats:pseudo                          |
+-------------------------------+---------+-----------+----------------------+---------------------------------------------------------+
4 rows in set (0.00 sec)

The query SELECT /*+ use_index(@sel_1 test.t1 c) */ * FROM test.t1 WHERE b=2 AND c=3924541 would be normalized as select * from test . t1 where b = ? and c = ?, while the original_sql of the created bind is select * from t1 where b = ? and c = ?, they do not match, so the bind cannot be hit.

lzmhhh123 picture lzmhhh123 on 23 Nov 2020

SPM has many related changes in release-4.0, so this fix delays to v4.0.10
cc @zz-jason @shuke987

SunRunAway picture SunRunAway on 25 Nov 2020

Please edit this comment or add a new comment to complete the following information

1

Not a bug

  1. Remove the 'type/bug' label
  2. Add notes to indicate why it is not a bug

Duplicate bug

  1. Add the 'type/duplicate' label
  2. Add the link to the original bug

Bug

Note: Make Sure that 'component', and 'severity' labels are added
Example for how to fill out the template: https://github.com/pingcap/tidb/issues/20100

1. Root Cause Analysis (RCA) (optional)

2. Symptom (optional)

3. All Trigger Conditions (optional)

4. Workaround (optional)

5. Affected versions

[v4.0.1:v4.0.9]

6. Fixed versions

v4.0.10

ti-srebot picture ti-srebot on 6 Jan 2021

Please edit this comment or add a new comment to complete the following information

Bug

Note: Make Sure that 'component', and 'severity' labels are added

1. Root Cause Analysis (RCA)

The same SQL has two different representations in SPM, that is, it does not contain the schema name and it is represented in the default_db field or contains the name of the complete schema. But in TiDB, we think the two are different.

2. Symptom

SQL bindings cannot take effect.

3. All Trigger Conditions

The bind SQL in SPM does not contain the schema name, but the query SQL does.
The opposite applies.

5. Affected versions


[v4.0.1:v4.0.9]

6. Fixed versions


v4.0.10

rebelice picture rebelice on 29 Jan 2021

( FixedVersions AffectedVersions ) fields are empty.

ti-srebot picture ti-srebot on 29 Jan 2021
Was this page helpful?
0 / 5 - 0 ratings

Related issues

you06 picture you06  路  3Comments
ekexium picture ekexium  路  3Comments
wjhuang2016 picture wjhuang2016  路  3Comments
breeswish picture breeswish  路  3Comments
lysu picture lysu  路  3Comments