Bug #46175 NULL read_view and consistent read assertion
Submitted: 14 Jul 2009 15:33 Modified: 20 Jun 2010 22:29
Reporter: Adam Erickson Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Optimizer Severity:S1 (Critical)
Version:5.1.35, 5.1.39, 5.1.40, 5.1.41,5.4.3 OS:Any
Assigned to: Georgi Kodinov CPU Architecture:Any
Tags: assert, crash, innodb, mysqld, segfault, txisolation

[14 Jul 2009 15:33] Adam Erickson
Description:
After testing for over a month we deployed 5.1.35 and got our first crash. :)

This may be related to BUG #43503 but since I do not see a stack trace in that bug I've created a new one.

The offending query has been tested and does not cause a crash on it's own.  There was a significant slowdown just before the crash.  Queries that return in < 1 second took up to 30.  Example slow query log header:

# Time: 090714  5:58:20
# User@Host: XXXX[XXXX] @ host.name.removed [X.X.X.X]
# Query_time: 27.175840  Lock_time: 0.000133 Rows_sent: 7  Rows_examined: 62

Brief error log is below.  Full log is attached with my.cnf along with show global status shortly before the crash.

InnoDB: Error: MySQL is trying to perform a consistent read
InnoDB: but the read view is not assigned!
TRANSACTION 0 132894301, ACTIVE 0 sec, process no 20815, OS thread id 1180526912 starting index read
mysql tables in use 3, locked 1
MySQL thread id 9699, query id 7033508 host.name.removed X.X.X.X db_name Sending data
... partial query removed ...
090714  5:59:19  InnoDB: Assertion failure in thread 1180526912 in file row/row0sel.c line 3642
...
...
thd: 0x2aace88808c0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x465d6108 thread_stack 0x40000
/opt/mysql/bin/mysqld(my_print_stacktrace+0x20) [0xa05744]
/opt/mysql/bin/mysqld(handle_segfault+0x368) [0x60074c]
/lib64/libpthread.so.0 [0x3ab900de60]
/opt/mysql/bin/mysqld(row_search_for_mysql+0x2c5b) [0x91f53d]
/opt/mysql/bin/mysqld(ha_innobase::index_read(unsigned char*, unsigned char const*, unsigned int, ha_rkey_function)+0x2bf) [0x8333c9]
/opt/mysql/bin/mysqld [0x748aa0]
/opt/mysql/bin/mysqld [0x690608]
/opt/mysql/bin/mysqld(sub_select(JOIN*, st_join_table*, bool)+0xa1) [0x68dc9d]
/opt/mysql/bin/mysqld [0x68df7f]
/opt/mysql/bin/mysqld(sub_select(JOIN*, st_join_table*, bool)+0xc9) [0x68dcc5]
/opt/mysql/bin/mysqld [0x68d80f]
/opt/mysql/bin/mysqld(JOIN::exec()+0x1990) [0x6881e0]
/opt/mysql/bin/mysqld(mysql_select(THD*, Item***, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, 
st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*)+0x18b) [0x66c827]
/opt/mysql/bin/mysqld(handle_select(THD*, st_lex*, select_result*, unsigned long)+0x16c) [0x695220]
/opt/mysql/bin/mysqld [0x616ad8]
/opt/mysql/bin/mysqld(mysql_execute_command(THD*)+0x4b00) [0x610c30]
/opt/mysql/bin/mysqld(mysql_parse(THD*, char const*, unsigned int, char const**)+0x20a) [0x61706e]
/opt/mysql/bin/mysqld(dispatch_command(enum_server_command, THD*, char*, unsigned int)+0x133f) [0x60b5d9]
/opt/mysql/bin/mysqld(do_command(THD*)+0x114) [0x60a296]
/opt/mysql/bin/mysqld(handle_one_connection+0xd20) [0x60564c]
/lib64/libpthread.so.0 [0x3ab90062e7]
/lib64/libc.so.6(clone+0x6d) [0x3ab88ce3bd]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x2aace873df50 is an invalid pointer
thd->thread_id=9699
thd->killed=NOT_KILLED
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
090714 05:59:20 mysqld_safe Number of processes running now: 0
090714 05:59:20 mysqld_safe mysqld restarted

How to repeat:
As of yet unknown.

Suggested fix:
Not crash.
[15 Jul 2009 6:39] Sveta Smirnova
Thank you for report.

Please provide output of SHOW CREATE TABLE and SHOW TABLE STATUS for all underlying tables.
[17 Jul 2009 19:30] Adam Erickson
I believe we've duplicated the crash in a different environment.

Error log, table status and table DDL provided from 2nd crash.

Interesting bits from the error log 2nd time:

InnoDB: Error: MySQL is trying to perform a consistent read
InnoDB: but the read view is not assigned!
TRANSACTION 0 263467025, ACTIVE 0 sec, process no 12867, OS thread id 1196529984 starting index read, thread declared inside InnoDB 496
mysql tables in use 3, locked 1

090717  7:19:40  InnoDB: Assertion failure in thread 1196529984 in file row/row0sel.c line 3642

thd: 0x20449280
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
InnoDB: Thread 1157658944 stopped in file ../../storage/innobase/include/sync0sync.ic line 115
InnoDB: Thread 1177360704 stopped in file os/os0sync.c line 588
InnoDB: Thread 1191737664 stopped in file handler/ha_innodb.cc line 1222
stack_bottom = 0x47519118 thread_stack 0x40000
/opt/mysql/bin/mysqld(my_print_stacktrace+0x20) [0xa05744]
/opt/mysql/bin/mysqld(handle_segfault+0x368) [0x60074c]
/lib64/libpthread.so.0 [0x31fc20de70]
/opt/mysql/bin/mysqld(row_search_for_mysql+0x2c5b) [0x91f53d]
/opt/mysql/bin/mysqld(ha_innobase::index_read(unsigned char*, unsigned char const*, unsigned int, ha_rkey_function)+0x2bf) [0x8333c9]
/opt/mysql/bin/mysqld [0x748aa0]
/opt/mysql/bin/mysqld [0x690608]
/opt/mysql/bin/mysqld(sub_select(JOIN*, st_join_table*, bool)+0xa1) [0x68dc9d]
/opt/mysql/bin/mysqld [0x68df7f]
/opt/mysql/bin/mysqld(sub_select(JOIN*, st_join_table*, bool)+0xc9) [0x68dcc5]
/opt/mysql/bin/mysqld [0x68d80f]
/opt/mysql/bin/mysqld(JOIN::exec()+0x1990) [0x6881e0]
/opt/mysql/bin/mysqld(mysql_select(THD*, Item***, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*)+0x18b) [0x66c827]
/opt/mysql/bin/mysqld(handle_select(THD*, st_lex*, select_result*, unsigned long)+0x16c) [0x695220]
/opt/mysql/bin/mysqld [0x616ad8]
/opt/mysql/bin/mysqld(mysql_execute_command(THD*)+0x4b00) [0x610c30]
/opt/mysql/bin/mysqld(mysql_parse(THD*, char const*, unsigned int, char const**)+0x20a) [0x61706e]
/opt/mysql/bin/mysqld(dispatch_command(enum_server_command, THD*, char*, unsigned int)+0x133f) [0x60b5d9]
/opt/mysql/bin/mysqld(do_command(THD*)+0x114) [0x60a296]
/opt/mysql/bin/mysqld(handle_one_connection+0xd20) [0x60564c]
/lib64/libpthread.so.0 [0x31fc2062f7]
/lib64/libc.so.6(clone+0x6d) [0x31fb6ce85d]
Trying to get some variables.
[17 Jul 2009 19:31] Adam Erickson
Since we've seen the crash twice I'm working on a test case.
[23 Jul 2009 22:12] MySQL Verification Team
Thank you for the feedback. Was you able to create a test case?. Thanks in advance.
[23 Jul 2009 22:48] Adam Erickson
I haven't been able to reproduce the issue yet.
[28 Jul 2009 10:56] Susanne Ebrecht
This looks like an InnoDB issue.

