MySQL Bugs: #7267: MySql crashed during use

Bug #7267	MySql crashed during use
Submitted:	14 Dec 2004 13:48	Modified:	14 Dec 2004 20:08
Reporter:	Chad Fleenor	Email Updates:
Status:	Can't repeat	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S1 (Critical)
Version:	4.0.20	OS:	Linux (RedHat 9.0 Linux)
Assigned to:	Heikki Tuuri	CPU Architecture:	Any

Description:
Here is the log file: 
 
---TRANSACTION 0 205437860, ACTIVE 593 sec, process no 30426, OS thread id 1277970 
updating or deleting, thread declared inside InnoDB 421 
mysql tables in use 1, locked 1 
774 lock struct(s), heap size 44352, undo log entries 9558 
MySQL thread id 781521, query id 711106394 localhost web updating 
DELETE from HCM_ADT where status = 'S' and `time` < '2004-12-11 03:05:00' 
---TRANSACTION 0 205128850, ACTIVE 40704 sec, process no 4162, OS thread id 348185 
fetching rows, thread declared inside InnoDB 461 
mysql tables in use 1, locked 0 
MySQL thread id 132885, query id 681214908 localhost web Sending data 
select * from HCM_ADT where status = 'n' order by id 
Trx read view will not see trx with id >= 0 205128851, sees < 0 205128848 
-------- 
FILE I/O 
-------- 
I/O thread 0 state: waiting for i/o request (insert buffer thread) 
I/O thread 1 state: waiting for i/o request (log thread) 
I/O thread 2 state: waiting for i/o request (read thread) 
I/O thread 3 state: waiting for i/o request (write thread) 
Pending normal aio reads: 0, aio writes: 0, 
 ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0 
Pending flushes (fsync) log: 0; buffer pool: 0 
88493977 OS file reads, 6319500 OS file writes, 5213165 OS fsyncs 
37.94 reads/s, 83647 avg bytes/read, 18.56 writes/s, 17.87 fsyncs/s 
------------------------------------- 
INSERT BUFFER AND ADAPTIVE HASH INDEX 
------------------------------------- 
Ibuf for space 0: size 1, free list len 5, seg size 7, 
457492 inserts, 457492 merged recs, 214390 merges 
Hash table size 415141, used cells 3379, node heap has 4 buffer(s) 
20.44 hash searches/s, 15.25 non-hash searches/s 
--- 
LOG 
--- 
Log sequence number 7 3132922873 
Log flushed up to   7 3132922873 
Last checkpoint at  7 3132820751 
0 pending log writes, 0 pending chkp writes 
4928747 log i/o's done, 17.62 log i/o's/second 
---------------------- 
BUFFER POOL AND MEMORY 
---------------------- 
Total memory allocated 138854404; in additional pool allocated 2324480 
Buffer pool size   6400 
Free buffers       1 
Database pages     6393 
Modified db pages  38 
Pending reads 0  
Pending writes: LRU 0, flush list 0, single page 0 
Pages read 812890997, created 117300, written 1801545 
193.68 reads/s, 0.19 creates/s, 1.25 writes/s 
Buffer pool hit rate 974 / 1000 
-------------- 
ROW OPERATIONS 
-------------- 
4 queries inside InnoDB, 0 queries in queue 
Main thread process no. 1351, id 28680, state: sleeping 
Number of rows inserted 1817945, updated 3756558, deleted 1220436, read 1537092630 
0.56 inserts/s, 16.75 updates/s, 0.00 deletes/s, 6424.41 reads/s 
---------------------------- 
END OF INNODB MONITOR OUTPUT 
============================ 
InnoDB: ###### Diagnostic info printed to the standard error stream 
InnoDB: Warning: a long semaphore wait: 
--Thread 1277970 has waited at btr0cur.c line 401 for 594.00 seconds the semaphore: 
X-lock on RW-latch at 0x479ac518 created in file buf0buf.c line 438 
a writer (thread id 1277970) has reserved it in mode  wait exclusive 
number of readers 1, waiters flag 1 
Last time read locked in file ../../innobase/btr/../include/btr0btr.ic line 28 
Last time write locked in file buf0buf.c line 1401 
InnoDB: Warning: a long semaphore wait: 
--Thread 1286164 has waited at ../../innobase/btr/../include/btr0btr.ic line 28 for 571.00 
seconds the semaphore: 
S-lock on RW-latch at 0x479ac518 created in file buf0buf.c line 438 
a writer (thread id 1277970) has reserved it in mode  wait exclusive 
number of readers 1, waiters flag 1 
Last time read locked in file ../../innobase/btr/../include/btr0btr.ic line 28 
Last time write locked in file buf0buf.c line 1401 
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info: 
InnoDB: Pending preads 0, pwrites 0 
 
