Bug 1483331 - Couldn't start mariadb.service
Summary: Couldn't start mariadb.service
Keywords:
Status: CLOSED EOL
Alias: None
Product: Fedora
Classification: Fedora
Component: selinux-policy
Version: 27
Hardware: Unspecified
OS: Unspecified
high
high
Target Milestone: ---
Assignee: Lukas Vrabec
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard: RejectedBlocker AcceptedFreezeException
: 1483712 1488426 1515779 (view as bug list)
Depends On:
Blocks: F27BetaBlocker F27BetaFreezeException
TreeView+ depends on / blocked
 
Reported: 2017-08-20 15:21 UTC by Mikhail
Modified: 2018-11-30 22:36 UTC (History)
23 users (show)

Fixed In Version: selinux-policy-3.13.1-283.4.fc27
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2018-11-30 22:36:34 UTC


Attachments (Terms of Use)

Description Mikhail 2017-08-20 15:21:46 UTC
Description of problem:
[root@localhost var]# systemctl restart 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.
[root@localhost var]# systemctl  status mariadb.service
● mariadb.service - MariaDB 10.2 database server
   Loaded: loaded (/usr/lib/systemd/system/mariadb.service; disabled; vendor preset: disabled)
   Active: failed (Result: exit-code) since Sun 2017-08-20 20:19:27 +05; 2s ago
  Process: 30111 ExecStart=/usr/libexec/mysqld --basedir=/usr $MYSQLD_OPTS $_WSREP_NEW_CLUSTER (code=exited, status=1/FAILURE)
  Process: 30075 ExecStartPre=/usr/libexec/mysql-prepare-db-dir mariadb.service (code=exited, status=0/SUCCESS)
  Process: 30053 ExecStartPre=/usr/libexec/mysql-check-socket (code=exited, status=0/SUCCESS)
 Main PID: 30111 (code=exited, status=1/FAILURE)
   Status: "MariaDB server is down"

Aug 20 20:19:24 localhost.localdomain systemd[1]: Starting MariaDB 10.2 database server...
Aug 20 20:19:24 localhost.localdomain mysql-prepare-db-dir[30075]: Database MariaDB is probably initialized in /var/lib/mysql already, nothing is done.
Aug 20 20:19:24 localhost.localdomain mysql-prepare-db-dir[30075]: If this is not the case, make sure the /var/lib/mysql is empty before running mysql-prepare-db-dir.
Aug 20 20:19:24 localhost.localdomain mysqld[30111]: 2017-08-20 20:19:24 140097941032192 [Note] /usr/libexec/mysqld (mysqld 10.2.7-MariaDB) starting as process 30111 ...
Aug 20 20:19:24 localhost.localdomain mysqld[30111]: 2017-08-20 20:19:24 140097941032192 [Warning] Changed limits: max_open_files: 4096  max_connections: 151  table_cache: 1967
Aug 20 20:19:27 localhost.localdomain systemd[1]: mariadb.service: Main process exited, code=exited, status=1/FAILURE
Aug 20 20:19:27 localhost.localdomain systemd[1]: Failed to start MariaDB 10.2 database server.
Aug 20 20:19:27 localhost.localdomain systemd[1]: mariadb.service: Unit entered failed state.
Aug 20 20:19:27 localhost.localdomain systemd[1]: mariadb.service: Failed with result 'exit-code'.


# rpm -q mariadb-server
mariadb-server-10.2.7-8.fc27.x86_64

Comment 1 Morten Stevens 2017-09-13 16:00:08 UTC
confirmed latest mariadb doesn't start.

# rpm -q mariadb-server
mariadb-server-10.2.8-2.fc28.x86_64

# systemctl status mariadb
● mariadb.service - MariaDB 10.2 database server
   Loaded: loaded (/usr/lib/systemd/system/mariadb.service; enabled; vendor preset: disabled)
   Active: failed (Result: exit-code) since Wed 2017-09-13 17:50:13 CEST; 7min ago
 Main PID: 1219 (code=exited, status=1/FAILURE)
   Status: "MariaDB server is down"