I will give this into InnoDB development.
[4 Aug 2009 7:41] Marko Mäkelä
It looks like MySQL is invoking InnoDB in an unexpected way, or InnoDB fails to notice the start of an SQL statement. The crash is caused by an assertion failure. A consistent read is being attempted, even though the read view has not been opened. It should be opened at the start of a SQL statement.

This bug should be reproducible with just one client.

The SELECT statement in one of the crash reports is very long, and it was displayed only in part. Could it be that the start of SQL statement is not properly detected by InnoDB when there are too many subselects or joins? Does the same SELECT statement always lead into a crash? If not, is it possible to determine the preceding commands sent by the client connection?

Last but not least, please try to enable core dumps. It would be extremely helpful to open the core file in gdb, to see the complete stack trace including the values of parameters and variables.
[4 Aug 2009 7:49] Marko Mäkelä
The SELECT statements in bug46175_error.log and 2nd_crash.log are similar, but not identical. The difference (different "symbol IN (...)" list) should not matter from the query execution point of view.
[4 Aug 2009 13:43] Adam Erickson
The query displayed in the 2nd crash error log is the complete query and by itself does not cause the crash.  It is executed very frequently.

I have the full query log for the day of the 2nd crash (6GB).  It includes all the statements issued by this connection (250MB.)  I've replayed the last 2000 lines multiple times (with and without concurrency) and cannot reproduce the crash with that.

I will enable core dumps on the .35 instances we still have running but as far as I know we haven't seen the crash again.  If I can get a core dump I'll attach it here.
[5 Aug 2009 7:00] Marko Mäkelä
There is a typo in the Description: this is a likely duplicate of Bug #45303, not Bug #43503.
[5 Aug 2009 7:28] Marko Mäkelä
The Bug #45303 comment http://bugs.mysql.com/bug.php?id=45303#c237604 has one thing in common with this one: A subquery in the failing query. The cause can be a bug in MySQL or in the InnoDB storage engine. See my comment in Bug #45303. We definitely need a core dump and a dump of *trx and *prebuilt during the assertion failure.
[5 Aug 2009 12:29] Adam Erickson
Marko, do you have any advice for reproducing any of the conditions mentioned in either this or the suspected-duplicate?
[5 Aug 2009 12:45] Marko Mäkelä
Sorry Adam, I don't have any advice how to reproduce this bug. My best bet is that it requires subqueries, but I might be wrong about that.

Do you happen to use triggers or stored procedures? If not, we should be able to rule out cursor read views.
[5 Aug 2009 12:56] Adam Erickson
There are update and insert triggers on one of the tables used in the query which caused the crash.  I'm not sure if they were fired around the time of the crash.  I will review the query logs.
[5 Aug 2009 14:46] Adam Erickson
10 minutes prior to the 2nd crash a different thread would have fired the update trigger (a large amount of times, this was a big update.)

1 hour prior, the same thread which executed the offending SQL would have triggered the insert trigger.  Between this trigger and the offending statement I cannot find any references to the table.  I cannot confirm for certain if autocommit was enabled or disabled but the only commit between the trigger and the final select was a XA commit.
[20 Oct 2009 16:13] Adam Erickson
We have reproduced the crash in 5.1.39 and InnoDB plugin 1.0.4.
[20 Oct 2009 16:17] Adam Erickson
Core dump files are being compressed and will be attached when they're finished.