===================================== 
041214  3:15:09 INNODB MONITOR OUTPUT 
===================================== 
Per second averages calculated from the last 16 seconds 
---------- 
SEMAPHORES 
---------- 
OS WAIT ARRAY INFO: reservation count 315947963, signal count 314662630 
--Thread 1277970 has waited at btr0cur.c line 401 for 604.00 seconds the semaphore: 
X-lock on RW-latch at 0x479ac518 created in file buf0buf.c line 438 
a writer (thread id 1277970) has reserved it in mode  wait exclusive 
number of readers 1, waiters flag 1 
Last time read locked in file ../../innobase/btr/../include/btr0btr.ic line 28 
Last time write locked in file buf0buf.c line 1401 
--Thread 1286164 has waited at ../../innobase/btr/../include/btr0btr.ic line 28 for 581.00 
seconds the semaphore: 
S-lock on RW-latch at 0x479ac518 created in file buf0buf.c line 438 
a writer (thread id 1277970) has reserved it in mode  wait exclusive 
number of readers 1, waiters flag 1 
Last time read locked in file ../../innobase/btr/../include/btr0btr.ic line 28 
Last time write locked in file buf0buf.c line 1401 
--Thread 618557 has waited at btr0cur.c line 339 for 37.00 seconds the semaphore: 
X-lock on RW-latch at 0x410a24bc created in file dict0dict.c line 3397 
a writer (thread id 618557) has reserved it in mode  wait exclusive 
number of readers 1, waiters flag 1 
Last time read locked in file btr0cur.c line 346 
Last time write locked in file btr0cur.c line 339 
Mutex spin waits 1301666567, rounds 3637635576, OS waits 20889137 
RW-shared spins 533023361, OS waits 253541664; RW-excl spins 376674, OS waits 
115855 
------------ 
TRANSACTIONS 
------------ 
Trx id counter 0 205443353 
Purge done for trx's n:o < 0 205128854 undo n:o < 0 2 
Total number of lock structs in row lock hash table 773 
LIST OF TRANSACTIONS FOR EACH SESSION: 
---TRANSACTION 0 205443351, not started, process no 5762, OS thread id 884758 
MySQL thread id 781677, query id 711527471 localhost web 
---TRANSACTION 0 205443303, not started, process no 20102, OS thread id 1368077 
MySQL thread id 777886, query id 711527356 localhost web 
---TRANSACTION 0 205341499, not started, process no 9890, OS thread id 1318962 
MySQL thread id 776242, query id 703799610 localhost web 
---TRANSACTION 0 205443002, not started, process no 28160, OS thread id 1359935 
MySQL thread id 767895, query id 711527040 localhost web 
---TRANSACTION 0 205443309, not started, process no 32531, OS thread id 1151022 
MySQL thread id 764769, query id 711527397 localhost web 
---TRANSACTION 0 205443305, not started, process no 22600, OS thread id 1290266 
MySQL thread id 759697, query id 711527363 localhost web 
---TRANSACTION 0 205443301, not started, process no 19555, OS thread id 1257515 
MySQL thread id 759633, query id 711527349 localhost web 
---TRANSACTION 0 205443304, not started, process no 27305, OS thread id 1204247 
MySQL thread id 629876, query id 711527357 localhost web 
---TRANSACTION 0 205442995, not started, process no 11478, OS thread id 233530 
MySQL thread id 544641, query id 711527011 localhost web 
---TRANSACTION 0 205443000, not started, process no 1636, OS thread id 782364 
MySQL thread id 433162, query id 711527038 localhost web 
---TRANSACTION 0 205443313, not started, process no 9455, OS thread id 630800 
MySQL thread id 259959, query id 711527421 localhost web 
---TRANSACTION 0 205442998, not started, process no 10531, OS thread id 516110 
MySQL thread id 243302, query id 711527019 localhost web 
---TRANSACTION 0 205443087, not started, process no 16338, OS thread id 512039 
MySQL thread id 201317, query id 711527126 localhost web 
---TRANSACTION 0 205442999, not started, process no 2947, OS thread id 450626 
MySQL thread id 201229, query id 711527031 localhost web 
---TRANSACTION 0 205437644, not started, process no 4659, OS thread id 274456 
MySQL thread id 30771, query id 710940401 localhost web 
---TRANSACTION 0 205437603, not started, process no 6108, OS thread id 192560 
MySQL thread id 127, query id 710940272 localhost web 
---TRANSACTION 0 205443302, not started, process no 2660, OS thread id 139299 
MySQL thread id 72, query id 711527350 localhost web 
---TRANSACTION 0 205443307, not started, process no 10345, OS thread id 221239 
MySQL thread id 195, query id 711527391 localhost web 
---TRANSACTION 0 205443312, not started, process no 11786, OS thread id 237627 
MySQL thread id 184, query id 711527405 localhost web 
---TRANSACTION 0 205443088, not started, process no 11087, OS thread id 229433 
MySQL thread id 175, query id 711527127 localhost web 
---TRANSACTION 0 205442992, not started, process no 10794, OS thread id 225336 
MySQL thread id 169, query id 711526954 localhost web 
---TRANSACTION 0 205443308, not started, process no 9842, OS thread id 217142 
MySQL thread id 159, query id 711527396 localhost web 
---TRANSACTION 0 205443314, not started, process no 9048, OS thread id 213045 
MySQL thread id 154, query id 711527422 localhost web 
---TRANSACTION 0 205442985, not started, process no 8933, OS thread id 208948 
MySQL thread id 149, query id 711526918 localhost web 
---TRANSACTION 0 205443086, not started, process no 3013, OS thread id 151590 
MySQL thread id 137, query id 711527125 localhost web 
---TRANSACTION 0 205443306, not started, process no 6473, OS thread id 196657 
MySQL thread id 132, query id 711527371 localhost web 
---TRANSACTION 0 205442310, not started, process no 4962, OS thread id 176172 
MySQL thread id 107, query id 711516934 localhost web 
---TRANSACTION 0 205441040, not started, process no 3663, OS thread id 159784 
MySQL thread id 87, query id 711441945 localhost web 
---TRANSACTION 0 205443310, not started, process no 2659, OS thread id 135202 
MySQL thread id 71, query id 711527398 localhost web 
---TRANSACTION 0 205443311, not started, process no 2656, OS thread id 122911 
MySQL thread id 68, query id 711527399 localhost web 
---TRANSACTION 0 205442997, not started, process no 2661, OS thread id 143396 
MySQL thread id 73, query id 711527013 localhost web 
---TRANSACTION 0 205442774, not started, process no 2649, OS thread id 106523 
MySQL thread id 64, query id 711526686 localhost web 
---TRANSACTION 0 205441071, not started, process no 1353, OS thread id 36874 
MySQL thread id 48, query id 711527472 localhost web 
---TRANSACTION 0 205442307, ACTIVE 37 sec, process no 4749, OS thread id 618557 
inserting, thread declared inside InnoDB 499 
mysql tables in use 1, locked 1 
2 lock struct(s), heap size 320 
MySQL thread id 439392, query id 711514941 localhost web update 
insert into HL7Live.HCM_ADT values('','STAR_HBO','2004-12-14 
03:14:31','n','A08','MSH:;~\\&:ST01:A:IM:A:20041214031429::ADT;A08:670147:P:2.2:670147::AL:::::::2.2b\rEVN:A08:20041214031429:::LAA\rPID:1::999999;;;ST01A;MR~00999999;;;ST01;PI::DOE;JANE;J;
\"\"::19801028:F::1:534 ROAD CRK;;MELBORN 
---TRANSACTION 0 205437892, ACTIVE 581 sec, process no 21157, OS thread id 1286164 
fetching rows, thread declared inside InnoDB 461 
mysql tables in use 1, locked 0 
MySQL thread id 768008, query id 711106502 localhost web Sending data 
select * from HCM_ADT where status = 'n' order by id 
Trx read view will not see trx with id >= 0 205437893, sees < 0 205128850 
---TRANSACTION 0 205437860, ACTIVE 609 sec, process no 30426, OS thread id 1277970 
updating or deleting, thread declared inside InnoDB 421 
mysql tables in use 1, locked 1 
774 lock struct(s), heap size 44352, undo log entries 9558 
MySQL thread id 781521, query id 711106394 localhost web updating 
DELETE from HCM_ADT where status = 'S' and `time` < '2004-12-11 03:05:00' 
---TRANSACTION 0 205128850, ACTIVE 40720 sec, process no 4162, OS thread id 348185 
fetching rows, thread declared inside InnoDB 461 
mysql tables in use 1, locked 0 
MySQL thread id 132885, query id 681214908 localhost web Sending data 
select * from HCM_ADT where status = 'n' order by id 
Trx read view will not see trx with id >= 0 205128851, sees < 0 205128848 
-------- 
FILE I/O 
-------- 
I/O thread 0 state: waiting for i/o request (insert buffer thread) 
I/O thread 1 state: waiting for i/o request (log thread) 
I/O thread 2 state: waiting for i/o request (read thread) 
I/O thread 3 state: waiting for i/o request (write thread) 
Pending normal aio reads: 0, aio writes: 0, 
 ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0 
Pending flushes (fsync) log: 0; buffer pool: 0 
88494690 OS file reads, 6319663 OS file writes, 5213297 OS fsyncs 
44.56 reads/s, 123236 avg bytes/read, 10.19 writes/s, 8.25 fsyncs/s 
------------------------------------- 
INSERT BUFFER AND ADAPTIVE HASH INDEX 
------------------------------------- 
Ibuf for space 0: size 1, free list len 5, seg size 7, 
457495 inserts, 457492 merged recs, 214390 merges 
Hash table size 415141, used cells 1060, node heap has 2 buffer(s) 
12.50 hash searches/s, 3.69 non-hash searches/s 
--- 
LOG 
--- 
Log sequence number 7 3132957311 
Log flushed up to   7 3132957311 
Last checkpoint at  7 3132943348 
0 pending log writes, 0 pending chkp writes 
4928875 log i/o's done, 8.00 log i/o's/second 
---------------------- 
BUFFER POOL AND MEMORY 
---------------------- 
Total memory allocated 138854404; in additional pool allocated 2324480 
Buffer pool size   6400 
Free buffers       0 
Database pages     6396 
Modified db pages  9 
Pending reads 0  
Pending writes: LRU 0, flush list 0, single page 0 
Pages read 812896360, created 117301, written 1801588 
335.17 reads/s, 0.06 creates/s, 2.69 writes/s 
Buffer pool hit rate 969 / 1000 
-------------- 
ROW OPERATIONS 
-------------- 
4 queries inside InnoDB, 0 queries in queue 
Main thread process no. 1351, id 28680, state: sleeping 
Number of rows inserted 1817948, updated 3756681, deleted 1220436, read 1537241939 
0.19 inserts/s, 7.69 updates/s, 0.00 deletes/s, 9331.23 reads/s 
---------------------------- 
END OF INNODB MONITOR OUTPUT 
============================ 
 
===================================== 
041214  3:15:25 INNODB MONITOR OUTPUT 
===================================== 
Per second averages calculated from the last 16 seconds 
---------- 
SEMAPHORES 
---------- 
OS WAIT ARRAY INFO: reservation count 315948288, signal count 314662955 
--Thread 1277970 has waited at btr0cur.c line 401 for 620.00 seconds the semaphore: 
X-lock on RW-latch at 0x479ac518 created in file buf0buf.c line 438 
a writer (thread id 1277970) has reserved it in mode  wait exclusive 
number of readers 1, waiters flag 1 
Last time read locked in file ../../innobase/btr/../include/btr0btr.ic line 28 
Last time write locked in file buf0buf.c line 1401 
--Thread 1286164 has waited at ../../innobase/btr/../include/btr0btr.ic line 28 for 597.00 
seconds the semaphore: 
S-lock on RW-latch at 0x479ac518 created in file buf0buf.c line 438 
a writer (thread id 1277970) has reserved it in mode  wait exclusive 
number of readers 1, waiters flag 1 
Last time read locked in file ../../innobase/btr/../include/btr0btr.ic line 28 
Last time write locked in file buf0buf.c line 1401 
--Thread 618557 has waited at btr0cur.c line 339 for 53.00 seconds the semaphore: 
X-lock on RW-latch at 0x410a24bc created in file dict0dict.c line 3397 
a writer (thread id 618557) has reserved it in mode  wait exclusive 
number of readers 1, waiters flag 1 
Last time read locked in file btr0cur.c line 346 
Last time write locked in file btr0cur.c line 339 
Mutex spin waits 1301668618, rounds 3637642342, OS waits 20889145 
RW-shared spins 533023998, OS waits 253541970; RW-excl spins 376674, OS waits 
115855 
------------ 
TRANSACTIONS 
------------ 
Trx id counter 0 205443623 
Purge done for trx's n:o < 0 205128854 undo n:o < 0 2 
Total number of lock structs in row lock hash table 773 
LIST OF TRANSACTIONS FOR EACH SESSION: 
---TRANSACTION 0 205443606, not started, process no 5762, OS thread id 884758 
MySQL thread id 781677, query id 711527747 localhost web 
---TRANSACTION 0 205443303, not started, process no 20102, OS thread id 1368077 
MySQL thread id 777886, query id 711527356 localhost web 
---TRANSACTION 0 205341499, not started, process no 9890, OS thread id 1318962 
MySQL thread id 776242, query id 703799610 localhost web 
---TRANSACTION 0 205443622, not started, process no 28160, OS thread id 1359935 
MySQL thread id 767895, query id 711527804 localhost web 
---TRANSACTION 0 205443309, not started, process no 32531, OS thread id 1151022 
MySQL thread id 764769, query id 711527397 localhost web 
---TRANSACTION 0 205443305, not started, process no 22600, OS thread id 1290266 
MySQL thread id 759697, query id 711527363 localhost web 
---TRANSACTION 0 205443301, not started, process no 19555, OS thread id 1257515 
MySQL thread id 759633, query id 711527349 localhost web 
---TRANSACTION 0 205443304, not started, process no 27305, OS thread id 1204247 
MySQL thread id 629876, query id 711527357 localhost web 
---TRANSACTION 0 205443613, not started, process no 11478, OS thread id 233530 
MySQL thread id 544641, query id 711527763 localhost web 
---TRANSACTION 0 205443619, not started, process no 1636, OS thread id 782364 
MySQL thread id 433162, query id 711527794 localhost web 
---TRANSACTION 0 205443621, not started, process no 9455, OS thread id 630800 
MySQL thread id 259959, query id 711527803 localhost web 
---TRANSACTION 0 205443614, not started, process no 10531, OS thread id 516110 
MySQL thread id 243302, query id 711527764 localhost web 
---TRANSACTION 0 205443087, not started, process no 16338, OS thread id 512039 
MySQL thread id 201317, query id 711527126 localhost web 
---TRANSACTION 0 205443618, not started, process no 2947, OS thread id 450626 
MySQL thread id 201229, query id 711527793 localhost web 
---TRANSACTION 0 205437644, not started, process no 4659, OS thread id 274456 
MySQL thread id 30771, query id 710940401 localhost web 
---TRANSACTION 0 205437603, not started, process no 6108, OS thread id 192560 
MySQL thread id 127, query id 710940272 localhost web 
---TRANSACTION 0 205443302, not started, process no 2660, OS thread id 139299 
MySQL thread id 72, query id 711527350 localhost web 
---TRANSACTION 0 205443307, not started, process no 10345, OS thread id 221239 
MySQL thread id 195, query id 711527391 localhost web 
---TRANSACTION 0 205443617, not started, process no 11786, OS thread id 237627 
MySQL thread id 184, query id 711527791 localhost web 
---TRANSACTION 0 205443088, not started, process no 11087, OS thread id 229433 
MySQL thread id 175, query id 711527127 localhost web 
---TRANSACTION 0 205443609, not started, process no 10794, OS thread id 225336 
MySQL thread id 169, query id 711527759 localhost web 
---TRANSACTION 0 205443608, not started, process no 9842, OS thread id 217142 
MySQL thread id 159, query id 711527753 localhost web 
---TRANSACTION 0 205443314, not started, process no 9048, OS thread id 213045 
MySQL thread id 154, query id 711527422 localhost web 
---TRANSACTION 0 205442985, not started, process no 8933, OS thread id 208948 
MySQL thread id 149, query id 711526918 localhost web 
---TRANSACTION 0 205443086, not started, process no 3013, OS thread id 151590 
MySQL thread id 137, query id 711527125 localhost web 
---TRANSACTION 0 205443615, not started, process no 6473, OS thread id 196657 
MySQL thread id 132, query id 711527776 localhost web 
---TRANSACTION 0 205443616, not started, process no 4962, OS thread id 176172 
MySQL thread id 107, query id 711527778 localhost web 
---TRANSACTION 0 205441040, not started, process no 3663, OS thread id 159784 
MySQL thread id 87, query id 711441945 localhost web 
---TRANSACTION 0 205443310, not started, process no 2659, OS thread id 135202 
MySQL thread id 71, query id 711527398 localhost web 
---TRANSACTION 0 205443620, not started, process no 2656, OS thread id 122911 
MySQL thread id 68, query id 711527800 localhost web 
---TRANSACTION 0 205443611, not started, process no 2661, OS thread id 143396 
MySQL thread id 73, query id 711527761 localhost web 
---TRANSACTION 0 205443353, not started, process no 2649, OS thread id 106523 
MySQL thread id 64, query id 711527487 localhost web 
---TRANSACTION 0 205441071, not started, process no 1353, OS thread id 36874 
MySQL thread id 48, query id 711527785 localhost web 
---TRANSACTION 0 205442307, ACTIVE 53 sec, process no 4749, OS thread id 618557 
inserting, thread declared inside InnoDB 499 
mysql tables in use 1, locked 1 
2 lock struct(s), heap size 320 
MySQL thread id 439392, query id 711514941 localhost web update 
insert into HL7Live.HCM_ADT values('','STAR_HBO','2004-12-14 
03:14:31','n','A08','MSH:;~\\&:ST01:A:IM:A:20041214031429::ADT;A08:670147:P:2.2:670147::AL:::::::2.2b\rEVN:A08:20041214031429:::LAA\rPID:1::999999;;;ST01A;MR~00999999;;;ST01;PI::DOE;JANE;J;
\"\"::19801028:F::1:534 ROAD CRK;;MELBORN 
---TRANSACTION 0 205437892, ACTIVE 597 sec, process no 21157, OS thread id 1286164 
fetching rows, thread declared inside InnoDB 461 
mysql tables in use 1, locked 0 
MySQL thread id 768008, query id 711106502 localhost web Sending data 
select * from HCM_ADT where status = 'n' order by id 
Trx read view will not see trx with id >= 0 205437893, sees < 0 205128850 
---TRANSACTION 0 205437860, ACTIVE 625 sec, process no 30426, OS thread id 1277970 
updating or deleting, thread declared inside InnoDB 421 
mysql tables in use 1, locked 1 
774 lock struct(s), heap size 44352, undo log entries 9558 
MySQL thread id 781521, query id 711106394 localhost web updating 
DELETE from HCM_ADT where status = 'S' and `time` < '2004-12-11 03:05:00' 
---TRANSACTION 0 205128850, ACTIVE 40736 sec, process no 4162, OS thread id 348185 
fetching rows, thread declared inside InnoDB 461 
mysql tables in use 1, locked 0 
MySQL thread id 132885, query id 681214908 localhost web Sending data 
select * from HCM_ADT where status = 'n' order by id 
Trx read view will not see trx with id >= 0 205128851, sees < 0 205128848 
-------- 
FILE I/O 
-------- 
I/O thread 0 state: waiting for i/o request (insert buffer thread) 
I/O thread 1 state: waiting for i/o request (log thread) 
I/O thread 2 state: waiting for i/o request (read thread) 
I/O thread 3 state: waiting for i/o request (write thread) 
Pending normal aio reads: 0, aio writes: 0, 
 ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0 
Pending flushes (fsync) log: 0; buffer pool: 0 
88495276 OS file reads, 6319815 OS file writes, 5213436 OS fsyncs 
36.62 reads/s, 85135 avg bytes/read, 9.50 writes/s, 8.69 fsyncs/s 
------------------------------------- 
INSERT BUFFER AND ADAPTIVE HASH INDEX 
------------------------------------- 
Ibuf for space 0: size 1, free list len 5, seg size 7, 
457496 inserts, 457496 merged recs, 214392 merges 
Hash table size 415141, used cells 829, node heap has 2 buffer(s) 
13.12 hash searches/s, 4.06 non-hash searches/s 
--- 
LOG 
--- 
Log sequence number 7 3132997185 
Log flushed up to   7 3132997185 
Last checkpoint at  7 3132982017 
0 pending log writes, 0 pending chkp writes 
4929010 log i/o's done, 8.44 log i/o's/second 
---------------------- 
BUFFER POOL AND MEMORY 
---------------------- 
Total memory allocated 138854404; in additional pool allocated 2324480 
Buffer pool size   6400 
Free buffers       1 
Database pages     6395 
Modified db pages  16 
Pending reads 0  
Pending writes: LRU 0, flush list 0, single page 0 
Pages read 812899405, created 117304, written 1801608 
190.30 reads/s, 0.19 creates/s, 1.25 writes/s 
Buffer pool hit rate 974 / 1000 
-------------- 
ROW OPERATIONS 
-------------- 
4 queries inside InnoDB, 0 queries in queue 
Main thread process no. 1351, id 28680, state: sleeping 
Number of rows inserted 1817953, updated 3756807, deleted 1220436, read 1537344437 
0.31 inserts/s, 7.87 updates/s, 0.00 deletes/s, 6405.72 reads/s 
---------------------------- 
END OF INNODB MONITOR OUTPUT 
============================ 
InnoDB: ###### Diagnostic info printed to the standard error stream 
InnoDB: Warning: a long semaphore wait: 
--Thread 1277970 has waited at btr0cur.c line 401 for 627.00 seconds the semaphore: 
X-lock on RW-latch at 0x479ac518 created in file buf0buf.c line 438 
a writer (thread id 1277970) has reserved it in mode  wait exclusive 
number of readers 1, waiters flag 1 
Last time read locked in file ../../innobase/btr/../include/btr0btr.ic line 28 
Last time write locked in file buf0buf.c line 1401 
InnoDB: Error: semaphore wait has lasted > 600 seconds 
InnoDB: We intentionally crash the server, because it appears to be hung. 
041214  3:15:32InnoDB: Assertion failure in thread 24583 in file sync0arr.c line 925 
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. See section 6.1 of 
InnoDB: http://www.innodb.com/ibman.php about forcing recovery. 
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=268435456 
read_buffer_size=1044480 
max_used_connections=56 
max_connections=100 
threads_connected=47 
It is possible that mysqld could use up to  
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 466543 K 
bytes of memory 
Hope that's ok; if not, decrease some variables in the equation. 
 
thd=(nil) 
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=0xbfedf758, backtrace may not be correct. 
Stack range sanity check OK, backtrace follows: 
0x8070740 
0x8247998 
0x81e5f57 
0x80f54b0 
0x824514c 
0x827b17a 
New value of fp=(nil) failed sanity check, terminating stack trace! 
Please read http://www.mysql.com/doc/en/Using_stack_trace.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 
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 don't know how to repeat the bug.

Chad,

this row fetch operation has hung after it latched a buffer pool page to read it:

"
---TRANSACTION 0 205128850, ACTIVE 40736 sec, process no 4162, OS thread id
348185 
fetching rows, thread declared inside InnoDB 461 
mysql tables in use 1, locked 0 
MySQL thread id 132885, query id 681214908 localhost web Sending data 
select * from HCM_ADT where status = 'n' order by id 
Trx read view will not see trx with id >= 0 205128851, sees < 0 205128848 
"

Have you seen other similar crashes?

If the table HCM_ADT is not very big, please run CHECK TABLE on it to check if it is corrupt. Best that you stop all user activity, and run CHECK TABLE in a quiet server.

When the hang occurs, does 'top' show CPU usage at 100 %?

Regards,

Heikki

I ran the CHECK TABLE on HCM_ADT and it came back clean.  When the crash occurred the CPU on top was not at 100%.  It was operating at normal specs. 1.0 or below.

Chad,

thank you for the extra information. No similar bug, a thread hanging in the middle of a buffer pool page access, has been reported from InnoDB in several years.

This may be a bug in Red Hat Linux 9.

I am changing the status of this bug report to 'Can't repeat'. If you experience more problems with mysqld, please add the .err log here for further study.

Regards,

Heikki