MySQL Bugs: #56821: Failure to start the MySQL Service

Bug #56821	Failure to start the MySQL Service
Submitted:	16 Sep 2010 16:03	Modified:	13 Nov 2010 2:18
Reporter:	Victor Kirkebo	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server	Severity:	S3 (Non-critical)
Version:	5.1.51, 5.5.7, 5.6.1	OS:	Windows (Any)
Assigned to:	Dmitry Shulga	CPU Architecture:	Any
Tags:	regression

Description:
The server fails to start as a service during instance configuration/startup on Processing configuration/Start service step

This is not happening with 5.1.50, only with 5.1.51
The new version of Config Wizard might be the cause (1.0.17.0 in 5.1.51 vs 1.0.16.0 in 5.1.50). In the Event Viewer there are errors related to the InnoDB Plugin. Maybe the Config Wizard has undergone changes to take care of InnoDB as the default engine in 5.5.x.

How to repeat:
- install server from an msi package (Typical setup is enough);
- run Config Wizard;
- accept all defaults in Config Wizard
- when service fails to start: see the Application errors in the Event Viewer:
From Event Viewer:
------------------
Plugin 'InnoDB' init function returned error.
Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
Unknown/unsupported table type: INNODB

Thank you for the report.

This reminds me one of older bugs. Please send us your configuration file.

Bug #42820 I was told of.

Looks like the Event Viewer didn't show one error message. In the .err file there is also this message: InnoDB: Error: log file .\ib_logfile0 is of different size 0 77594624 bytes
InnoDB: than specified in the .cnf file 0 10485760 bytes!

I did a fresh install with 5.1.51 and picked only default options in the Config Wizard. ib_logfile0 and ib_logfile1 were created with size 74M while the config file specified innodb_log_file_size=10M

I did another fresh install with 5.1.50 which has the previous version of Config Wizard. This time ib_logfile0 and ib_logfile1 were created with size 10M and the service started.

With 5.1.51 I also tried to set the database usage in the Config Wizard to "Transactional Database Only" instead of the default "Multifunctional Database". This time ib_logfile0 and ib_logfile1 were created with size 10M. The strange thing was that the Service still failed to start. This time there were no error messages in the .err file. The Event Viewer only showed one error message saying "Aborting".

Configuration file (with default values chosen in Config Wizard)

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

I did another fresh install with 5.1.51. As before the service did not start. I tried to start the MySQL service manually with the Start/Administrative/Services tool. Again it failed. I then removed the 5.1.51 mysqld.exe and copied over mysqld.exe from 5.1.50 instead. This time I could start the MySQL service manually without problems. Maybe there is something new in mysqld version 5.1.51 that is causing it to not start.
BTW: The error message is : Error 1067 : The process terminated unexpectedly

