MySQL Bugs: #28805: MySQL Service takes a very long time to start up

Bug #28805	MySQL Service takes a very long time to start up
Submitted:	31 May 2007 12:32	Modified:	15 Jan 2009 8:44
Reporter:	Francisco J. Montes	Email Updates:
Status:	Not a Bug	Impact on me:	None
Category:	MySQL Server	Severity:	S3 (Non-critical)
Version:	4.0.18-nt, 5.0.45	OS:	Windows (Windows Server 2003 R2, Service Pack 1)
Assigned to:		CPU Architecture:	Any
Tags:	windows service startup slow

Description:
After the service has started up (either through the Services control panel or by issuing a "net start mysql" console command) the msqld-nt.exe process starts taking up more and more memory during a variable length of time (15 mins to a whole hour if not more) after the first attempt of connecting to it. During this time:

- The MySQL server does not accept any connections.
- Nothing is written to any of the log files (ie: the .err log) so there is really no way to tell what the process is doing or trying to do while in this state.

The "msqld-nt.exe" process allocated memory eventually reaches a large size (from 30Mb to nearly 90Mb) before suddenly deallocating most of it and staying with around 10MB. It is only at this moment when the MySQL server starts accepting connections. It is only at this point when the following lines are appended to the .err log file:

mysqld-nt: ready for connections.
Version: '4.0.18-nt-log' socket: '' port: 3306

How to repeat:
Our environment:
- MySQL 4.0.18-nt installed and running as a service.
- Windows 2003 Server R2, Standard Edition, Service Pack 1.
This issue is also happening on a different server:
- Windows 2003 Web Edition, Service Pack 1.

Start the service through "net start mysql".

Try to connect with a console window, it will ask for the password (if applicable), the process will hang for a long time (The mysql> prompt won´t show up).

Suggested fix:
Workaround:

Instead of using the MySQL Server as a windows service, starting it from a window console with a command like "mysql-nt --console" skips the large memory allocation and the slow startup period symptoms. It also makes the MySQL server immediately available for connections.

Thank you for a problem report. Do you have any anti-virus software running on the server?

Please, send your my.ini file and entire MySQL error log.

Logs corresponding to a complete startup and shutdown of the service afterwards

Attachment: logs.zip (application/x-zip-compressed, text), 728 bytes.

We do not have antivirus software of any kind installed on the server.

This are the contents of the "My.ini" file that we are using. We disabled the InnoDB engine as we do not need transaction support:

[mysqld]
basedir=C:/Program Files/mysql
datadir=C:/s18web03/data
skip-innodb
long_query_time=5
log-long-format
log-slow-queries
log-bin=binlog
log-warnings
[WinMySQLadmin]
Server=C:/Program Files\mysql\bin\mysqld-nt.exe

I have attached a logs.zip file to the Files section with a set of log files that got generated after a complete startup and shutdown sequence of the MySQL server.

Thank you for the feedback. Could you please provide the output of SC like
showed below to see how the service binary path was installed?

Microsoft Windows [versão 6.0.6000]
Copyright (c) 2006 Microsoft Corporation. Todos os direitos reservados.

c:\>sc qc MySQL
[SC] QueryServiceConfig ÊXITO

NOME_DO_SERVIÇO: MySQL
    TIPO                       : 10  WIN32_OWN_PROCESS
    TIPO_DE_INÍCIO             : 2   AUTO_START
    CONTROLE_DE_ERRO           : 1   NORMAL
    NOME_DO_CAMINHO_BINÁRIO    : "C:\Program Files\MySQL\MySQL Server 5.0\bin\mysqld-nt" --defaults-file="C:\Program Files\MySQL\MySQL Server
 5.0\my.ini" MySQL
    GRUPO_DE_ORDEM_DE_CARREG.  :
    MARCA                      : 0
    NOME_PARA_EXIBIÇÃO         : MySQL
    DEPENDÊNCIAS               :
       NOME_DO_INÍCIO_DO_SERVIÇO  : LocalSystem

c:\>

Thanks in advance.

This is the output obtained after executing "sc qc MySQL":

C:\Documents and Settings\francisco.mont.admin>sc qc MySQL
[SC] QueryServiceConfig SUCCESS

