MySQL Bugs: #31511: MySQL Instance crashes after a long semaphore wait.

Bug #31511	MySQL Instance crashes after a long semaphore wait.
Submitted:	10 Oct 2007 17:55	Modified:	27 Dec 2007 14:45
Reporter:	Marcos Cuadrado	Email Updates:
Status:	No Feedback	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S2 (Serious)
Version:	5.0.37-community-nt	OS:	Windows (XP Professional SP2)
Assigned to:	Assigned Account	CPU Architecture:	Any
Tags:	long, Semaphore, wait

Description:
MySQL Instance crashes after a long semaphore wait.
I'm uploading the .err file with all MySQL debug information.

As I could check in the .err file, the crash happened during the following insertion:

INSERT INTO `Capture`  (`IdSystemFPS`, `Memo`, `InitialTime`) VALUES (3, 'Captura automática', 1190367480)

Here is some information you can use:

 1) The time of the insertion above is "070921 11:38:00" (got from the last field)
 2) There where several thousand uninterrupted insertions in the same table.
    (one per minute within the previous 7 days).
 3) There is a sequence of two related insertions every minute, and the first
    one is the one pasted above: so, there where no insertions within the minute
    previous to the insertion pasted above.

 4) The MySQL server is running correctly since it was restarted.

 5) All insertions are sent from an external C++ aplication that uses:

            LIBRARY		LIBMYSQL
            DESCRIPTION	'MySQL 5.0 Client Library'
            VERSION		6.0

Ask for more information you may need.

How to repeat:
I've been using this MySQL version (or any previous versions) in several servers 
for two years (with high number of transactions) and this is the only time it happened. 
Can't repeat.

.err file with MySQL debug information

Attachment: molde.err (application/octet-stream, text), 82.22 KiB.

More information...
the sequence of every pair of insertions I said above are inside a transaction.
So, every minute I start one transaction, execute the two insertions, and commit.

Thank you for the bug report. Could you please test with latest released
version and if the issue continues are you able to provide the create
tables statements, insert data and the C++ application to test on our
side?. Thanks in advance.

As I said before, this was the only time this error happened, in several
different servers with 5.0.37-community-nt version and some other previous
versions in the last two years: so I can't reproduce the same error.
This bug report is just for helping fix it. As long as this is a low frequent
error, it's not a big deal to me.

I can't send you the C++ application because it needs some particular hardware
and complex configuration.
If it helps, here is the create table statements (just the involved tables):

--
-- Definition of table `systemfps`
--

CREATE TABLE `systemfps` (
  `Id` int(10) unsigned NOT NULL auto_increment,
  `Name` varchar(750) NOT NULL,
  `WatchDogTime` int(10) unsigned NOT NULL,
  `RefreshTime` int(10) unsigned NOT NULL,
  `ConfFPS` longblob,
  `Scheduler` longblob,
  `InsertDBGap` int(10) unsigned NOT NULL,
  `IdPowerPlant` int(10) unsigned NOT NULL,
  PRIMARY KEY  (`Id`),
  UNIQUE KEY `Name` (`Name`),
  KEY `FK_SystemFPS_PowerPlant` (`IdPowerPlant`),
  CONSTRAINT `FK_SystemFPS_PowerPlant` FOREIGN KEY (`IdPowerPlant`) REFERENCES `powerplant` (`Id`) ON DELETE CASCADE ON UPDATE CASCADE
) ENGINE=InnoDB DEFAULT CHARSET=latin1;

--
-- Definition of table `source`
--

CREATE TABLE `source` (
  `Id` int(10) unsigned NOT NULL auto_increment,
  `IdSystemFPS` int(10) unsigned NOT NULL,
  `Name` varchar(750) NOT NULL,
  PRIMARY KEY  (`Id`),
  KEY `FK_Source_SystemFPS` (`IdSystemFPS`),
  CONSTRAINT `FK_Source_SystemFPS` FOREIGN KEY (`IdSystemFPS`) REFERENCES `systemfps` (`Id`) ON DELETE CASCADE ON UPDATE CASCADE
) ENGINE=InnoDB DEFAULT CHARSET=latin1;

--
-- Definition of table `capture`
--

CREATE TABLE `capture` (
  `Id` int(10) unsigned NOT NULL auto_increment,
  `IdSystemFPS` int(10) unsigned NOT NULL,
  `Memo` varchar(32768) default NULL,
  `InitialTime` int(10) unsigned NOT NULL,
  PRIMARY KEY  (`Id`),
  KEY `FK_Capture_SystemFPS` (`IdSystemFPS`),
  KEY `IndexInitialTime` (`InitialTime`),
  CONSTRAINT `FK_Capture_SystemFPS` FOREIGN KEY (`IdSystemFPS`) REFERENCES `systemfps` (`Id`) ON DELETE CASCADE ON UPDATE CASCADE
) ENGINE=InnoDB DEFAULT CHARSET=latin1;

--
-- Definition of table `capturedata`
--

CREATE TABLE `capturedata` (
  `Id` int(10) unsigned NOT NULL auto_increment,
  `IdCapture` int(10) unsigned NOT NULL,
  `IdSource` int(10) unsigned NOT NULL,
  `Data` longblob,
  PRIMARY KEY  (`Id`),
  KEY `FK_CaptureData_Capture` (`IdCapture`),
  KEY `FK_CaptureData_Source` (`IdSource`),
  CONSTRAINT `FK_CaptureData_Capture` FOREIGN KEY (`IdCapture`) REFERENCES `capture` (`Id`) ON DELETE CASCADE ON UPDATE CASCADE,
  CONSTRAINT `FK_CaptureData_Source` FOREIGN KEY (`IdSource`) REFERENCES `source` (`Id`)
) ENGINE=InnoDB DEFAULT CHARSET=latin1;

Assigning to Inaam.

Marcos,

The problem is with the IO subsystem. The .err log shows that InnoDB has submitted 32 write requests (asynchronously) and apparently those were enqueued without any errors (since no error to that effect shows up in the .err). But none of these requests was returned as completed by the OS.

I/O thread 0 state: wait Windows aio (insert buffer thread)

I/O thread 1 state: wait Windows aio (log thread)

I/O thread 2 state: wait Windows aio (read thread)

I/O thread 3 state: wait Windows aio (write thread)

Pending normal aio reads: 0, aio writes: 32,

 ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0

Pending flushes (fsync) log: 0; buffer pool: 0

2579214 OS file reads, 3130412 OS file writes, 196723 OS fsyncs

0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s

OS file writes remains pretty constant throughout and the pending aio writes stays at 32.

What type of IO subsystem you are using? Have you noticed anything unusual at IO/OS/hardware level when these waits happened? You mentioned some special hardware for your application. Any known issues with this hardware regarding IO?

regards,
inaam

No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".

This could be a duplicate of Bug #59733. Without having the stack traces of all threads during the hang or crash, it is impossible to tell.