Bug #34297 MySQL Server crashes when processing large table
Submitted: 4 Feb 2008 21:17 Modified: 22 May 2008 12:11
Reporter: Louis Breda van Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Compiling Severity:S1 (Critical)
Version:5.1.22, 5.1.23 OS:Microsoft Windows (VISTA 64)
Assigned to: Timothy Smith CPU Architecture:Any
Tags: 64 bit, crash, server, vista64
Triage: D1 (Critical)

[4 Feb 2008 21:17] Louis Breda van
Description:
Hello,

I have MySQL Server 5.1.22 64 bit running here on a VISTA 64 bit system with 8Gbyte of main memory, and it just is NOT stable.

I fact the server passes away when processing a large table under a couple of reproducable circumstances.

Despite this system is a very clean and up to date and stable vista64, I can of course never exclude the option that the problem is not related to MySQL at all but e.g. related to vista or its drivers.

Given that uncertainty it is not yet fair to mark this bug critical.

  

How to repeat:
On my system I did note the following problems:

When processing a large table many table 4,7 mln records 3.5 Gbyte of data.

- odbc error and server passing away when inserting a record
- odbc error and server passing away when opening a connection
- server dies when adding an extra field to the DB using mysql admin
- server dies when doing an optimise using mysql admin
- query browser dies with gmem error c173 when processing a query (bug reported by me under #34262)

In all these situations, there where plenty of system resources (ram) available as far as I can see. 

Suggested fix:
My feeling is that all those problems are related. Perhabs related to memory handling under vista64 especially when the first 4Gbyte are used. Not sure of course.

Louis
[4 Feb 2008 22:17] Sveta Smirnova
Thank you for the report.

Please provide exact error message you get.
[5 Feb 2008 7:46] Louis Breda van
I am terrible sorry, but appart from the problem with the query browser, where I get the gmem error, I do not get the problem error message. The server simply simply quites. I verified that using windows service console.

Of course I get indirect messages as a concequence. Just to give an example of that. I just provoked the problem by trying to add a field to the table with the admin table editor. Very logical ofcourse that the table edditor message is "Lost server connection during table manipulation. Changes will be cancelled and the editor will be closed. Same kind of messages when using odbc to open a connection or to update a record (doing so in a loop, working ok up to the moment te server dies).

So sorry again, I do not have error messages related to the real problem the dying server.

Sincerely,

Louis
[5 Feb 2008 8:00] Valeriy Kravchuk
Please, send/upload entire MySQL server's error log. It is <hostname>.err file usually in data subdirectory.
[5 Feb 2008 8:09] Louis Breda van
Hello Valeriy,

Hereby the error log. Looking at the file I did become the feelding that there is more than the mentioned problem. Threre could be some smaller installer related bugs as well.

Sincerely,

Louis
[8 Feb 2008 14:43] Heikki Tuuri
InnoDB: 1 transaction(s) which must be rolled back or cleaned up
InnoDB: in total 1803 row operations to undo
InnoDB: Trx id counter is 0 8448
080203 21:15:46  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 InnoDB: Error: Memory area size 2048, next area size 0 not a power of 2!
InnoDB: Possibly a memory overrun of the buffer being freed here.

...
InnoDB: Scanning backward trying to find previous allocated mem blocks
Freed mem block at - 1000, file t0mem.c, line 246
Mem block at - 2024, file t0mem.c, line 47
Mem block at - 3048, file t0mem.c, line 47
Mem block at - 4072, file t0mem.c, line 47
Mem block at - 6120, file purge.c, line 177
Mem block at - 6376, file t0mem.c, line 246
Mem block at - 6632, file t0mem.c, line 47
Mem block at - 7144, file purge.c, line 49
Mem block at - 8168, file purge.c, line 177
Mem block at - 10216, file x0trx.c, line 107
InnoDB: Scanning forward trying to find next allocated mem 

There is probably corruption in InnoDB data files that causes InnoDB to corrupt its additional memory pool. This could well be an InnoDB bug.
[8 Feb 2008 15:50] Heikki Tuuri
A probable duplicate:

http://bugs.mysql.com/bug.php?id=34420

This is a serious bug.
[8 Feb 2008 16:17] Heikki Tuuri
Both reports are from a 64-bit Windows.

There was a suspected compiler bug in 64-bit Windows a few years ago.
[8 Feb 2008 16:23] Heikki Tuuri
This is probably the same compiler bug as http://bugs.mysql.com/bug.php?id=19424

The fix is to remove compiler optimizations in the /innobase/mem directory.

MySQL build team, please do so also in 5.1.
[15 Feb 2008 19:03] Louis Breda van
Hello,

I just did a small test with the new 5.1 ODBC and 5.1.23 server release.

Just to be short. Same kind of problem.

Note that this error is a show stopper! Can't use MySQL in the given situation.
Also note that changing the compiler options, is just a workarround IMHO.

Below latest part of my error log (latest lines relaed to install 5.1.23 and the lines related to the real problem.

Sincerely,

Louis

080215 18:38:05 [Note] Event Scheduler: Purging the queue. 0 events
080215 18:38:05  InnoDB: Starting shutdown...
080215 18:38:06  InnoDB: Shutdown completed; log sequence number 4 3086639267
080215 18:38:06 [Note] C:\Program Files\MySQL\MySQL Server 5.1\bin\mysqld: Shutdown complete

080215 18:39:38  InnoDB: Started; log sequence number 4 3086639267
080215 18:39:38 [ERROR] Can't open and lock privilege tables: Table 'mysql.servers' doesn't exist
080215 18:39:38 [Note] Event Scheduler: Loaded 0 events
080215 18:39:38 [Note] C:\Program Files\MySQL\MySQL Server 5.1\bin\mysqld: ready for connections.
Version: '5.1.23-rc-community'  socket: ''  port: 3306  MySQL Community Server (GPL)
InnoDB: Log scan progressed past the checkpoint lsn 4 4255832255
080215 19:51:40  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...
InnoDB: Doing recovery: scanned up to log sequence number 4 4261074944
InnoDB: Doing recovery: scanned up to log sequence number 4 4266317824
InnoDB: Doing recovery: scanned up to log sequence number 4 4271560704
InnoDB: Doing recovery: scanned up to log sequence number 4 4276803584
InnoDB: Doing recovery: scanned up to log sequence number 4 4282046464
InnoDB: Doing recovery: scanned up to log sequence number 4 4287289344
InnoDB: Doing recovery: scanned up to log sequence number 4 4292532224
InnoDB: Doing recovery: scanned up to log sequence number 5 2807808
InnoDB: Doing recovery: scanned up to log sequence number 5 8050688
InnoDB: Doing recovery: scanned up to log sequence number 5 13293568
InnoDB: Doing recovery: scanned up to log sequence number 5 18536448
InnoDB: Doing recovery: scanned up to log sequence number 5 23779328
InnoDB: Doing recovery: scanned up to log sequence number 5 27434929
InnoDB: 1 transaction(s) which must be rolled back or cleaned up
InnoDB: in total 790 row operations to undo
InnoDB: Trx id counter is 0 15104
080215 19:51:46  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 InnoDB: Error: Memory area size 2048, next area size 0 not a power of 2!
InnoDB: Possibly a memory overrun of the buffer being freed here.
InnoDB: Apparent memory corruption: mem dump  len 500; hex 000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000008000000000000000000000000000000000000000000009268a5200000000074306d656d2e63002f0000000000000000000000000000000000000000000000000000000000000078ecc002000000000000000000000000b00400000000000000000000000000000000000000000000d800000000000000700000000000000000000000000000000300010004000000080001000600200078ecc0020000000078fac0020000000000000000000000000000000000008000e800c102000000000000000000000000080010000104004048fac0020000000000000000000000000000000000000000000000000000000000000000000000000000; asc                                                                                                                                                                                                                                                                                   ’h¥     t0mem.c /                               xìÀ             °                       Ø       p                               xìÀ     xúÀ                     è Á                    @HúÀ                                       ;
InnoDB: Scanning backward trying to find previous allocated mem blocks
Freed mem block at - 1000, file t0mem.c, line 246
Mem block at - 2024, file t0mem.c, line 47
Mem block at - 3048, file t0mem.c, line 47
Mem block at - 4072, file t0mem.c, line 47
Mem block at - 6120, file purge.c, line 177
Freed mem block at - 6376, file t0mem.c, line 246
Mem block at - 6632, file t0mem.c, line 47
Mem block at - 7144, file purge.c, line 49
Mem block at - 8168, file purge.c, line 177
Mem block at - 10216, file x0trx.c, line 107
InnoDB: Scanning forward trying to find next allocated mem blocks
Freed mem block at + 24, file t0mem.c, line 47
Freed mem block at + 1048, file t0mem.c, line 246
Freed mem block at + 2072, file t0mem.c, line 246
Freed
[15 Feb 2008 19:03] Louis Breda van
Hello,

I just did a small test with the new 5.1 ODBC and 5.1.23 server release.

Just to be short. Same kind of problem.

Note that this error is a show stopper! Can't use MySQL in the given situation.
Also note that changing the compiler options, is just a workarround IMHO.

Below latest part of my error log (latest lines relaed to install 5.1.23 and the lines related to the real problem.

Sincerely,

Louis

080215 18:38:05 [Note] Event Scheduler: Purging the queue. 0 events
080215 18:38:05  InnoDB: Starting shutdown...
080215 18:38:06  InnoDB: Shutdown completed; log sequence number 4 3086639267
080215 18:38:06 [Note] C:\Program Files\MySQL\MySQL Server 5.1\bin\mysqld: Shutdown complete

080215 18:39:38  InnoDB: Started; log sequence number 4 3086639267
080215 18:39:38 [ERROR] Can't open and lock privilege tables: Table 'mysql.servers' doesn't exist
080215 18:39:38 [Note] Event Scheduler: Loaded 0 events
080215 18:39:38 [Note] C:\Program Files\MySQL\MySQL Server 5.1\bin\mysqld: ready for connections.
Version: '5.1.23-rc-community'  socket: ''  port: 3306  MySQL Community Server (GPL)
InnoDB: Log scan progressed past the checkpoint lsn 4 4255832255
080215 19:51:40  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...
InnoDB: Doing recovery: scanned up to log sequence number 4 4261074944
InnoDB: Doing recovery: scanned up to log sequence number 4 4266317824
InnoDB: Doing recovery: scanned up to log sequence number 4 4271560704
InnoDB: Doing recovery: scanned up to log sequence number 4 4276803584
InnoDB: Doing recovery: scanned up to log sequence number 4 4282046464
InnoDB: Doing recovery: scanned up to log sequence number 4 4287289344
InnoDB: Doing recovery: scanned up to log sequence number 4 4292532224
InnoDB: Doing recovery: scanned up to log sequence number 5 2807808
InnoDB: Doing recovery: scanned up to log sequence number 5 8050688
InnoDB: Doing recovery: scanned up to log sequence number 5 13293568
InnoDB: Doing recovery: scanned up to log sequence number 5 18536448
InnoDB: Doing recovery: scanned up to log sequence number 5 23779328
InnoDB: Doing recovery: scanned up to log sequence number 5 27434929
InnoDB: 1 transaction(s) which must be rolled back or cleaned up
InnoDB: in total 790 row operations to undo
InnoDB: Trx id counter is 0 15104
080215 19:51:46  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 InnoDB: Error: Memory area size 2048, next area size 0 not a power of 2!
InnoDB: Possibly a memory overrun of the buffer being freed here.
InnoDB: Apparent memory corruption: mem dump  len 500; hex 000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000008000000000000000000000000000000000000000000009268a5200000000074306d656d2e63002f0000000000000000000000000000000000000000000000000000000000000078ecc002000000000000000000000000b00400000000000000000000000000000000000000000000d800000000000000700000000000000000000000000000000300010004000000080001000600200078ecc0020000000078fac0020000000000000000000000000000000000008000e800c102000000000000000000000000080010000104004048fac0020000000000000000000000000000000000000000000000000000000000000000000000000000; asc                                                                                                                                                                                                                                                                                   ’h¥     t0mem.c /                               xìÀ             °                       Ø       p                               xìÀ     xúÀ                     è Á                    @HúÀ                                       ;
InnoDB: Scanning backward trying to find previous allocated mem blocks
Freed mem block at - 1000, file t0mem.c, line 246
Mem block at - 2024, file t0mem.c, line 47
Mem block at - 3048, file t0mem.c, line 47
Mem block at - 4072, file t0mem.c, line 47
Mem block at - 6120, file purge.c, line 177
Freed mem block at - 6376, file t0mem.c, line 246
Mem block at - 6632, file t0mem.c, line 47
Mem block at - 7144, file purge.c, line 49
Mem block at - 8168, file purge.c, line 177
Mem block at - 10216, file x0trx.c, line 107
InnoDB: Scanning forward trying to find next allocated mem blocks
Freed mem block at + 24, file t0mem.c, line 47
Freed mem block at + 1048, file t0mem.c, line 246
Freed mem block at + 2072, file t0mem.c, line 246
Freed
[19 Feb 2008 22:00] Randall Chilson
Is it possible to run this under another compiler for Win 64 platforms?  This problem is also a BIG problem here as well.  Any ETA on patch/release of a working version?
[25 Feb 2008 15:57] Randall Chilson
Moved back to 32bit version of 5.1.22 till action on this issue is complete.  Note that to enable larger address space, use the /3GB option in Windows boot.ini.   Bottom line is a need for a STABLE system.
[5 Mar 2008 20:28] Bugs System
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/43487

ChangeSet@1.2543, 2008-03-05 13:27:17-07:00, tsmith@ramayana.hindu.god +1 -0
  Bug #34297: MySQL Server crashes when processing large table
  
  Compiler bug.  Fix is to reduce optimization if the compiler is
  "Visual Studio 8 2005 Win64".  This was already done in 5.0 as a
  fix for Bug 19424.  The present bug is 5.1+ only.
[5 Mar 2008 20:47] Randall Chilson
GREAT News!!

But does this mean there will be a Zip release of the binary install available for this.  We do not compile our own code; only download the zip/install releases.  I understand at this time the status is "Patch pending" so possibly there will be a link to the precompiled update when finished, so sorry for jumping too quick on this if that is the case.

Thank you.  

Randy Chilson
[8 Apr 2008 23: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".
[11 Apr 2008 7:02] Louis Breda van
Hello,

This message is just to keep to bugreport open.
 
I had a temporary fix from MySQL. 
So MySQL is working on this one.
I asume we will se a real fix soon.

Louis
[11 Apr 2008 7:02] Louis Breda van
Hello,

This message is just to keep to bugreport open.
 
I had a temporary fix from MySQL. 
So MySQL is working on this one.
I asume we will se a real fix soon.

Louis
[18 Apr 2008 22:29] Louis Breda van
Hello,

I am running a workarround version of 5.1.23 which bypasses the memory problem.

However, when I saw there was a new version 5.1.23. MySQL is not indicating something about this bug. 

Never the less I decide to try the new release. As could be expected the bug is still there. Have to go back to the patched 5.1.23 version.

Louis
[18 Apr 2008 22:29] Louis Breda van
Hello,

I am running a workarround version of 5.1.23 which bypasses the memory problem.

However, when I saw there was a new version 5.1.23. MySQL is not indicating something about this bug. 

Never the less I decide to try the new release. As could be expected the bug is still there. Have to go back to the patched 5.1.23 version.

Louis
[29 Apr 2008 13:26] Sveta Smirnova
Bug #36390 seems to be duplicate of this one.
[29 Apr 2008 14:23] Heikki Tuuri
Tim, Shane,

can you find out if the fix made it to 5.1.24 64-bit on Windows?

From the comments above I conclude that the bug really is in the compiler, and can be worked around by reducing optimization.

--Heikki
[9 May 2008 6:38] Bugs System
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/46548

ChangeSet@1.2617, 2008-05-09 00:38:17-06:00, tsmith@ramayana.hindu.god +1 -0
  Bug #34297: MySQL Server crashes when processing large table
  
  Remove optimizations on innobase/mem/* to avoid apparent compiler bug which
  causes memory overruns.  See also bug 19424, and probably bug 36366.
  
  This is done in 5.1+; 5.0 already has this workaround in place.
[9 May 2008 6:57] Louis Breda van
Hello,

I am not compiling the DB-sources. I always use the (windows) binary.

So for me the workaround (sorry I do not see this as a real solution) if it appears in the regular binaries. 

Also note that I wonder if 
-	you created a (critical) compiler bugzilla
-	you tried another compiler
-	mysql is using the very latest compiler

Sincerely,

Louis
PS as known the .23 executable I got from MySQL for testing worked for me
[9 May 2008 6:57] Louis Breda van
Hello,

I am not compiling the DB-sources. I always use the (windows) binary.

So for me the workaround (sorry I do not see this as a real solution) if it appears in the regular binaries. 

Also note that I wonder if 
-	you created a (critical) compiler bugzilla
-	you tried another compiler
-	mysql is using the very latest compiler

Sincerely,

Louis
PS as known the .23 executable I got from MySQL for testing worked for me
[12 May 2008 16:02] Miguel Solorzano
Bug: http://bugs.mysql.com/bug.php?id=36366 has been marked as duplicate of this one.
[14 May 2008 15:20] Bugs System
Pushed into 5.1.25-rc
[15 May 2008 1:16] Paul Dubois
Noted in 5.1.25 changelog.

On Windows 64-bit builds, an apparent compiler bug caused memory
overruns for code in innobase/mem/*. Removed optimizations so as not
to trigger this problem. 

Setting report to Patch queued pending push into 6.0.x.
[15 May 2008 15:53] Paul Dubois
Setting report to Need Doc Info pending push into 6.0.x.
[22 May 2008 9:50] Bugs System
Pushed into 6.0.6-alpha
[22 May 2008 12:11] Paul Dubois
Noted in 6.0.6 changelog.