The crash occurs during a long running insert ... select.  While this insert is running a second thread runs a select with a subquery which uses the table the insert is adding rows to.  Right now this is as best I can explain the scenario.
[21 Oct 2009 5:09] MySQL Verification Team
Adam, which version of glibc is on the machine that produced these core files? Also, exactly which mysql package did you download - I need to have identical mysqld binary...  Thanks!
[21 Oct 2009 14:30] Adam Erickson
mysql-5.1.39-linux-x86_64-glibc23.tar.gz (non-RPM, Linux (AMD64 / Intel EM64T)

glibc-2.5-34.el5_3.1
[22 Oct 2009 10:48] Marko Mäkelä
In the gdb output of the core dump, we have trx == prebuilt->trx and trx->global_read_view = trx->read_view = NULL. trx->global_read_view = NULL can be assigned in three places:

trx_free() [not called, because trx->magic_n == TRX_MAGIC_N]
trx_commit_off_kernel() [not called, because trx->conc_state == TRX_ACTIVE]
trx_create()
read_view_close_for_mysql()

The trx->global_read_view is assigned to read_view_open_now() [which can never return NULL] in the following places:

row_search_check_if_query_cache_permitted()
trx_assign_read_view()

There are two possible failure scenarios:

(1) read_view_close_for_mysql() is called too early. This function is only called by ha_innodb.cc, in ha_innobase::store_lock() and ha_innobase::external_lock() when the transaction isolation level is READ UNCOMMITTED or READ COMMITTED. We have trx->isolation_level == TRX_ISO_REPEATABLE_READ, which is the default (consistent read). So, this scenario is impossible.

(2) neither row_search_check_if_query_cache_permitted() nor trx_assign_read_view() is called after trx_create(). The query cache function is called by MySQL via the callback that is registered by handler::register_query_cache_table(). I do not think that the call in the query cache check is essential. It merely ensures the consistency of cached and non-cached results. So, that leaves a missing trx_assign_read_view() call as the only possible explanation.

The function trx_assign_read_view() is called at different places:
ha_innobase::init_table_handle_for_HANDLER()
innobase_start_trx_and_assign_read_view() [via innobase_hton->start_consistent_snapshot]
row_sel_step() [only used in the InnoDB internal SQL parser, for some DDL ops]
row_search_for_mysql() [the fetch function]

In the core dump, we have prebuilt->select_lock_type = 5. Is this the built-in InnoDB or the InnoDB Plugin? Because the test before the assertion failure is for LOCK_NONE, I guess that the core dump is from the InnoDB Plugin. In the built-in InnoDB, LOCK_NONE=0.

One possible culprit could be that prebuilt->sql_stat_start is never set TRUE, or it is set FALSE too early. We have prebuilt->n_rows_fetched = 0, meaning that the statement has not retrieved anything from the table yet.

Because the logic behind row_prebuilt_struct is quite involved, I am going to ask Heikki’s opinion. All fingers are pointing at that structure now.
[22 Oct 2009 11:54] Marko Mäkelä
I could not resist checking all code paths that do prebuilt->sql_stat_start = FALSE.

ha_innobase::init_table_handle_for_HANDLER() is OK, because it also does trx_assign_read_view(prebuilt->trx).

row_insert_for_mysql() is not applicable, because the crash occurs in SELECT, and DML statements use locking reads. (Read views only apply to non-locking, a.k.a. multi-versioned, or consistent, reads.)

row_search_for_mysql() assigns prebuilt->sql_stat_start = FALSE when prebuilt->sql_stat_start = TRUE.

It seems that row_search_for_mysql() must have been called at least twice, and somehow the first call failed to assign the read view. That could occur if prebuilt->select_lock_type was initially something else than LOCK_NONE and it was reset to LOCK_NONE later.

I reviewed the assignments of prebuilt->select_lock_type.  It can be assigned to LOCK_NONE in the following places:

ha_innobase::init_table_handle_for_HANDLER() [not an issue, because this will also do trx_assign_read_view(prebuilt->trx)]
ha_innobase::start_stmt()
ha_innobase::store_lock()

Could MySQL invoke start_stmt() or store_lock() on a table handle multiple times per statement? Perhaps on some obscure condition when executing joins or subselects? I am reclassifying this as an “Optimizer” bug to find out. (Sorry, I did not find any category that would refer to query execution.)
[22 Oct 2009 13:12] Adam Erickson
For what its worth, I can reproduce the crash with 5.1.35 and the built-in InnoDB  as well as 5.1.39 and the 1.0.4 plugin.

My test case is reliable but is large in size.  My attempts to trim it down so far make the bug disappear.
[22 Oct 2009 15:41] MySQL Verification Team
Adam - how large is it when bzip2'd ? If you have time/bandwidth please upload it to the ftp server.
[22 Oct 2009 18:48] Adam Erickson
After bzip2 it's 52MB.  The other issue is the data contained within may be considered proprietary.
[23 Oct 2009 5:39] MySQL Verification Team
a stroke of luck is that I repeated this today on 5.4.3-beta-x64 on windows, with a debug binary.  Will upload a file containing more debugging information as soon as I download the source..
[23 Oct 2009 6:17] MySQL Verification Team
trx->active_trans == 0, but trx->conc_state != TRX_NOT_STARTED is repeatable, but not the crash :(

Attachment: sbester_tests_5.4.3_windows.txt (text/plain), 11.44 KiB.

[23 Oct 2009 6:38] MySQL Verification Team
the tx not started error message is the subject of bug #25439
[23 Oct 2009 6:41] MySQL Verification Team
Marko, Adam, 

Here's the testcase:

drop table if exists t1,t2;
create table t1(col60 char(13),key(col60))engine=innodb;
create table t2(col12 datetime,key(col12))engine=innodb;
insert into t1 values (),();
insert into t2 values (),();
create or replace view v1 as
select 1
from t2 where  `col12` =(select `col60` from t1 limit 1);

show create table v1;

Now run SHOW CREATE TABLE v1 in multiple threads.  Crash happens shortly.
[26 Oct 2009 5:02] MySQL Verification Team
My testcase crashes quickly if you run 'show create view v1' in a loop in 2 threads.  I can repeat the crash using Adam's testcase too (had to change insert into.. to be replace into.. to avoid duplicate keys) by running
that 'select '.. and 'replace into .. select ' in two threads in a loop
with binlogs enabled.

5.1.40 stack trace:

 mysqld.exe!row_search_for_mysql()[row0sel.c:3642]
 mysqld.exe!ha_innobase::index_read()[ha_innodb.cc:4595]
 mysqld.exe!handler::index_read_map()[handler.h:1403]
 mysqld.exe!join_read_always_key()[sql_select.cc:11683]
 mysqld.exe!sub_select()[sql_select.cc:11131]
 mysqld.exe!evaluate_join_record()[sql_select.cc:11247]
 mysqld.exe!sub_select()[sql_select.cc:11137]
 mysqld.exe!do_select()[sql_select.cc:10888]
 mysqld.exe!JOIN::exec()[sql_select.cc:2206]
 mysqld.exe!mysql_select()[sql_select.cc:2396]
 mysqld.exe!handle_select()[sql_select.cc:268]
 mysqld.exe!execute_sqlcom_select()[sql_parse.cc:5044]
 mysqld.exe!mysql_execute_command()[sql_parse.cc:2238]
 mysqld.exe!mysql_parse()[sql_parse.cc:5967]
 mysqld.exe!dispatch_command()[sql_parse.cc:1226]
 mysqld.exe!do_command()[sql_parse.cc:865]
 mysqld.exe!handle_one_connection()[sql_connect.cc:1127]
 mysqld.exe!pthread_start()[my_winthread.c:85]
 mysqld.exe!_callthreadstart()[thread.c:295]
 mysqld.exe!_threadstart()[thread.c:275]
 kernel32.dll!BaseThreadStart()
[26 Oct 2009 5:13] MySQL Verification Team
verified using my testcase, and the privately uploaded testcase.
[26 Oct 2009 7:20] Marko Mäkelä
Thank you for the simple test case, Shane. On the first try, I got a different assertion:

Thread 20 (Thread 0xb0ab3b90 (LWP 7124)):
#0  ut_dbg_assertion_failed (expr=0x869dec0 "mode != LOCK_S || lock_table_has(thr_get_trx(thr), index->table, LOCK_IS)", file=0x869c785 "lock/lock0lock.c", line=5216) at ut/ut0dbg.c:60
#1  0x0841d38a in lock_sec_rec_read_check_and_lock (flags=0, block=0xb6e370bc, rec=0xb712007e "", index=0x9787558, offsets=0xb0ab0840, mode=LOCK_S, gap_mode=0, thr=0x978ee50) at lock/lock0lock.c:5215
#2  0x0846af64 in sel_set_rec_lock (block=0xb6e370bc, rec=0xb712007e "", index=0x9787558, offsets=0xb0ab0840, mode=2, type=0, thr=0x978ee50) at row/row0sel.c:970
#3  0x0846f90a in row_search_for_mysql (buf=0x97856f0 "\377", ' ' <repeats 13 times>, '\245' <repeats 18 times>, "\030Wx\t", mode=1, prebuilt=0x9629ee8, match_mode=0, direction=0) at row/row0sel.c:4041
#4  0x08408c9c in ha_innobase::index_read (this=0x97855a0, buf=0x97856f0 "\377", ' ' <repeats 13 times>, '\245' <repeats 18 times>, "\030Wx\t", key_ptr=0x0, key_len=0, find_flag=HA_READ_AFTER_KEY) at handler/ha_innodb.cc:5115
#5  0x084005ff in ha_innobase::index_first (this=0x97855a0, buf=0x97856f0 "\377", ' ' <repeats 13 times>, '\245' <repeats 18 times>, "\030Wx\t") at handler/ha_innodb.cc:5399
#6  0x0828700c in join_read_first (tab=0x97a3df0) at sql_select.cc:11832
#7  0x082859ce in sub_select (join=0x97a4bf8, join_tab=0x97a3df0, end_of_records=false) at sql_select.cc:11137
#8  0x08296143 in do_select (join=0x97a4bf8, fields=0x978b814, table=0x0, procedure=0x0) at sql_select.cc:10894
#9  0x082a6899 in JOIN::exec (this=0x97a4bf8) at sql_select.cc:2199
#10 0x081bdab6 in subselect_single_select_engine::exec (this=0x978bfa0) at item_subselect.cc:1958
#11 0x081c25c3 in Item_subselect::exec (this=0x978bf00) at item_subselect.cc:263
#12 0x081bb5c0 in Item_singlerow_subselect::val_str (this=0x978bf00, str=0xb0ab1350) at item_subselect.cc:581
#13 0x0818d45c in Arg_comparator::can_compare_as_dates (a=0x978b6f0, b=0x978bf00, const_value=0xb0ab13f0) at item_cmpfunc.cc:769
#14 0x0818dd06 in Arg_comparator::set_cmp_func (this=0x978c040, owner_arg=0x978bfc8, a1=0x978c01c, a2=0x978c020, type=STRING_RESULT) at item_cmpfunc.cc:853
#15 0x0819334b in Arg_comparator::set_cmp_func (this=0x978c040, owner_arg=0x978bfc8, a1=0x978c01c, a2=0x978c020) at item_cmpfunc.h:69
#16 0x08193382 in Item_bool_func2::set_cmp_func (this=0x978bfc8) at item_cmpfunc.h:336
#17 0x0818e69d in Item_bool_func2::fix_length_and_dec (this=0x978bfc8) at item_cmpfunc.cc:524
#18 0x08175df6 in Item_func::fix_fields (this=0x978bfc8, thd=0x9788cb8, ref=0x97a3da4) at item_func.cc:198
#19 0x082609b8 in setup_conds (thd=0x9788cb8, tables=0x978b4d0, leaves=0x978b4d0, conds=0x97a3da4) at sql_base.cc:7982
#20 0x082a88de in setup_without_group (thd=0x9788cb8, ref_pointer_array=0x978c1c8, tables=0x978b4d0, leaves=0x978b4d0, fields=@0x978ae28, all_fields=@0x97a3d30, conds=0x97a3da4, order=0x0, group=0x0, hidden_group_fields=0x97a3d13) at sql_select.cc:412
#21 0x082a0a7f in JOIN::prepare (this=0x97a2c10, rref_pointer_array=0x978ae8c, tables_init=0x978b4d0, wild_num=0, conds_init=0x978bfc8, og_num=0, order_init=0x0, group_init=0x0, having_init=0x0, proc_param_init=0x0, select_lex_arg=0x978ad94, unit_arg=0x978ab24) at sql_select.cc:494
#22 0x0839f698 in st_select_lex_unit::prepare (this=0x978ab24, thd_arg=0x9788cb8, sel_result=0x978c138, additional_options=0) at sql_union.cc:264
#23 0x083a07dc in mysql_derived_prepare (thd=0x9788cb8, lex=0x9789d88, orig_table_list=0x978a730) at sql_derived.cc:151
#24 0x083a040b in mysql_handle_derived (lex=0x9789d88, processor=0x83a06bf <mysql_derived_prepare(THD*, st_lex*, TABLE_LIST*)>) at sql_derived.cc:56
#25 0x0826ed48 in open_normal_and_derived_tables (thd=0x9788cb8, tables=0x978a730, flags=0) at sql_base.cc:5026
#26 0x0836f060 in mysqld_show_create (thd=0x9788cb8, table_list=0x978a730) at sql_show.cc:601
#27 0x0821dbd5 in mysql_execute_command (thd=0x9788cb8) at sql_parse.cc:2921
#28 0x08224e01 in mysql_parse (thd=0x9788cb8, inBuf=0x978a690 "show create table v1", length=20, found_semicolon=0xb0ab326c) at sql_parse.cc:5933

On the second try, I got the familiar assertion about NULL read_view.
[26 Oct 2009 7:49] MySQL Verification Team
I suspect bug #39022 could be related to this..
[26 Oct 2009 8:53] Marko Mäkelä
The SHOW CREATE TABLE v1 is calling none of the handler methods start_stmt, store_lock, or external_lock.

I added debug prints to every place where prebuilt->sql_stat_start is assigned, and the only assignment is to FALSE, in row_search_for_mysql(), after assigning trx->read_view. I guess that the trx->read_view will be reset to NULL at transaction commit.

InnoDB really needs to know when an SQL statement starts, because the row_prebuilt_t is a per-statement data structure for speeding up data retrieval. The failure to call the per-statement handler methods is a bug in MySQL, presumably in mysqld_show_create().
[3 Nov 2009 8:09] MySQL Verification Team
Joro, this is exact steps you can try:

tar zxvf mysql-advanced-gpl-5.1.40-linux-i686-glibc23.tar.gz
cd mysql-advanced-gpl-5.1.40-linux-i686-glibc23
./scripts/mysql_install_db --no-defaults
./bin/mysqld_safe --no-defaults --skip-grant-tables --skip-name-resolve --port=3307 --socket=sock &

./bin/mysql --no-defaults -uroot -h127.0.0.1 -P3307 test
drop table if exists t1,t2;
create table t1(col60 char(13),key(col60))engine=innodb;
create table t2(col12 datetime,key(col12))engine=innodb;
insert into t1 values (),();
insert into t2 values (),();
create or replace view v1 as
select 1
from t2 where  `col12` =(select `col60` from t1 limit 1);

delimiter $
drop procedure if exists p1$
create procedure p1(num int)
begin
  declare i int default '0';
  repeat
    show create view v1;
    set i:=i+1;
  until i>num end repeat;

end $
exit $

./bin/mysql --no-defaults -P3307 -h127.0.0.1 test -e "call p1(1000000)" > /dev/null &

./bin/mysql --no-defaults -P3307 -h127.0.0.1 test -e "call p1(1000000)" > /dev/null &

./bin/mysql --no-defaults -P3307 -h127.0.0.1 test -e "call p1(1000000)" > /dev/null &
[3 Nov 2009 17:08] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/89178

3165 Georgi Kodinov	2009-11-03
      Bug #46175: NULL read_view and consistent read assertion
      
      The SE API requires mysql to notify the storage engine that
      it's going to read certain tables at the beginning of the 
      statement (by calling start_stmt(), store_lock() or
      external_lock()).
      These are typically called by the lock_tables(). 
      However SHOW CREATE TABLE is not pre-locking the tables
      because it's not expected to access the data at all.
      But for some view definitions (that include comparing a
      date/datetime/timestamp column to a string returning
      scalar subquery) the JOIN::prepare may still access data
      when materializing the scalar non-correlated subquery
      in Arg_comparator::can_compare_as_dates().
      Fixed by not materializing the subquery there (similarly
      how this is fixed in other places in the code : grep for
      with_subselect to find them).
[4 Nov 2009 10:45] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/89291

3165 Georgi Kodinov	2009-11-04
      Bug #46175: NULL read_view and consistent read assertion
      
      The SE API requires mysql to notify the storage engine that
      it's going to read certain tables at the beginning of the 
      statement (by calling start_stmt(), store_lock() or
      external_lock()).
      These are typically called by the lock_tables(). 
      However SHOW CREATE TABLE is not pre-locking the tables
      because it's not expected to access the data at all.
      But for some view definitions (that include comparing a
      date/datetime/timestamp column to a string returning
      scalar subquery) the JOIN::prepare may still access data
      when materializing the scalar non-correlated subquery
      in Arg_comparator::can_compare_as_dates().
      Fixed by not materializing the subquery when the function
      is called in a SHOW/EXPLAIN/CREATE VIEW
[4 Nov 2009 11:54] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/89298

3165 Georgi Kodinov	2009-11-04
      Bug #46175: NULL read_view and consistent read assertion
      
      The SE API requires mysql to notify the storage engine that
      it's going to read certain tables at the beginning of the 
      statement (by calling start_stmt(), store_lock() or
      external_lock()).
      These are typically called by the lock_tables(). 
      However SHOW CREATE TABLE is not pre-locking the tables
      because it's not expected to access the data at all.
      But for some view definitions (that include comparing a
      date/datetime/timestamp column to a string returning
      scalar subquery) the JOIN::prepare may still access data
      when materializing the scalar non-correlated subquery
      in Arg_comparator::can_compare_as_dates().
      Fixed by not materializing the subquery when the function
      is called in a SHOW/EXPLAIN/CREATE VIEW
[6 Nov 2009 13:24] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/89591

3197 Georgi Kodinov	2009-11-04
      Bug #46175: NULL read_view and consistent read assertion
      
      The SE API requires mysql to notify the storage engine that
      it's going to read certain tables at the beginning of the 
      statement (by calling start_stmt(), store_lock() or
      external_lock()).
      These are typically called by the lock_tables(). 
      However SHOW CREATE TABLE is not pre-locking the tables
      because it's not expected to access the data at all.
      But for some view definitions (that include comparing a
      date/datetime/timestamp column to a string returning
      scalar subquery) the JOIN::prepare may still access data
      when materializing the scalar non-correlated subquery
      in Arg_comparator::can_compare_as_dates().
      Fixed by not materializing the subquery when the function
      is called in a SHOW/EXPLAIN/CREATE VIEW
[19 Nov 2009 14:52] Adam Erickson
I built 5.1.41 with the patch supplied and am still able to reproduce the crash using the test case already uploaded here.

Error log below:

Version: '5.1.41ae1-log'  socket: '/var/mysql/mysql.sock'  port: 3306  Source distribution
091119 14:44:03 [Note] Event Scheduler: scheduler thread started with id 1
InnoDB: Error: MySQL is trying to perform a consistent read
InnoDB: but the read view is not assigned!
TRANSACTION 0 45179138, ACTIVE 0 sec, process no 18745, OS thread id 1172142400 starting index read, thread declared inside InnoDB 478
mysql tables in use 3, locked 1
MySQL thread id 3, query id 4 localhost adam Sending data
SELECT INSTRUMENT.SYMBOL as symbol,
    INSTRUMENT.INSTRUMENT_TYPE AS instrumentType,
    PRICING.CLOSE_PRICE AS closePrice,
    PRICING.LAST_TRADED_PRICE AS tradePrice,
    PRICING.BID_PRICE AS bidPrice,
    PRICING.ASK_PRICE AS askPrice
    
FROM tbl_i INSTRUMENT,
     tbl_s PRICING
 WHERE INSTRUMENT.INSTRUMENT_ID = PRICING.INSTRUMENT_ID
   AND INSTRUMENT.STATUS= 'Active'
   AND INSTRUMENT.INSTRUMENT_TYPE = 'Option'
   AND INSTRUMENT.SYMBOL IN ('CKOXG',
   'CBIAE',
   'DISAF',
   'DVNDO',
   'UNYWL',
   'IBMKF',
   'AJLKV',
   'RQEEB',
   'BQBXB',
   'RJFKE',
   'SLVKR',
   'HQIKL',
   'IAQP

091119 14:44:27  InnoDB: Assertion failure in thread 1172142400 in file row/row0sel.c line 3642
InnoDB: Failing assertion: 0
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-recovery.html
InnoDB: about forcing recovery.
091119 14:44:27 - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help diagnose
the problem, but since we have already crashed, something is definitely wrong
and this may fail.

key_buffer_size=134217728
read_buffer_size=4194304
max_used_connections=2
max_threads=300
threads_connected=3
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2591721 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x2aab600e6780
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x45dd6f60 thread_stack 0x40000
[0x78de5e]
[0x4c8352]
[0x64e7b0]
[0x82b755]
[0x7f0f30]
[0x6f6010]
[0x667bcd]
[0x5407d5]
[0x53a2a9]
[0x53a1a0]
[0x53a263]
[0x53a70d]
[0x54b230]
[0x54cba8]
[0x54d4e9]
[0x4d2f1c]
[0x4d81c1]
[0x4de6a1]
[0x4deaa3]
[0x4dfca4]
[0x4d06e7]
[0x64abb7]
[0x81a0b9]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x155a81e0 = SELECT INSTRUMENT.SYMBOL as symbol,
    INSTRUMENT.INSTRUMENT_TYPE AS instrumentType,
    PRICING.CLOSE_PRICE AS closePrice,
    PRICING.LAST_TRADED_PRICE AS tradePrice,
    PRICING.BID_PRICE AS bidPrice,
    PRICING.ASK_PRICE AS askPrice
    
FROM tbl_i INSTRUMENT,
     tbl_s PRICING
 WHERE INSTRUMENT.INSTRUMENT_ID = PRICING.INSTRUMENT_ID
   AND INSTRUMENT.STATUS= 'Active'
   AND INSTRUMENT.INSTRUMENT_TYPE = 'Option'
   AND INSTRUMENT.SYMBOL IN ('CKOXG',
   'CBIAE',
   'DISAF',
   'DVNDO',
   'UNYWL',
   'IBMKF',
   'AJLKV',
   'RQEEB',
   'BQBXB',
   'RJFKE',
   'SLVKR',
   'HQIKL',
   'IAQPK',
   'CKOWA',
   'YUXKG',
   'KANAJ',
   'SLVAS',
   'LMQLH',
   'SLVAQ',
   'XTYWB',
   'YAAKZ',
   'QEKLA',
   'VIQDD',
   'HKUXX',
   'BQUKH',
   'UNYAL',
   'SPJKJ',
   'CSXWH',
   'IAQMK',
   'FQRWZ',
   'KANML',
   'FLRWI',
   'SPJWJ',
   'IOCAJ',
   'KOKK',
   'PGKY',
   'QHHXE',
   'NGCA',
   'DBAQ',
   'EQAKV',
   'NSIKV',
   'UNEAQ',
   'STJDI',
   'AUYDG',
   'SVUXC',
   'DBMQ',
   'UNYKL',
   'SLWCT',
   'O
thd->thread_id=3
thd->killed=NOT_KILLED
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
Writing a core file
091119 14:44:28 mysqld_safe Number of processes running now: 0
091119 14:44:28 mysqld_safe mysqld restarted
[24 Nov 2009 6:42] Marko Mäkelä
Adam, as far as I understand, core files are always tied with an executable. MySQL can interpret core files of binaries that they have built and archived, but not core files from binaries built by others. Can you please extract the stack trace with gdb? Something like this:

gdb /path/to/mysqld core_file
set log on
set height 0
bt full
quit

The output should be written to a file gdb.txt in the current working directory.
[24 Nov 2009 15:36] Adam Erickson
gdb output

Attachment: gdb_out.txt (text/plain), 11.01 KiB.

[24 Nov 2009 15:37] Adam Erickson
Recompiled with debug enabled and recrashed.  See attached gdb_out.txt
[26 Nov 2009 13:19] Marko Mäkelä
Adam, I am sorry, I should have asked you for the following too:

frame 5
p *trx
p *prebuilt

This should display the contents of *trx and *prebuilt in the stack frame of row_search_for_mysql(). If you are posting this from a different core dump than the gdb_out.txt that you previously attached, please also do "info locals".
[26 Nov 2009 13:28] Heikki Tuuri
This error print from an earlier comment shows a major confusion about when an SQL statement ends or a transaction ends:

"
Version: '5.4.3-beta-community'  socket: ''  port: 3306  MySQL Community Server (GPL)
091023  7:23:37 [ERROR] trx->active_trans == 0, but trx->conc_state != TRX_NOT_STARTED
091023  7:23:37 [Warning] MySQL is closing a connection that has an active InnoDB transaction.  0 row modifications will roll back.
091023  7:23:40 [ERROR] trx->active_trans == 0, but trx->conc_state != TRX_NOT_STARTED
091023  7:23:40 [Warning] MySQL is closing a connection that has an active InnoDB transaction.  0 row modifications will roll back.
InnoDB: Error: MySQL is trying to perform a consistent read
InnoDB: but the read view is not assigned!
TRANSACTION 2795, ACTIVE 94 sec, OS thread id 1036 starting index read
3 lock struct(s), heap size 1216, 6 row lock(s)
MySQL thread id 6, query id 24094 localhost 127.0.0.1 root Sending data
show create table `test`.`v201.901`

091023  7:23:40  InnoDB: Assertion failure in thread 1036 in file .\row\row0sel.c line 3740
InnoDB: Failing assertion: 0
"

MySQL engineers shoudl check that the call order of ::external_lock(), start_stmt(), etc. are right. Marko suspected in an earlier comment that there might be duplicate calls on the same table handle.
[1 Dec 2009 14:15] Marko Mäkelä
I am moving this away from Patch queued, because the fix that was committed fixes a different bug than the one that was reported. The “wrong” bug is in SHOW CREATE TABLE, while the original workload does something different and is repeatable with the fix. Both bugs happen to trigger the same InnoDB assertion.

MySQL engineers may want to create another ticket for the SHOW CREATE TABLE bug, so that the same bug # will not be fixed twice.

I will look at Adam’s gdb output shortly. I believe that the bug is outside InnoDB, but I would like to verify my analysis from [22 Oct 12:48] and [22 Oct 13:54]. At a glance, the situation is similar: we have trx == prebuilt->trx, trx->read_view == NULL and trx->global_read_view == NULL.

Adam, please preserve the core dump and the corresponding mysqld executable, so that we can ask further questions if needed. Or be prepared to repeat the bug once more and preserve that core dump and mysqld. I may also have to ask you to add some debug prints or assertions.

It would be extremely helpful if MySQL engineers could repeat this bug. Adam, can you obfuscate the data in the dump you mentioned on [22 Oct 20:48] and still repeat this bug? That would avoid exposing any secrets to us. :-)
[1 Dec 2009 19:43] Adam Erickson
I still have the mysqld binary and core files from the latest crash.  I can provide them if you'd like or I am happy to proxy gdb commands for you as well.  Resolving this issue is a high priority for us, rebuilding and testing are not a problem.

I have already provided an obfuscated-enough test case on Oct 23.  It is the exact test I use here locally and was verified by your engineer, Shane Bester, on Oct 26th.
[2 Dec 2009 8:06] Bugs System
Pushed into 5.1.42 (revid:joro@sun.com-20091202080033-mndu4sxwx19lz2zs) (version source revid:kristofer.pettersson@sun.com-20091109223504-xvwgsdqiyuve6frt) (merge vers: 5.1.41) (pib:13)
[2 Dec 2009 9:08] Georgi Kodinov
Moving back to open. I've fixed what Shane provided as steps to reproduce. I need help in reproducing this bug.
[2 Dec 2009 10:26] Sveta Smirnova
Adam,

thank you for the feedback.

> Recompiled with debug enabled and recrashed.  See attached gdb_out.txt

Could you please send us configure options you used: I can not repeat the problem with our binaries.
[2 Dec 2009 14:14] MySQL Verification Team
repeatable on 5.1.41 within ~20 seconds here.
I didn't yet apply that patch - will do it now and rebuild.
[2 Dec 2009 14:25] MySQL Verification Team
testcase of the reporter

Attachment: bug46175.c (text/x-csrc), 7.74 KiB.

[2 Dec 2009 14:27] MySQL Verification Team
I uploaded a bug46175.c testcase that runs the replace into .. select .. and select .. in 5 threads with random 0-5 second sleeps inbetween.   to repeat the
bug, start mysqld like this:

mysqld --console --skip-grant-tables     --innodb_lock_wait_timeout=1 --innodb_flush_log_at_trx_commit=0 --innodb_buffer_pool_size=250M --log-bin --sync-binlog=0  --binlog-format=statement  --skip-name-resolve

then import the reporter's database uploaded as bug-data-testcase-46175.tar.bz2.
then run the testcase against the server.  I get a crash within 10 seconds each time.
[2 Dec 2009 14:46] MySQL Verification Team
some gdb details from a crash i just got with the above testcase.

Attachment: bug46175_my_gdb_output.txt (text/plain), 81.94 KiB.

[2 Dec 2009 16:00] Adam Erickson
It sounds like you don't need this but my configure line:

$ CFLAGS="-O3" CXX=gcc CXXFLAGS="-O3 -felide-constructors -fno-exceptions -fno-rtti" ./configure --enable-assembler --with-mysqld-ldflags=-all-static --prefix=/opt/mysql-5.1.41ae --with-client-ldflags=-all-static --with-extra-charsets=all --enable-thread-safe-client --with-big-tables --enable-profiling --enable-community-features --with-plugins=innobase,federated,blackhole,archive,partition,innodb_plugin --with-server-suffix='ae1' --with-debug=full --with-fast-mutexes
[3 Dec 2009 11:18] Sveta Smirnova
Shane, thank you for the test. It works for me.

Adam, thank you for the configure options. I used them to repeat the problem.

Set back to "Verified".
[7 Dec 2009 7:12] Marko Mäkelä
This may be related to Bug #39022. Both seem to have trx->read_view == NULL.
[7 Dec 2009 9:49] Marko Mäkelä
I can repeat the bug.

The function trx_view_close_for_mysql() is not being called during the test case. 

trx_view_close() is called, once by trx_purge() and a few times by trx_commit_off_kernel() before the assertion failure. The first calls to trx_commit_off_kernel() are legitimate, for START TRANSACTION and COMMIT. The last call before the crash makes me suspect that InnoDB expects MySQL to handle the error situation but MySQL carries on with statement execution:

Breakpoint 9, read_view_close (view=0xb6fbe068) at read/read0read.c:314
(gdb) bt
#0  read_view_close (view=0xb6fbe068) at read/read0read.c:314
#1  0x08530d53 in trx_commit_off_kernel (trx=0xb6fbdc68) at trx/trx0trx.c:854
#2  0x0852d3ef in trx_finish_rollback_off_kernel (graph=0xb6fcfc68, trx=0xb6fbdc68, next_thr=0xb50fbb3c) at trx/trx0roll.c:1249
#3  0x08504b37 in que_thr_dec_refer_count (thr=0xb6fcfce8, next_thr=0xb50fbb3c) at que/que0que.c:876
#4  0x08505599 in que_run_threads_low (thr=0xb6fcfce8) at que/que0que.c:1331
#5  0x08505604 in que_run_threads (thr=0xb6fcf918) at que/que0que.c:1355
#6  0x0852b82f in trx_general_rollback_for_mysql (trx=0xb6fbdc68, partial=0, savept=0x0) at trx/trx0roll.c:82
#7  0x0850e702 in row_mysql_handle_errors (new_err=0xb50fc20c, trx=0xb6fbdc68, thr=0xb6fc9e78, savept=0x0) at row/row0mysql.c:515
#8  0x0851b36b in row_search_for_mysql (buf=0x9462dd0 "\377", '\245' <repeats 47 times>, "\020.F\th.F\t\300.F\t", mode=2, prebuilt=0xb6fc9868, match_mode=1, direction=0) at row/row0sel.c:4359
#9  0x084b3d31 in ha_innobase::index_read (this=0x9462c80, buf=0x9462dd0 "\377", '\245' <repeats 47 times>, "\020.F\th.F\t\300.F\t", key_ptr=0x943ca88 "\002\347\261\324\350", key_len=8, find_flag=HA_READ_KEY_EXACT) at handler/ha_innodb.cc:4584
#10 0x083bc1c2 in handler::index_read_map (this=0x9462c80, buf=0x9462dd0 "\377", '\245' <repeats 47 times>, "\020.F\th.F\t\300.F\t", key=0x943ca88 "\002\347\261\324\350", keypart_map=1, find_flag=HA_READ_KEY_EXACT) at ../../sql/handler.h:1401
#11 0x082fb741 in join_read_always_key (tab=0x943c8f0) at sql_select.cc:11836
#12 0x082f9bff in sub_select (join=0x943af78, join_tab=0x943c8f0, end_of_records=false) at sql_select.cc:11238
#13 0x0830ab6a in do_select (join=0x943af78, fields=0x943c0e0, table=0x0, procedure=0x0) at sql_select.cc:10995
#14 0x0831bbb1 in JOIN::exec (this=0x943af78) at sql_select.cc:2246
#15 0x0822c2a3 in subselect_single_select_engine::exec (this=0x941c410) at item_subselect.cc:1966
#16 0x082311cf in Item_subselect::exec (this=0x941c370) at item_subselect.cc:261
#17 0x08229be0 in Item_singlerow_subselect::val_str (this=0x941c370, str=0x941c378) at item_subselect.cc:584
#18 0x081b683a in Item::save_in_field (this=0x941c370, field=0x946bd88, no_conversions=true) at item.cc:5108
#19 0x0831c6a4 in store_key_item::copy_inner (this=0x946bd70) at sql_select.h:711
#20 0x082319ca in store_key::copy (this=0x946bd70) at sql_select.h:642
#21 0x082f097a in cp_buffer_from_ref (thd=0x9454538, table=0x9331338, ref=0x946bcd0) at sql_select.cc:14328
#22 0x082fb6e1 in join_read_always_key (tab=0x946bbb4) at sql_select.cc:11834
#23 0x082f9bff in sub_select (join=0x9444f28, join_tab=0x946bbb4, end_of_records=false) at sql_select.cc:11238
#24 0x082f9a46 in evaluate_join_record (join=0x9444f28, join_tab=0x946ba20, error=0) at sql_select.cc:11365
#25 0x082f9c4a in sub_select (join=0x9444f28, join_tab=0x946ba20, end_of_records=false) at sql_select.cc:11245
#26 0x0830ab6a in do_select (join=0x9444f28, fields=0x9455970, table=0x0, procedure=0x0) at sql_select.cc:10995
#27 0x0831bbb1 in JOIN::exec (this=0x9444f28) at sql_select.cc:2246
#28 0x08316881 in mysql_select (thd=0x9454538, rref_pointer_array=0x94559d4, tables=0x946ea10, wild_num=1, fields=@0x9455970, conds=0x946f260, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2148813312, result=0x941c598, unit=0x945566c, select_lex=0x94558dc) at sql_select.cc:2435
#29 0x0831bf05 in handle_select (thd=0x9454538, lex=0x9455610, result=0x941c598, setup_tables_done_option=0) at sql_select.cc:269
#30 0x0828ba56 in execute_sqlcom_select (thd=0x9454538, all_tables=0x946ea10) at sql_parse.cc:5051
#31 0x0828dc6c in mysql_execute_command (thd=0x9454538) at sql_parse.cc:2246
#32 0x08296f78 in mysql_parse (thd=0x9454538, inBuf=0x946e170 "SELECT * FROM t2 INSTRUMENT , t1 PRICING  WHERE INSTRUMENT.INSTRUMENT_ID = PRICING.INSTRUMENT_ID    AND INSTRUMENT.STATUS= 'Active'    AND INSTRUMENT.INSTRUMENT_TYPE = 'Option'    AND INSTRUMENT.SYMBO"..., length=963, found_semicolon=0xb50fe260) at sql_parse.cc:5970

row_mysql_handle_errors() is rolling back the transaction when handling DB_DEADLOCK:

	} else if (err == DB_DEADLOCK
		   || err == DB_LOCK_TABLE_FULL
		   || (err == DB_LOCK_WAIT_TIMEOUT
		       && row_rollback_on_timeout)) {
		/* Roll back the whole transaction; this resolution was added
		to version 3.23.43 */

		trx_general_rollback_for_mysql(trx, FALSE, NULL);
…
	}

The DB_DEADLOCK is translated into rc=NESTED_LOOP_ERROR in sub_select() and -1 in do_select().  It looks like the error status could be lost in the call to copy_inner() in store_key::copy().  The index_read_map() call in join_read_always_key() seems to be the culprit to the crash:

  if (cp_buffer_from_ref(tab->join->thd, table, &tab->ref))
    return -1;
  if ((error=table->file->index_read_map(table->record[0],
                                         tab->ref.key_buff,
                                         make_prev_keypart_map(tab->ref.key_parts),
                                         HA_READ_KEY_EXACT)))

The cp_buffer_from_ref() will return 0, although the previous access resulted in HA_ERR_LOCK_DEADLOCK and the value being mapped to NULL. The index_read_map() will call row_search_for_mysql(), although the transaction no longer exists (InnoDB rolled it back before reporting the deadlock):

#0  row_search_for_mysql (buf=0x97c04d8 '\245' <repeats 48 times>, "\030\005|\tp\005|\t\310\005|\t", mode=2, prebuilt=0xb6f58668, match_mode=1, direction=0) at row/row0sel.c:3188
#1  0x084b3d31 in ha_innobase::index_read (this=0x97c0388, buf=0x97c04d8 '\245' <repeats 48 times>, "\030\005|\tp\005|\t\310\005|\t", key_ptr=0x97efeb8 "\001", key_len=4, find_flag=HA_READ_KEY_EXACT) at handler/ha_innodb.cc:4584
#2  0x083bc1c2 in handler::index_read_map (this=0x97c0388, buf=0x97c04d8 '\245' <repeats 48 times>, "\030\005|\tp\005|\t\310\005|\t", key=0x97efeb8 "\001", keypart_map=1, find_flag=HA_READ_KEY_EXACT) at ../../sql/handler.h:1401
#3  0x082fb741 in join_read_always_key (tab=0x97efd24) at sql_select.cc:11836
[10 Dec 2009 14:06] Heikki Tuuri
The test program contains SELECT and REPLACE statements. For a deadlock to happen in a SELECT, it should be a locking read. I do not see how/why the test program uses locking reads. Does it run on the level SERIALIZABLE where all SELECTs are locking reads?
[10 Dec 2009 14:09] Heikki Tuuri
Marko noticed that --log-bin is needed for the bug to appear. Why would --log-bin cause a SERIALIZABLE level?
[16 Dec 2009 8:40] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20091216083311-xorsasf5kopjxshf) (version source revid:alik@sun.com-20091214191830-wznm8245ku8xo702) (merge vers: 6.0.14-alpha) (pib:14)
[16 Dec 2009 8:47] Bugs System
Pushed into 5.5.0-beta (revid:alik@sun.com-20091216082430-s0gtzibcgkv4pqul) (version source revid:alexey.kopytov@sun.com-20091124081906-6pqi7e7sajimog71) (merge vers: 5.5.0-beta) (pib:14)
[16 Dec 2009 8:54] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20091216083231-rp8ecpnvkkbhtb27) (version source revid:alik@sun.com-20091212203859-fx4rx5uab47wwuzd) (merge vers: 5.6.0-beta) (pib:14)
[23 Dec 2009 12:03] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/95501

