| Bug #76446 | max_statement_time: Assertion `explain_other || unit->is_optimized()' failed. | ||
|---|---|---|---|
| Submitted: | 23 Mar 2015 6:07 | Modified: | 14 Apr 2015 20:12 |
| Reporter: | Roel Van de Paar | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Optimizer | Severity: | S1 (Critical) |
| Version: | 5.7.5-m16 | OS: | Any |
| Assigned to: | CPU Architecture: | Any | |
| Tags: | KILL_TIMEOUT, max_statement_time, UNION | ||
[23 Mar 2015 6:07]
Roel Van de Paar
Bug bundle with all scripts listed above
Attachment: 1427085872.tar.gz (application/gzip, text), 2.19 KiB.
[28 Mar 2015 8:03]
MySQL Verification Team
Version: '5.7.8-rc-debug' MySQL Community Server (GPL) Assertion failed: explain_other || unit->is_optimized(), file ..\..\sql\opt_explain.cc, line 557 mysqld-debug.exe!my_sigabrt_handler()[my_thr_init.c:366] mysqld-debug.exe!raise()[winsig.c:594] mysqld-debug.exe!abort()[abort.c:82] mysqld-debug.exe!_wassert()[assert.c:156] mysqld-debug.exe!Explain::explain_subqueries()[opt_explain.cc:557] mysqld-debug.exe!Explain::send()[opt_explain.cc:660] mysqld-debug.exe!explain_query_specification()[opt_explain.cc:2102] mysqld-debug.exe!st_select_lex_unit::explain()[sql_union.cc:744] mysqld-debug.exe!mysql_explain_unit()[opt_explain.cc:2241] mysqld-debug.exe!explain_query()[opt_explain.cc:2188] mysqld-debug.exe!handle_query()[sql_select.cc:176] mysqld-debug.exe!execute_sqlcom_select()[sql_parse.cc:4767] mysqld-debug.exe!mysql_execute_command()[sql_parse.cc:2468] mysqld-debug.exe!mysql_parse()[sql_parse.cc:5201] mysqld-debug.exe!dispatch_command()[sql_parse.cc:1283] mysqld-debug.exe!do_command()[sql_parse.cc:851] mysqld-debug.exe!handle_connection()[connection_handler_per_thread.cc:299] mysqld-debug.exe!pfs_spawn_thread()[pfs.cc:2149] mysqld-debug.exe!win_thread_start()[my_thread.c:37] mysqld-debug.exe!_callthreadstartex()[threadex.c:376] mysqld-debug.exe!_threadstartex()[threadex.c:359]
[28 Mar 2015 8:19]
MySQL Verification Team
Testcase -------- drop table if exists `t1`; create table t1(a int) engine=innodb; Then, run mysqlslap: mysqlslap.exe --number-of-queries=10000000000 \ --query="set sql_select_limit=0;set max_statement_time=1;explain select 1 from `t1` where `a` in (select 1 union select 1) union select 1;" \ --iterations=1000000 --create-schema=test
[28 Mar 2015 9:23]
MySQL Verification Team
verified on 5.7 and 5.8 branches: [sbester@fc17 mysql-5.7]$ git log |head commit 31b5f6f63aab3ff3f0d5dd8291aa00f250897314 Merge: f39b1c2 f11a637 Author: Mattias Jonsson <mattias.jonsson@oracle.com> Date: Sat Mar 28 01:45:56 2015 +0100 [sbester@fc17 mysql-trunk]$ git log|head commit 515d9e1d808ce0ece244b89cc4f5567ffdc316f1 Merge: 5ea75dd 31b5f6f Author: Mattias Jonsson <mattias.jonsson@oracle.com> Date: Sat Mar 28 01:55:36 2015 +0100 the slap command was: mysqlslap --number-of-queries=10000000000 --query="set sql_select_limit=0;set max_statement_time=1;explain select 1 from t1 where a in (select 1 union select 1) union select 1;" --iterations=1000000 --create-schema=test
[14 Apr 2015 20:12]
Paul DuBois
Noted in 5.7.8, 5.8.0 changelogs. An assertion could be raised with max_statement_time set greater than zero and multiple concurrent sessions executing certain EXPLAIN statements.
Description: mysqld: /bzr/mysql-5.7.6-m16_dbg/sql/opt_explain.cc:557: bool Explain::explain_subqueries(): Assertion `explain_other || unit->is_optimized()' failed. 06:02:15 UTC - mysqld got signal 6 ; +bt #0 0x00007f80fe415771 in pthread_kill () from /lib64/libpthread.so.0 #1 0x00000000013a521c in my_write_core (sig=6) at /bzr/mysql-5.7.6-m16_dbg/mysys/stacktrace.c:247 #2 0x0000000000bb713c in handle_fatal_signal (sig=6) at /bzr/mysql-5.7.6-m16_dbg/sql/signal_handler.cc:220 #3 <signal handler called> #4 0x00007f80fd0195c9 in raise () from /lib64/libc.so.6 #5 0x00007f80fd01acd8 in abort () from /lib64/libc.so.6 #6 0x00007f80fd012536 in __assert_fail_base () from /lib64/libc.so.6 #7 0x00007f80fd0125e2 in __assert_fail () from /lib64/libc.so.6 #8 0x0000000001236e23 in Explain::explain_subqueries (this=0x7f80fe9ca2b0) at /bzr/mysql-5.7.6-m16_dbg/sql/opt_explain.cc:557 #9 0x0000000001237441 in Explain::send (this=0x7f80fe9ca2b0) at /bzr/mysql-5.7.6-m16_dbg/sql/opt_explain.cc:660 #10 0x000000000123c285 in explain_no_table (thd=0x7f80d541a000, select_lex=0x7f80d542c160, message=0x1b574d0 <plan_not_ready> "Plan isn't ready yet", ctx=CTX_JOIN) at /bzr/mysql-5.7.6-m16_dbg/sql/opt_explain.cc:1924 #11 0x000000000123c931 in explain_query_specification (ethd=0x7f80d541a000, select_lex=0x7f80d542c160, ctx=CTX_JOIN) at /bzr/mysql-5.7.6-m16_dbg/sql/opt_explain.cc:2074 #12 0x000000000114ff73 in st_select_lex_unit::explain (this=0x7f80d542c438, ethd=0x7f80d541a000) at /bzr/mysql-5.7.6-m16_dbg/sql/sql_union.cc:739 #13 0x000000000123d37d in mysql_explain_unit (ethd=0x7f80d541a000, unit=0x7f80d542c438) at /bzr/mysql-5.7.6-m16_dbg/sql/opt_explain.cc:2284 #14 0x000000000123d142 in explain_query (ethd=0x7f80d541a000, unit=0x7f80d542c438) at /bzr/mysql-5.7.6-m16_dbg/sql/opt_explain.cc:2231 #15 0x00000000010f3173 in handle_query (thd=0x7f80d541a000, lex=0x7f80d541c068, result=0x7f80d553cf88, added_options=0, removed_options=0) at /bzr/mysql-5.7.6-m16_dbg/sql/sql_select.cc:173 #16 0x00000000010a9e05 in execute_sqlcom_select (thd=0x7f80d541a000, all_tables=0x7f80d553d350) at /bzr/mysql-5.7.6-m16_dbg/sql/sql_parse.cc:4697 #17 0x00000000010a3aa0 in mysql_execute_command (thd=0x7f80d541a000) at /bzr/mysql-5.7.6-m16_dbg/sql/sql_parse.cc:2450 #18 0x00000000010aae7a in mysql_parse (thd=0x7f80d541a000, parser_state=0x7f80fe9cbe00) at /bzr/mysql-5.7.6-m16_dbg/sql/sql_parse.cc:5129 #19 0x00000000010a0bd4 in dispatch_command (command=COM_QUERY, thd=0x7f80d541a000, packet=0x7f80d5535011 "", packet_length=157) at /bzr/mysql-5.7.6-m16_dbg/sql/sql_parse.cc:1249 #20 0x000000000109f925 in do_command (thd=0x7f80d541a000) at /bzr/mysql-5.7.6-m16_dbg/sql/sql_parse.cc:835 #21 0x00000000011c2fd9 in handle_connection (arg=0x7f80f53f78c0) at /bzr/mysql-5.7.6-m16_dbg/sql/conn_handler/connection_handler_per_thread.cc:298 #22 0x00000000013d2299 in pfs_spawn_thread (arg=0x7f80f63b2ed0) at /bzr/mysql-5.7.6-m16_dbg/storage/perfschema/pfs.cc:2147 #23 0x00007f80fe410df3 in start_thread () from /lib64/libpthread.so.0 #24 0x00007f80fd0da1ad in clone () from /lib64/libc.so.6 How to repeat: IMPORTANT: the testcase needs to be executed about 3 to 4 times in a row using the ./{epoch}_run script to trigger this sporadic (or means-caused) 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 attached to correct mysqld & generated core $ ./{epoch}_parse_core # Create {epoch}_STD.gdb and {epoch}_FULL.gdb; standard and full var gdb stack traces etc.