Just to clarify:
It is only the notes from 17 Sep 10:54 and onwards that apply to this particular bug report. Initially I did the mistake of not manually deleting an existing datadir with logfiles with sizes different than 10M before doing the new installation. I have created a new bug report bug #56851 where I request the Config Wizard to handle this in a more user-friendly manner for any MySQL version.
Back to this bug report (#56821): for 5.1.51 I am not able to install the MySQL service even if I do make sure that I choose a brand new location for the datadir. The error log is empty. The event log only says 'Aborting'.

The error log might be the root cause of the problem. 

I can imitate the same error on Server 2008 while starting mysqld from the command line when the error file already existed but the user was not its owner.

However, when server is started as a service, the error happens even if the file did not exist -- it is created, but nothing is written into it.

It is not limited to running server as SYSTEM user -- re-assigning it to a local user does not help.

If I add 'console' option to the ini file, so error log is not written, the service starts properly.

There was a fix bug#29751 in this release, could be related?

Bug for Config Wizard: bug #56851

Hello Dmitry, could you please take a look at it?

I guess the reopen_ routine  could have missed the case where fileno(stdout) or fileno(stderr) is be -1, which according to some internet search is what one would see on Windows in service. In this case, I'd guess just a normal freopen()
can be done , fileno() would be different from -1 next time around.

Actually, I fail to understand how it can fail in 5.1 and work in 5.5.6 (which I just downloaded and installed amd service has started and .err file is written)

According to bug #29751 the patch was pushed into 5.5.7. I just ran two tests: 5.5.7 failed to start as a Windows service while 5.5.6 succeeded.

This also fails with 5.6.1.

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/118771

3514 Dmitry Shulga	2010-09-22
      Fixed bug#56821 - failure to start the MySQL Service.
     @ sql/log.cc
        reopen_fstreams modified: fixed error in processing of
        stdout/stderr when run mysqld as Windows service.

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/118772

3514 Dmitry Shulga	2010-09-22
      Fixed bug#56821 - failure to start the MySQL Service.
     @ sql/log.cc
        reopen_fstreams modified: fixed error in processing of
        stdout/stderr when run mysqld as Windows service.

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/118787

3515 Dmitry Shulga	2010-09-22
      Fixed bug#56821 - failure to start the MySQL Service.
     @ sql/log.cc
        reopen_fstreams modified: fixed error in processing of
        stdout/stderr when run mysqld as Windows service.

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/118817

3515 Dmitry Shulga	2010-09-22
      Fixed bug#56821 - failure to start the MySQL Service.
     @ sql/log.cc
        reopen_fstreams modified: fixed error in processing of
        stdout/stderr when run mysqld as Windows service.

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/118824

3211 Dmitry Shulga	2010-09-22 [merge]
      Auto-merge from mysql-5.1-bugteam for bug#56821.

Pushed to mysql-5.1-bugteam. Merged and pushed to mysql-5.5-merge.

Pushed into mysql-trunk 5.6.1-m4 (revid:alik@sun.com-20100928153607-tdsxkdm5cmuym5sq) (version source revid:alik@sun.com-20100928153508-0saa6v93dinqx1u7) (merge vers: 5.6.1-m4) (pib:21)

Pushed into mysql-next-mr (revid:alik@sun.com-20100928153646-pqp8o1a92mxtuj3h) (version source revid:alik@sun.com-20100928153532-lr3gtvnyp2en4y75) (pib:21)

Pushed into mysql-5.5 5.5.7-rc (revid:alik@sun.com-20100928153459-4nudf4zgzlou4s7q) (version source revid:alik@sun.com-20100928153459-4nudf4zgzlou4s7q) (merge vers: 5.5.7-rc) (pib:21)

Pushed into mysql-5.1 5.1.53 (revid:build@mysql.com-20101101184443-o2olipi8vkaxzsqk) (version source revid:build@mysql.com-20101101184443-o2olipi8vkaxzsqk) (merge vers: 5.1.53) (pib:21)

Noted in 5.1.52, 5.1.57, 5.6.1 changelogs.

When mysqld was started as a service on Windows and mysqld was
writing the error log to a file (for example, if it was started with
the --log-error option), the server reassigned the file descriptors
of the stdout and stderr streams to the file descriptor of the log
file. On Windows, if stdout or stderr is not associated with an
output stream, the file descriptor returns a negative value.
Previously, this would cause the file descriptor reassignment to fail
and the server to abort. To avoid this problem on Windows, stdout and
stderr streams are now first assigned to the log file stream by 
opening this file. This causes stdout and stderr file descriptors to
be nonzero and the server can successfully reassign them to the file
descriptor of the log file.

Just installed MySQL 5.5.8 GA.  Experienced the exact same problem with same three messages in Windows event log.

Hi Chris,
Maybe bug#56851 is the problem?
The Config Wizard generates my.ini with default setting innodb_log_file_size=10M.
This will cause a problem if the Wizard is used to select an existing datadir from a previously installed database where ib_logfile0 has a size different from 10M. You will see an error message in the .err file similar to this: InnoDB: Error: log file .\ib_logfile0 is of different size 0 20971520 bytes than specified in the .cnf file 0 10485760 bytes!
(Please note that .cnf here actually refers to .ini since we're running on Windows)

Hi, Victor:
You are right it was collision with the ib_logfile files in the C:\Users\All Users\MySQL Server 5.5\data directory.  I figured it out from the posts in your thread plus another one I found on mysql.com.  I had previously installed MySQL 5.5.6 RC2, and did not realize the use of the shared directory.  By uninstalling, and manually cleaning out the above named directory before re-installing, the problem went away.

I have used MySQL for many years, and installed it many, many, times, and had not run into this before.  This is the first time I was even aware of the shared data directory usage in C:\Users (C:\Documents and Settings in older versions of Windows.)

I have this immediate problem resolved, but I foresee bigger issues down the road as I find it necessary to run multiple versions of MySQL server frequently.  It's how I migrate production environments to newer versions of the server.  It has not been a problem in the past as I simply install in a different executable directory using a different data directory and a different TCP port.  Now there is a collision on installing multiple versions due to the shared directory.  I also don't like having that shared directory with log files in it in C:\Users as I often setup servers with SSD boot drives and like to keep the contents as static as possible.

Is there a way to move the directory an instance of MySQL expects the .err, .pid, ib_logfile0, ib_logfile1, etc., files install into and operate out of?

Nevermind, Victor, I discovered that it's just more silliness with the installation software.  While it prompts you to enter a data directory, it still creates the data directory in the shared application data on the Windows root disk and leaves the .ini file pointing at it.  I manually fixed up my.ini, and copied the contents of the shared data directory over to the location I wanted, and things are as before.

Sever still works the same graceful way with mutliple versions installed, the installation applet is just weak.

See bug #59341

For what it is worth, this type of errors will be fixed in MySQL 5.6.8:

InnoDB: Error: log file .\ib_logfile0 is of different size 0 36700160 bytes
InnoDB: than specified in the .cnf file 0 10485760 bytes!

In the case of a size mismatch, we would apply the old logs and then rewrite new ones. Also, with this change, the log file creation and database startup should be more crash-safe. Previously, if mysqld was killed while it was creating the files, it would not recover, and you would have to delete all files before restarting.