SERVICE_NAME: MySQL
        TYPE               : 10  WIN32_OWN_PROCESS
        START_TYPE         : 2   AUTO_START
        ERROR_CONTROL      : 1   NORMAL
        BINARY_PATH_NAME   : "c:\program files\mysql\bin\mysqld-nt" MySQL
        LOAD_ORDER_GROUP   :
        TAG                : 0
        DISPLAY_NAME       : MySQL
        DEPENDENCIES       :
        SERVICE_START_NAME : LocalSystem

C:\Documents and Settings\francisco.mont.admin>

Thank you for the feedback. Then try the following: open a command prompt
as Admisitrator, go to the bin install directory, stop the service or
shutdown the server if it was started as standalone; remove the service
and then re-install it with the --default-file="path_for_the_my.ini"
and try the server start:

Microsoft Windows [versão 6.0.6000]
Copyright (c) 2006 Microsoft Corporation. Todos os direitos reservados.

C:\Windows\system32>cd\"Arquivos de Programas\MySQL\Mysql Server 5.0\bin"

C:\Arquivos de programas\MySQL\MySQL Server 5.0\bin>net stop MySQL
O serviço de MySQL está sendo finalizado ..
O serviço de MySQL foi finalizado com êxito.

C:\Arquivos de programas\MySQL\MySQL Server 5.0\bin>mysqld-nt --remove MySQL
Service successfully removed.

C:\Arquivos de programas\MySQL\MySQL Server 5.0\bin>mysqld-nt --install MySQL --defaults-file="C:\Arquivos de programas\MySQL\MySQL Server 5.0\my.ini"
Service successfully installed.

C:\Arquivos de programas\MySQL\MySQL Server 5.0\bin>net start MySQL
O serviço de MySQL está sendo iniciado.
O serviço de MySQL foi iniciado com êxito.

C:\Arquivos de programas\MySQL\MySQL Server 5.0\bin>sc qc MySQL
[SC] QueryServiceConfig ÊXITO

NOME_DO_SERVIÇO: MySQL
    TIPO                       : 10  WIN32_OWN_PROCESS
    TIPO_DE_INÍCIO             : 2   AUTO_START
    CONTROLE_DE_ERRO           : 1   NORMAL
    NOME_DO_CAMINHO_BINÁRIO    : "C:\Arquivos de programas\MySQL\MySQL Server 5.0\bin\mysqld-nt" "--defaults-file=C:\Arquivos de programas\My
SQL\MySQL Server 5.0\my.ini" MySQL
    GRUPO_DE_ORDEM_DE_CARREG.  :
    MARCA                      : 0
    NOME_PARA_EXIBIÇÃO         : MySQL
    DEPENDÊNCIAS               :
       NOME_DO_INÍCIO_DO_SERVIÇO  : LocalSystem

C:\Arquivos de programas\MySQL\MySQL Server 5.0\bin>mysql -uroot -P3307
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 2
Server version: 5.0.41-community-nt MySQL Community Edition (GPL)

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> 

Thanks in advance.

Thanks for you reply.

I have followed the procedure suggested this is the console output obtained. Please read the note I appended at the bottom.

C:\Documents and Settings\francisco.mont.admin>net stop MySQL
The MySQL service is stopping.
The MySQL service was stopped successfully.

C:\Documents and Settings\francisco.mont.admin>mysqld-nt --remove MySQL
Service successfully removed.

C:\Documents and Settings\francisco.mont.admin>mysqld-nt --install MySQL --defau
lts-file="C:\WINDOWS\my.ini"
Service successfully installed.

C:\Documents and Settings\francisco.mont.admin>net start MySQL
The MySQL service is starting.
The MySQL service was started successfully.

C:\Documents and Settings\francisco.mont.admin>sc qc MySQL
[SC] QueryServiceConfig SUCCESS

SERVICE_NAME: MySQL
TYPE : 10 WIN32_OWN_PROCESS
START_TYPE : 2 AUTO_START
ERROR_CONTROL : 1 NORMAL
BINARY_PATH_NAME : "c:\program files\mysql\bin\mysqld-nt" --defaults-f
ile=C:\WINDOWS\my.ini MySQL
LOAD_ORDER_GROUP :
TAG : 0
DISPLAY_NAME : MySQL
DEPENDENCIES :
SERVICE_START_NAME : LocalSystem

