Bug 588090 - "Timeout error occurred trying to start MySQL Daemon." - When starting mysqld after increasing innodb_log_file_size
Summary: "Timeout error occurred trying to start MySQL Daemon." - When starting mysqld...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat Enterprise Linux 5
Classification: Red Hat
Component: mysql
Version: 5.0
Hardware: x86_64
OS: Linux
low
medium
Target Milestone: rc
: ---
Assignee: Tom Lane
QA Contact: qe-baseos-daemons
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2010-05-02 15:51 UTC by Ahmed Medhat
Modified: 2013-03-20 09:00 UTC (History)
3 users (show)

Fixed In Version: mysql-5.0.95-2.el5
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2013-03-20 09:00:22 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)

Description Ahmed Medhat 2010-05-02 15:51:24 UTC
Description of problem:

After increasing the innodb_log_file_size value, the mysql-server needs to get stopped and then the log files be removed and then mysql-server be restarted again.

The procedure for deleting the log files is # rm -f /var/lib/mysql/ib_logfile*

When starting mysqld again, it takes time creating the log files which passes the 30secs. timeout statically specified inside /etc/init.d/mysqld with variable name STARTTIMEOUT

After changing this variable to a higher value it started normally.

If this value needs to be change very often, I believe it should be in some /etc/sysconfig/mysqld file.

Monitoring the /var/log/mysqld.log returned the following just from firing up #service mysqld start

#### JUST AFTER STARTING
100502 08:30:51  mysqld started 
100502  8:30:51  InnoDB: Log file ./ib_logfile0 did not exist: new to be created 
InnoDB: Setting log file ./ib_logfile0 size to 256 MB 
InnoDB: Database physically writes the file full: wait... 
InnoDB: Progress in MB: 100 200 

#### A FEW SECONDS AFTER STARTING
100502  8:31:11  InnoDB: Log file ./ib_logfile1 did not exist: new to be created 
InnoDB: Setting log file ./ib_logfile1 size to 256 MB 
InnoDB: Database physically writes the file full: wait... 
InnoDB: Progress in MB: 100 200 

#### JUST AFTER THE TIMEOUT ERROR BY FEW SECONDS
InnoDB: The log sequence number in ibdata files does not match 
InnoDB: the log sequence number in the ib_logfiles! 
100502  8:31:29  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... 
100502  8:31:30  InnoDB: Started; log sequence number 0 220411916 
100502  8:31:30 [Note] /usr/libexec/mysqld: ready for connections. 
Version: '5.0.77'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  Source distribution 


My best bet from the log files, and after checking, the mysqld starts fine even with the error, however did not check all DBs, also another bet is that its an HDD I/O performance issue since the mysqld process expects to write all the log files within the predefined 30 secs. but which I still see low.


Version-Release number of selected component (if applicable):
mysql-server-5.0.77-4.el5_4.2


How reproducible:
Always.


Steps to Reproduce:
1. service mysqld stop
2. increase innodb_log_file_size inside /etc/my.cnf to a great value, ex. 256MB.
3. rm -f /var/lib/mysql/ib_logfile*
4. service mysqld start
 

Actual results:
Timeout error occurred trying to start MySQL Daemon.
Starting MySQL:                                            [FAILED]


Expected results:
Starting MySQL:                                            [  OK  ]


Additional info:
This system is a Xen domU.

Comment 1 Tom Lane 2010-05-02 16:07:29 UTC
The error is only cosmetic, so I can't get too excited about this.

(FWIW, we did increase the timeout to 120 seconds in later versions.)

Comment 2 Ahmed Medhat 2010-05-02 16:25:29 UTC
Glad to hear it, but why make it statically defined in the first place ?

Comment 3 Tom Lane 2010-05-02 16:37:49 UTC
Well, the example you give is a poor argument for making it user-configurable --- by the time the user figures out that he could have changed the timeout, his need will be gone.  It's not like anybody reconfigures such a thing on a routine basis.

Comment 4 Ahmed Medhat 2010-05-02 18:05:01 UTC
Well, I agree its a weak debate but still would confuse someone less experienced sooner or later and takes him time to figure it out.

But the bright side so far, setting the timeout to 120sec. in future releases makes more sense anyway and is enough considering the size of the DBs I am running, actually a value more than 60 fixed my problem while I had DBs with multiple hundred millions records.

Comment 5 Markus Falb 2011-08-05 18:46:07 UTC
(In reply to comment #1)
> The error is only cosmetic, so I can't get too excited about this.

I think it's not only cosmetic because /var/lock/subsys/mysqld will not created.
Consequently the init script is not able to stop, status etc. because it thinks mysqld is not running.

Comment 6 Honza Horak 2013-03-20 09:00:22 UTC
I've realized, that this bug has been fixed as a part of bug #703476, which means the variable is increased to 120 in mysql-5.0.95-2.el5 and later releases. Therefore I'm closing this as CURRENTRELEASE.


Note You need to log in before you can comment on or make changes to this bug.