Header RSS Feed
 
If you only want to see the articles of a certain category, please click on the desired category below:
ALL Android Backup BSD Database Hacks Hardware Internet Linux Mail MySQL Monitoring Network Personal PHP Proxy Shell Solaris Unix Virtualization VMware Windows Wyse

MySQL InnoDB: Operating system error number 13 in a file operation
Tuesday - Feb 21st 2017 - by - (0 comments)

Got an interesting MySQL error today, after I updated an Ubuntu 14.04 system with apt-get upgrade:

[...]
libwbclient0:amd64 (2:4.3.11+dfsg-0ubuntu0.14.04.4) wird eingerichtet ...
libdbd-mysql-perl (4.025-1ubuntu0.1) wird eingerichtet ...
mysql-client-core-5.5 (5.5.54-0ubuntu0.14.04.1) wird eingerichtet ...
mysql-client-5.5 (5.5.54-0ubuntu0.14.04.1) wird eingerichtet ...
mysql-server-core-5.5 (5.5.54-0ubuntu0.14.04.1) wird eingerichtet ...
mysql-server-5.5 (5.5.54-0ubuntu0.14.04.1) wird eingerichtet ...

Konfigurationsdatei »/etc/apparmor.d/usr.sbin.mysqld«
 ==> Geändert (von Ihnen oder von einem Skript) seit der Installation.
 ==> Paketverteiler hat eine aktualisierte Version herausgegeben.
   Wie möchten Sie vorgehen? Ihre Wahlmöglichkeiten sind:
    Y oder I : Die Version des Paket-Betreuers installieren
    N oder O : Die momentan installierte Version beibehalten
       D     : Die Unterschiede zwischen den Versionen anzeigen
       Z     : Eine Shell starten, um die Situation zu begutachten
 Der Standardweg ist das Beibehalten der momentanen Version.
*** usr.sbin.mysqld (Y/I/N/O/D/Z) [Vorgabe=N] ? D

Konfigurationsdatei »/etc/apparmor.d/usr.sbin.mysqld«
 ==> Geändert (von Ihnen oder von einem Skript) seit der Installation.
 ==> Paketverteiler hat eine aktualisierte Version herausgegeben.
   Wie möchten Sie vorgehen? Ihre Wahlmöglichkeiten sind:
    Y oder I : Die Version des Paket-Betreuers installieren
    N oder O : Die momentan installierte Version beibehalten
       D     : Die Unterschiede zwischen den Versionen anzeigen
       Z     : Eine Shell starten, um die Situation zu begutachten
 Der Standardweg ist das Beibehalten der momentanen Version.
*** usr.sbin.mysqld (Y/I/N/O/D/Z) [Vorgabe=N] ? I
Neue Version der Konfigurationsdatei /etc/apparmor.d/usr.sbin.mysqld wird installiert ...
start: Job failed to start
invoke-rc.d: initscript mysql, action "start" failed.
dpkg: Fehler beim Bearbeiten des Paketes mysql-server-5.5 (--configure):
 Unterprozess installiertes post-installation-Skript gab den Fehlerwert 1 zurück
dpkg: Abhängigkeitsprobleme verhindern Konfiguration von mysql-server:
 mysql-server hängt ab von mysql-server-5.5; aber:
  Paket mysql-server-5.5 ist noch nicht konfiguriert.

dpkg: Fehler beim Bearbeiten des Paketes mysql-server (--configure):
 Abhängigkeitsprobleme - verbleibt unkonfiguriert
mysql-client (5.5.54-0ubuntu0.14.04.1) wird eingerichtet ...
Es wurde kein Apport-Bericht verfasst, da die Fehlermeldung darauf hindeutet, dass dies lediglich ein Folgefehler eines vorherigen Problems ist.
[...]

So MySQL didn't start, that's why apt-get upgrade didn't finish with success. In /var/log/mysql/error I saw the following errors:

170221 14:24:14 [Warning] Using unique option prefix myisam-recover instead of myisam-recover-options is deprecated and will be removed in a future release. Please use the full name instead.
170221 14:24:14 [Note] Plugin 'FEDERATED' is disabled.
/usr/sbin/mysqld: Can't find file: './mysql/plugin.frm' (errno: 13)
170221 14:24:14 [ERROR] Can't open the mysql.plugin table. Please run mysql_upgrade to create it.
170221 14:24:14 InnoDB: The InnoDB memory heap is disabled
170221 14:24:14 InnoDB: Mutexes and rw_locks use GCC atomic builtins
170221 14:24:14 InnoDB: Compressed tables use zlib 1.2.8
170221 14:24:14 InnoDB: Using Linux native AIO
170221 14:24:14 InnoDB: Initializing buffer pool, size = 128.0M
170221 14:24:14 InnoDB: Completed initialization of buffer pool
170221 14:24:14  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.
InnoDB: File name ./ibdata1
InnoDB: File operation call: 'open'.
InnoDB: Cannot continue operation.

