MySQL Bugs: #70867: Wrong OS error number reported in error log during failure at startup

Bug #70867	Wrong OS error number reported in error log during failure at startup
Submitted:	10 Nov 2013 6:17	Modified:	4 Dec 2013 12:30
Reporter:	Justin Swanhart	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Errors	Severity:	S3 (Non-critical)
Version:	5.6.10, 5.5, 5.1(innodb plugin), 5.6.14	OS:	Any
Assigned to:		CPU Architecture:	Any

Description:
Sometimes InnoDB can fail to initialize.  This can happen if you try to start mysql as the wrong username for example:

2013-11-09 18:10:58 7f28cc119740  InnoDB: Operating system error number 13 in a file operation.
InnoDB: The error means mysqld does not have the access rights to
InnoDB: the directory.
2013-11-09 18:10:58 7f28cc119740  InnoDB: File name ./ibdata1
2013-11-09 18:10:58 7f28cc119740  InnoDB: File operation call: 'create' returned OS error 113.
2013-11-09 18:10:58 7f28cc119740  InnoDB: Cannot continue operation.

You will notice that the error is reported properly in the first line:
2013-11-09 18:10:58 7f28cc119740  InnoDB: Operating system error number 13 in a file operation

However, later, this same error is reported as being error 113:
2013-11-09 18:10:58 7f28cc119740  InnoDB: File operation call: 'create' returned OS error 113.

How to repeat:
Change the permissions on a mysql data directory such that the user specified in my.cnf for the mysql daemon is not able to write into the data directory.

Suggested fix:
Report the proper error number in the log.

This appears to have been introduced in the InnoDB plugin.

Hello Justin,

Thank you for the bug report.
Verified as described.

Thanks,
Umesh

// 5.6.15 too affected

2013-11-30 23:10:54 21976 [ERROR] Can't open shared library '/data/ushastry/server/mysql-5.6.15/lib/plugin/authentication_pam.so' (errno: 0 /data/ushastry/server/mysql-5.6.15/lib/plugin/authentication_pam.so: cannot open shared object file: No such file or directory)
2013-11-30 23:10:54 21976 [Note] InnoDB: The InnoDB memory heap is disabled
2013-11-30 23:10:54 21976 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2013-11-30 23:10:54 21976 [Note] InnoDB: Compressed tables use zlib 1.2.3
2013-11-30 23:10:54 21976 [Note] InnoDB: Using Linux native AIO
2013-11-30 23:10:54 21976 [Note] InnoDB: Not using CPU crc32 instructions
2013-11-30 23:10:54 21976 [Note] InnoDB: Initializing buffer pool, size = 1.0G
2013-11-30 23:10:55 21976 [Note] InnoDB: Completed initialization of buffer pool
2013-11-30 23:10:56 7f8ea1356720  InnoDB: Operating system error number 13 in a file operation.
InnoDB: The error means mysqld does not have the access rights to
InnoDB: the directory.
2013-11-30 23:10:56 21976 [ERROR] InnoDB: File /tmp/master_1/ibdata1: 'create' returned OS error 113. Cannot continue operation

Fixed as of 5.6.16, and here's the changelog entry:

 "InnoDB" would report an incorrect operating system error code after
failing to initialize. 

Thank you for the bug report.

5.6$ bzr log -r 5669
------------------------------------------------------------
revno: 5669
committer: Krunal Bauskar krunal.bauskar@oracle.com
branch nick: mysql-5.6
timestamp: Wed 2013-12-04 15:58:27 +0530
message:
  - bug#70867: WRONG OS ERROR NUMBER REPORTED IN ERROR LOG DURING FAILURE AT
    STARTUP
  
    InnoDB has handler to handle some of the common known errors.
    One of such error is ACCESS VIOLATION error which is detected and
    proper notifying error message is printed but it left unmapped to internal
    InnoDB error code that causes caller function to think that error is
    is not from know list and caller try to invoke default error handle
    leading to error-code and message mis-match.
  
    Fixed by ensuring that known ACCESS VIOLATION error is mapped to proper
    InnoDB error code.
  
    Approved by: Kevin (rb#3986)
    (BPS approval by Sveta)