Mysql – MariaDB doesn’t start after upgrade from MySQL 5.7

mariadbMySQL

I installed MariaDB server, my MySQL got removed automatically and I tried to get it running using sudo service mysql start, which caused the following error message:

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

Systemctl status mariadb.service answered me:

● mariadb.service - MariaDB database server
   Loaded: loaded (/lib/systemd/system/mariadb.service; enabled; vendor preset: enabled)
   Active: failed (Result: timeout) since Thu 2018-08-02 22:28:04 CEST; 10min ago
  Process: 10343 ExecStart=/usr/sbin/mysqld $MYSQLD_OPTS $_WSREP_NEW_CLUSTER $_WSREP_START_POSITION (code=exited, status=0/SUCCESS)
  Process: 10256 ExecStartPre=/bin/sh -c [ ! -e /usr/bin/galera_recovery ] && VAR= ||   VAR=`/usr/bin/galera_recovery`; [ $? -eq 0 ]   && systemctl set-environment _WSREP_START_POSITION=$VAR || exit 1 (co
  Process: 10252 ExecStartPre=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/SUCCESS)
  Process: 10247 ExecStartPre=/usr/bin/install -m 755 -o mysql -g root -d /var/run/mysqld (code=exited, status=0/SUCCESS)
 Main PID: 10343 (code=exited, status=0/SUCCESS)

Aug 02 22:26:31 example.com systemd[1]: Starting MariaDB database server...
Aug 02 22:26:32 example.com mysqld[10343]: 2018-08-02 22:26:32 140165196823680 [Note] /usr/sbin/mysqld (mysqld 10.1.29-MariaDB-6) starting as process 10343 ...
Aug 02 22:28:02 example.com systemd[1]: mariadb.service: Start operation timed out. Terminating.
Aug 02 22:28:04 example.com systemd[1]: mariadb.service: Failed with result 'timeout'.
Aug 02 22:28:04 example.com systemd[1]: Failed to start MariaDB database server.

Journalctl on the other hand specified it more detailled as a authentication error, as far as I can read it out:

