MySQL Bugs: #40621: Innodb file locking error on startup

Bug #40621	Innodb file locking error on startup
Submitted:	10 Nov 2008 20:07	Modified:	20 Jul 2010 12:55
Reporter:	matthew schiros	Email Updates:
Status:	Not a Bug	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S1 (Critical)
Version:	5.0.67_1	OS:	FreeBSD (6.2-RELEASE kernel)
Assigned to:		CPU Architecture:	Any
Tags:	file lock, innodb

Description:
After upgrading from 5.0.51a to 5.0.67_1 on a FreeBSD server, InnoDB is no longer able to grab a lock on the file ./ibdata1.  

Here's what the startup looks like in the logs for 5.0.51a:

----5.0.51a log start---
081031 13:19:59  mysqld started
081031 13:20:02  InnoDB: Started; log sequence number 0 37115409
081031 13:20:04 [Note] /usr/local/libexec/mysqld: ready for connections.
Version: '5.0.51a'  socket: '/tmp/mysql.sock'  port: 3306  FreeBSD port: mysql-server-5.0.51a
----5.0.51a log end---

Here's what it looks like in 5.0.67_1

----5.0.67_1 log start---
081106 05:46:37  mysqld started
081106  5:46:37 [Warning] option 'max_join_size': unsigned value 18446744073709551615 adjusted to 4294967295
081106  5:46:37 [Warning] option 'max_join_size': unsigned value 18446744073709551615 adjusted to 4294967295
InnoDB: Unable to lock ./ibdata1, error: 22
081106  5:46:37  InnoDB: Retrying to lock the first data file
InnoDB: Unable to lock ./ibdata1, error: 22
InnoDB: Unable to lock ./ibdata1, error: 22
InnoDB: Unable to lock ./ibdata1, error: 22
InnoDB: Unable to lock ./ibdata1, error: 22
(repeated a lot)....
081106  5:48:17  InnoDB: Unable to open the first data file
InnoDB: Error in opening ./ibdata1
081106  5:48:17  InnoDB: Operating system error number 22 in a file operation.
InnoDB: Error number 22 means 'Invalid argument'.
InnoDB: Some operating system error numbers are described at
InnoDB: http://dev.mysql.com/doc/refman/5.0/en/operating-system-error-codes.html
InnoDB: Could not open or create data files.
InnoDB: If you tried to add new data files, and it failed here,
InnoDB: you should now edit innodb_data_file_path in my.cnf back
InnoDB: to what it was, and remove the new ibdata files InnoDB created
InnoDB: in this failed attempt. InnoDB only wrote those files full of
InnoDB: zeros, but did not yet use them in any way. But be careful: do not
InnoDB: remove old data files which contain your precious data!
081106  5:48:17 [Note] /usr/local/libexec/mysqld: ready for connections.
Version: '5.0.67'  socket: '/tmp/mysql.sock'  port: 3306  FreeBSD port: mysql-server-5.0.67_1
----5.0.67_1 log end---

No config changes occurred during the upgrade process, so the upgrade itself is the only thing I can pinpoint as the potential issue.  I'm able to manually lock, and release the lock of, the ibdata1 file, as well as all other files on the file system.  Blowing away the existing ibdata and ib_logfile* files and restarting the server doesn't resolve the issue either.

How to repeat:
For me, I can repeat this just by starting up mysql.  I don't have another BSD box to test on, so I'm not sure if this is something that's unique to the 5.0.51a -> 5.0.67_1 upgrade process, or a raw install of 5.0.67_1.

Many thanks for writing a bug report.

For making a deeper analysis of your problem I need to know exactly how you installed MySQL and how you upgrade from one version to the other.

Hi,
I initially installed, and then upgraded, via the FreeBSD ports system (databases/mysql50-server).  When I rolled back to 5.0.51a to avoid the problem, I compiled from source.  I haven't tried compiling 5.0.67 from source, because it's a production box, and I don't want to jack customers data on accident.

Let me know if there's any further information I can give you.

Thanks,
Matt

Matthew, somewhat unrelated advice: before upgrading your critical packages (like the database server, web server, mail server etc) you can "pkg_create -b /var/db/pkg/THAT_PACKAGE-1.2.3" which will archive the package in question so that it can be quickly restored if the new version does not work.

This looks related to ``Bug#29155 Innodb "Parallel recovery" is not prevented'' but is probably not because the fix for Bug#29155 went into MySQL 5.0.48.

Has anyone found a solution for this? I have the same problem here:

FreeBSD server.com 6.2-RELEASE-p11 FreeBSD 6.2-RELEASE-p11 #0: Tue Mar 25 11:24:22 UTC 2008     root@server:/usr/obj/usr/src/sys/srv  i386

mysql 5.0.75

Anyone? I had to file a support ticket w/ Cpanel to figure out this was a bug with MySQL. This issue was addressed a while ago! Common...do we have a fix for this?

This also struck us after an a cPanel upgrade. 

MySQL 5.0.77
FreeBSD 6.2-RELEASE

To the others affected by this, how have you worked around it?

We just successfully worked around this today by downgrading MySQL to 5.0.45.

I now speculate this bug is due to different options for threading libraries that are possible to use on FreeBSD. If this happened to us again, I would try adding lines like this to /etc/libmap.conf:

libpthread.so.1 libthr.so.1
libpthread.so.2 libthr.so.2
libkse.so.3 libthr.so.3

Perhaps some adjustments would need to be made here depending on your FreeBSD thread library versions. 

I say this because whatever happened during that upgrade also caused darcs to start segfaulting, also with a lock related error:

Fatal error 'Exceeded maximum lock level' at line 611 in file /usr/src/lib/libpthread/thread/thr_kern.c (errno = 0)

And a libmap.conf update like the above fixed the darcs case.

I got the same bug when upgrading MySQL from 5.0.55 to MySQL 5.0.77 on FreeBSD 7.0-RELEASE i386, such that InnoDB no longer works. The error when starting mysqld is: 

090606 22:39:34 mysqld started
InnoDB: Unable to lock ./ibdata1, error: 22
090606 22:39:34 InnoDB: Retrying to lock the first data file
InnoDB: Unable to lock ./ibdata1, error: 22
InnoDB: Unable to lock ./ibdata1, error: 22
InnoDB: Unable to lock ./ibdata1, error: 22
InnoDB: Unable to lock ./ibdata1, error: 22
090606 22:41:14 InnoDB: Unable to open the first data file
InnoDB: Error in opening ./ibdata1
090606 22:41:14 InnoDB: Operating system error number 22 in a file operation.
InnoDB: Error number 22 means 'Invalid argument'.

upgrading MySQL to 5.0.81 didn't help..

I got the same bug when upgrading MySQL from 5.0.51a to MySQL 5.0.81 on FreeBSD 6.4-RELEASE i386.

Hmmm

I contacted with Cpanel support, they did something on my server (they asked root access) and mysql started to work with innodb correctly.

I don't know that they did exactly.  Supporter said that I had wrong  user permissions at ibdata1 file. But I'm not so stupid and checked this at first, before contacting support.

I saw some commands in the "w" command output while they worked with my server, they did mysql package reinstall and sysctl changes in the  kern.argmax.

Thank you for the feedback.

I can not repeat described behavior with upgrade 5.0.51a->5.0.83. Please try in your environment with current version 5.0.84 and if problem still exists describe how you did upgrade.

Yep, happens in 5.0.51a -> 5.0.84 too.  Same issues, same upgrade method (ports).

Thank you for the feedback.

> Same issues, same upgrade method (ports).

We don't provide ports, so this can be bug in ports. Please try our binaries located at http://dev.mysql.com/downloads to determine if problem exists in our version.

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

The same error popped up two days ago on my server after cPanel upgraded MySQL automatically from 5.0.88 to 5.0.89. I am using FREEBSD 7.0 amd64 (RELEASE) and cPanel/WHM cPanel 11.25.0-R42399. Here is an escerpt from my log file:

100105 03:43:07 mysqld started
100105 3:43:08 [Warning] option 'thread_stack': unsigned value 65536 adjusted to 131072
InnoDB: Unable to lock ./ibdata1, error: 22
100105 3:43:08 InnoDB: Retrying to lock the first data file
InnoDB: Unable to lock ./ibdata1, error: 22
InnoDB: Unable to lock ./ibdata1, error: 22
...
100105 3:44:48 InnoDB: Unable to open the first data file
InnoDB: Error in opening ./ibdata1
100105 3:44:48 InnoDB: Operating system error number 22 in a file operation.
InnoDB: Error number 22 means 'Invalid argument'.
InnoDB: Some operating system error numbers are described at
InnoDB: http://dev.mysql.com/doc/refman/5.0/en/operating-system-error-codes.html
InnoDB: Could not open or create data files.
InnoDB: If you tried to add new data files, and it failed here,
InnoDB: you should now edit innodb_data_file_path in my.cnf back
InnoDB: to what it was, and remove the new ibdata files InnoDB created
InnoDB: in this failed attempt. InnoDB only wrote those files full of
InnoDB: zeros, but did not yet use them in any way. But be careful: do not
InnoDB: remove old data files which contain your precious data!
100105 3:44:48 [Note] /usr/local/libexec/mysqld: ready for connections.
Version: '5.0.89' socket: '/tmp/mysql.sock' port: 3306 FreeBSD port: mysql-server-5.0.89

As of yet no solution exists for this problem. It might not even be a MySQL issue proper since it might come from cPanel. The cPanel support team has been notified; if they are unable to fix the problem, I will try and reinstall MySQL fresh from the port and if that fails I will try directly from the MySQL binaries.

All reporters:

please try our binaries available at http://dev.mysql.com/downloads/mysql/5.0.html#freebsd We don't support FreeBSD ports and this can be separate problem.

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 this problem when trying to enable InnoDB under FreeBSD 7.0-RELEASE with mysql-server-5.0.67_1 (compiled port, not BSD pkg). As recommended, I downloaded current MySQL binaries (mysql-5.1.48-freebsd7.0-i386) and installed (just unpacked everything, set mysql user/group permissions on data dir, and ran mysql_install_db). Running with default vanilla config, everything worked INCLUDING InnoDB ... or, more specifically, it successfully created and initialized all the InnoDB files without the "error 22" problem. Thus, it would seem the problem does indeed come from the port and not MySQL itself.

Thank you for the feedback.

Closing as "Not a Bug" as this seems to be not a bug in MySQL packages/code. If anybody is able to prove opposite feel free to add a comment and reopen the report.