3294 Georgi Kodinov	2009-12-23
      Bug #46175: NULL read_view and consistent read assertion
      
      The optimizer must not continue executing the current query
      if e.g. the storage engine reports an error.
      This is somewhat hard to implement with Item::val_xxx()
      because they do not have means to return error code.
      This is why we need to check the thread's error state after
      a call to one of the Item::val_xxx() methods.
      
      Fixed store_key_item::copy_inner() to return an error state 
      if an error happened during the call to Item::save_in_field() 
      because it calls Item::val_xxx().
[23 Dec 2009 16:17] Adam Erickson
5.1.41 compiled with Georgi's fix no longer crashes under the test case.
[12 Jan 2010 16:31] Gleb Shchepa
Agree with Evgeny's commentary.
[14 Jan 2010 14:41] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/96911

3294 Georgi Kodinov	2010-01-14
      Bug #46175: NULL read_view and consistent read assertion
      
      The optimizer must not continue executing the current query
      if e.g. the storage engine reports an error.
      This is somewhat hard to implement with Item::val_xxx()
      because they do not have means to return error code.
      This is why we need to check the thread's error state after
      a call to one of the Item::val_xxx() methods.
      
      Fixed store_key_item::copy_inner() to return an error state 
      if an error happened during the call to Item::save_in_field() 
      because it calls Item::val_xxx().
      Also added similar checks to related places.