Sep 13 17:50:06 localhost.localdomain systemd[1]: Starting MariaDB 10.2 database server...
Sep 13 17:50:07 localhost.localdomain mysql-prepare-db-dir[1182]: Database MariaDB is probably initialized in /var/lib/mysql already, nothing is done.
Sep 13 17:50:07 localhost.localdomain mysql-prepare-db-dir[1182]: If this is not the case, make sure the /var/lib/mysql is empty before running mysql-pre
Sep 13 17:50:07 localhost.localdomain mysqld[1219]: 2017-09-13 17:50:07 140151126424832 [Note] /usr/libexec/mysqld (mysqld 10.2.8-MariaDB) starting as pr
Sep 13 17:50:07 localhost.localdomain mysqld[1219]: 2017-09-13 17:50:07 140151126424832 [Warning] Changed limits: max_open_files: 1024  max_connections:
Sep 13 17:50:13 localhost.localdomain systemd[1]: mariadb.service: Main process exited, code=exited, status=1/FAILURE
Sep 13 17:50:13 localhost.localdomain systemd[1]: Failed to start MariaDB 10.2 database server.
Sep 13 17:50:13 localhost.localdomain systemd[1]: mariadb.service: Unit entered failed state.
Sep 13 17:50:13 localhost.localdomain systemd[1]: mariadb.service: Failed with result 'exit-code'.

Comment 2 James Hogarth 2017-09-21 09:46:04 UTC
This isn't just a rawhide issue ... this is a F27 issue.

=====================================
[root@f27-template ~]# dnf install mariadb-server
Last metadata expiration check: 0:10:20 ago on Thu 21 Sep 2017 09:06:16 UTC.
Dependencies resolved.
....
Complete!
[root@f27-template ~]# systemctl start mariadb
Job for mariadb.service failed because the control process exited with error code.
See "systemctl  status mariadb.service" and "journalctl  -xe" for details.
[root@f27-template ~]# systemctl status mariadb
● mariadb.service - MariaDB 10.2 database server
   Loaded: loaded (/usr/lib/systemd/system/mariadb.service; bad; vendor preset: disabled)
   Active: failed (Result: exit-code) since Thu 2017-09-21 09:41:11 UTC; 42s ago
  Process: 11099 ExecStart=/usr/libexec/mysqld --basedir=/usr $MYSQLD_OPTS $_WSREP_NEW_CLUSTER (code=exited, status=1/FAILURE)
  Process: 10990 ExecStartPre=/usr/libexec/mysql-prepare-db-dir mariadb.service (code=exited, status=0/SUCCESS)
  Process: 10968 ExecStartPre=/usr/libexec/mysql-check-socket (code=exited, status=0/SUCCESS)
 Main PID: 11099 (code=exited, status=1/FAILURE)
   Status: "MariaDB server is down"

Sep 21 09:41:06 f27-template.changeme mysql-prepare-db-dir[10990]: MySQL manual for more instructions.
Sep 21 09:41:06 f27-template.changeme mysql-prepare-db-dir[10990]: Please report any problems at http://mariadb.org/jira
Sep 21 09:41:06 f27-template.changeme mysql-prepare-db-dir[10990]: The latest information about MariaDB is available at http://mariadb.org/.
Sep 21 09:41:06 f27-template.changeme mysql-prepare-db-dir[10990]: You can find additional information about the MySQL part at:
Sep 21 09:41:07 f27-template.changeme mysqld[11099]: 2017-09-21  9:41:07 140354794310912 [Note] /usr/libexec/mysqld (mysqld 10.2.8-MariaDB) starting as process 11099 ...
Sep 21 09:41:07 f27-template.changeme mysqld[11099]: 2017-09-21  9:41:07 140354794310912 [Warning] Changed limits: max_open_files: 1024  max_connections: 151  table_cache: 431
Sep 21 09:41:11 f27-template.changeme systemd[1]: mariadb.service: Main process exited, code=exited, status=1/FAILURE
Sep 21 09:41:11 f27-template.changeme systemd[1]: Failed to start MariaDB 10.2 database server.
Sep 21 09:41:11 f27-template.changeme systemd[1]: mariadb.service: Unit entered failed state.
Sep 21 09:41:12 f27-template.changeme systemd[1]: mariadb.service: Failed with result 'exit-code'.
[root@f27-template ~]# tail /var/log/mariadb/mariadb.log 
2017-09-21  9:41:07 140354794310912 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2017-09-21  9:41:08 140354794310912 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2017-09-21  9:41:08 140354794310912 [Note] InnoDB: Waiting for purge to start
2017-09-21  9:41:08 140354794310912 [Note] InnoDB: 5.7.19 started; log sequence number 1620349
2017-09-21  9:41:08 140353743083264 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2017-09-21  9:41:08 140353743083264 [Note] InnoDB: Buffer pool(s) load completed at 170921  9:41:08
2017-09-21  9:41:08 140354794310912 [Note] Plugin 'FEEDBACK' is disabled.
2017-09-21  9:41:08 140354794310912 [ERROR] Can't init tc log
2017-09-21  9:41:08 140354794310912 [ERROR] Aborting
=======================================================

