Bug #75688 Assertion `!first_qep_tab->table()->no_keyread' failed.
Submitted: 30 Jan 2015 4:04 Modified: 23 Feb 2015 15:50
Reporter: Roel Van de Paar Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Optimizer Severity:S6 (Debug Builds)
Version:5.7.5-m15, 5.7.6 OS:Any
Assigned to: Tor Didriksen CPU Architecture:Any

[30 Jan 2015 4:04] Roel Van de Paar
Description:
2015-01-30T03:44:25.411701Z 0 [Note] /sda/MS-mysql-5.7.5-m15-linux-x86_64-debug/bin/mysqld: ready for connections.
Version: '5.7.5-m15-debug'  socket: '/sda/MS-mysql-5.7.5-m15-linux-x86_64-debug/socket.sock'  port: 16633  MySQL Community Server (GPL)
mysqld: /bzr/testbuild/mysql-5.7.5-m15_dbg/sql/sql_optimizer.cc:840: int JOIN::replace_index_subquery(): Assertion `!first_qep_tab->table()->no_keyread' failed.
03:44:29 UTC - mysqld got signal 6 ;

============

Thread 1 (Thread 0x7f27ffe25700 (LWP 29074)):
#0  0x00007f27ff86d771 in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000000e15d58 in my_write_core (sig=6) at /bzr/mysql-5.7-percona-patches_dbg/mysys/stacktrace.c:247
#2  0x0000000000822044 in handle_fatal_signal (sig=6) at /bzr/mysql-5.7-percona-patches_dbg/sql/signal_handler.cc:219
#3  <signal handler called>
#4  0x00007f27fe4715c9 in raise () from /lib64/libc.so.6
#5  0x00007f27fe472cd8 in abort () from /lib64/libc.so.6
#6  0x00007f27fe46a536 in __assert_fail_base () from /lib64/libc.so.6
#7  0x00007f27fe46a5e2 in __assert_fail () from /lib64/libc.so.6
#8  0x0000000000b25ca4 in JOIN::replace_index_subquery (this=0x7f27c853af28) at /bzr/mysql-5.7-percona-patches_dbg/sql/sql_optimizer.cc:840
#9  0x0000000000b24891 in JOIN::optimize (this=0x7f27c853af28) at /bzr/mysql-5.7-percona-patches_dbg/sql/sql_optimizer.cc:495
#10 0x0000000000b871ba in mysql_prepare_and_optimize_select (thd=0x7f27c841c000, fields=..., select_options=2147748608, result=0x0, select_lex=0x7f27c8428240, free_join=0x7f27ffe22a2f) at /bzr/mysql-5.7-percona-patches_dbg/sql/sql_select.cc:1011
#11 0x0000000000bde889 in mysql_union_prepare_and_optimize (thd=0x7f27c841c000, lex=0x7f27c841e370, result=0x0, unit=0x7f27c84284b8, union_options=2147748608) at /bzr/mysql-5.7-percona-patches_dbg/sql/sql_union.cc:126
#12 0x0000000000bde618 in mysql_optimize_prepared_inner_units (thd=0x7f27c841c000, unit=0x7f27c84272e8, options=2147748608) at /bzr/mysql-5.7-percona-patches_dbg/sql/sql_union.cc:57
#13 0x0000000000b872a3 in mysql_select (thd=0x7f27c841c000, fields=..., select_options=2147748608, result=0x7f27c8428d78, select_lex=0x7f27c8427070) at /bzr/mysql-5.7-percona-patches_dbg/sql/sql_select.cc:1052
#14 0x0000000000b8575f in handle_select (thd=0x7f27c841c000, result=0x7f27c8428d78, setup_tables_done_option=0) at /bzr/mysql-5.7-percona-patches_dbg/sql/sql_select.cc:97
#15 0x0000000000b4edf5 in execute_sqlcom_select (thd=0x7f27c841c000, all_tables=0x7f27c853a598) at /bzr/mysql-5.7-percona-patches_dbg/sql/sql_parse.cc:5028
#16 0x0000000000b47775 in mysql_execute_command (thd=0x7f27c841c000) at /bzr/mysql-5.7-percona-patches_dbg/sql/sql_parse.cc:2488
#17 0x0000000000b4fcc1 in mysql_parse (thd=0x7f27c841c000, parser_state=0x7f27ffe23e60) at /bzr/mysql-5.7-percona-patches_dbg/sql/sql_parse.cc:5427
#18 0x0000000000b44814 in dispatch_command (command=COM_QUERY, thd=0x7f27c841c000, packet=0x7f27c8433011 "SELECT a IN(SELECT a FROM t1)FROM t1", packet_length=36) at /bzr/mysql-5.7-percona-patches_dbg/sql/sql_parse.cc:1250
#19 0x0000000000b4354d in do_command (thd=0x7f27c841c000) at /bzr/mysql-5.7-percona-patches_dbg/sql/sql_parse.cc:834
#20 0x0000000000c4d49e in handle_connection (arg=0x7f27ecf54180) at /bzr/mysql-5.7-percona-patches_dbg/sql/conn_handler/connection_handler_per_thread.cc:298
#21 0x0000000000e39538 in pfs_spawn_thread (arg=0x7f27e1ff7190) at /bzr/mysql-5.7-percona-patches_dbg/storage/perfschema/pfs.cc:2137
#22 0x00007f27ff868df3 in start_thread () from /lib64/libpthread.so.0
#23 0x00007f27fe5321ad in clone () from /lib64/libc.so.6

How to repeat:
DROP DATABASE test;CREATE DATABASE test;USE test;
CREATE TABLE t1(a INT,b POINT NOT NULL,KEY(a));
SET SESSION TRANSACTION READ ONLY,ISOLATION LEVEL REPEATABLE READ;
HANDLER t1 OPEN;
select * from t1 where MATCH a,b AGAINST('"Now sUPPort"' IN BOOLEAN MODE);
prepare stmt1 from "truncate t1";
SELECT a IN(SELECT a FROM t1)FROM t1;

Though the testcase above should suffice for reproducing the bug, the attached tarball gives the testcase as an exact match of our system, including some handy utilities
$ vi {epoch}_mybase     # Update base path in this file (the only change required!)
$ ./{epoch}_init        # Initializes the data dir
$ ./{epoch}_start       # Starts mysqld
$ ./{epoch}_cl          # To check mysqld is up
$ ./{epoch}_run         # Run the testcase (produces output)
$ vi /dev/shm/{epoch}/error.log.out  # Verify the error log
$ ./{epoch}_gdb         # Brings you to a gdb prompt
$ ./{epoch}_parse_core  # Create {epoch}_STD.gdb and {epoch}_FULL.gdb; standard and full var gdb stack traces

Suggested fix:
Fix JOIN::replace_index_subquery and rejoice
[30 Jan 2015 4:05] Roel Van de Paar
As described above

Attachment: 1422580718_bug_bundle.tar.gz (application/gzip, text), 93.32 KiB.

[30 Jan 2015 4:49] MySQL Verification Team
Hello Roel,

Thank you for the bug report and test case.
Observed that 5.7.6 debug build is affected.

Thanks,
Umesh
[30 Jan 2015 4:51] MySQL Verification Team
// 5.7.6 debug build affected

bin/mysql_install_db --basedir=/export/umesh/mysql-5.7.6 --datadir=/export/umesh/mysql-5.7.6/75684 -v
bin/mysqld --basedir=/export/umesh/mysql-5.7.6 --datadir=/export/umesh/mysql-5.7.6/75684 --core-file --socket=/tmp/mysql_ushastry.sock  --port=15000 --log-error=/export/umesh/mysql-5.7.6/75684/log.err 2>&1 &

// Build used

commit: 348792f557bf6d66fc8e794b938c4bb9b917fa5e
date: 2015-01-28 16:35:09 +0100
build-date: 2015-01-28 17:07:08 +0100
short: 348792f
branch: mysql-trunk

MySQL source 5.7.6

2015-01-30T04:45:52.384294Z 0 [Note] bin/mysqld-debug: ready for connections.
Version: '5.7.6-m16-enterprise-commercial-advanced-debug'  socket: '/tmp/mysql_ushastry.sock'  port: 15000  MySQL Enterprise Server - Advanced Edition Debug (Commercial)
mysqld-debug: /export/home/pb2/build/sb_0-14236670-1422462446.39/mysqlcom-pro-5.7.6-m16/sql/sql_optimizer.cc:858: int JOIN::replace_index_subquery(): Assertion `!first_qep_tab->table()->no_keyre
ad' failed.
04:46:13 UTC - mysqld got signal 6 ;

