Bug #82969 InnoDB statistics update may temporarily cause wrong index cardinalities
Submitted: 13 Sep 2016 13:05 Modified: 14 Sep 2016 8:19
Reporter: Sergey Petrunya Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S3 (Non-critical)
Version:5.7.15 OS:Any
Assigned to: CPU Architecture:Any

[13 Sep 2016 13:05] Sergey Petrunya
Description:
This is coming from https://jira.mariadb.org/browse/MDEV-10790.

The issue is similar to http://bugs.mysql.com/bug.php?id=82968 , but this time,  it's about index cardinalities.  Suggested fix for the above bug doesn't fix this one.

The bug is a race condition in updating index cardinalities. Cardinalities are reset and then updated, so an unlucky query may see a very wrong index cardinality values.

How to repeat:
* Apply the attached patch. The patch adds a few debug printouts, and a way to stop index cardinality update at an "interesting" point.

* Run the commands  (my comments start with ##)

Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MySQL connection id is 2
Server version: 5.7.15-debug Source distribution

Copyright (c) 2000, 2016, Oracle, MariaDB Corporation Ab and others.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

MySQL [(none)]> use test;
Database changed
MySQL [test]> create table ten(a int) engine=myisam;
Query OK, 0 rows affected (0.04 sec)

MySQL [test]> insert into ten values (0),(1),(2),(3),(4),(5),(6),(7),(8),(9);
Query OK, 10 rows affected (0.00 sec)
Records: 10  Duplicates: 0  Warnings: 0

MySQL [test]>  
MySQL [test]> create table one_k(a int) engine=myisam;
Query OK, 0 rows affected (0.03 sec)

MySQL [test]> insert into one_k select A.a + B.a* 10 + C.a * 100 from ten A, ten B, ten C;
Query OK, 1000 rows affected (0.01 sec)
Records: 1000  Duplicates: 0  Warnings: 0

MySQL [test]>  
MySQL [test]> create table t0 (a int) engine=myisam;
Query OK, 0 rows affected (0.02 sec)

MySQL [test]> insert into t0 values (1),(2),(3);
Query OK, 3 rows affected (0.00 sec)
Records: 3  Duplicates: 0  Warnings: 0

MySQL [test]>  
MySQL [test]> create table t1 (
    ->   pk int primary key,
    ->   col1 int not null,
    ->   col2 int not null,
    ->   key(col1)
    -> ) engine= innodb;
Query OK, 0 rows affected (0.25 sec)

MySQL [test]>  
MySQL [test]> insert into t1 select a,a,a from one_k;
Query OK, 1000 rows affected (0.23 sec)
Records: 1000  Duplicates: 0  Warnings: 0

MySQL [test]> analyze table t1;
+---------+---------+----------+----------+
| Table   | Op      | Msg_type | Msg_text |
+---------+---------+----------+----------+
| test.t1 | analyze | status   | OK       |
+---------+---------+----------+----------+
1 row in set (0.08 sec)

MySQL [test]> explain select * from t0, t1 where t1.col1=t0.a;
+----+-------------+-------+------------+------+---------------+------+---------+-----------+------+----------+-------------+
| id | select_type | table | partitions | type | possible_keys | key  | key_len | ref       | rows | filtered | Extra       |
+----+-------------+-------+------------+------+---------------+------+---------+-----------+------+----------+-------------+
|  1 | SIMPLE      | t0    | NULL       | ALL  | NULL          | NULL | NULL    | NULL      |    3 |   100.00 | Using where |
|  1 | SIMPLE      | t1    | NULL       | ref  | col1          | col1 | 4       | test.t0.a |    1 |   100.00 | NULL        |
+----+-------------+-------+------------+------+---------------+------+---------+-----------+------+----------+-------------+
2 rows in set, 1 warning (0.01 sec)

## ^^ Observe t1.rows=1 which is a precise index statistics. Good so far.

##  Now, make innodb's statistics update stop in the middle of update:
MySQL [test]> system touch /tmp/dict_stats_analyze_index_must_stop

## Do something to cause auto statistics update (we are running 
##    with innodb_stats_auto_recalc=ON, which is the default).

MySQL [test]> insert into t1 select 5000+pk,5000+col1, 5000+col2 from t1 limit 2000;
Query OK, 1000 rows affected (0.38 sec)
Records: 1000  Duplicates: 0  Warnings: 0

## OPTIONAL: You can check the server stderr and see this line there:
##     AAA: dict_stats_analyze_index called dict_stats_empty_index for col1

## Now,  the test query again:

MySQL [test]> flush tables;
Query OK, 0 rows affected (0.00 sec)

MySQL [test]> explain select * from t0, t1 where t1.col1=t0.a;
+----+-------------+-------+------------+------+---------------+------+---------+------+------+----------+----------------------------------------------------+
| id | select_type | table | partitions | type | possible_keys | key  | key_len | ref  | rows | filtered | Extra                                              |
+----+-------------+-------+------------+------+---------------+------+---------+------+------+----------+----------------------------------------------------+
|  1 | SIMPLE      | t0    | NULL       | ALL  | NULL          | NULL | NULL    | NULL |    3 |   100.00 | NULL                                               |
|  1 | SIMPLE      | t1    | NULL       | ALL  | col1          | NULL | NULL    | NULL | 2000 |   100.00 | Using where; Using join buffer (Block Nested Loop) |
+----+-------------+-------+------------+------+---------------+------+---------+------+------+----------+----------------------------------------------------+
2 rows in set, 1 warning (0.01 sec)

## Note rows=2000 ! The real value is rows=1, both before and after the update. 
## The value one is seeing is about equal to table_rows

## Let the stats calculation finish:
MySQL [test]> system rm  /tmp/dict_stats_analyze_index_must_stop

# Wait a few seconds, and check again:

MySQL [test]> flush tables;
Query OK, 0 rows affected (0.00 sec)

MySQL [test]> explain select * from t0, t1 where t1.col1=t0.a;
+----+-------------+-------+------------+------+---------------+------+---------+-----------+------+----------+-------------+
| id | select_type | table | partitions | type | possible_keys | key  | key_len | ref       | rows | filtered | Extra       |
+----+-------------+-------+------------+------+---------------+------+---------+-----------+------+----------+-------------+
|  1 | SIMPLE      | t0    | NULL       | ALL  | NULL          | NULL | NULL    | NULL      |    3 |   100.00 | Using where |
|  1 | SIMPLE      | t1    | NULL       | ref  | col1          | col1 | 4       | test.t0.a |    1 |   100.00 | NULL        |
+----+-------------+-------+------------+------+---------------+------+---------+-----------+------+----------+-------------+
2 rows in set, 1 warning (0.01 sec)

# Everything's back to normal.                                                                                                               
                                                         

Suggested fix:
None yet. Index statistics should be updated atomically, somehow?
[14 Sep 2016 4:57] Umesh Shastry
Hello Sergey,

Thank you for the report and test case.
Imho you forgot to attach patch here but for now I've used patch(mdev10790-mysql-5.7.diff) from the original bug report to reproduce.

Thanks,
Umesh
[14 Sep 2016 5:00] Umesh Shastry
test results

Attachment: 82969_5.7.15.results (application/octet-stream, text), 8.50 KiB.

[14 Sep 2016 5:15] Laurynas Biveinis
Bug 78401?
[14 Sep 2016 8:19] Sergey Petrunya
Confirm Laurynas's finding. Bug#78401 is the same issue.  The difference is manifestation - this bug shows how a suffers from index cardinality stats, while in #78401 filesort code suffers from wrong results ofstimate_rows_upper_bound() call.
[14 Sep 2016 8:21] Sergey Petrunya
Patch with debug printouts (as mentioned in the report)

Attachment: mdev10790-mysql-5.7.diff (text/x-patch), 1.45 KiB.