dmesg revealed some more information:

[  634.595214] init: mysql respawning too fast, stopped
[  790.457596] audit_printk_skb: 69 callbacks suppressed
[  790.457599] audit: type=1400 audit(1487683611.187:119): apparmor="DENIED" operation="mknod" profile="/usr/sbin/mysqld" name="/db/mysql/app003.lower-test" pid=32765 comm="mysqld" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
[  790.457620] audit: type=1400 audit(1487683611.187:120): apparmor="DENIED" operation="mknod" profile="/usr/sbin/mysqld" name="/db/mysql/app003.lower-test" pid=32765 comm="mysqld" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
[  790.459437] audit: type=1400 audit(1487683611.187:121): apparmor="DENIED" operation="open" profile="/usr/sbin/mysqld" name="/db/mysql/mysql/db.frm" pid=302 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=105 ouid=105
[  790.472090] audit: type=1400 audit(1487683611.199:122): apparmor="DENIED" operation="mknod" profile="/usr/sbin/mysqld" name="/db/mysql/app003.lower-test" pid=315 comm="mysqld" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
[  790.472117] audit: type=1400 audit(1487683611.199:123): apparmor="DENIED" operation="mknod" profile="/usr/sbin/mysqld" name="/db/mysql/app003.lower-test" pid=315 comm="mysqld" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
[  790.486818] audit: type=1400 audit(1487683611.215:124): apparmor="DENIED" operation="open" profile="/usr/sbin/mysqld" name="/db/mysql/ibdata1" pid=315 comm="mysqld" requested_mask="wr" denied_mask="wr" fsuid=105 ouid=105
[  790.610780] audit: type=1400 audit(1487683611.339:125): apparmor="DENIED" operation="mknod" profile="/usr/sbin/mysqld" name="/db/mysql/app003.lower-test" pid=333 comm="mysqld" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
[  790.610820] audit: type=1400 audit(1487683611.339:126): apparmor="DENIED" operation="mknod" profile="/usr/sbin/mysqld" name="/db/mysql/app003.lower-test" pid=333 comm="mysqld" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
[  790.624533] audit: type=1400 audit(1487683611.351:127): apparmor="DENIED" operation="open" profile="/usr/sbin/mysqld" name="/db/mysql/ibdata1" pid=333 comm="mysqld" requested_mask="wr" denied_mask="wr" fsuid=105 ouid=105
[  790.740241] audit: type=1400 audit(1487683611.467:128): apparmor="DENIED" operation="mknod" profile="/usr/sbin/mysqld" name="/db/mysql/app003.lower-test" pid=349 comm="mysqld" requested_mask="c" denied_mask="c" fsuid=0 ouid=0
[  791.175361] init: mysql main process (430) terminated with status 1
[  791.175369] init: mysql main process ended, respawning
[  792.060469] init: mysql post-start process (431) terminated with status 1
[  792.203859] init: mysql main process (475) terminated with status 1
[  792.203867] init: mysql main process ended, respawning
[  793.085085] init: mysql post-start process (476) terminated with status 1
[  793.237776] init: mysql main process (521) terminated with status 1
[  793.237793] init: mysql respawning too fast, stopped

Combine the errors from mysql ("InnoDB: Operating system error number 13 in a file operation.") and dmesg ("apparmor="DENIED" operation="mknod" profile="/usr/sbin/mysqld") and you know where the problem is. During the system patching, a new version of the apparmor rules file was also installed. In most cases this is wanted, as the rule files themselves get patched and fixed from previous bugs.  But on this particular server this was not a wise choice, because - for an unknown reason to me - the admin who installed this system (with German as system language, ugh!) chose /db as path for the MySQL datadir. The Debian/Ubuntu default is of course /var/lib/mysql. Instead of setting /db as datadir and making a new partition on /db, it would have been easier to keep the system defaults and just mount /var/lib/mysql as a separate partition. This would have kept the MySQL installation compatible to future updates.

Because I didn't want apparmor to be running anyway, I stopped and removed apparmor (alternative would have been to edit the apparmor rules file for the MySQL binary). But even after that, MySQL was not able to start. I needed to reboot the server completely in order to get rid of the apparmor security settings. But after the reboot MySQL started correctly again.

 

Add a comment

Show form to leave a comment

Comments (newest first):

No comments yet.

Go to Homepage home
Linux Howtos how to's
Monitoring Plugins monitoring plugins
Links links

Valid HTML 4.01 Transitional
Valid CSS!
[Valid RSS]

7576 Days
until Death of Computers
Why?