[MDEV-4453] Windows service fails with old data Created: 2013-04-29  Updated: 2013-05-01  Resolved: 2013-05-01

Status: Closed
Project: MariaDB Server
Component/s: None
Affects Version/s: 10.0.1, 10.0.2
Fix Version/s: None

Type: Bug Priority: Minor
Reporter: Axel Dörfler (Inactive) Assignee: Vladislav Vaintroub
Resolution: Cannot Reproduce Votes: 0
Labels: None
Environment:

Windows 7 x64


Attachments: File optiplex-ad.err    

 Description   

I've migrated my data from MySQL 5.5 to MariaDB 10.0.1|2 (one after the other) by replacing the data/ directory with the mysql data/ directory, and putting MariaDB's my.ini in there. Launching the service failed with error 1067 on first try (with 10.0.1), and error 1053 (I think) on the second try (with 10.0.2).

I could launch mysqld from the command line without any issues (without admin rights), though, and could then run the mysql_upgrade commmand which successfully converted the databases.

Afterwards, launching the service worked just fine.



 Comments   
Comment by Elena Stepanova [ 2013-04-29 ]

Hi,

Do you still have the error log from the failed start? Could you please send it, along with my.ini file?

Thanks.

Comment by Axel Dörfler (Inactive) [ 2013-04-29 ]

I'm not sure if this error is the one, but the time of the error might match:

InnoDB: Error: log file .\ib_logfile0 is of different size 5242880 bytes
InnoDB: than specified in the .cnf file 52428800 bytes!
130426 13:28:18 [ERROR] Plugin 'InnoDB' init function returned error.
130426 13:28:18 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
130426 13:28:18 [Note] Plugin 'FEEDBACK' is disabled.
130426 13:28:18 [ERROR] Unknown/unsupported storage engine: innodb
130426 13:28:18 [ERROR] Aborting

The my.ini file has not been changed, and came straight from the installer:
[mysqld]
datadir=C:/Program Files/MariaDB 10.0/data
port=3306
sql_mode="STRICT_TRANS_TABLES,NO_ENGINE_SUBSTITUTION"
default_storage_engine=innodb
innodb_buffer_pool_size=1009M
innodb_log_file_size=50M
character-set-server=utf8
[client]
port=3306

Comment by Elena Stepanova [ 2013-04-29 ]

Yes, that's exactly the kind of error which would cause the problem you described.
But then it becomes interesting how it started working. A few more questions, if you don't mind:

  • how did you run mysqld manually? (the full command line; did you provide --defaults-file option or any other options?)
  • what is the current size of C:/Program Files/MariaDB 10.0/data/ib_logfile0 file?
  • could you please quote the full error log starting from your quote above and up to the end (when the service is running normally already)?

Thank you.

Comment by Axel Dörfler (Inactive) [ 2013-04-30 ]

1) I just ran "mysqld" without any options at all.
2) The size of ib_logfile0 now is 5 MB, exactly the same as before with the old data.
3) I've attached the log file.

Comment by Axel Dörfler (Inactive) [ 2013-04-30 ]

Log file containing the error, and possibly startup information afterwards.

Comment by Elena Stepanova [ 2013-04-30 ]

Thanks, it helps to understand the whole story.
It looks like the following has happened:

1) you had a previous installation with innodb_log_file_size 5 Mb (default), so you had corresponding ib_logfile-s in your datadir;
2) you installed the new version, which also has innodb_log_file_size 5 Mb as default, BUT there is a non-default value of 50 Mb in the config file, so the server wouldn't start (that's an ancient InnoDB problem, there are a couple of parameters that cannot be changed just like that); so, the server aborted;
3) you started mysqld manually; as said before, it still has default 5 Mb, and you didn't point it at the config file with 50 Mb value, so it started all right, and you could run mysql_upgrade etc.; BUT it never stopped.
4) so, when you started the service, it tried for a while and then gave up. From all we can see from the log, you are still working on the manually started server.

See here:

That's your manual server went through the startup process and is up and running

130426 13:52:00 [Note] mysqld: ready for connections.
Version: '10.0.2-MariaDB' socket: '' port: 3306 mariadb.org binary distribution

Here you are running a check, or using the server

