Bug #66841 Server crash after upgrade from 5.5.27 to 5.6.x
Submitted: 17 Sep 2012 8:04 Modified: 12 Oct 2012 11:10
Reporter: Olag Ulga Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server Severity:S2 (Serious)
Version:5.6.6-m9 5.6.7 OS:Windows (Win7x64)
Assigned to: CPU Architecture:Any
Tags: crash upgrade 5.5 5.6

[17 Sep 2012 8:04] Olag Ulga
Description:
Normal Server shutdown on 5.5 upgrade to 5.6 then start after some seconds the server crashes. 

Here the logfile with the last start on 5.5, normal shotdown on 5.5 and the start with 5.6 until the crash:
120917  9:05:17 [Note] Plugin 'FEDERATED' is disabled.
120917  9:05:17 InnoDB: The InnoDB memory heap is disabled
120917  9:05:17 InnoDB: Mutexes and rw_locks use Windows interlocked functions
120917  9:05:17 InnoDB: Compressed tables use zlib 1.2.3
120917  9:05:17 InnoDB: Initializing buffer pool, size = 128.0M
120917  9:05:17 InnoDB: Completed initialization of buffer pool
120917  9:05:17 InnoDB: highest supported file format is Barracuda.
120917  9:06:10  InnoDB: Waiting for the background threads to start
120917  9:06:11 InnoDB: 1.1.8 started; log sequence number 105176037621
120917  9:06:12 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3355
120917  9:06:12 [Note]   - '0.0.0.0' resolves to '0.0.0.0';
120917  9:06:12 [Note] Server socket created on IP: '0.0.0.0'.
120917  9:06:12 [Note] Event Scheduler: Loaded 0 events
120917  9:06:12 [Note] d:\TempMesserli55\bin64\mysqld.exe: ready for connections.
Version: '5.5.27-log'  socket: ''  port: 3355  MySQL Community Server (GPL)
120917  9:06:36 [Note] d:\TempMesserli55\bin64\mysqld.exe: Normal shutdown

120917  9:06:36 [Note] Event Scheduler: Purging the queue. 0 events
120917  9:06:36  InnoDB: Starting shutdown...
120917  9:06:36  InnoDB: Shutdown completed; log sequence number 105176037621
120917  9:06:36 [Note] d:\TempMesserli55\bin64\mysqld.exe: Shutdown complete

120917  9:13:28 [Note] Plugin 'FEDERATED' is disabled.
120917  9:13:28 InnoDB: The InnoDB memory heap is disabled
120917  9:13:28 InnoDB: Mutexes and rw_locks use Windows interlocked functions
120917  9:13:28 InnoDB: Compressed tables use zlib 1.2.3
120917  9:13:28 InnoDB: CPU does not support crc32 instructions
120917  9:13:28 InnoDB: Initializing buffer pool, size = 128.0M
120917  9:13:28 InnoDB: Completed initialization of buffer pool
120917  9:13:28 InnoDB: highest supported file format is Barracuda.
120917  9:14:20 InnoDB: 128 rollback segment(s) are active.
120917  9:14:20 [Note] InnoDB: Creating tablespace and datafile system tables.

120917  9:14:20 [Note] InnoDB: Tablespace and datafile system tables created

120917  9:14:20 InnoDB: Waiting for the background threads to start
120917  9:14:20 InnoDB: 1.2.6 started; log sequence number 105176037621
120917  9:14:20 [Warning] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: 4ce58cd8-0097-11e2-8161-c860005a3177.
120917  9:14:20 [Note] Server hostname (bind-address): '*'; port: 3356
120917  9:14:20 [Note]   - '::' resolves to '::';
120917  9:14:20 [Note] Server socket created on IP: '::'.
<CRASH>

How to repeat:
maybe difficult. tell me if you need more informations

stop 5.5
open my.ini and comment deprecated innodb_additional_mem_pool_size=16M
upgrade to 5.6
start server
CRASH

Suggested fix:
server should be able to start
[17 Sep 2012 8:04] Olag Ulga
server config

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