$ journalctl -xe
Aug 02 22:16:51 example.com sudo[10011]: pam_unix(sudo:session): session opened for user root by nekura(uid=0)
Aug 02 22:16:53 example.com systemd[1]: Starting MariaDB database server...
-- Subject: Unit mariadb.service has begun start-up
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
-- 
-- Unit mariadb.service has begun starting up.
Aug 02 22:16:53 example.com mysqld[10139]: 2018-08-02 22:16:53 139725684759680 [Note] /usr/sbin/mysqld (mysqld 10.1.29-MariaDB-6) starting as process 10139 ...
Aug 02 22:16:53 example.com audit[10139]: AVC apparmor="DENIED" operation="sendmsg" info="Failed name lookup - disconnected path" error=-13 profile="/usr/sbin/mysqld" name="run/systemd/notify" pid=
Aug 02 22:16:53 example.com kernel: audit: type=1400 audit(1533241013.968:40): apparmor="DENIED" operation="sendmsg" info="Failed name lookup - disconnected path" error=-13 profile="/usr/sbin/mysql
Aug 02 22:16:56 example.com dhclient[943]: DHCPREQUEST of 123.123.123.123 on ens3 to 255.255.255.255 port 67 (xid=0x5ab749b3)
Aug 02 22:17:01 example.com CRON[10167]: pam_unix(cron:session): session opened for user root by (uid=0)
Aug 02 22:17:01 example.com CRON[10168]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Aug 02 22:17:01 example.com CRON[10167]: pam_unix(cron:session): session closed for user root
Aug 02 22:17:04 example.com dhclient[943]: DHCPREQUEST of 123.123.123.123 on ens3 to 255.255.255.255 port 67 (xid=0x5ab749b3)
Aug 02 22:17:18 example.com dhclient[943]: DHCPREQUEST of 123.123.123.123 on ens3 to 255.255.255.255 port 67 (xid=0x5ab749b3)
Aug 02 22:17:39 example.com dhclient[943]: DHCPREQUEST of 123.123.123.123 on ens3 to 255.255.255.255 port 67 (xid=0x5ab749b3)
Aug 02 22:17:47 example.com dhclient[943]: DHCPREQUEST of 123.123.123.123 on ens3 to 255.255.255.255 port 67 (xid=0x5ab749b3)
Aug 02 22:17:52 example.com sshd[10170]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=182.100.67.106  user=root
Aug 02 22:17:55 example.com sshd[10170]: Failed password for root from 182.100.67.106 port 56800 ssh2
Aug 02 22:17:58 example.com dhclient[943]: DHCPREQUEST of 123.123.123.123 on ens3 to 255.255.255.255 port 67 (xid=0x5ab749b3)
Aug 02 22:18:06 example.com dhclient[943]: DHCPREQUEST of 123.123.123.123 on ens3 to 255.255.255.255 port 67 (xid=0x5ab749b3)
Aug 02 22:18:08 example.com sshd[10170]: Failed password for root from 182.100.67.106 port 56800 ssh2
Aug 02 22:18:15 example.com dhclient[943]: DHCPREQUEST of 123.123.123.123 on ens3 to 255.255.255.255 port 67 (xid=0x5ab749b3)
Aug 02 22:18:16 example.com sshd[10170]: Failed password for root from 182.100.67.106 port 56800 ssh2
Aug 02 22:18:16 example.com sshd[10170]: Received disconnect from 182.100.67.106 port 56800:11:  [preauth]
Aug 02 22:18:16 example.com sshd[10170]: Disconnected from authenticating user root 182.100.67.106 port 56800 [preauth]
Aug 02 22:18:16 example.com sshd[10170]: PAM 2 more authentication failures; logname= uid=0 euid=0 tty=ssh ruser= rhost=182.100.67.106  user=root
Aug 02 22:18:23 example.com systemd[1]: mariadb.service: Start operation timed out. Terminating.
Aug 02 22:18:23 example.com kernel: audit: type=1400 audit(1533241103.679:41): apparmor="DENIED" operation="sendmsg" info="Failed name lookup - disconnected path" error=-13 profile="/usr/sbin/mysql
Aug 02 22:18:23 example.com audit[10139]: AVC apparmor="DENIED" operation="sendmsg" info="Failed name lookup - disconnected path" error=-13 profile="/usr/sbin/mysqld" name="run/systemd/notify" pid=
Aug 02 22:18:25 example.com audit[10139]: AVC apparmor="DENIED" operation="sendmsg" info="Failed name lookup - disconnected path" error=-13 profile="/usr/sbin/mysqld" name="run/systemd/notify" pid=
Aug 02 22:18:25 example.com kernel: audit: type=1400 audit(1533241105.719:42): apparmor="DENIED" operation="sendmsg" info="Failed name lookup - disconnected path" error=-13 profile="/usr/sbin/mysql
Aug 02 22:18:25 example.com systemd[1]: mariadb.service: Failed with result 'timeout'.
Aug 02 22:18:25 example.com sudo[10011]: pam_unix(sudo:session): session closed for user root
Aug 02 22:18:25 example.com systemd[1]: Failed to start MariaDB database server.
-- Subject: Unit mariadb.service has failed
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
-- 
-- Unit mariadb.service has failed.
-- 
-- The result is RESULT.
Aug 02 22:18:25 example.com dhclient[943]: DHCPREQUEST of 123.123.123.123 on ens3 to 255.255.255.255 port 67 (xid=0x5ab749b3)
Aug 02 22:18:44 example.com dhclient[943]: DHCPREQUEST of 123.123.123.123 on ens3 to 255.255.255.255 port 67 (xid=0x5ab749b3)
Aug 02 22:18:47 example.com sshd[10183]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=182.100.67.106  user=root
Aug 02 22:18:49 example.com sshd[10183]: Failed password for root from 182.100.67.106 port 39521 ssh2
Aug 02 22:18:51 example.com dhclient[943]: DHCPREQUEST of 123.123.123.123 on ens3 to 255.255.255.255 port 67 (xid=0x5ab749b3)
Aug 02 22:19:11 example.com dhclient[943]: DHCPREQUEST of 123.123.123.123 on ens3 to 255.255.255.255 port 67 (xid=0x5ab749b3)
Aug 02 22:19:28 example.com dhclient[943]: DHCPREQUEST of 123.123.123.123 on ens3 to 255.255.255.255 port 67 (xid=0x5ab749b3)
Aug 02 22:19:38 example.com dhclient[943]: DHCPREQUEST of 123.123.123.123 on ens3 to 255.255.255.255 port 67 (xid=0x5ab749b3)
Aug 02 22:19:48 example.com dhclient[943]: DHCPREQUEST of 123.123.123.123 on ens3 to 255.255.255.255 port 67 (xid=0x5ab749b3)
Aug 02 22:19:59 example.com dhclient[943]: DHCPREQUEST of 123.123.123.123 on ens3 to 255.255.255.255 port 67 (xid=0x5ab749b3)
Aug 02 22:20:09 example.com dhclient[943]: DHCPREQUEST of 123.123.123.123 on ens3 to 255.255.255.255 port 67 (xid=0x5ab749b3)