[15 Jan 2010 14:09] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/97085

3294 Georgi Kodinov	2010-01-15
      Bug #46175: NULL read_view and consistent read assertion
      
      The optimizer must not continue executing the current query
      if e.g. the storage engine reports an error.
      This is somewhat hard to implement with Item::val_xxx()
      because they do not have means to return error code.
      This is why we need to check the thread's error state after
      a call to one of the Item::val_xxx() methods.
      
      Fixed store_key_item::copy_inner() to return an error state 
      if an error happened during the call to Item::save_in_field() 
      because it calls Item::val_xxx().
      Also added similar checks to related places.
[15 Jan 2010 14:12] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/97088

3316 Georgi Kodinov	2010-01-15
      Bug #46175: NULL read_view and consistent read assertion
      
      The optimizer must not continue executing the current query
      if e.g. the storage engine reports an error.
      This is somewhat hard to implement with Item::val_xxx()
      because they do not have means to return error code.
      This is why we need to check the thread's error state after
      a call to one of the Item::val_xxx() methods.
      
      Fixed store_key_item::copy_inner() to return an error state 
      if an error happened during the call to Item::save_in_field() 
      because it calls Item::val_xxx().
      Also added similar checks to related places.
[28 Jan 2010 22:25] Adam Erickson
I just got around to testing this and it fails based on my test 
case.  The server still crashes with this patch applied to a clean 
5.1.42 source.