C:\Documents and Settings\francisco.mont.admin>mysql -u root -p
Enter password: ***********

NOTE: At this point, the console does not repond with the mysql> prompt. It stays like that while the "mysqld-nt" process is taking memory. After a long time the prompt appears and it is only at that moment when the MySQL server starts accepting connections.

Thank you for the feedback. If possible for you to test this behavior with
a newer MySQL version since 4.0.XX is already in the end-life?. Thanks in
advance.

We can´t think of upgrading to a new version of MySQL as it would create quite a bit of hassle at the moment.

Still, we found a new workaround. The MySQL service was running under the local SYSTEM account. We changed it so it now runs from another account specifically created for this service. This account belongs to the local Users group and we gave it specific rights to read and write to and from the MySQL data folder.

After doing that, the service seems to work fine again starting up and accepting connections immediately.

Thank you for the feedback. I understand what you said, however I meant
to try the test with newer version in test environment not to replace
the production one, because if the issue exist with Local System account
which is the default install account is very important to track how it
was affected i.e: That happened after a Windows SP was installed? If
the same version is re-installed after the SP fixes that problem? If
the today released version is affected too?. Thanks in advance.

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".

I had the exact same problem. I fixed it by changing the account (usually the SYSTEM account) the service runs under to another account with sufficient privileges (you can test by changing it to the administrator account). After that the service would start normal.

I had the same problem.

My version is mysql 5.0.45.

OS: Windows Server 2003 

I don't find any release notes include this bug was fixed.

Currently i have installed 5.0.67 for testing, but i got the same result. So i thought 5.0.67 have this issue too.

To the last comment regarding 5.0.67 version: could you please provide your my.ini  
file?. Thanks in advance.

My server have 2G memory.

The following is my my.ini setting.

# MySQL Server Instance Configuration File
# ----------------------------------------------------------------------
# Generated by the MySQL Server Instance Configuration Wizard
#
#
# Installation Instructions
# ----------------------------------------------------------------------
#
# On Linux you can copy this file to /etc/my.cnf to set global options,
# mysql-data-dir/my.cnf to set server-specific options
# (@localstatedir@ for this installation) or to
# ~/.my.cnf to set user-specific options.
#
# On Windows you should keep this file in the installation directory 
# of your server (e.g. C:\Program Files\MySQL\MySQL Server X.Y). To
# make sure the server reads the config file use the startup option 
# "--defaults-file". 
#
# To run run the server from the command line, execute this in a 
# command line shell, e.g.
# mysqld --defaults-file="C:\Program Files\MySQL\MySQL Server X.Y\my.ini"
#
# To install the server as a Windows service manually, execute this in a 
# command line shell, e.g.
# mysqld --install MySQLXY --defaults-file="C:\Program Files\MySQL\MySQL Server X.Y\my.ini"
#
# And then execute this in a command line shell to start the server, e.g.
# net start MySQLXY
#
#
# Guildlines for editing this file
# ----------------------------------------------------------------------
#
# In this file, you can use all long options that the program supports.
# If you want to know the options a program supports, start the program
# with the "--help" option.
#
# More detailed information about the individual options can also be
# found in the manual.
#
#
# CLIENT SECTION
# ----------------------------------------------------------------------
#
# The following options will be read by MySQL client applications.
# Note that only client applications shipped by MySQL are guaranteed
# to read this section. If you want your own MySQL client program to
# honor these values, you need to specify it as an option during the
# MySQL client library initialization.
#
[client]

port=3306

[mysql]

default-character-set=utf8

[mysqld]

port=3306

basedir="D:/MySQL5.0.67/"

datadir="D:/MySQL5.0.67/Data/"

default-character-set=utf8

default-storage-engine=myisam

skip-innodb
skip-locking
skip-bdb

ft_min_word_len=1

sql-mode="STRICT_TRANS_TABLES,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION"

log-slow-queries = D:/MySQL5.0.67/log/SlowSQL.sql
long_query_time = 1
log-long-format

max_connections=512

query_cache_size=384M
query_cache_type = 1

query_cache_limit=1M

wait_timeout = 10
interactive_timeout = 120

table_cache=512

tmp_table_size=128M

thread_concurrency = 4

back_log = 384

max_allowed_packet = 4M

