MariaDB – Determine Cause of Failed Start on CentOS 7

We are a free/open source project. We are having problems determining why MariaDB 5.5.58 on CentOS 7 is not starting. The start problems happened after we enabled CentOS Software Collections (SCL) and performed a MediaWiki upgrade.

Lack of useful error information is making it hard for us to troubleshoot the issue. I found CentOS's Issue 9519, /usr/libexec/mariadb-prepare-db-dir fails (and Mariadb won't start – Failed at step EXEC spawning), but the permissions on / seem OK (see below). We also have the PID file discussed in Red Hat's Issue 1082018, systemctl start mariadb.service wouldn't start.

The result of running /usr/libexec/mariadb-prepare-db-dir manually with set -x as root is shown below. I don't know how systemd is running it (I have not found the commands to print the information yet).

We rent our VM so there is no dmesg or syslog to inspect. It is empty.

If anyone could provide more information on the cause of the failure or additional steps to troubleshoot, then we would be grateful.

MariaDB Conf

# grep -v '#' /etc/my.cnf
[mysqld]
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
symbolic-links=0

[mysqld_safe]
log-error=/var/log/mariadb/mariadb.log
pid-file=/var/run/mariadb/mariadb.pid

!includedir /etc/my.cnf.d

And then:

# echo "" > /var/log/mariadb/mariadb.log

Other Directories

# ls -al /
total 64
dr-xr-xr-x 20 root root 4096 Dec 23 15:46 .
dr-xr-xr-x 20 root root 4096 Dec 23 15:46 ..

# ls -al /var/run/mariadb/
total 0
drwxr-xr-x  2 mysql mysql  40 Dec 23 15:46 .
drwxr-xr-x 26 root  root  680 Dec 23 18:26 ..

Data Directory

# ls -al /var/lib/mysql
total 35060
drwxr-xr-x  5 mysql mysql     4096 Dec 23 15:45 .
drwxr-xr-x 30 root  root      4096 Dec 23 18:52 ..
-rw-rw----  1 mysql mysql    16384 Dec 23 15:45 aria_log.00000001
-rw-rw----  1 mysql mysql       52 Dec 23 15:45 aria_log_control
-rw-rw----  1 mysql mysql 35651584 Dec 23 15:45 ibdata1
-rw-rw----  1 mysql mysql  5242880 Dec 23 15:45 ib_logfile0
-rw-rw----  1 mysql mysql  5242880 Dec 23 15:31 ib_logfile1
drwx------  2 mysql mysql     4096 Sep 18  2016 mysql
drwx------  2 mysql mysql    16384 Dec 23 01:14 my_wiki
drwx------  2 mysql mysql     4096 Sep 18  2016 performance_schema

Attempt to Start

# ls /usr/libexec/mariadb-prepare-db-dir
/usr/libexec/mariadb-prepare-db-dir

# systemctl start mariadb.service
Job for mariadb.service failed because the control process exited with error code.
See "systemctl status mariadb.service" and "journalctl -xe" for details.

mariadb.log

# cat /var/log/mariadb/mariadb.log
#

systemctl status

# systemctl -l status mariadb.service
● mariadb.service - MariaDB database server
   Loaded: loaded (/usr/lib/systemd/system/mariadb.service; enabled; vendor preset: disabled)
   Active: failed (Result: exit-code) since Sat 2017-12-23 18:29:28 EST; 23s ago
  Process: 14537 ExecStartPre=/usr/libexec/mariadb-prepare-db-dir %n (code=exited, status=1/FAILURE)

Dec 23 18:29:28 ftpit systemd[1]: Starting MariaDB database server...
Dec 23 18:29:28 ftpit systemd[1]: mariadb.service: control process exited, code=exited status=1
Dec 23 18:29:28 ftpit systemd[1]: Failed to start MariaDB database server.
Dec 23 18:29:28 ftpit systemd[1]: Unit mariadb.service entered failed state.
Dec 23 18:29:28 ftpit systemd[1]: mariadb.service failed.
Oct 27 19:05:23 ftpit systemd[1]: Stopping MariaDB database server...
Oct 27 19:05:28 ftpit systemd[1]: Stopped MariaDB database server.
Nov 16 12:48:44 ftpit systemd[1]: Stopping MariaDB database server...
Nov 16 12:48:54 ftpit systemd[1]: Stopped MariaDB database server.