Although the "Database Featured Role" mentions Postgresql specifically, MariaDB is sufficiently common I'd suggest that it should be included in the definition as a valid release blocker.

Raising this with QA for an analysis.

Comment 3 Fedora Blocker Bugs Application 2017-09-21 09:55:15 UTC
Proposed as a Blocker for 27-beta by Fedora user jhogarth using the blocker tracking app because:

 Although the formal Fedora Server Database role definition calls for Postgresql to be functional there are many situation postgresql is not an option, with many projects only supporting a mysql-style database.

At present on a current F27 install the standard basic steps to install and start mariadb (as the default mysql-style database supported) fails:

dnf -y install mariadb-server
systemctl start mariadb

I do not think it useful to our users or community to have a Fedora release where mariadb fails to start on a default install.

Comment 4 František Zatloukal 2017-09-21 10:28:39 UTC
I was able to reproduce this bug on a fresh F27 installation.

The issue is because of: 
SELinux is preventing mysqld from map access on the file /var/lib/mysql/tc.log

The workaround:
sudo setenforce 0
sudo rm /var/lib/mysql/tc.log
sudo systemctl start mariadb

Comment 5 James Hogarth 2017-09-21 10:49:50 UTC
Verified the root issue:

----
time->Thu Sep 21 10:13:38 2017
type=AVC msg=audit(1505988818.197:215): avc:  denied  { map } for  pid=14260 comm="mysqld" path="/var/lib/mysql/tc.log" dev="dm-0" ino=25364204 scontext=system_u:system_r:mysqld_t:s0 tcontext=system_u:object_r:mysqld_db_t:s0 tclass=file permissive=1
[root@f27-template ~]# ausearch -m avc | grep mysql
type=AVC msg=audit(1505986868.987:195): avc:  denied  { map } for  pid=11099 comm="mysqld" path="/var/lib/mysql/tc.log" dev="dm-0" ino=25223936 scontext=system_u:system_r:mysqld_t:s0 tcontext=system_u:object_r:mysqld_db_t:s0 tclass=file permissive=0
type=AVC msg=audit(1505987149.829:199): avc:  denied  { map } for  pid=11226 comm="mysqld" path="/var/lib/mysql/tc.log" dev="dm-0" ino=25251482 scontext=system_u:system_r:mysqld_t:s0 tcontext=system_u:object_r:mysqld_db_t:s0 tclass=file permissive=0
type=AVC msg=audit(1505988818.197:215): avc:  denied  { map } for  pid=14260 comm="mysqld" path="/var/lib/mysql/tc.log" dev="dm-0" ino=25364204 scontext=system_u:system_r:mysqld_t:s0 tcontext=system_u:object_r:mysqld_db_t:s0 tclass=file permissive=1

Setting to selinux-policy so they can update it.

Comment 6 James Hogarth 2017-09-21 14:01:51 UTC
To make it clear ... here's the commit upstream that fixes this:

https://github.com/fedora-selinux/selinux-policy-contrib/commit/542b8bfcda1e26524d735ec09016abd3278ae4e0

Comment 7 Kamil Páral 2017-09-21 18:14:17 UTC
Discussed during blocker review [1]:

RejectedBlocker (beta) AcceptedFreezeException - mariadb isn't blocking for Server Database role, but it is important enough so the fixing update will be considered as Freeze Exception

[1] https://meetbot-raw.fedoraproject.org/fedora-meeting-1/2017-09-21/

Comment 8 Fedora Update System 2017-09-22 09:50:34 UTC
selinux-policy-3.13.1-283.4.fc27 has been submitted as an update to Fedora 27. https://bodhi.fedoraproject.org/updates/FEDORA-2017-1fd5e1aff6