(gdb) bt
#0  0x00007f484e2c6771 in pthread_kill () from /lib64/libpthread.so.0
#1  0x00000000012bc5f8 in my_write_core (sig=6) at /export/home/pb2/build/sb_0-14236670-1422462446.39/mysqlcom-pro-5.7.6-m16/mysys/stacktrace.c:247
#2  0x0000000000b3254e in handle_fatal_signal (sig=6) at /export/home/pb2/build/sb_0-14236670-1422462446.39/mysqlcom-pro-5.7.6-m16/sql/signal_handler.cc:220
#3  <signal handler called>
#4  0x00007f484cecc5c9 in raise () from /lib64/libc.so.6
#5  0x00007f484cecdcd8 in abort () from /lib64/libc.so.6
#6  0x00007f484cec5536 in __assert_fail_base () from /lib64/libc.so.6
#7  0x00007f484cec55e2 in __assert_fail () from /lib64/libc.so.6
#8  0x0000000000fb63e0 in JOIN::replace_index_subquery (this=0x7f47d4027af0) at /export/home/pb2/build/sb_0-14236670-1422462446.39/mysqlcom-pro-5.7.6-m16/sql/sql_optimizer.cc:858
#9  0x0000000000fb500a in JOIN::optimize (this=0x7f47d4027af0) at /export/home/pb2/build/sb_0-14236670-1422462446.39/mysqlcom-pro-5.7.6-m16/sql/sql_optimizer.cc:514
#10 0x000000000101787c in st_select_lex::optimize (this=0x7f47d4006758, thd=0x7f47d4000c00) at /export/home/pb2/build/sb_0-14236670-1422462446.39/mysqlcom-pro-5.7.6-m16/sql/sql_select.cc:995
#11 0x00000000010710dc in st_select_lex_unit::optimize (this=0x7f47d4006a20, thd=0x7f47d4000c00)
    at /export/home/pb2/build/sb_0-14236670-1422462446.39/mysqlcom-pro-5.7.6-m16/sql/sql_union.cc:658