journalctl -xe

# journalctl -xe
-- Subject: Unit sysinit.target has finished shutting down
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit sysinit.target has finished shutting down.
Nov 16 12:48:57 ftpit systemd[1]: Stopping System Initialization.
-- Subject: Unit sysinit.target has begun shutting down
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit sysinit.target has begun shutting down.
Nov 16 12:48:57 ftpit systemd[1]: Stopped target Swap.
-- Subject: Unit swap.target has finished shutting down
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit swap.target has finished shutting down.
Nov 16 12:48:57 ftpit systemd[1]: Stopping Swap.
-- Subject: Unit swap.target has begun shutting down
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit swap.target has begun shutting down.

Here is the result of running /usr/libexec/mariadb-prepare-db-dir manually with set -x added to the script. Honestly, I can't tell if this is expected or not.

# /usr/libexec/mariadb-prepare-db-dir
+ get_mysql_option mysqld datadir /var/lib/mysql
+ '[' 3 -ne 3 ']'
++ tail -n 1
++ sed -n 's/^--datadir=//p'
++ /usr/bin/my_print_defaults mysqld
+ result=/var/lib/mysql
+ '[' -z /var/lib/mysql ']'
+ datadir=/var/lib/mysql
+ get_mysql_option mysqld_safe log-error /var/log/mariadb/mariadb.log
+ '[' 3 -ne 3 ']'
++ sed -n 's/^--log-error=//p'
++ tail -n 1
++ /usr/bin/my_print_defaults mysqld_safe
+ result=/var/log/mariadb/mariadb.log
+ '[' -z /var/log/mariadb/mariadb.log ']'
+ errlogfile=/var/log/mariadb/mariadb.log
+ get_mysql_option mysqld socket /var/lib/mysql/mysql.sock
+ '[' 3 -ne 3 ']'
++ tail -n 1
++ sed -n 's/^--socket=//p'
++ /usr/bin/my_print_defaults mysqld
+ result=/var/lib/mysql/mysql.sock
+ '[' -z /var/lib/mysql/mysql.sock ']'
+ socketfile=/var/lib/mysql/mysql.sock
+ SERVICE_NAME=
+ '[' x = x ']'
+ SERVICE_NAME=mysqld.service
++ sed 's/^User=//'
++ systemctl show -p User mysqld.service
+ myuser=
+ '[' x = x ']'
+ myuser=mysql
++ sed 's/^Group=//'
++ systemctl show -p Group mysqld.service
+ mygroup=
+ '[' x = x ']'
+ mygroup=mysql
++ dirname /var/log/mariadb/mariadb.log
+ '[' '!' -e /var/log/mariadb/mariadb.log -a '!' -h /var/log/mariadb/mariadb.log -a x/var/log/mariadb = x/var/log ']'
++ dirname /var/log/mariadb/mariadb.log
+ errlogdir=/var/log/mariadb
+ '[' -d /var/log/mariadb ']'
+ '[' -e /var/log/mariadb/mariadb.log -a '!' -w /var/log/mariadb/mariadb.log ']'
+ fuser /var/lib/mysql/mysql.sock
+ export LC_ALL=C
+ LC_ALL=C
+ should_initialize /var/lib/mysql
++ list_datadir /var/lib/mysql
++ grep -v -e '^lost+found$' -e '\.err$' -e '^.bash_history$'
++ ls -1A /var/lib/mysql
+ test -z 'aria_log.00000001
aria_log_control
ib_logfile0
ib_logfile1
ibdata1
my_wiki
mysql
performance_schema'
+ '[' -d /var/lib/mysql/mysql/ ']'
+ echo 'Database MariaDB is probably initialized in /var/lib/mysql already, nothing is done.'
Database MariaDB is probably initialized in /var/lib/mysql already, nothing is done.
++ basename /usr/libexec/mariadb-prepare-db-dir
+ echo 'If this is not the case, make sure the /var/lib/mysql is empty before running mariadb-prepare-db-dir.'
If this is not the case, make sure the /var/lib/mysql is empty before running mariadb-prepare-db-dir.
+ exit 0