MySQL Bugs: #39695: Crash in SRLUpdateRecords::thaw during falcon_chill

Bug #39695	Crash in SRLUpdateRecords::thaw during falcon_chill_thaw test
Submitted:	27 Sep 2008 15:14	Modified:	13 Dec 2008 9:03
Reporter:	John Embretsen	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Falcon storage engine	Severity:	S1 (Critical)
Version:	6.0-falcon-team (6.0.8a)	OS:	Linux
Assigned to:	Christopher Powers	CPU Architecture:	Any
Tags:	F_CHILL THAW, pb2, pushbuild, test failure

Description:
From falcon_chill_thaw test output ("Pushbuild 2", Random Query Generator) for revid vvaintroub@mysql.com-20080926112420-gpbrqg6cmlqkvn77:

# 14:11:54 Query: UPDATE C AS X SET `int_key` = 209 WHERE X . `pk` > 44 failed: 1205 Lock wait timeout exceeded; try restarting transaction
# 14:11:54 Query: UPDATE B AS X SET `int_key` = 114 WHERE X . `int_nokey` < 212 failed: 2013 Lost connection to MySQL server during query

From error log:
(...)
Table::fetchForUpdate: Update Conflict: TransId=2113, RecordNumber=0, Table TEST.C
Table::fetchForUpdate: Update Conflict: TransId=2113, RecordNumber=2, Table TEST.B
Table::fetchForUpdate: Update Conflict: TransId=2113, RecordNumber=0, Table TEST.B
Table::fetchForUpdate: Update Conflict: TransId=2113, RecordNumber=34, Table TEST.C
Table::fetchForUpdate: Update Conflict: TransId=2140, RecordNumber=99, Table TEST.B
080926 15:11:54 - mysqld got signal 11 ;
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=1048576
read_buffer_size=131072
max_used_connections=12
max_threads=151
thread_count=11
connection_count=11
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 60039 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x9e2f708
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 = 0xa7e7cfa8 thread_stack 0x30c00
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld(my_print_stacktrace+0x26) [0x87e9197]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld(handle_segfault+0x2cd) [0x82ae5a5]
[0x13f420]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld(SRLUpdateRecords::thaw(RecordVersion*, bool*)+0xcf) [0x85e0e97]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld(Transaction::thaw(RecordVersion*)+0x96) [0x855729e]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld(RecordVersion::thaw()+0x68) [0x85c3678]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld(Record::getRecordData()+0x23) [0x854f31f]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld(RecordVersion::fetchVersionRecursive(Transaction*)+0xd5) [0x85c3e91]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld(RecordVersion::fetchVersion(Transaction*)+0x6c) [0x85c3f52]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld(StorageDatabase::nextRow(StorageTable*, int, bool)+0xb3) [0x8533f85]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld(StorageTable::next(int, bool)+0x3a) [0x853a024]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld(StorageInterface::rnd_next(unsigned char*)+0x92) [0x8525398]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld(rr_sequential(READ_RECORD*)+0x71) [0x83d3207]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld(sub_select(JOIN*, st_join_table*, bool)+0x1c7) [0x8329b87]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld [0x8330f8b]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld(JOIN::exec()+0x20ac) [0x834d168]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/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*)+0x329) [0x8347ec3]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld(handle_select(THD*, LEX*, select_result*, unsigned long)+0x1ec) [0x834d478]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld [0x82be2c3]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld(mysql_execute_command(THD*)+0x728) [0x82bf292]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld(mysql_parse(THD*, char const*, unsigned int, char const**)+0x22f) [0x82c7565]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld(dispatch_command(enum_server_command, THD*, char*, unsigned int)+0x87c) [0x82c8520]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld(do_command(THD*)+0x23b) [0x82c97eb]
/export/home/pb2/test/sb-40647-1222431083.23/mysql-6.0.8-alpha-linux-i686-test/libexec/mysqld(handle_one_connection+0x11d) [0x82b71ad]
/lib/libpthread.so.0 [0x89a45b]
/lib/libc.so.6(clone+0x5e) [0x7f1c4e]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x9d0cf40 = SELECT `int_key` FROM E WHERE `int_nokey` > 34
thd->thread_id=15
thd->killed=NOT_KILLED

