Percona Server not starting in Ubuntu focal

General Questions
1

Hi,

I am using:

Distributor ID: Ubuntu
Description: Ubuntu 20.04.6 LTS
Release: 20.04
Codename: focal

I install Percona Server Server version: 8.0.31-23 Percona Server (GPL), Release '23', Revision '71449379'

I shutdown mysql, then add a mount and softlink the data and log directors to that mount:

> ls -l /var/lib/mysql
lrwxrwxrwx 1 root root 15 Aug  7 19:08 /var/lib/mysql -> /mnt/data/mysql

Additionally I made some updates to the /etc/my.cnf

When I restart MySQL, it fails, and I am not sure where to look. The output is /var/log/syslog is not very helpful. I get the following:

Aug  8 15:10:31 ip-10-71-252-15 systemd[1]: Starting Percona MySQL Server...
Aug  8 15:10:31 ip-10-71-252-15 kernel: [72315.912589] kauditd_printk_skb: 30 callbacks suppressed
Aug  8 15:10:31 ip-10-71-252-15 kernel: [72315.912594] audit: type=1400 audit(1691507431.403:345): apparmor="ALLOWED" operation="open" profile="/usr/sbin/mysqld" name="/etc/my.cnf" pid=22454 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=114 ouid=0
Aug  8 15:10:31 ip-10-71-252-15 kernel: [72315.912662] audit: type=1400 audit(1691507431.403:346): apparmor="ALLOWED" operation="open" profile="/usr/sbin/mysqld" name="/mnt/data/mysql/my.cnf" pid=22454 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=114 ouid=114
Aug  8 15:10:31 ip-10-71-252-15 kernel: [72315.912908] audit: type=1400 audit(1691507431.403:347): apparmor="ALLOWED" operation="open" profile="/usr/sbin/mysqld" name="/etc/my.cnf" pid=22454 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=114 ouid=0
Aug  8 15:10:31 ip-10-71-252-15 kernel: [72315.912952] audit: type=1400 audit(1691507431.403:348): apparmor="ALLOWED" operation="open" profile="/usr/sbin/mysqld" name="/mnt/data/mysql/my.cnf" pid=22454 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=114 ouid=114
Aug  8 15:10:31 ip-10-71-252-15 kernel: [72316.206126] audit: type=1400 audit(1691507431.695:349): apparmor="ALLOWED" operation="open" profile="/usr/sbin/mysqld" name="/var/log/mysqld.log" pid=22454 comm="mysqld" requested_mask="ac" denied_mask="ac" fsuid=114 ouid=114
Aug  8 15:10:31 ip-10-71-252-15 kernel: [72316.206137] audit: type=1400 audit(1691507431.695:350): apparmor="ALLOWED" operation="open" profile="/usr/sbin/mysqld" name="/var/log/mysqld.log" pid=22454 comm="mysqld" requested_mask="ac" denied_mask="ac" fsuid=114 ouid=114
Aug  8 15:10:31 ip-10-71-252-15 kernel: [72316.206206] audit: type=1400 audit(1691507431.695:351): apparmor="ALLOWED" operation="file_perm" profile="/usr/sbin/mysqld" name="/var/log/mysqld.log" pid=22454 comm="mysqld" requested_mask="w" denied_mask="w" fsuid=114 ouid=114
Aug  8 15:10:31 ip-10-71-252-15 kernel: [72316.206549] audit: type=1400 audit(1691507431.699:352): apparmor="ALLOWED" operation="open" profile="/usr/sbin/mysqld" name="/var/log/mysqld.log" pid=22454 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=114 ouid=114
Aug  8 15:10:31 ip-10-71-252-15 systemd[1]: mysql.service: Control process exited, code=exited, status=1/FAILURE
Aug  8 15:10:31 ip-10-71-252-15 systemd[1]: mysql.service: Failed with result 'exit-code'.
Aug  8 15:10:31 ip-10-71-252-15 systemd[1]: Failed to start Percona MySQL Server.
Aug  8 15:10:31 ip-10-71-252-15 systemd[1]: mysql.service: Scheduled restart job, restart counter is at 1.
Aug  8 15:10:31 ip-10-71-252-15 systemd[1]: Stopped Percona MySQL Server.
Aug  8 15:10:31 ip-10-71-252-15 systemd[1]: Starting Percona MySQL Server...
Aug  8 15:10:31 ip-10-71-252-15 kernel: [72316.456922] audit: type=1400 audit(1691507431.947:353): apparmor="ALLOWED" operation="open" profile="/usr/sbin/mysqld" name="/etc/my.cnf" pid=22506 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=114 ouid=0
Aug  8 15:10:31 ip-10-71-252-15 kernel: [72316.456991] audit: type=1400 audit(1691507431.947:354): apparmor="ALLOWED" operation="open" profile="/usr/sbin/mysqld" name="/mnt/data/mysql/my.cnf" pid=22506 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=114 ouid=114
Aug  8 15:10:32 ip-10-71-252-15 systemd[1]: mysql.service: Control process exited, code=exited, status=1/FAILURE
Aug  8 15:10:32 ip-10-71-252-15 systemd[1]: mysql.service: Failed with result 'exit-code'.
Aug  8 15:10:32 ip-10-71-252-15 systemd[1]: Failed to start Percona MySQL Server.
Aug  8 15:10:32 ip-10-71-252-15 systemd[1]: mysql.service: Scheduled restart job, restart counter is at 2.
Aug  8 15:10:32 ip-10-71-252-15 systemd[1]: Stopped Percona MySQL Server.
Aug  8 15:10:32 ip-10-71-252-15 systemd[1]: Starting Percona MySQL Server...
Aug  8 15:10:33 ip-10-71-252-15 systemd[1]: mysql.service: Control process exited, code=exited, status=1/FAILURE
Aug  8 15:10:33 ip-10-71-252-15 systemd[1]: mysql.service: Failed with result 'exit-code'.
Aug  8 15:10:33 ip-10-71-252-15 systemd[1]: Failed to start Percona MySQL Server.
Aug  8 15:10:33 ip-10-71-252-15 systemd[1]: mysql.service: Scheduled restart job, restart counter is at 3.
Aug  8 15:10:33 ip-10-71-252-15 systemd[1]: Stopped Percona MySQL Server.
Aug  8 15:10:33 ip-10-71-252-15 systemd[1]: Starting Percona MySQL Server...
Aug  8 15:10:33 ip-10-71-252-15 systemd[1]: mysql.service: Control process exited, code=exited, status=1/FAILURE
Aug  8 15:10:33 ip-10-71-252-15 systemd[1]: mysql.service: Failed with result 'exit-code'.
Aug  8 15:10:33 ip-10-71-252-15 systemd[1]: Failed to start Percona MySQL Server.
Aug  8 15:10:34 ip-10-71-252-15 systemd[1]: mysql.service: Scheduled restart job, restart counter is at 4.
Aug  8 15:10:34 ip-10-71-252-15 systemd[1]: Stopped Percona MySQL Server.
Aug  8 15:10:34 ip-10-71-252-15 systemd[1]: Starting Percona MySQL Server...
Aug  8 15:10:34 ip-10-71-252-15 systemd[1]: mysql.service: Control process exited, code=exited, status=1/FAILURE
Aug  8 15:10:34 ip-10-71-252-15 systemd[1]: mysql.service: Failed with result 'exit-code'.
Aug  8 15:10:34 ip-10-71-252-15 systemd[1]: Failed to start Percona MySQL Server.
Aug  8 15:10:34 ip-10-71-252-15 systemd[1]: mysql.service: Scheduled restart job, restart counter is at 5.
Aug  8 15:10:34 ip-10-71-252-15 systemd[1]: Stopped Percona MySQL Server.
Aug  8 15:10:34 ip-10-71-252-15 systemd[1]: mysql.service: Start request repeated too quickly.
Aug  8 15:10:34 ip-10-71-252-15 systemd[1]: mysql.service: Failed with result 'exit-code'.
Aug  8 15:10:34 ip-10-71-252-15 systemd[1]: Failed to start Percona MySQL Server.