Comment 9 Fedora Update System 2017-09-22 17:54:12 UTC
selinux-policy-3.13.1-283.4.fc27 has been pushed to the Fedora 27 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2017-1fd5e1aff6

Comment 10 František Zatloukal 2017-09-25 11:13:43 UTC
Fix confirmed.

Comment 11 Fedora Update System 2017-09-30 06:48:56 UTC
selinux-policy-3.13.1-283.4.fc27 has been pushed to the Fedora 27 stable repository. If problems still persist, please make note of it in this bug report.

Comment 12 Steven Lilley 2017-11-20 10:43:36 UTC
Upgraded from Fedora 26 to 27 over the weekend and mariadb service now fails to start. I've tried the work around suggested above:

sudo setenforce 0
sudo rm /var/lib/mysql/tc.log
sudo systemctl start mariadb

but the service still fails to start. From journalctl -xe:

-- Unit mariadb.service has begun starting up.
Nov 20 10:42:12 dev-6514004 mysql-prepare-db-dir[3486]: Database MariaDB is probably initialized in /var/lib/mysql already, nothing is done.
Nov 20 10:42:12 dev-6514004 mysql-prepare-db-dir[3486]: If this is not the case, make sure the /var/lib/mysql is empty before running mysql-prepare-db-dir.
Nov 20 10:42:13 dev-6514004 mysqld[3523]: 2017-11-20 10:42:13 139863307046144 [Note] /usr/libexec/mysqld (mysqld 10.2.9-MariaDB) starting as process 3523 ...
Nov 20 10:42:13 dev-6514004 mysqld[3523]: 2017-11-20 10:42:13 139863307046144 [Warning] Changed limits: max_open_files: 1024  max_connections: 151  table_cach
Nov 20 10:42:14 dev-6514004 systemd[1]: mariadb.service: Main process exited, code=exited, status=1/FAILURE
Nov 20 10:42:14 dev-6514004 systemd[1]: Failed to start MariaDB 10.2 database server.
-- Subject: Unit mariadb.service has failed
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit mariadb.service has failed.
-- 
-- The result is failed.
Nov 20 10:42:14 dev-6514004 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=mariadb comm="systemd" exe="/usr/lib/systemd/systemd"
Nov 20 10:42:14 dev-6514004 systemd[1]: mariadb.service: Unit entered failed state.
Nov 20 10:42:14 dev-6514004 systemd[1]: mariadb.service: Failed with result 'exit-code'.

Comment 13 James Hogarth 2017-11-20 11:48:54 UTC
Steven,

Check your /etc/my.cnf.d directory.

If you made any manual changes to /etc/my.cnf.d/mariadb-server.cnf then you'll need to merge the /etc/my.cnf.d/mariadb-server.cnf.rpmnew file in ...

The location of /run/mysqld/mariadb.pid changed from /run/mariadb to /run/mysqld 

At least that's what caused my mysql failure on upgrade, on merging in the new config file mariadb ran correctly.

Comment 14 Steven Lilley 2017-11-21 09:04:52 UTC
Thank you James, it was exactly that :-)

(Now just need to get my machine to start with selinux set to permissive!)

Comment 15 Michal Schorm 2017-11-21 16:18:40 UTC
*** Bug 1515779 has been marked as a duplicate of this bug. ***

Comment 16 Fedora Update System 2017-11-23 21:27:33 UTC
mariadb-10.2.10-2.fc27 has been submitted as an update to Fedora 27. https://bodhi.fedoraproject.org/updates/FEDORA-2017-7b83201239

Comment 17 Michal Schorm 2017-11-23 21:29:06 UTC
Please not that I found it was actually a bug and it is beeing fixed by 10.2.10 update.

(So update to previous configuration could be needed again. Sorry for the incovinience)

Comment 18 Steven Lilley 2017-11-23 21:34:09 UTC
(In reply to Michal Schorm from comment #17)
> Please not that I found it was actually a bug and it is beeing fixed by
> 10.2.10 update.
> 
> (So update to previous configuration could be needed again. Sorry for the
> incovinience)

Thanks for the heads-up :-)