The patch here still worked with 5.1.41 at least:
http://lists.mysql.com/commits/95501
[1 Feb 2010 8:44] Georgi Kodinov
Adam,

thanks for testing it. We will look into this problem some more.
[4 Feb 2010 10:20] Bugs System
Pushed into 5.1.44 (revid:joro@sun.com-20100204101444-2j32mhqroo0iiio6) (version source revid:joro@sun.com-20100115140920-wjbo6jzev3auxkvz) (merge vers: 5.1.43) (pib:16)
[5 Feb 2010 11:50] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100204063540-9czpdmpixi3iw2yb) (version source revid:alik@sun.com-20100127191532-z9p9z09bmjhonewb) (pib:16)
[5 Feb 2010 11:51] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20100205113942-oqovjy0eoqbarn7i) (version source revid:alik@sun.com-20100204064210-ljwanqvrjs83s1gq) (merge vers: 6.0.14-alpha) (pib:16)
[5 Feb 2010 12:02] Bugs System
Pushed into 5.5.2-m2 (revid:alik@sun.com-20100203172258-1n5dsotny40yufxw) (version source revid:alexey.kopytov@sun.com-20100123210923-lx4o1ettww9fdkqk) (merge vers: 5.5.2-m2) (pib:16)
[11 Feb 2010 17:40] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/99992