[17 Sep 2012 8:16] Olag Ulga
Crashreport on ftp named: BUG-66841_AppCrash_mysqld.exe
[17 Sep 2012 8:35] Olag Ulga
Crashreport named: bug-data-66841.zip
[17 Sep 2012 17:46] MySQL Verification Team
Could you please elaborate how you did the upgrade..step by step. Thanks.
[18 Sep 2012 7:55] Olag Ulga
- stop and remove 5.5 service (net stop <servicename> and mysqld.exe --remove <servicename>
- check log that service shutdown was successful
- copy the hole installation from /55/ to /56/ (bins, data, config, etc)
- copy the content of mysql-5.6.6-m9-winx64.zip over the 56 folder (except the data-folder)
- change the following things in my.ini of the 5.6 installation:
* comment depricated setting innodb_additional_mem_pool_size=16M 
* change the datadir to /56/-installation
* change the tmpdir to /56/-installation
* change the port from 3355 to 3356
- install and start the 5.6 service (mysqld.exe --install <servicename> --defaults-file=/56/my.ini then net start <servicename>)
[18 Sep 2012 19:53] Sveta Smirnova
Thank you for the feedback.

Please provide us full error log file. We are interested in <CRASH> part.
[24 Sep 2012 19:56] Olag Ulga
there is no <crash> part. the log ends at the <crash>-tag.
[25 Sep 2012 6:40] Olag Ulga
Debug-Error-Log mysqld-debug.exe --debug

Attachment: werner.err (application/octet-stream, text), 3.31 KiB.

[1 Oct 2012 7:42] Olag Ulga
Same behaviour with 5.6.7
here the debug log:
121001  9:35:29 [Note] Plugin 'FEDERATED' is disabled.
121001  9:35:29 InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
121001  9:35:29 InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!
121001  9:35:29 InnoDB: The InnoDB memory heap is disabled
121001  9:35:29 InnoDB: Mutexes and rw_locks use Windows interlocked functions
121001  9:35:29 InnoDB: Compressed tables use zlib 1.2.3
121001  9:35:29 InnoDB: CPU does not support crc32 instructions
121001  9:35:29 InnoDB: Initializing buffer pool, size = 128.0M
121001  9:35:29 InnoDB: Completed initialization of buffer pool
121001  9:35:29 InnoDB: highest supported file format is Barracuda.
121001  9:36:21 InnoDB: 128 rollback segment(s) are active.
121001  9:36:21 [Note] InnoDB: Creating tablespace and datafile system tables.

121001  9:36:21 [Note] InnoDB: Tablespace and datafile system tables created

121001  9:36:21 InnoDB: Waiting for the background threads to start
121001  9:36:21 InnoDB: 1.2.7 started; log sequence number 105373592927
121001  9:36:21 [Warning] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: b21c6b74-0b9a-11e2-8931-c860005a3177.
121001  9:36:21 [Note] Server hostname (bind-address): '*'; port: 3356
121001  9:36:21 [Note] IPv6 is available.
121001  9:36:21 [Note]   - '::' resolves to '::';
121001  9:36:21 [Note] Server socket created on IP: '::'.
07:36:21 UTC - mysqld got exception 0xc0000005 ;
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=8388608
read_buffer_size=131072
max_used_connections=0
max_threads=200
thread_count=0
connection_count=0
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 87452 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x16fd91e0
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...
13f43b52d    mysqld-debug.exe!Field::val_str()[field.h:634]
13f5a2122    mysqld-debug.exe!get_field()[table.cc:2924]
13f4cf69f    mysqld-debug.exe!acl_load()[sql_acl.cc:1139]
13f4ced30    mysqld-debug.exe!acl_reload()[sql_acl.cc:1547]
13f4ce5a5    mysqld-debug.exe!acl_init()[sql_acl.cc:970]
13f387dbf    mysqld-debug.exe!win_main()[mysqld.cc:5369]
13f38ba67    mysqld-debug.exe!mysql_service()[mysqld.cc:5556]
13f38bef0    mysqld-debug.exe!mysqld_main()[mysqld.cc:5749]
13f381034    mysqld-debug.exe!main()[main.cc:26]
13fe8f6c7    mysqld-debug.exe!__tmainCRTStartup()[crt0.c:266]
13fe8f5ce    mysqld-debug.exe!mainCRTStartup()[crt0.c:182]
76dd652d    kernel32.dll!BaseThreadInitThunk()
76f0c521    ntdll.dll!RtlUserThreadStart()

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0): Connection ID (thread ID): 0
Status: NOT_KILLED

The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
[11 Oct 2012 16:39] Sveta Smirnova
Thank you for the feedback.

Actually acl_* calls are related to privilege handling, not to InnoDB options. Have you run mysql_upgrade after upgrade? If not, please run now. Don't allow other user connections yet.
[12 Oct 2012 11:10] Olag Ulga
Thank you for the hint!

It seems that after the previous upgrade to 5.5 mysql_upgrade.exe was not executed. After mysql_upgrade.exe was executed on the 5.5 installation the upgrade to 5.6 worked well.

This is clearly our fault. Thank you for the support.