Bug #67728 Faulting module is killing Mysql 5.5.28.0 on Windows
Submitted: 27 Nov 2012 15:18 Modified: 21 Aug 2014 20:09
Reporter: George Kaz Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Server: Replication Severity:S2 (Serious)
Version:5.5.28 GPL OS:Windows (Server 2003 SE SP2)
Assigned to: CPU Architecture:Any

[27 Nov 2012 15:18] George Kaz
Description:
Eventvwr reports:
Application Error, Event ID 1000

Faulting application mysqld.exe, version 5.5.28.0, faulting module mysqld.exe, 
version 5.5.28.0, fault address 0x000d8d19.

and mysqld.exe which is running as a service dies.

There is nothing reported in the mysql error log until the service is restarted.

121127 14:57:06 [Note] Plugin 'FEDERATED' is disabled.
121127 14:57:06 InnoDB: The InnoDB memory heap is disabled
121127 14:57:06 InnoDB: Mutexes and rw_locks use Windows interlocked functions
121127 14:57:06 InnoDB: Compressed tables use zlib 1.2.3
121127 14:57:07 InnoDB: Initializing buffer pool, size = 350.0M
121127 14:57:07 InnoDB: Completed initialization of buffer pool
121127 14:57:07 InnoDB: highest supported file format is Barracuda.
InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
121127 14:57:07  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...

All our tables are myisam (because innodb is unbelievably slow on Windows)

This server acts as a replication slave. It was recently upgraded to v5.5.28. The master is 5.0.74-enterprise-gpl on Ubuntu 10.04, and there is another Windows slave still running 5.0.74-enterprise-gpl-nt, which has not been crashing.

When the service is started again after a crash, it seems to resume as normal with no persistent error.

How to repeat:
It is a random crash.

Suggested fix:
None yet
[27 Nov 2012 18:07] MySQL Verification Team
Please provide your my.ini file for the slave server (5.5.28). Thanks.
[27 Nov 2012 21:50] George Kaz
File created by crash dump

Attachment: appcompat.txt (text/plain), 23.44 KiB.

[27 Nov 2012 21:50] George Kaz
File created by crash dump

Attachment: manifest.txt (text/plain), 1.65 KiB.

[27 Nov 2012 21:52] George Kaz
my.ini

Attachment: my.ini (application/octet-stream, text), 11.34 KiB.

[27 Nov 2012 21:56] George Kaz
I've also got hdmp and mdmp files but they are around 1.5G. If you want them, I can make them available for you to download.
[22 Dec 2012 11:20] MySQL Verification Team
Hi George,

Please use 7zip or bzip2 to compress the hdmp and mdmp files so we can download them and analyze the crash.   Thanks!
[22 Dec 2012 11:22] MySQL Verification Team
BTW, InnoDB on windows is probably much faster if you run on Vista, Win7, or Win8.
Win2003/XP have disadvantages when it comes to some of the locking primitives used.
[23 Jan 2013 1:00] Bugs System
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".
[29 May 2013 9:49] George Kaz
Sorry, I didn't notice that I'd had a response on this. I've since updated the version to 5.5.29 but the crash still occurs. I've uploaded a recent crash dump to the ftp location.
[29 May 2013 11:20] MySQL Verification Team
Slave I/O thread is crashing while writing an event fro ma 5.0.74 master.

