[SOLVED] ERROR: Could not open file '/var/log/mysql/error.log' for error logging: Permission denied
Hello š
I got a task from my client today, their MySQL services didn't start after VPS was restarted. Their VPS using Ubuntu 18.04 operating system.
root@staging:/var/lib/mysql# systemctl status mysql
ā mysql.service - MySQL Community Server
Loaded: loaded (/lib/systemd/system/mysql.service; enabled; vendor preset: enabled)
Active: failed (Result: exit-code) since Mon 2022-10-31 10:20:10 WIB; 10min ago
Process: 4331 ExecStart=/usr/sbin/mysqld --daemonize --pid-file=/run/mysqld/mysqld.pid (code=exited, status=1/FAILURE)
Process: 4308 ExecStartPre=/usr/share/mysql/mysql-systemd-start pre (code=exited, status=0/SUCCESS)
Oct 31 10:20:10 staging.mywebsite.com systemd[1]: Failed to start MySQL Community Server.
Oct 31 10:20:10 staging.mywebsite.com systemd[1]: mysql.service: Service hold-off time over, scheduling restart.
Oct 31 10:20:10 staging.mywebsite.com systemd[1]: mysql.service: Scheduled restart job, restart counter is at 5.
Oct 31 10:20:10 staging.mywebsite.com systemd[1]: Stopped MySQL Community Server.
Oct 31 10:20:10 staging.mywebsite.com systemd[1]: mysql.service: Start request repeated too quickly.
Oct 31 10:20:10 staging.mywebsite.com systemd[1]: mysql.service: Failed with result 'exit-code'.
Oct 31 10:20:10 staging.mywebsite.com systemd[1]: Failed to start MySQL Community Server.
Problem :
- MySQL didn't start after VPS was restarted
Check the log error by:
- Checking the journal by using the command:
journalctl -xe
And I found the log:
--
-- Unit mysql.service has finished shutting down.
Oct 31 10:31:12 staging.mywebsite.com systemd[1]: Starting MySQL Community Server...
-- Subject: Unit mysql.service has begun start-up
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
--
-- Unit mysql.service has begun starting up.
Oct 31 10:31:12 staging.mywebsite.com mysqld[4781]: 2022-10-31T03:31:12.555159Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_fo
Oct 31 10:31:12 staging.mywebsite.com mysqld[4781]: 2022-10-31T03:31:12.557628Z 0 [Note] /usr/sbin/mysqld (mysqld 5.7.40-0ubuntu0.18.04.1) starting as process 4783 ...
Oct 31 10:31:12 staging.mywebsite.com mysqld[4781]: 2022-10-31T03:31:12.560595Z 0 [ERROR] Could not open file '/var/log/mysql/error.log' for error logging: Permission denied
Oct 31 10:31:12 staging.mywebsite.com mysqld[4781]: 2022-10-31T03:31:12.560766Z 0 [ERROR] Aborting
Oct 31 10:31:12 staging.mywebsite.com mysqld[4781]: Initialization of mysqld failed: 0
Oct 31 10:31:12 staging.mywebsite.com systemd[1]: mysql.service: Control process exited, code=exited status=1
Oct 31 10:31:12 staging.mywebsite.com mysqld[4781]: 2022-10-31T03:31:12.563090Z 0 [Note] Binlog end
Oct 31 10:31:12 staging.mywebsite.com mysqld[4781]: 2022-10-31T03:31:12.563196Z 0 [Note] /usr/sbin/mysqld: Shutdown complete
Oct 31 10:31:12 staging.mywebsite.com systemd[1]: mysql.service: Failed with result 'exit-code'.
Oct 31 10:31:12 staging.mywebsite.com systemd[1]: Failed to start MySQL Community Server.
-- Subject: Unit mysql.service has failed
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
The MySQL service has failed to start because could not open file /var/log/mysql/error.log
2022-10-31T03:31:12.560595Z 0 [ERROR] Could not open file '/var/log/mysql/error.log' for error logging: Permission deniedSo, I need to check the directory /var/log/mysql:
root@staging:~# cd /var/log/mysql
root@staging:/var/log/mysql# ls -lah
total 208K
drwxr-x--- 2 www-data www-data 4.0K Oct 31 06:25 .
drwxrwxr-x 14 root syslog 4.0K Oct 31 09:16 ..
-rw-r----- 1 mysql adm 0 Oct 31 06:25 error.log
-rw-r----- 1 www-data www-data 123K Oct 31 09:15 error.log.1
-rw-r----- 1 www-data www-data 7.9K Oct 30 06:16 error.log.2.gz
-rw-r----- 1 www-data www-data 3.8K Oct 29 05:36 error.log.3.gz
-rw-r----- 1 www-data www-data 4.8K Oct 28 05:14 error.log.4.gz
-rw-r----- 1 www-data www-data 5.7K Oct 27 05:14 error.log.5.gz
-rw-r----- 1 www-data www-data 11K Oct 26 05:14 error.log.6.gz
-rw-r----- 1 www-data www-data 5.1K Oct 25 02:27 error.log.7.gz
-rw-r----- 1 www-data www-data 22K Oct 24 05:38 error.log.8.gz
Looks fine, error.log is owned by mysql and adm group, but why the other files are owned by www-data ?? Let's find out the whole /var/log directory š§
root@staging:/var/log# ls -lah
total 111M
drwxrwxr-x 14 root syslog 4.0K Oct 31 09:16 .
drwxr-xr-x 14 root root 4.0K Jun 22 2020 ..
-rw-r--r-- 1 www-data www-data 318 Oct 31 09:16 alternatives.log
-rw-r--r-- 1 www-data www-data 5.9K Sep 23 23:08 alternatives.log.1
-rw-r--r-- 1 www-data www-data 322 Dec 29 2021 alternatives.log.10.gz
-rw-r--r-- 1 www-data www-data 709 Nov 17 2021 alternatives.log.11.gz
-rw-r--r-- 1 www-data www-data 172 Oct 27 2021 alternatives.log.12.gz
-rw-r--r-- 1 www-data www-data 496 Aug 28 01:51 alternatives.log.2.gz
-rw-r--r-- 1 www-data www-data 299 Jul 29 06:02 alternatives.log.3.gz
-rw-r--r-- 1 www-data www-data 301 Jun 26 13:52 alternatives.log.4.gz
-rw-r--r-- 1 www-data www-data 490 May 26 06:52 alternatives.log.5.gz
-rw-r--r-- 1 www-data www-data 566 Apr 21 2022 alternatives.log.6.gz
-rw-r--r-- 1 www-data www-data 134 Mar 16 2022 alternatives.log.7.gz
-rw-r--r-- 1 www-data www-data 105 Feb 5 2022 alternatives.log.8.gz
-rw-r--r-- 1 www-data www-data 395 Jan 22 2022 alternatives.log.9.gz
drwxr-x--- 2 www-data www-data 4.0K Jun 23 06:25 apache2
-rw-r----- 1 www-data www-data 0 Mar 28 2021 apport.log
-rw-r----- 1 www-data www-data 799 Mar 27 2021 apport.log.1
-rw-r----- 1 www-data www-data 276 Jul 22 2020 apport.log.2.gz
drwxr-xr-x 2 www-data www-data 4.0K Oct 29 06:16 apt
-rw-r----- 1 syslog adm 68K Oct 31 10:31 auth.log
-rw-r----- 1 www-data www-data 15M Oct 31 06:25 auth.log.1
-rw-r----- 1 www-data www-data 728K Oct 23 06:25 auth.log.2.gz
-rw-r----- 1 www-data www-data 1.6M Oct 17 06:25 auth.log.3.gz
-rw-r----- 1 www-data www-data 592K Oct 9 06:25 auth.log.4.gz
-rw-rw---- 1 root utmp 35M Oct 31 10:31 btmp
-rw-rw---- 1 www-data www-data 12M Oct 1 06:19 btmp.1
drwxr-xr-x 2 www-data www-data 4.0K Oct 31 06:25 clamav
-rw-r----- 1 www-data www-data 97K Oct 31 09:16 cloud-init-output.log
-rw-r--r-- 1 syslog adm 2.4M Oct 31 09:16 cloud-init.log
drwxr-xr-x 2 www-data www-data 4.0K Sep 12 06:25 dbconfig-common
drwxr-xr-x 2 www-data www-data 4.0K Jul 16 2018 dist-upgrade
-rw-r--r-- 1 www-data www-data 49K Oct 29 06:16 dpkg.log
-rw-r--r-- 1 www-data www-data 77K Sep 28 06:18 dpkg.log.1
-rw-r--r-- 1 www-data www-data 6.1K Dec 17 2021 dpkg.log.10.gz
-rw-r--r-- 1 www-data www-data 1.6K Nov 17 2021 dpkg.log.11.gz
-rw-r--r-- 1 www-data www-data 2.9K Oct 30 2021 dpkg.log.12.gz
-rw-r--r-- 1 www-data www-data 2.4K Aug 31 06:52 dpkg.log.2.gz
-rw-r--r-- 1 www-data www-data 5.2K Jul 29 06:02 dpkg.log.3.gz
-rw-r--r-- 1 www-data www-data 5.9K Jun 25 06:46 dpkg.log.4.gz
-rw-r--r-- 1 www-data www-data 4.7K Jun 1 06:14 dpkg.log.5.gz
-rw-r--r-- 1 www-data www-data 6.5K Apr 29 2022 dpkg.log.6.gz
-rw-r--r-- 1 www-data www-data 3.9K Mar 31 2022 dpkg.log.7.gz
-rw-r--r-- 1 www-data www-data 2.5K Feb 25 2022 dpkg.log.8.gz
-rw-r--r-- 1 www-data www-data 1.9K Jan 28 2022 dpkg.log.9.gz
drwxr-sr-x+ 3 root systemd-journal 4.0K Jun 3 2020 journal
-rw-r----- 1 syslog adm 119K Oct 31 10:31 kern.log
-rw-r----- 1 www-data www-data 8.6M Oct 31 06:24 kern.log.1
-rw-r----- 1 www-data www-data 797K Oct 23 06:25 kern.log.2.gz
-rw-r----- 1 www-data www-data 1.1M Oct 17 06:24 kern.log.3.gz
-rw-r----- 1 www-data www-data 964K Oct 9 06:24 kern.log.4.gz
drwxr-xr-x 2 www-data www-data 4.0K Jun 3 2020 landscape
-rw-rw-r-- 1 root utmp 287K Oct 31 10:16 lastlog
drwx------ 2 www-data www-data 4.0K Oct 31 06:25 letsencrypt
drwxr-xr-x 2 www-data www-data 4.0K Jun 6 2018 lxd
-rw-r----- 1 syslog adm 204 Oct 31 09:16 mail.err
-rw-r----- 1 syslog adm 204 Oct 31 09:16 mail.log
-rw-r----- 1 www-data www-data 13M Oct 31 06:24 mail.log.1
-rw-r----- 1 www-data www-data 739K Oct 23 06:25 mail.log.2.gz
-rw-r----- 1 www-data www-data 983K Oct 17 06:25 mail.log.3.gz
-rw-r----- 1 www-data www-data 862K Oct 9 06:25 mail.log.4.gz
drwxr-x--- 2 www-data www-data 4.0K Oct 31 06:25 mysql
drwxr-xr-x 2 www-data www-data 4.0K Oct 31 06:25 nginx
-rw------- 1 www-data www-data 444 Oct 31 09:16 php7.4-fpm.log
-rw------- 1 www-data www-data 591 Oct 31 02:25 php7.4-fpm.log.1
-rw------- 1 www-data www-data 195 Aug 28 01:51 php7.4-fpm.log.10.gz
-rw------- 1 www-data www-data 166 Aug 19 07:21 php7.4-fpm.log.11.gz
-rw------- 1 www-data www-data 76 Aug 7 06:25 php7.4-fpm.log.12.gz
-rw------- 1 www-data www-data 159 Oct 18 05:54 php7.4-fpm.log.2.gz
-rw------- 1 www-data www-data 76 Oct 9 06:25 php7.4-fpm.log.3.gz
-rw------- 1 www-data www-data 76 Oct 2 06:25 php7.4-fpm.log.4.gz
-rw------- 1 www-data www-data 173 Sep 27 05:17 php7.4-fpm.log.5.gz
-rw------- 1 www-data www-data 268 Sep 23 23:08 php7.4-fpm.log.6.gz
-rw------- 1 www-data www-data 166 Sep 14 13:15 php7.4-fpm.log.7.gz
-rw------- 1 www-data www-data 76 Sep 4 06:25 php7.4-fpm.log.8.gz
-rw------- 1 www-data www-data 362 Sep 4 00:07 php7.4-fpm.log.9.gz
-rw------- 1 www-data www-data 126K Jul 21 12:10 rkhunter.log
-rw-r----- 1 syslog adm 573K Oct 31 10:31 syslog
-rw-r----- 1 www-data www-data 4.8M Oct 31 06:25 syslog.1
-rw-r----- 1 www-data www-data 302K Oct 30 06:25 syslog.2.gz
-rw-r----- 1 www-data www-data 313K Oct 29 06:25 syslog.3.gz
-rw-r----- 1 www-data www-data 328K Oct 28 06:25 syslog.4.gz
-rw-r----- 1 www-data www-data 322K Oct 27 06:25 syslog.5.gz
-rw-r----- 1 www-data www-data 330K Oct 26 06:25 syslog.6.gz
-rw-r----- 1 www-data www-data 329K Oct 25 06:25 syslog.7.gz
-rw------- 1 www-data www-data 63K Oct 19 11:24 tallylog
-rw-r--r-- 1 www-data www-data 13K Oct 31 06:02 ubuntu-advantage-timer.log
-rw-r--r-- 1 www-data www-data 13K Oct 1 03:42 ubuntu-advantage-timer.log.1
-rw-r--r-- 1 www-data www-data 1.5K Sep 1 04:45 ubuntu-advantage-timer.log.2.gz
-rw-r--r-- 1 www-data www-data 1.5K Aug 1 01:24 ubuntu-advantage-timer.log.3.gz
-rw------- 1 www-data www-data 1.5K Jul 1 03:00 ubuntu-advantage-timer.log.4.gz
-rw------- 1 www-data www-data 1.5K Jun 1 00:56 ubuntu-advantage-timer.log.5.gz
-rw------- 1 www-data www-data 1.5K May 1 2022 ubuntu-advantage-timer.log.6.gz
-rw------- 1 www-data www-data 0 Jan 1 2022 ubuntu-advantage.log
-rw------- 1 www-data www-data 13K Dec 7 2021 ubuntu-advantage.log.1
-rw------- 1 www-data www-data 2.1K Dec 1 2021 ubuntu-advantage.log.2.gz
-rw------- 1 www-data www-data 2.2K Nov 1 2021 ubuntu-advantage.log.3.gz
-rw------- 1 www-data www-data 2.2K Oct 1 2021 ubuntu-advantage.log.4.gz
-rw------- 1 www-data www-data 2.3K Sep 1 2021 ubuntu-advantage.log.5.gz
-rw------- 1 www-data www-data 2.3K Aug 1 2021 ubuntu-advantage.log.6.gz
-rw-r----- 1 www-data www-data 0 Oct 31 06:25 ufw.log
-rw-r----- 1 www-data www-data 8.6M Oct 31 06:24 ufw.log.1
-rw-r----- 1 www-data www-data 797K Oct 23 06:25 ufw.log.2.gz
-rw-r----- 1 www-data www-data 1.1M Oct 17 06:24 ufw.log.3.gz
-rw-r----- 1 www-data www-data 963K Oct 9 06:24 ufw.log.4.gz
drwxr-x--- 2 www-data www-data 4.0K Oct 1 06:25 unattended-upgrades
-rw-rw-r-- 1 root utmp 52K Oct 31 10:16 wtmp
-rw-rw-r-- 1 www-data www-data 33K Sep 30 23:02 wtmp.1
Welp, looks like someone changed the ownership of the /var/log/ to www-data user and group recursively.
Fixed by:
So, all I have to do is revert back the ownership of /var/log/mysql directory to mysql:adm as it should.
root@staging:/var/log# chown mysql:adm mysql/ -R
Start the MySQL process again by using the following command:
systemctl start mysqlroot@staging:/var/log# service mysql status
ā mysql.service - MySQL Community Server
Loaded: loaded (/lib/systemd/system/mysql.service; enabled; vendor preset: enabled)
Active: active (running) since Mon 2022-10-31 10:32:16 WIB; 1h 2min ago
Process: 4920 ExecStart=/usr/sbin/mysqld --daemonize --pid-file=/run/mysqld/mysqld.pid (code=exited, status=0/SUCCESS)
Process: 4896 ExecStartPre=/usr/share/mysql/mysql-systemd-start pre (code=exited, status=0/SUCCESS)
Main PID: 4922 (mysqld)
Tasks: 29 (limit: 2352)
CGroup: /system.slice/mysql.service
āā4922 /usr/sbin/mysqld --daemonize --pid-file=/run/mysqld/mysqld.pid
Oct 31 10:32:15 staging.mywebsite.com systemd[1]: Starting MySQL Community Server...
Oct 31 10:32:16 staging.mywebsite.com systemd[1]: Started MySQL Community Server.
And the MySQL service was started normally as it should š
Thanks for reading š„·