thread_cache_size=32

myisam_max_sort_file_size=100G

myisam_max_extra_sort_file_size=100G

myisam_sort_buffer_size=64M

key_buffer_size=384M

read_buffer_size=2M

read_rnd_buffer_size=32M

join_buffer_size=8M

sort_buffer_size=32M

[mysqldump]
quick
max_allowed_packet = 16M

[mysql]
no-auto-rehash
# Remove the next comment character if you are not familiar with SQL
#safe-updates

[isamchk]
key_buffer = 256M
sort_buffer_size = 256M
read_buffer = 2M
write_buffer = 2M

[myisamchk]
key_buffer = 256M
sort_buffer_size = 256M
read_buffer = 2M
write_buffer = 2M

[mysqlhotcopy]
interactive-timeout

Thanks

My mysql server startup is well before 5 months. When server startup was slow we don't do anything.

I found if mysql start with administrator, the mysql server will intermittence no response(mysql does not accept any connections, about pass 2-20 seconds it will automatic response) and in this time i don't find slow sql by checking slow sql log.

PS. My server OS is windows server 2003 + SP2 + all patch.

Sorry for my english.

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".

Race condition fix in 5.1.31 http://bugs.mysql.com/bug.php?id=20430.

wow!

I have reproduced this issue.

You can reprodurce this issue by installing microsoft .net 2.0 with SP1(In fact you must install .net 2.0 with SP1) in windows server 2003 SP2.

I thought that the .net 2.0 SP1 and the mysql have conflict.

If you just install .net 2.0 it works fine.

"You can reprodurce this issue by installing microsoft .net 2.0 with SP1(In fact you must install .net 2.0 with SP1) in windows server 2003 SP2."

I tried the above and I couldn't repeat.

Hello all.

It is my opinion this is *not* a bug and most of the things written here are in "conspiracy theory" domain.
There is absolutely *nothing* that can link MySQL server service to this or that .NET FW and/or user account type (if it has enough privileges). However, as no MS OS is usable before at least SP1, I deem they changed something other than just FW revision.

What could be relevant is following:

  o Wlad's patch for Bug#20430 which forbids MySQL service entering running state *before* entire start up is finished including possible database recovery and such. This is opposed to prior behavior where "net start" would return in a matter of milliseconds even though databases are nor yet ready.

  o I guess your table engine is doing something in the background causing the delay. It could be InnoDB recovery is running or that InnoDB file(s) is locked by some other process. In that case InnoDB checks it's state only periodically. If I'm correct in my assumptions, <your_host>.err file should contain enough info to get you on top of things.

My environment:

Windows server 2008 + SP2
Mysql 5.0.86

Today my server power failure and Mysql abNormal shutdown then MySQL Service takes a very long time to start up, but if i set mysql service start log on as "administrator" it will immediately start up.

Hello,
i dont know why, but mysql scans the c:/windows/temp directory and the start delays when too many files are in the directory. My problem was that many php session files where in the directory and after deletion the problem was gone.
My system: 
Windows Server 2003
Mysql 5.0.67

hi Dimitrij,

you should create a new directory and set my.ini variable "tmpdir" to point to that directory.  also, disable all antivirus scanners on this directory, since they can interfere with mysqld.

so, this is still not bug, but intended behaviour..

It would be nice if MySQL had notified about this situation in the log, like "Warning, a large amount of files in temp directory is slowing down the start process".
This silly problem gave me a lot of grief, and I had it for months, until I finally found this post, thanks!

I'm new to this forum and adding a comment to an old thread that I hope is not dead.

Trying to figure out a slow startup issue that someone else has come across and fixed. I spent a day looking through google but didn't find anything that exactly matched my issue.

Would someone take a look at my innodb config and log to see what I may be missing that is causing the slow start ups, I'd really appreciate the help.

Thanks! D

I don't think this is a bug but rather a MySQL innodb config issue. Shutdown of the MySQL Instance is fast but start up is extremely slow (40 minutes).

Platform: Windows 2003 Adv Server R2 SP2
MySQL version: 5.5.16

======= LOG START =======
Version: '5.5.16'  socket: ''  port: 3306  MySQL Community Server (GPL)
130302  6:54:45 [Note] C:\mysql\bin\mysqld: Normal shutdown