Comment 19 Fedora Update System 2017-11-25 00:37:18 UTC
mariadb-10.2.10-2.fc27 has been pushed to the Fedora 27 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2017-7b83201239

Comment 20 toshi 2018-01-17 12:48:44 UTC
I think the problem is in the /var/lib/mysql folder

you must remove all files in that folder and start mariadb

enjoy!!!

Comment 21 Fedora Update System 2018-01-23 21:42:59 UTC
mariadb-10.2.10-2.fc27 has been pushed to the Fedora 27 stable repository. If problems still persist, please make note of it in this bug report.

Comment 22 linux4desktop 2018-01-25 10:27:41 UTC
Dear all,
this is my first comment on this bugtracker, so i hope i do everything right.

I have this same issue on a F26 Server, after updating yesterday to mariadb 10.1.30.

Log:
Jan 25 09:28:27 oc.server.com systemd[1]: Starting MariaDB 10.1 database server...
Jan 25 09:28:27 oc.server.com mysql-check-socket[3547]: Socket file /var/lib/mysql/mysql.sock exists.
Jan 25 09:28:27 oc.server.com mysql-check-socket[3547]: No process is using /var/lib/mysql/mysql.sock, which means it is a garbage, so it will be removed automatically.
Jan 25 09:28:27 oc.server.com mysql-prepare-db-dir[3570]: Database MariaDB is probably initialized in /var/lib/mysql already, nothing is done.
Jan 25 09:28:27 oc.server.com mysql-prepare-db-dir[3570]: If this is not the case, make sure the /var/lib/mysql is empty before running mysql-prepare-db-dir.
Jan 25 09:28:28 oc.server.com mysqld[3605]: 2018-01-25  9:28:28 139930537759936 [Note] /usr/libexec/mysqld (mysqld 10.1.30-MariaDB) starting as process 3605 ...
Jan 25 09:28:28 oc.server.com systemd[1]: mariadb.service: Main process exited, code=exited, status=1/FAILURE
Jan 25 09:28:28 oc.server.com systemd[1]: Failed to start MariaDB 10.1 database server.
Jan 25 09:28:28 oc.server.com systemd[1]: mariadb.service: Unit entered failed state.
Jan 25 09:28:28 oc.server.com systemd[1]: mariadb.service: Failed with result 'exit-code'.

I tried applying the hints from Comment 4, w/o success.
I checked for rpmnew like suggested in Comment 13 => there is no mariadb-server.cnf.rpmnew file.
And i tried comment 20, with no improvement.

When i try to revert the problematic update: dnf history undo 54
but this fails with:
No package GeoIP-GeoLite-data-0:2017.10-1.fc26.noarch available.
Error: An operation cannot be undone

Anybody an idea how to fix this on F26?

Comment 23 Michal Schorm 2018-01-25 10:56:21 UTC
Hi, you did gave an usefull information.

However this bug aim at different issue.
The correct for you is: https://bugzilla.redhat.com/show_bug.cgi?id=1538066

*This* bug is caused by SELInux problems,
*Your* bug is caused by incorrect tmpfiles configuration and is only applicable for Fedora 26.

I already proposed a solution for the bug, check it in the referenced bug tracker.


And welcome to Bugzilla :)

Comment 24 linux4desktop 2018-01-25 11:51:58 UTC
Hi,
thanks Michal for the information.
I will post a comment over there, how the test went!

Comment 25 Lukas Vrabec 2018-07-03 11:11:50 UTC
*** Bug 1488426 has been marked as a duplicate of this bug. ***

Comment 26 Lukas Vrabec 2018-07-03 11:11:58 UTC
*** Bug 1483712 has been marked as a duplicate of this bug. ***

Comment 27 Ben Cotton 2018-11-27 14:35:22 UTC
This message is a reminder that Fedora 27 is nearing its end of life.
On 2018-Nov-30  Fedora will stop maintaining and issuing updates for
Fedora 27. It is Fedora's policy to close all bug reports from releases
that are no longer maintained. At that time this bug will be closed as
EOL if it remains open with a Fedora  'version' of '27'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 27 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 28 Ben Cotton 2018-11-30 22:36:34 UTC
Fedora 27 changed to end-of-life (EOL) status on 2018-11-30. Fedora 27 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.


Note You need to log in before you can comment on or make changes to this bug.