Bug #37391 mysqld should not log scary warning messages when adjusting innodb logfile sizes
Submitted: 13 Jun 2008 9:59 Modified: 13 Jun 2008 10:51
Reporter: Joel Shapiro Email Updates:
Status: Not a Bug Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S3 (Non-critical)
Version:5.0.51a OS:Linux (2.4 kernel)
Assigned to: CPU Architecture:Any
Tags: ib_logfile, innodb, innodb_buffer_pool_size, innodb_log_buffer_size, mysqld, tuning

[13 Jun 2008 9:59] Joel Shapiro
Description:
Suppose I have innodb tuned as follows:

  innodb_buffer_pool_size=500M
  innodb_log_file_size=250M

and I want to downsize my buffer pool and log file sizes, say to

  innodb_buffer_pool_size=400M
  innodb_log_file_size=200M

OK, I follow the instructions at http://dev.mysql.com/doc/refman/5.0/en/adding-and-removing.html :

-I do a shutdown of mysql,
-verify the shutdown was clean and error free (fast shutdown is set to 1)
-edit my.cnf to the 400M and 200M settings
-move data/ib_logfile* to somewhere safe
-restart mysql

After restarting, my logfile has messages about recreating the logfiles, as expected, but then a bunch of scary messages about the server not being shut down properly (it was) and doing crash recovery (why?).  I suppose this is just a symptom of mysqld not finding ib_logfile* and assuming there was a crash, when in fact I moved the ib_logfile on purpose.  But still, in a production system, it is scary to see such warnings . . .

Is there any way to eliminate such scary warnings when somebody purposely removes the ib_logfile* in order to resize them, as prescribed in the mysql doc page referenced above?

I guess this is not so much a bug as a feature request to remove "scary warnings".  Or maybe there is no way to do that, since not finding the ib_logfile* when they got accidentally deleted (real crash) cannot be distinguished from intentionally removing them to resize them?

Here is my my.cnf:

[mysqld]
character_set_server      = utf8
collation_server          = utf8_bin
init-connect='SET NAMES utf8 COLLATE utf8_bin'
socket     = /tmp/mysql1/mysql.sock
port       = 3307
pid-file   = /tmp/mysql1/mysql.pid
datadir    = /tmp/mysql1/data
server-id  = 110101
log-bin    = /tmp/mysql1/log/log-update
log-error  = /tmp/mysql1/log/log-error
tmpdir     = /tmp/mysql1/tmp
max_connections=2000
innodb_data_file_path = ibdata1:1G;ibdata2:100M:autoextend
innodb_buffer_pool_size=500M
innodb_additional_mem_pool_size=32M
innodb_log_file_size=200M
innodb_log_buffer_size=8M

Here is my logfile:

InnoDB: The first specified data file ./ibdata1 did not exist:
InnoDB: a new database to be created!
080613  2:34:00  InnoDB: Setting file ./ibdata1 size to 1024 MB
InnoDB: Database physically writes the file full: wait...
InnoDB: Progress in MB: 100 200 300 400 500 600 700 800 900 1000
080613  2:34:22  InnoDB: Data file ./ibdata2 did not exist: new to be created
080613  2:34:22  InnoDB: Setting file ./ibdata2 size to 100 MB
InnoDB: Database physically writes the file full: wait...
InnoDB: Progress in MB: 100
080613  2:34:25  InnoDB: Log file ./ib_logfile0 did not exist: new to be created
InnoDB: Setting log file ./ib_logfile0 size to 250 MB
InnoDB: Database physically writes the file full: wait...
InnoDB: Progress in MB: 100 200
080613  2:34:30  InnoDB: Log file ./ib_logfile1 did not exist: new to be created
InnoDB: Setting log file ./ib_logfile1 size to 250 MB
InnoDB: Database physically writes the file full: wait...
InnoDB: Progress in MB: 100 200
InnoDB: Doublewrite buffer not found: creating new
InnoDB: Doublewrite buffer created
InnoDB: Creating foreign key constraint system tables
InnoDB: Foreign key constraint system tables created
080613  2:34:35  InnoDB: Started; log sequence number 0 0
080613  2:34:35 [Note] bin/mysqld: ready for connections.
Version: '5.0.51a-log'  socket: '/tmp/mysql1/mysql.sock'  port: 3307  MySQL Community Server (GPL)
080613  2:43:02 [Note] bin/mysqld: Normal shutdown

080613  2:43:02  InnoDB: Starting shutdown...
080613  2:43:03  InnoDB: Shutdown completed; log sequence number 0 43656
080613  2:43:03 [Note] bin/mysqld: Shutdown complete

080613  2:44:19  InnoDB: Log file ./ib_logfile0 did not exist: new to be created
InnoDB: Setting log file ./ib_logfile0 size to 200 MB
InnoDB: Database physically writes the file full: wait...
InnoDB: Progress in MB: 100 200
080613  2:44:23  InnoDB: Log file ./ib_logfile1 did not exist: new to be created
InnoDB: Setting log file ./ib_logfile1 size to 200 MB
InnoDB: Database physically writes the file full: wait...
InnoDB: Progress in MB: 100 200
InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
080613  2:44:27  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...
080613  2:44:27  InnoDB: Started; log sequence number 0 44044
080613  2:44:27 [Note] bin/mysqld: ready for connections.
Version: '5.0.51a-log'  socket: '/tmp/mysql1/mysql.sock'  port: 3307  MySQL Community Server (GPL)

How to repeat:
See description.

Suggested fix:
Remove scary warnings when somebody purposely removes ib_logfile* so they can be resized as per mysql docs . . .
[13 Jun 2008 10:51] Susanne Ebrecht
Many thanks for writing a bug report.

We can't change this warnings.

Software has no artificial intelligence and so the software don't know what you wanted to do.

You removed ib_logfile* from the data directory. 
For the systems this is the same as when the server or the disk crashed. 
The server just can't read these files anymore and that's the reason why it thinks there was a crash or a non proper shutdown before.

It would be fatal to remove this warning because when there is a real crash or non proper shutdown the system would not recognise it.