#12 0x00000000010178d8 in st_select_lex::optimize (this=0x7f47d4005540, thd=0x7f47d4000c00) at /export/home/pb2/build/sb_0-14236670-1422462446.39/mysqlcom-pro-5.7.6-m16/sql/sql_select.cc:1001
#13 0x0000000001015fc5 in handle_query (thd=0x7f47d4000c00, lex=0x7f47d4002e18, result=0x7f47d40072d0, added_options=0, removed_options=0)
    at /export/home/pb2/build/sb_0-14236670-1422462446.39/mysqlcom-pro-5.7.6-m16/sql/sql_select.cc:160
#14 0x0000000000fdf467 in execute_sqlcom_select (thd=0x7f47d4000c00, all_tables=0x7f47d4026068)
    at /export/home/pb2/build/sb_0-14236670-1422462446.39/mysqlcom-pro-5.7.6-m16/sql/sql_parse.cc:4944
#15 0x0000000000fd814e in mysql_execute_command (thd=0x7f47d4000c00) at /export/home/pb2/build/sb_0-14236670-1422462446.39/mysqlcom-pro-5.7.6-m16/sql/sql_parse.cc:2447
#16 0x0000000000fe03eb in mysql_parse (thd=0x7f47d4000c00, parser_state=0x7f4838db0e50) at /export/home/pb2/build/sb_0-14236670-1422462446.39/mysqlcom-pro-5.7.6-m16/sql/sql_parse.cc:5356
#17 0x0000000000fd517b in dispatch_command (command=COM_QUERY, thd=0x7f47d4000c00, packet=0x7f47d4009b91 "SELECT a IN(SELECT a FROM t1)FROM t1", packet_length=36)
    at /export/home/pb2/build/sb_0-14236670-1422462446.39/mysqlcom-pro-5.7.6-m16/sql/sql_parse.cc:1203
#18 0x0000000000fd3eca in do_command (thd=0x7f47d4000c00) at /export/home/pb2/build/sb_0-14236670-1422462446.39/mysqlcom-pro-5.7.6-m16/sql/sql_parse.cc:789
#19 0x00000000010df974 in handle_connection (arg=0x3c34d50) at /export/home/pb2/build/sb_0-14236670-1422462446.39/mysqlcom-pro-5.7.6-m16/sql/conn_handler/connection_handler_per_thread.cc:298
#20 0x0000000001348de3 in pfs_spawn_thread (arg=0x3caaf60) at /export/home/pb2/build/sb_0-14236670-1422462446.39/mysqlcom-pro-5.7.6-m16/storage/perfschema/pfs.cc:2137
#21 0x00007f484e2c1df3 in start_thread () from /lib64/libpthread.so.0
#22 0x00007f484cf8d47d in clone () from /lib64/libc.so.6
[4 Feb 2015 15:55] Tor Didriksen
Posted by developer:
 
Duplicate of internal bug
Bug#20261601 ASSERTION FAILED: !FIRST_QEP_TAB->TABLE()->NO_KEYREAD

Added testcase from this bug as well.
[4 Feb 2015 19:32] Roel Van de Paar
Thanks Tor
[23 Feb 2015 15:50] Paul DuBois
Noted in 5.7.6 changelog.

For some full-text queries, incomplete optimizer cleanup regarding
index use could affect subsequent queries against the same table.