I also took a look into the error log, which listed only some notes:

2018-08-02 22:26:32 140165196823680 [Note] InnoDB: innodb_empty_free_list_algorithm has been changed to legacy because of small buffer pool size. In order to use backoff, increase buffer pool at least up to 20MB.

2018-08-02 22:26:32 140165196823680 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2018-08-02 22:26:32 140165196823680 [Note] InnoDB: The InnoDB memory heap is disabled
2018-08-02 22:26:32 140165196823680 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2018-08-02 22:26:32 140165196823680 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2018-08-02 22:26:32 140165196823680 [Note] InnoDB: Compressed tables use zlib 1.2.11
2018-08-02 22:26:32 140165196823680 [Note] InnoDB: Using Linux native AIO
2018-08-02 22:26:32 140165196823680 [Note] InnoDB: Using SSE crc32 instructions
2018-08-02 22:26:32 140165196823680 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2018-08-02 22:26:32 140165196823680 [Note] InnoDB: Completed initialization of buffer pool
2018-08-02 22:26:32 140165196823680 [Note] InnoDB: Highest supported file format is Barracuda.
2018-08-02 22:26:32 140165196823680 [Note] InnoDB: 128 rollback segment(s) are active.
2018-08-02 22:26:32 140165196823680 [Note] InnoDB: Waiting for purge to start
2018-08-02 22:26:32 140165196823680 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.36-82.2 started; log sequence number 1616757
2018-08-02 22:26:32 140165196823680 [Note] Plugin 'FEEDBACK' is disabled.
2018-08-02 22:26:32 140164575749888 [Note] InnoDB: Dumping buffer pool(s) not yet started
2018-08-02 22:26:32 140165196823680 [Note] Server socket created on IP: '127.0.0.1'.
2018-08-02 22:26:32 140165196823680 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.1.29-MariaDB-6'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  Ubuntu 18.04
2018-08-02 22:28:02 140165196183296 [Note] /usr/sbin/mysqld: Normal shutdown

I already ran mysql_secure_installation, but without success. How can I fix the server installation?

Best Answer

The significant error is the following. Its showing permission denied (error 13) for mysqld trying to notify systemd that its ready. Because this wasn't received in 90 seconds systemd assumed it didn't start.

Aug 02 22:18:23 example.com audit[10139]: AVC apparmor="DENIED" operation="sendmsg" info="Failed name lookup - disconnected path" error=-13 profile="/usr/sbin/mysqld" name="run/systemd/notify" pid=

Search/write a bug report for the distributor of the mariadb package (mariadb.org or ubuntu).