Any ideas?

Thanks!

2

Hi Gabe,

Could it be that apparmor is blocking access to configuration files?

Screenshot 2023-08-08 at 19.03.55
Screenshot 2023-08-08 at 19.03.551311×305 16.8 KB

3

Hi,

I don’t think so. I stopped apparmor systemctl stop apparmor , confirmed that it was indeed stopped, and then tried starting MySQL. It still failed.

Thanks

4

Also, in the mysqld.log, I see that mysql starts, and then it is shutdown immediately. This did not happen today though, this is what it looked like yesterday. I’ll try to get back to this point. :crossed_fingers: :

2023-08-07T19:06:09.361581Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.31-23) starting as process 794
2023-08-07T19:06:09.712686Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2023-08-07T19:06:11.918692Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2023-08-07T19:06:13.562833Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2023-08-07T19:06:13.562887Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2023-08-07T19:06:13.655102Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: '0.0.0.0' port: 33060, socket: /var/run/mysqld/mysqlx.sock
2023-08-07T19:06:13.655237Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: '8.0.31-23'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  Percona Server (GPL), Release '23', Revision '71449379'.
2023-08-07T19:08:14.927744Z 0 [System] [MY-013172] [Server] Received SHUTDOWN from user <via user signal>. Shutting down mysqld (Version: 8.0.31-23).
2023-08-07T19:08:16.320018Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.0.31-23)  Percona Server (GPL), Release '23', Revision '71449379'.
5

