./mysql-test-run t/bug82968.test Logging: ./mysql-test-run t/bug82968.test MySQL Version 5.7.13 Checking supported features... - SSL connections supported - binaries are debug compiled Collecting tests... Removing old var directory... Creating var directory '/home/smilivoj/mysql-5.7.13/mysql-test/var'... Installing system database... ============================================================================== TEST RESULT TIME (ms) or COMMENT -------------------------------------------------------------------------- worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009 set @stats_backup= @@innodb_stats_persistent; set @dbug_backup= @@debug; set global innodb_stats_persistent=ON; CREATE TABLE t1 ( pk bigint(20) unsigned NOT NULL, key1 int, col1 int, filler1 varchar(255), filler2 text, PRIMARY KEY (pk), KEY (key1) ) ENGINE=InnoDB; create table ten(a int primary key); insert into ten values (0),(1),(2),(3),(4),(5),(6),(7),(8),(9); insert into t1 (pk, key1) select A.a+10*B.a+100*C.a+1000*D.a, A.a+10*B.a+100*C.a+1000*D.a from ten A, ten B, ten C, ten D; select count(*) from t1; count(*) 10000 # # Normal plan for UPDATE: # explain extended UPDATE t1 SET col1 = 1234 WHERE pk IN (1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20); id select_type table partitions type possible_keys key key_len ref rows filtered Extra 1 UPDATE t1 NULL range PRIMARY PRIMARY 8 const 20 100.00 Using where Warnings: Warning 1681 'EXTENDED' is deprecated and will be removed in a future release. # # Check that it lives up to the plan: # flush status; UPDATE t1 SET col1 = 1234 WHERE pk IN (1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20); show status like 'Handler_read%'; Variable_name Value Handler_read_first 0 Handler_read_key 20 Handler_read_last 0 Handler_read_next 0 Handler_read_prev 0 Handler_read_rnd 0 Handler_read_rnd_next 0 # # Now let's trigger the race condition. # # First, we need to activate the sleep in dict_stats_update: # set global debug= '+d,innodb_wait_with_empty_stats'; set debug= '+d,innodb_wait_with_empty_stats'; # # The sync point is only needed if we want to reproduce the printout from the patch, # where Records == Records2 == 1 and Records3 is the real number. # Without the printing patch the sync point won't make any difference. set debug_sync= 'opt_range_wait_for_innodb_stats WAIT_FOR go'; # flush status; connect con1,localhost,root,,; # # Get the table evicted from the cache; # flush tables with read lock; unlock tables; # # Insert something into the table to trigger a call to dict_stats_update, # which will in turn trigger a call to dict_stats_empty_table and then will repopulate statistics. # Only we have a big delay between the call to dict_stats_empty_table and repopulating statistics, so it will wait there. # We are sending the INSERT now... insert into t1 (pk,key1,col1) select pk+100000, 345,345 from t1 limit 2000; connection default; # # Wait a bit to make sure the insert reached the injected sleep... # # Now, run our UPDATE. The table right now has "empty" statistics, which will give us 1 row, and full scan will be preferred. # Since we might have enabled the sync point, the UPDATE will wait for a signal after it has done the quick check. # We are sending the UPDATE now... # UPDATE t1 SET col1 = 1234 WHERE pk IN (1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20); connection con1; # # Now wait for INSERT to finish, and send the signal to UPDATE to proceed (in case it's waiting on the sync point) # set debug_sync= 'now SIGNAL go'; connection default; # Now the UPDATE is finished too. This is how it ran: # show status like 'Handler_read%'; Variable_name Value Handler_read_first 1 Handler_read_key 1 Handler_read_last 0 Handler_read_next 0 Handler_read_prev 0 Handler_read_rnd 0 Handler_read_rnd_next 12001 # # Cleanup # disconnect con1; connection default; drop table t1; drop table ten; set global innodb_stats_persistent= @stats_backup; set global debug= @dbug_backup; set debug_sync= 'RESET'; main.bug82968 [ fail ] Found warnings/errors in server log file! Test ended at 2016-09-14 15:58:01 line 2016-09-14T13:58:00.770507Z 3 [Warning] DEBUG: Full table scan on table t1. Reason: 'quick == 0' Records2: 1 Records3: 12337 Optimizer_flag: 523775 Query: UPDATE t1 SET col1 = 1234 WHERE pk IN (1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20) ^ Found warnings in /home/smilivoj/mysql-5.7.13/mysql-test/var/log/mysqld.1.err ok - the logfile can be found in '/home/smilivoj/mysql-5.7.13/mysql-test/var/log/main.bug82968/bug82968.log' -------------------------------------------------------------------------- The servers were restarted 0 times Spent 0.000 of 41 seconds executing testcases mysql-test-run: WARNING: Got errors/warnings while running tests, please examine '/home/smilivoj/mysql-5.7.13/mysql-test/var/log/warnings' for details. Completed: Failed 1/1 tests, 0.00% were successful. Failing test(s): main.bug82968 The log files in var/log may give you some hint of what went wrong. If you want to report this error, please read first the documentation at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html mysql-test-run: *** ERROR: there were failing test cases