130426 13:52:32 [ERROR] mysqld: Table '.\mysql\proc' is marked as crashed and should be repaired
130426 13:52:32 [Warning] Checking table: '.\mysql\proc'
130426 13:54:41 [ERROR] mysqld: Table '.\phpmyadmin\pma_recent' is marked as crashed and should be repaired
130426 13:54:41 [Warning] Checking table: '.\phpmyadmin\pma_recent'

And here is another server starts 5 min later. There is no indication that the previous one shut down:

130426 13:59:12 InnoDB: The InnoDB memory heap is disabled
130426 13:59:12 InnoDB: Mutexes and rw_locks use Windows interlocked functions
130426 13:59:12 InnoDB: Compressed tables use zlib 1.2.3
130426 13:59:12 InnoDB: CPU does not support crc32 instructions
130426 13:59:12 InnoDB: Initializing buffer pool, size = 1009.0M
130426 13:59:12 InnoDB: Completed initialization of buffer pool

Of course it could have happened that you terminated it yourself, but the following tells us it's unlikely:

130426 13:59:12 InnoDB: Operating system error number 32 in a file operation.
InnoDB: The error means that another program is using InnoDB's files.
InnoDB: This might be a backup or antivirus software or another instance

So that's the story. To have your service really work, you can do one of two things:
1) modify my.cnf file to remove innodb_log_file_size=50M or to set it back to 5M. It's the simplest way but might be not the best performance-wise;
2) if you want to keep the setting, you'll need to go through the process of "fixing" innodb_log_file_size. It's a bit cumbersome, but doable:
http://www.mysqlperformanceblog.com/2011/07/09/how-to-change-innodb_log_file_size-safely/
http://dev.mysql.com/doc/refman/5.6/en/innodb-data-log-reconfiguration.html
(the latter is the official version, but it doesn't describe the exact process for log files)

Meanwhile, we need to check where the new setting in the config file comes from, it's not particularly user-friendly for sure.

Comment by Vladislav Vaintroub [ 2013-05-01 ]

The story sounds a bit complicated to me and details are left out.

50MB logsize is something that initial installation has done (MariaDB MSI instalation would never create logfile that is 5MB big). How you got your logfile down to 5 MB is a mystery, perhaps you did not copy it , or maybe something else went wrong

Now. to simplify the process of migration, and avoid mistakes while migrating manually, we created a utility mysql_upgrade_service.exe , which makes migration from version X to version Y as simple as

mysql_upgrade_service.exe --service=Name (run this in elevated prompt)

It does change service configuration to new mysqld.exe path (10.0 in your case), and it does run mysql_upgrade as well (compared to your scenario, it does not copy database files around).

It is documented here : https://kb.askmonty.org/en/upgrading-mariadb-on-windows/

I would like to encourage anyone to use automatic migration, e.g with mysql_upgrade_service.exe, and report any errors about it.

Comment by Vladislav Vaintroub [ 2013-05-01 ]

closing as "Can't reproduce", because well, I can't reproduce. Also see the previous note about mysql_upgrade_service.exe

Comment by Elena Stepanova [ 2013-05-01 ]

>> 50MB logsize is something that initial installation has done (MariaDB MSI instalation would never create logfile that is 5MB big).
>> How you got your logfile down to 5 MB is a mystery, perhaps you did not copy it , or maybe something else went wrong

It was a migration from MySQL 5.5 to MariaDB 10.0, so 5 Mb ib_logfiles were created by MySQL, not by MariaDB. Which is quite possible because, again, it's a default value, all that one needed to get it is not have a non-default setting in the config file.
Then when MariaDB 10.0 was installed, with the non-default log file size, the problem happened.

Comment by Axel Dörfler (Inactive) [ 2013-05-01 ]

Elena Stepanova wrote:
"Of course it could have happened that you terminated it yourself, but the following tells us it's unlikely:"

Actually, I manually killed the server I manually started (CTRL-C did have no effect on it). However, for some reason the previous MySQL service was restarted, even though I removed it, and was running from the old config/data directory. The error messages must predate that event. I just can't understand how I missed that restarting MariaDB did not succeed.
In any case, if I run mysqld pointing it to the data/my.ini file, it fails like expected.

My previous installation actually did not run as a Windows service, so I could not use mysql_upgrade_service.exe. Anyway, I've now removed the logfiles manually (using "SET GLOBAL innodb_fast_shutdown = 0"), and starting the service now works as expected.

I would still consider it a bug that InnoDB does not handle this case gracefully, but that's obviously your call. Thanks for the help and explanation!

Generated at Thu Feb 08 06:56:32 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.