Hi @Gabe,

About "mysql starts, and then it is shutdown immediately" I think it has to do with the timeout for the service to start.

I’d suggest adding the following;


[Service]
TimeoutStartSec=6000

$ systemctl daemon-reload

Thanks,
K

6

Hi

I have some more details - I found the mysqld.log file being used.

2023-08-08T18:41:00.521676Z 0 [Warning] [MY-013907] [InnoDB] Deprecated configuration parameters innodb_log_file_size and/or innodb_log_files_in_group have been used to compute innodb_redo_log_capacity=8589934592. Please use innodb_redo_log_capacity instead.
2023-08-08T18:41:00.524550Z 1 [System] [MY-011012] [Server] Starting upgrade of data directory.
2023-08-08T18:41:00.524625Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2023-08-08T18:41:05.643951Z 1 [ERROR] [MY-012526] [InnoDB] Upgrade is not supported after a crash or shutdown with innodb_fast_shutdown = 2. This redo log was created with MySQL 5.7.34-37, and it appears logically non empty. Please follow the instructions at http://dev.mysql.com/doc/refman/8.0/en/upgrading.html
2023-08-08T18:41:05.644198Z 1 [ERROR] [MY-012930] [InnoDB] Plugin initialization aborted with error Generic error.
2023-08-08T18:41:06.249897Z 1 [ERROR] [MY-011013] [Server] Failed to initialize DD Storage Engine.
2023-08-08T18:41:06.250389Z 0 [ERROR] [MY-010020] [Server] Data Dictionary initialization failed.
2023-08-08T18:41:06.250457Z 0 [ERROR] [MY-010119] [Server] Aborting
2023-08-08T18:41:06.255234Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.0.31-23)  Percona Server (GPL), Release '23', Revision '71449379'.

I am building out V8 using a snapshot of V5.7.
This step is restoring a snapshot of the data/logs from 5.7 and then starting MySQL V8.

Thanks

7

I am starting to believe that I cannot restore a V5.7 snapshot for upgrade to V8…

8

Hi @Gabe
This is a major upgrade, and although you could do an in-place upgrade, it would require you to stop MySQL properly before trying to start using the new binaries.

From the logs and the information you shared, I’m guessing the snapshot was taken while MySQL 5.7 was running:

2023-08-08T18:41:05.643951Z 1 [ERROR] [MY-012526] [InnoDB] Upgrade is not supported after a crash or shutdown with innodb_fast_shutdown = 2. This redo log was created with MySQL 5.7.34-37, and it appears logically non empty. Please follow the instructions at http://dev.mysql.com/doc/refman/8.0/en/upgrading.html

As the error in there mentions, you could take a look at the docs; or you could also look at this page from our Percona Docs.

Quoting from the Percona Page:

Do not upgrade from 5.7 to 8.0 on a crashed instance. If the server instance has crashed, run the crash recovery before proceeding with the upgrade.

Please try following the proper steps for upgrading.

Best,
Mauricio

1 Like
9

Hi @Gabe
The recommendation for an in-place upgrade is to always shutdown the 5.7 instance with

SET GLOBAL innodb_fast_shutdown=0;

It will perform a clean shutdown by doing a full undo log purge and change buffer merge.

Then you can proceed with the upgrade to 8.0 as explained in the docs