Ubuntu – Why does mariadb keep dying? How to stop it

15.10mariadbMySQLtimeout

I am running MariaDB 10.0.23-0 on Ubuntu 15.10 as a LAMP server. Running sudo /etc/init.d/mysql start results in:

Job for mariadb.service failed because a timeout was exceeded. See "systemctl status mariadb.service" and "journalctl -xe" for details.

The output of systemctl status mariadb.service is:

● mariadb.service - MariaDB database server
   Loaded: loaded (/lib/systemd/system/mariadb.service; enabled; vendor preset: enabled)
  Drop-In: /etc/systemd/system/mariadb.service.d
           └─migrated-from-my.cnf-settings.conf
   Active: failed (Result: timeout) since Sat 2016-03-26 22:52:42 EDT; 26s ago
  Process: 8707 ExecStart=/usr/sbin/mysqld $MYSQLD_OPTS $_WSREP_NEW_CLUSTER (code=exited, status=0/SUCCESS)
  Process: 8706 ExecStartPre=/usr/bin/install -m 755 -o mysql -g root -d /var/run/mysqld (code=exited, status=0/SUCCESS)
 Main PID: 8707 (code=exited, status=0/SUCCESS)

Mar 26 22:52:39 boggan systemd[1]: mariadb.service: Start operation timed out. Terminating.
Mar 26 22:52:39 boggan mysqld[8707]: 2016-03-26 22:52:39 140105856617216 [Note] /usr/sbin/mysqld: Normal shutdown
Mar 26 22:52:39 boggan mysqld[8707]: 2016-03-26 22:52:39 140105856617216 [Note] Event Scheduler: Purging the queue. 0 events
Mar 26 22:52:39 boggan mysqld[8707]: 2016-03-26 22:52:39 140104920164096 [Note] InnoDB: FTS optimize thread exiting.
Mar 26 22:52:39 boggan mysqld[8707]: 2016-03-26 22:52:39 140105856617216 [Note] InnoDB: Starting shutdown...
Mar 26 22:52:42 boggan mysqld[8707]: 2016-03-26 22:52:42 140105856617216 [Note] InnoDB: Shutdown completed; log sequence number 3336953
Mar 26 22:52:42 boggan mysqld[8707]: 2016-03-26 22:52:42 140105856617216 [Note] /usr/sbin/mysqld: Shutdown complete
Mar 26 22:52:42 boggan systemd[1]: Failed to start MariaDB database server.
Mar 26 22:52:42 boggan systemd[1]: mariadb.service: Unit entered failed state.
Mar 26 22:52:42 boggan systemd[1]: mariadb.service: Failed with result 'timeout'`

The first systemd line there is kind of a "well duh". I know it timed out. The second systemd, after the mysqld lines is a bit mystifying, because it does in fact start. An application (OwnCloud, specifically) that depends on the database works normally… for the minute-and-change that MariaDB is up.

Another question suggested using time /etc/init.d/mysql start to determine how long it was taking. I ran it repeatedly to confirm the time – it's a few seconds on either side of 90s each time.

Other research lead me to check file permissions, which are fine… besides, it does start up, temporarily. I've poked and prodded to the best of my (admittedly limited when it comes to Linux) ability, and I haven't made any headway.

So, the question is… How do I get the MariaDB service to stay up?

As an extra wrinkle, after writing this question, I left the machine up and running. I came back to it a week later (I didn't touch it between). Using the exact same command, sudo /etc/init.d/mysql start, was successful. The mysql daemon started and ran; it came back with a an [ ok ] report. I rebooted for experimentation's sake, and I'm back where I started.

In case it matters, the output of journalctl -xe is:

Apr 02 23:51:44 boggan systemd[1]: Stopped Read required files in advance.
-- Subject: Unit ureadahead.service has finished shutting down
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit ureadahead.service has finished shutting down.
Apr 02 23:51:55 boggan mysqld[2645]: 2016-04-02 23:51:55 140386161068800 [Note] InnoDB: Online DDL : Start
Apr 02 23:51:55 boggan mysqld[2645]: 2016-04-02 23:51:55 140386161068800 [Note] InnoDB: Online DDL : Start reading clustered index of the table and create temporary files
Apr 02 23:51:55 boggan mysqld[2645]: 2016-04-02 23:51:55 140386161068800 [Note] InnoDB: Online DDL : End of reading clustered index of the table and create temporary files
Apr 02 23:51:55 boggan mysqld[2645]: 2016-04-02 23:51:55 140386161068800 [Note] InnoDB: Online DDL : Completed
Apr 02 23:51:55 boggan mysqld[2645]: 2016-04-02 23:51:55 140386161068800 [Note] InnoDB: Online DDL : Completed
Apr 02 23:52:06 boggan dbus[713]: [system] Failed to activate service 'org.bluez': timed out
Apr 02 23:52:37 boggan systemd[1]: mariadb.service: Start operation timed out. Terminating.
Apr 02 23:52:37 boggan mysqld[2645]: 2016-04-02 23:52:37 140386097400576 [Note] /usr/sbin/mysqld: Normal shutdown
Apr 02 23:52:37 boggan kernel: audit: type=1400 audit(1459655557.935:31): apparmor="DENIED" operation="sendmsg" profile="/usr/sbin/mysqld" name="/run/systemd/notify" pid=2645 comm="mysqld" requested_mask="w" denied_mask="w" fsuid=122 ouid=0
Apr 02 23:52:37 boggan audit[2645]: AVC apparmor="DENIED" operation="sendmsg" profile="/usr/sbin/mysqld" name="/run/systemd/notify" pid=2645 comm="mysqld" requested_mask="w" denied_mask="w" fsuid=122 ouid=0
Apr 02 23:52:37 boggan mysqld[2645]: 2016-04-02 23:52:37 140386097400576 [Note] Event Scheduler: Purging the queue. 0 events
Apr 02 23:52:37 boggan mysqld[2645]: 2016-04-02 23:52:37 140385225500416 [Note] InnoDB: FTS optimize thread exiting.
Apr 02 23:52:37 boggan mysqld[2645]: 2016-04-02 23:52:37 140386097400576 [Note] InnoDB: Starting shutdown...
Apr 02 23:52:39 boggan mysqld[2645]: 2016-04-02 23:52:39 140386097400576 [Note] InnoDB: Shutdown completed; log sequence number 3360838
Apr 02 23:52:39 boggan mysqld[2645]: 2016-04-02 23:52:39 140386097400576 [Note] /usr/sbin/mysqld: Shutdown complete
Apr 02 23:52:39 boggan kernel: audit: type=1400 audit(1459655559.419:32): apparmor="DENIED" operation="sendmsg" profile="/usr/sbin/mysqld" name="/run/systemd/notify" pid=2877 comm="mysqld" requested_mask="w" denied_mask="w" fsuid=122 ouid=0
Apr 02 23:52:39 boggan audit[2877]: AVC apparmor="DENIED" operation="sendmsg" profile="/usr/sbin/mysqld" name="/run/systemd/notify" pid=2877 comm="mysqld" requested_mask="w" denied_mask="w" fsuid=122 ouid=0
Apr 02 23:52:39 boggan audit[2645]: AVC apparmor="DENIED" operation="sendmsg" profile="/usr/sbin/mysqld" name="/run/systemd/notify" pid=2645 comm="mysqld" requested_mask="w" denied_mask="w" fsuid=122 ouid=0
Apr 02 23:52:39 boggan kernel: audit: type=1400 audit(1459655559.419:33): apparmor="DENIED" operation="sendmsg" profile="/usr/sbin/mysqld" name="/run/systemd/notify" pid=2645 comm="mysqld" requested_mask="w" denied_mask="w" fsuid=122 ouid=0
Apr 02 23:52:39 boggan systemd[1]: Failed to start MariaDB database server.
-- Subject: Unit mariadb.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit mariadb.service has failed.
-- 
-- The result is failed.
Apr 02 23:52:39 boggan systemd[1]: mariadb.service: Unit entered failed state.
Apr 02 23:52:39 boggan systemd[1]: mariadb.service: Failed with result 'timeout'.

Best Answer

I had quite the same issue after upgrading from mysql to mariadb. The strange thing was that service mariadb start failed on timeout (either at system boot or manualy) whereas service mysql start succeded.

The explanation given by T.J.L. is right but the correction didn't work for me.

$ sudo aa-complain /usr/sbin/mysqld
Setting /usr/sbin/mysqld to complain mode.

ERROR: /etc/apparmor.d/usr.sbin.mysqld contains no profile

So I disabled the profile (with aa-disable which seems to be equivalent to plutocrat's solution)

$ sudo aa-disable /usr/sbin/mysqld
Disabling /usr/sbin/mysqld.

I disabled mysqld-akonadi and mysqld-digikam as well.

An apparmor reload was not enough, so I had to reboot and mariadb started perfectly well.