See also Bug#39694 - Crash in StorageTable::setRecord during falcon_chill_thaw test

How to repeat:
Branch or checkout the mysql-test-extra-6.0 bazaar tree and run:

$ cd mysql-test/gentest
$ ./runall.pl \
 --basedir=/path/to/mysql-6.0-falcon-team \
 --reporters=Deadlock,ErrorLog,Backtrace,Recovery,WinPackage \
 --mysqld=--loose-falcon-lock-wait-timeout=1 \
 --engine=Falcon \
 --grammar=conf/falcon_chill_thaw.yy \ 
 --queries=100000 \
 --mysqld=--falcon-index-chill-threshold=4K \ 
 --mysqld=--falcon-record-chill-threshold=4K \ 
 --duration=1200

Verified in Pushbuild 2:

  Test:      falcon_chill_thaw
  Branch:    mysql-6.0-falcon-team
  Platform:  Linux nanna21 2.6.18-92.1.10.el5 #1 SMP Wed Jul 23 03:55:54 EDT 2008 i686 athlon i386 GNU/Linux
  Push date: 2008-09-26 13:26:34

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/56961

2880 Christopher Powers	2008-10-24
      Bug#36631,"Assertion in SerialLogControl::nextRecord"
      Bug#38541,"Falcon RecordVersion::thaw assertion """"bytesRestored > 0 || data.record == NULL"""
      Bug#38567,"Falcon crash in  Record::getEncodedRecord at Record.cpp:743"
      Bug#38569,"Falcon assertion in SRLUpdateIndex::thaw : type == srlUpdateIndex"
      Bug#39694,"Crash in StorageTable::setRecord during falcon_chill_thaw test"
      Bug#39695,"Crash in SRLUpdateRecords::thaw during falcon_chill_thaw test"
      Bug#39696,"Assertion in Table.cpp (dup->state == recDeleted) fails during falcon_chill_thaw"
      
      Fix 1 of 3 for chill/thaw bugs.
      
      Modified Record::hasRecord() to thaw if necessary, removed redundant record thaws, added exception handling

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/56962

2881 Christopher Powers	2008-10-24
      Bug#36631,"Assertion in SerialLogControl::nextRecord"
      Bug#38541,"Falcon RecordVersion::thaw assertion """"bytesRestored > 0 || data.record == NULL"""
      Bug#38567,"Falcon crash in  Record::getEncodedRecord at Record.cpp:743"
      Bug#38569,"Falcon assertion in SRLUpdateIndex::thaw : type == srlUpdateIndex"
      Bug#39694,"Crash in StorageTable::setRecord during falcon_chill_thaw test"
      Bug#39695,"Crash in SRLUpdateRecords::thaw during falcon_chill_thaw test"
      Bug#39696,"Assertion in Table.cpp (dup->state == recDeleted) fails during falcon_chill_thaw"
      
      Fix 2 of 3 for chill/thaw bugs.
      
      Synchronized record thaw operations using a pool of sync objects in the associated table.
      Record chill operations do not need to be synchronized because chills are performed in one place, and only by the active Transaction.

Two patches approved to problems with concurent thaws.
1) enhance hasRecord to thaw when needed.
2) serialize thaws with a hash table of SyncOjects.

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/57140

2884 Christopher Powers	2008-10-27
      Bug#39695 "Crash in SRLUpdateRecords::thaw during falcon_chill_thaw_test"
      
      Fixed compile warning.

Pushed into 6.0.8-alpha  (revid:cpowers@mysql.com-20081027180009-z2wqt0142egulf58) (version source revid:alik@mysql.com-20081028074021-o49ijs3x4pxj1gbm) (pib:5)

No documentation needed (internal change only)