MySQL Bugs: #30078: server crash with signal 4

Bug #30078	server crash with signal 4
Submitted:	26 Jul 2007 16:20	Modified:	25 Aug 2007 6:13
Reporter:	Shane Bester (Platinum Quality Contributor)	Email Updates:
Status:	Can't repeat	Impact on me:	None
Category:	MySQL Server: Falcon storage engine	Severity:	S1 (Critical)
Version:	mysql-6.0.2-alpha-linux-i686	OS:	Any
Assigned to:		CPU Architecture:	Any
Tags:	concurrent threads, crash

Description:
Today I cloned bk://mysql.bkbits.net/mysql-6.0-falcon and ran some small tests
in just 10 threads and 4 tables:

070726 17:59:57 - mysqld got signal 4;
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=8388572
read_buffer_size=131072
max_used_connections=13
max_threads=151
threads_connected=12
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 337602 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x8e896f8
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...
Cannot determine thread, fp=0x4474c07c, backtrace may not be correct.
Stack range sanity check OK, backtrace follows:
0x821009b handle_segfault + 541
0xffffe410 _end + -142800224
0x83e58b2 _ZN5Error10debugBreakEv + 18
0x83e582a _ZN5Error5errorEPKcz + 82
0x83e5898 _ZN5Error15assertionFailedEPKci + 32
0x84093ba _ZN6RecordD2Ev + 42
0x840ad6d _ZN13RecordVersionD0Ev + 71
0x8409f4f _ZN6Record7releaseEv + 71
0x83c14d5 _ZN11Transaction13commitRecordsEv + 117
0x83c1f95 _ZN11Transaction17releaseDependencyEv + 183
0x83c144b _ZN11Transaction19releaseDependenciesEv + 193
0x83c06af _ZN11Transaction6commitEv + 619
0x83d1c2e _ZN10Connection6commitEv + 166
0x83ac3a0 _ZN17StorageConnection6commitEv + 100
0x83a6f64 _ZN16StorageInterface6commitEP10handlertonP3THDb + 134
0x82f8970 _Z19ha_commit_one_phaseP3THDb + 162
0x82f882d _Z15ha_commit_transP3THDb + 911
0x821958c _Z16end_active_transP3THD + 342
0x8219654 _Z11begin_transP3THD + 106
0x82215ee _Z21mysql_execute_commandP3THD + 20646
0x82259e1 _Z11mysql_parseP3THDPKcjPS2_ + 339
0x821b02d _Z16dispatch_command19enum_server_commandP3THDPcj + 2325
0x821a70c _Z10do_commandP3THD + 612
0x8219273 handle_one_connection + 253
0x40250aa7 _end + 933376311
0x401e6c2e _end + 932942526
New value of fp=(nil) failed sanity check, terminating stack trace!
Please read http://dev.mysql.com/doc/refman/5.1/en/resolve-stack-dump.html
and follow instructions on how to resolve the stack trace.
Resolved stack trace is much more helpful in diagnosing the
problem, so please do resolve it
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x8eb5260 = start transaction
thd->thread_id=545
The manual page at http://www.mysql.com/doc/en/Crashing.html contains
information that should help you find out what is causing the crash.

How to repeat:
I will upload my stress tester's input file.

Suggested fix:
.

complete error log, as you see there are a vast number of errors after the first crash

Attachment: www.err.txt (text/plain), 84.63 KiB.

gypsy --queryfile=falcon_simple.query  --threads=10 --duration=300 --shuffle-queries=1

Attachment: falcon_simple.query (application/octet-stream, text), 1.72 KiB.

just noticed an unbalanced 'start transaction' which has no corresponding 'commit'.  But, my server isn't running nearly out of memory, so this is still a bug.  I repeated it twice on a clean datadir within 5 mins of running.

log of a few crashes.

Attachment: two_crash_stress_tester_output.txt (text/plain), 91.53 KiB.

crashed calvin's windows binaries too.