3376 Georgi Kodinov	2010-02-11
      Addendum to bug #46175 : use and check for the correct error values
      when converting to a enumerated type.
[11 Feb 2010 17:42] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/99997

3376 Georgi Kodinov	2010-02-11
      Addendum to bug #46175 : use and check for the correct error values
        when converting to a enumerated type.
[12 Feb 2010 9:20] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/100083

3380 Georgi Kodinov	2010-02-11
      Addendum to bug #46175 : use and check for the correct error values
        when converting to a enumerated type.
[15 Feb 2010 8:55] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/100328

3340 Georgi Kodinov	2010-02-15
      Addendum 2 for bug #46175: NULL read_view and consistent read assertion
      
      Fixed a compilation warning.
[17 Feb 2010 16:39] Adam Erickson
Took a fresh 5.1.43 source and applied (in this order):

http://lists.mysql.com/commits/97088
http://lists.mysql.com/commits/100083
http://lists.mysql.com/commits/100328

This build passed the test case I provided without crashing.  Good work.
[1 Mar 2010 8:46] Bugs System
Pushed into 5.1.45 (revid:joro@sun.com-20100301083827-xnimmrjg6bh33o1o) (version source revid:joro@sun.com-20100215085427-g2we19b3m2a3jvne) (merge vers: 5.1.45) (pib:16)
[2 Mar 2010 14:36] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20100302142746-u1gxdf5yk2bjrq3e) (version source revid:alik@sun.com-20100225090938-2j5ybqoau570mytu) (merge vers: 6.0.14-alpha) (pib:16)
[2 Mar 2010 14:42] Bugs System
Pushed into 5.5.3-m2 (revid:alik@sun.com-20100302072233-t3uqgjzdukt1pyhe) (version source revid:alexey.kopytov@sun.com-20100221213311-xf5nyv391dsw9v6j) (merge vers: 5.5.2-m2) (pib:16)
[2 Mar 2010 14:47] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100302072432-k8xvfkgcggkwgi94) (version source revid:alik@sun.com-20100224135227-rcqs9pe9b2in80pf) (pib:16)
[12 Mar 2010 14:16] Bugs System
Pushed into 5.1.44-ndb-7.0.14 (revid:jonas@mysql.com-20100312135944-t0z8s1da2orvl66x) (version source revid:jonas@mysql.com-20100312115609-woou0te4a6s4ae9y) (merge vers: 5.1.44-ndb-7.0.14) (pib:16)
[12 Mar 2010 14:32] Bugs System
Pushed into 5.1.44-ndb-6.2.19 (revid:jonas@mysql.com-20100312134846-tuqhd9w3tv4xgl3d) (version source revid:jonas@mysql.com-20100312060623-mx6407w2vx76h3by) (merge vers: 5.1.44-ndb-6.2.19) (pib:16)
[12 Mar 2010 14:48] Bugs System
Pushed into 5.1.44-ndb-6.3.33 (revid:jonas@mysql.com-20100312135724-xcw8vw2lu3mijrhn) (version source revid:jonas@mysql.com-20100312103652-snkltsd197l7q2yg) (merge vers: 5.1.44-ndb-6.3.33) (pib:16)
[14 Mar 2010 1:51] Paul DuBois
Noted in 5.1.44, 5.5.2, 6.0.14 changelogs.

The optimizer could continue to execute a query after a storage 
engine reported an error, leading to a server crash.
[17 Jun 2010 12:05] Bugs System
Pushed into 5.1.47-ndb-7.0.16 (revid:martin.skold@mysql.com-20100617114014-bva0dy24yyd67697) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[17 Jun 2010 12:50] Bugs System
Pushed into 5.1.47-ndb-6.2.19 (revid:martin.skold@mysql.com-20100617115448-idrbic6gbki37h1c) (version source revid:martin.skold@mysql.com-20100609140708-52rvuyq4q500sxkq) (merge vers: 5.1.45-ndb-6.2.19) (pib:16)
[17 Jun 2010 13:32] Bugs System
Pushed into 5.1.47-ndb-6.3.35 (revid:martin.skold@mysql.com-20100617114611-61aqbb52j752y116) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)