00 ntdll!KiFastSystemCallRet
01 ntdll!NtWaitForSingleObject+0xc
02 kernel32!WaitForSingleObjectEx+0xac
03 kernel32!WaitForSingleObject+0x12
04 faultrep!MyCallNamedPipe+0x15b
05 faultrep!StartManifestReport+0x1d5
06 faultrep!ReportFault+0x3d2
07 kernel32!UnhandledExceptionFilter+0x494
08 kernel32!BaseThreadStart+0x4a
09 kernel32!_except_handler3+0x61
0a ntdll!ExecuteHandler2+0x26
0b ntdll!ExecuteHandler+0x24
0c ntdll!KiUserExceptionDispatcher+0xe
0d mysqld!Format_description_log_event::write+0xa9 [g:\pb2\build\sb_0-7814961-1355120855.15\mysql-5.5.29\sql\log_event.cc @ 4207]
0e mysqld!MYSQL_BIN_LOG::open+0x1e0 [g:\pb2\build\sb_0-7814961-1355120855.15\mysql-5.5.29\sql\log.cc @ 3102]
0f mysqld!MYSQL_BIN_LOG::new_file_impl+0x24c [g:\pb2\build\sb_0-7814961-1355120855.15\mysql-5.5.29\sql\log.cc @ 4327]
10 mysqld!MYSQL_BIN_LOG::new_file_without_locking+0x7 [g:\pb2\build\sb_0-7814961-1355120855.15\mysql-5.5.29\sql\log.cc @ 4209]
11 mysqld!MYSQL_BIN_LOG::appendv+0x78 [g:\pb2\build\sb_0-7814961-1355120855.15\mysql-5.5.29\sql\log.cc @ 4425]
12 mysqld!queue_event+0x467 [g:\pb2\build\sb_0-7814961-1355120855.15\mysql-5.5.29\sql\slave.cc @ 4112]
13 mysqld!handle_slave_io+0x5d2 [g:\pb2\build\sb_0-7814961-1355120855.15\mysql-5.5.29\sql\slave.cc @ 3010]
14 mysqld!pthread_start+0x14 [g:\pb2\build\sb_0-7814961-1355120855.15\mysql-5.5.29\mysys\my_winthread.c @ 61]
15 mysqld!_callthreadstartex+0x1b [f:\dd\vctools\crt_bld\self_x86\crt\src\threadex.c @ 348]
16 mysqld!_threadstartex+0x82 [f:\dd\vctools\crt_bld\self_x86\crt\src\threadex.c @ 326]
17 kernel32!BaseThreadStart+0x34
[30 May 2013 10:22] George Kaz
Thanks for the update. Yes, the situation is we have a linux master (5.0.74 as you pointed out). I had 2 slaves on Win2003 with the same version (5.0.74). We always had performance problems on Windows with innodb, so to see if 5.5 brought any improvements, I installed 5.5 on one of the slaves. No significant improvements were seen, but what with the regular crashes, I held back upgrading the other Windows slave to 5.5 too, and therefore also had to hold back on upgrading the master. Thus the current situation of Master v5.0.74 on Ubuntu 10.04, Slave 1 v5.0.74 on Win2003, Slave 2 v5.5.29 on Win2003.

From what you're saying, an upgrade of the master and other slave to 5.5 might resolve the crashes, but it would be good to address the fault too.
[5 Jun 2013 10:34] MySQL Verification Team
I tried a random DML workload from 5.0.74 -> 5.5.28 but the slave didn't crash.
So we'll either need the offending relay log/binlog and table schema, or you to test 5.5.32 on both master and slave to check if problems still happen there.
[5 Jun 2013 11:38] George Kaz
Most of the time it does run without crashing, otherwise I'd have had to sort this out earlier. But it does probably crash 2 or 3 times a week. I'll try and grab you a relay log. Do you need a full dataset or just table schemas? Dataset it large.
[5 Jun 2013 12:54] MySQL Verification Team
Try running mysqlbinlog against the binlog and relaylog.  If that crashes too, then we need to find what is wrong with the logfile. Maybe master corrupted it. Just schema might be needed in case we want to replay binlog/relay log against it..
[4 Jul 2013 12:24] George Kaz
Hi Shane,

I've just had a crash so have tried to do what you said. As this is on a production machine, I've configured the Windows mysql service to restart when it crashes. It seems that on restart mysql automatically deleted the relay logs prior to the crash, although there are now 2 logs since the restart, one of 1Kb and one that continues to grow.

mysqlbinlog seems to have run fine on both the master and the relay logs I have left, but it's possible that the error is in one of the relay logs that's no longer available.

mysqlbinlog on the 1kb relaylog:

/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#130704 10:58:56 server id 99  end_log_pos 107  Start: binlog v 4, server v 5.5.29-log created 130704 10:58:56
BINLOG '
YEfVUQ9jAAAAZwAAAGsAAAAAAAQANS41LjI5LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAVAAEGggAAAAICAgCAA==
'/*!*/;
# at 107
#130704 10:57:04 server id 7  end_log_pos 1073742028    Rotate to db-7-bin.013061  pos: 4
# at 149
#130704 10:58:56 server id 99  end_log_pos 202  Rotate to CHARTWEB1-relay-bin.014239  pos: 4
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;

At the point the server restarted itself, these lines are in the log:

130704 10:58:56 [Note] Slave I/O thread: connected to master 'replicate@10.0.2.7:3306',replication started in log 'db-7-bin.013060' at position 1073741662
130704 10:58:56 [Note] Slave SQL thread initialized, starting replication in log 'db-7-bin.013060' at position 1071120160, relay log '.\CHARTWEB1-relay-bin.014235' position: 1071120305

I've found the timestamp off position 1071120160 and have output the binlog from a second before that time to the end of the file, which was only 5 seconds later. Shall I upload that to the ftp server?

Thanks
George
[21 Jul 2014 20:09] Sveta Smirnova
Thank you for the feedback.

> I've found the timestamp off position 1071120160 and have output the binlog from a second before that time to the end of the file, which was only 5 seconds later. Shall I upload that to the ftp server?

Yes, please upload if you still have this data.
[22 Aug 2014 1:00] Bugs System
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".