mysqld-debug.exe!Error::debugBreak  Line 90
mysqld-debug.exe!Error::error Line 71
mysqld-debug.exe!Error::assertionFailed Line 76
mysqld-debug.exe!Transaction::commitRecords  Line 710
mysqld-debug.exe!Transaction::releaseDependency  Line 1115
mysqld-debug.exe!Transaction::releaseDependencies  Line 690
mysqld-debug.exe!Transaction::commit  Line 275
mysqld-debug.exe!Connection::commit  Line 270
mysqld-debug.exe!StorageConnection::commit  Line 153
mysqld-debug.exe!StorageHandler::commit Line 218
mysqld-debug.exe!StorageInterface::commit Line 1000
mysqld-debug.exe!ha_commit_one_phase Line 779
mysqld-debug.exe!ha_commit_trans Line 749
mysqld-debug.exe!end_active_trans Line 119
mysqld-debug.exe!begin_trans Line 142
mysqld-debug.exe!mysql_execute_command Line 3552
mysqld-debug.exe!mysql_parse Line 5381
mysqld-debug.exe!dispatch_command Line 907
mysqld-debug.exe!do_command Line 669
mysqld-debug.exe!handle_one_connection Line 1091
mysqld-debug.exe!pthread_start Line 62
mysqld-debug.exe!_threadstart Line 196

complete windows stack in file to avoid wrapping

Attachment: win_stack_complete.txt (text/plain), 2.11 KiB.

testcase!!!!!

Attachment: bug30078.c (text/x-csrc), 9.63 KiB.

Verified on Intel/Mac with latest change set 1.2662, 2007-07-26 14:30:05+02:00, hakank@au0012.local

Test case bug30078.c fails within 2 minutes.

(gdb) bt
#0  0x9003d66c in kill ()
#1  0x9010e8cf in raise ()
#2  0x002f4428 in Error::debugBreak () at Error.cpp:92
#3  0x002f448c in Error::error (string=0x5abde4 "assertion failed at line %d in file %s\n") at Error.cpp:69
#4  0x002f453c in Error::assertionFailed (fileName=0x5ae0e0 "Record.cpp", line=129) at Error.cpp:76
#5  0x003261a2 in Record::~Record (this=0x94aedb4) at Record.cpp:129
#6  0x00327f82 in RecordVersion::~RecordVersion (this=0x94aedb4) at RecordVersion.cpp:65
#7  0x003255e8 in Record::release (this=0x94aedb4) at Record.cpp:517
#8  0x002c354f in Transaction::commitRecords (this=0x5a702f0) at Transaction.cpp:713
#9  0x002c44b7 in Transaction::releaseDependency (this=0x5a702f0) at Transaction.cpp:1113
#10 0x002c45d7 in Transaction::releaseDependencies (this=0x5a616a0) at Transaction.cpp:687
#11 0x002c6371 in Transaction::commit (this=0x5a616a0) at Transaction.cpp:274
#12 0x002dc356 in Connection::commit (this=0x5a4afa4) at Connection.cpp:269
#13 0x002a7455 in StorageConnection::commit (this=0x5a4af48) at StorageConnection.cpp:153
#14 0x00294877 in StorageInterface::commit (hton=0x4d02638, thd=0x6087c18, all=true) at ha_falcon.cpp:998
#15 0x001c491c in ha_commit_one_phase (thd=0x6087c18, all=true) at handler.cc:779
#16 0x001c4f78 in ha_commit_trans (thd=0x6087c18, all=true) at handler.cc:749
#17 0x000c2c6d in end_active_trans (thd=0x6087c18) at sql_parse.cc:119
#18 0x000c2d6c in begin_trans (thd=0x6087c18) at sql_parse.cc:142
#19 0x000d0a18 in mysql_execute_command (thd=0x6087c18) at sql_parse.cc:3552
#20 0x000d3af7 in mysql_parse (thd=0x6087c18, inBuf=0x6094e28 "start transaction", length=17, found_semicolon=0xb040cdb8) at sql_parse.cc:5381
#21 0x000d474a in dispatch_command (command=COM_QUERY, thd=0x6087c18, packet=0x4ab1019 "start transaction", packet_length=18) at sql_parse.cc:907
#22 0x000d59c1 in do_command (thd=0x6087c18) at sql_parse.cc:669
#23 0x000c281e in handle_one_connection (arg=0x6087c18) at sql_connect.cc:1091
#24 0x90024227 in _pthread_body ()

Can'r repeat with latest change set.

./bug30078
...
...
...
query failed 'insert ignore into t3(id) select max(id)+1 from t2' : 1296 (Got error 210 'deadlock on key T3..PRIMARY_KEY in table TEST.T3' from Falcon)
query failed 'insert ignore into t1(id) select max(id)+1 from t2' : 1296 (Got error 210 'deadlock on key T1..PRIMARY_KEY in table TEST.T1' from Falcon)
waiting for worker threads to finish...