130302  6:54:45 [Note] Event Scheduler: Purging the queue. 0 events
130302  6:54:45  InnoDB: Starting shutdown...
130302  6:54:47  InnoDB: Shutdown completed; log sequence number 1288078673
130302  6:54:47 [Note] C:\mysql\bin\mysqld: Shutdown complete

130302  7:27:51 [Note] Plugin 'FEDERATED' is disabled.
130302  7:27:52 InnoDB: The InnoDB memory heap is disabled
130302  7:27:52 InnoDB: Mutexes and rw_locks use Windows interlocked functions
130302  7:27:52 InnoDB: Compressed tables use zlib 1.2.3
130302  7:27:53 InnoDB: Initializing buffer pool, size = 512.0M
130302  7:27:54 InnoDB: Completed initialization of buffer pool
130302  7:27:54 InnoDB: highest supported file format is Barracuda.
130302  7:27:58  InnoDB: Waiting for the background threads to start
130302  7:27:59 InnoDB: 1.1.8 started; log sequence number 1288078673
130302  8:05:30 [Note] Event Scheduler: Loaded 0 events
130302  8:05:30 [Note] C:\mysql\bin\mysqld: ready for connections.
Version: '5.5.16'  socket: ''  port: 3306  MySQL Community Server (GPL)
======= LOG END =======

======= MySQL INNODB CONFIG START =======
innodb_adaptive_flushing       : ON
innodb_adaptive_hash_index     : ON
innodb_additional_mem_pool_size: 20971520
innodb_autoextend_increment    : 8
innodb_autoinc_lock_mode       : 1
innodb_buffer_pool_instances   : 1
innodb_buffer_pool_size        : 536870912
innodb_change_buffering        : all
innodb_checksums               : ON
innodb_commit_concurrency      : 0
innodb_concurrency_tickets     : 500
innodb_data_file_path          : ibdata1:2000M;ibdata2:10M:autoextend
innodb_data_home_dir           : C:\mysql\data\
innodb_doublewrite             : ON
innodb_fast_shutdown           : 1
innodb_file_format             : Antelope
innodb_file_format_check       : ON
innodb_file_format_max         : Antelope
innodb_file_per_table          : OFF
innodb_flush_log_at_trx_commit : 1
innodb_flush_method            :
innodb_force_recovery          : 0
innodb_io_capacity             : 200
innodb_large_prefix            : OFF
innodb_lock_wait_timeout       : 50
innodb_locks_unsafe_for_binlog : OFF
innodb_log_buffer_size         : 8388608
innodb_log_file_size           : 134217728
innodb_log_files_in_group      : 2
innodb_log_group_home_dir      : C:\mysql\data\
innodb_max_dirty_pages_pct     : 75
innodb_max_purge_lag           : 0
innodb_mirrored_log_groups     : 1
innodb_old_blocks_pct          : 37
innodb_old_blocks_time         : 0
innodb_open_files              : 300
innodb_purge_batch_size        : 20
innodb_purge_threads           : 0
innodb_random_read_ahead       : OFF
innodb_read_ahead_threshold    : 56
innodb_read_io_threads         : 4
innodb_replication_delay       : 0
innodb_rollback_on_timeout     : OFF
innodb_rollback_segments       : 128
innodb_spin_wait_delay         : 6
innodb_stats_method            : nulls_equal
innodb_stats_on_metadata       : ON
innodb_stats_sample_pages      : 8
innodb_strict_mode             : OFF
innodb_support_xa              : ON
innodb_sync_spin_loops         : 30
innodb_table_locks             : ON
innodb_thread_concurrency      : 0
innodb_thread_sleep_delay      : 10000
innodb_use_native_aio          : ON
innodb_use_sys_malloc          : ON
innodb_version                 : 1.1.8
innodb_write_io_threads        : 4
======= MySQL INNODB CONFIG END =======

Hi David.
You should read the 2nd post above yours, about the c:/windows/temp directory, I am pretty sure your problem is the same, it took my server also around 40-50 minutes to start because of this.

Hi Atanas,

That solved the slow MySQL startup. It took 10 hours to delete all the temporary files from C:\WINDOWS\Temp/. I reconfigured my.ini to point to a dedicate folder C:\mysql\tmp/

Thanks!