Slow startup of mariadb

Issues related to applications and software problems and general support
Jean-Pierre
Posts: 12
Joined: 2020/05/31 16:36:25

Slow startup of mariadb

Post by Jean-Pierre » 2020/05/31 17:27:10

Hi all,

I have recently upgraded to Centos 8 on several computers (fresh installs). Doing so implied upgrading a mariadb database for switching from mariadb 5.5.64 to 10.3.17.

I see this is causing a long bootup :

Code: Select all

[root@optiplex doc]# systemd-analyze blame
         28.293s mariadb.service
          9.660s udisks2.service
          9.615s cups.service
          9.401s sssd.service
Similar times are experienced on all Centos 8 installations during bootup, but after the initialization phase, the response times for queries and updates are normal.

I do not really understand the only warning I can find :

Code: Select all

May 31 08:01:25 optiplex mysql-prepare-db-dir[1729]: Database MariaDB is probably initialized in /home/mysql already, nothing is done.
May 31 08:01:25 optiplex mysql-prepare-db-dir[1729]: If this is not the case, make sure the /home/mysql is empty before running mysql-prepare-db-dir.
I still have a Centos 7 installation on a slower computer with less memory, with the same database, and the bootup is much faster :

Code: Select all

[root@precision doc]# systemd-analyze blame
          8.998s mariadb.service
          5.265s kdump.service
          5.212s akmods.service
          4.785s tuned.service
The only similar issue pointed at by Google is about refreshening the time zone data, but this is for another version, ... and I do not understand the cure (probably not relevant).

Am I the only user to experience this ?

Any idea of what can I do to improve the bootup of mariadb ?

Jean-Pierre

gerry666uk
Posts: 98
Joined: 2020/02/10 19:06:06

Re: Slow startup of mariadb

Post by gerry666uk » 2020/06/01 20:10:59

You need to prevent it starting up automatically at boot time (for now), then stop mariadb, then reboot and see if the boot up is fast.
Assuming the boot up is now fast, the next step is to start mariadb manually, and watch all the log messages from both systemd, and also the mariadb log itself, and this should show where it slowing down. If you copied old binary data from mariadb 5.x and are now using it in 10.3, bad things could happen, but if you installed 10.3 clean and then imported from dumps, it should be ok.

Jean-Pierre
Posts: 12
Joined: 2020/05/31 16:36:25

Re: Slow startup of mariadb

Post by Jean-Pierre » 2020/06/03 12:34:27

Thanks for your reply.

First, from the mariadb log, when starting up today :

Code: Select all

2020-06-03  8:02:06 0 [Note] InnoDB: Completed initialization of buffer pool
2020-06-03  8:02:06 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2020-06-03  8:02:14 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2020-06-03  8:02:14 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2020-06-03  8:02:14 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2020-06-03  8:02:22 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2020-06-03  8:02:22 0 [Note] InnoDB: 10.3.17 started; log sequence number 497859003; transaction id 45991780
So it took 16 seconds creating rollback segments and building ./ibtmp1...

While closing down yesterday, I see :

Code: Select all

2020-06-02 22:18:31 0 [Note] InnoDB: Buffer pool(s) dump completed at 200602 22:18:31
2020-06-02 22:18:33 0 [Note] InnoDB: Shutdown completed; log sequence number 497859003; transaction id 45991778
2020-06-02 22:18:33 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2020-06-02 22:18:33 0 [Note] /usr/libexec/mysqld: Shutdown complete
So ibtmp1 has to be rebuilt because it is deleted on shutdown.

Now, disabling mariadb, then rebooting, then reenabling mariadb :

Code: Select all

[reboot]

[linux@optiplex doc]$ systemd-analyze blame
          9.468s sssd.service
          8.787s udisks2.service
          7.938s vdo.service
          7.841s NetworkManager-wait-online.service

[root@optiplex doc]# systemctl enable mariadb
Created symlink /etc/systemd/system/mysql.service  /usr/lib/systemd/system/mariadb.service.
Created symlink /etc/systemd/system/mysqld.service  /usr/lib/systemd/system/mariadb.service.
Created symlink /etc/systemd/system/multi-user.target.wants/mariadb.service  /usr/lib/systemd/system/mariadb.service.
[root@optiplex doc]# time systemctl start mariadb

real	0m3.469s
user	0m0.006s
sys	0m0.004s
This is quite fast !

The mariadb log shows :

Code: Select all

2020-06-03 13:37:51 0 [Note] InnoDB: Completed initialization of buffer pool
2020-06-03 13:37:51 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2020-06-03 13:37:52 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2020-06-03 13:37:52 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2020-06-03 13:37:52 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2020-06-03 13:37:52 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2020-06-03 13:37:52 0 [Note] InnoDB: Waiting for purge to start
2020-06-03 13:37:52 0 [Note] InnoDB: 10.3.17 started; log sequence number 497974104; transaction id 45992071
The sequence which lasted 16 seconds on bootup, is now performed in a couple of seconds !

Nothing special is seen in the systemd log :

Code: Select all

[root@optiplex doc]# journalctl
Jun 03 13:37:50 optiplex.localdomain systemd[1]: Starting MariaDB 10.3 database server...
Jun 03 13:37:51 optiplex.localdomain mysql-prepare-db-dir[2699]: Database MariaDB is probably initialized in /home/mysql already, nothing is done.
Jun 03 13:37:51 optiplex.localdomain mysql-prepare-db-dir[2699]: If this is not the case, make sure the /home/mysql is empty before running mysql-prepare-db-dir.
Jun 03 13:37:51 optiplex.localdomain mysqld[2738]: 2020-06-03 13:37:51 0 [Note] /usr/libexec/mysqld (mysqld 10.3.17-MariaDB) starting as process 2738 ...
Jun 03 13:37:54 optiplex.localdomain systemd[1]: Started MariaDB 10.3 database server.
It looks like the time is spent initializing some database file. The database is stored in /home which is in its own partition and assumed to not be accessed by other processes during bootup until a user logs in. Also /home is mounted and checked much earlier.

Note : I did a full fresh install of Centos8 (including mariadb), but the database was created fifteen years ago on mysql, and has been upgraded several times, whenever a newer system is installed.

Am I really the only user experiencing this long startup ?

Jean-Pierre

User avatar
TrevorH
Site Admin
Posts: 33216
Joined: 2009/09/24 10:40:56
Location: Brighton, UK

Re: Slow startup of mariadb

Post by TrevorH » 2020/06/03 12:55:35

If it takes 8 seconds to write a 12MB file then there is something quite seriously wrong with your disk subsystem. Is it using a floppy disk?
The future appears to be RHEL or Debian. I think I'm going Debian.
Info for USB installs on http://wiki.centos.org/HowTos/InstallFromUSBkey
CentOS 5 and 6 are deadest, do not use them.
Use the FAQ Luke

Jean-Pierre
Posts: 12
Joined: 2020/05/31 16:36:25

Re: Slow startup of mariadb

Post by Jean-Pierre » 2020/06/03 15:00:48

there is something quite seriously wrong with your disk subsystem
And the same defect on several computers ?
Is it using a floppy disk?
Would have to be a floppy disk with a gearbox for speeding after the startup is done...

TodoInTX
Posts: 1
Joined: 2022/04/25 03:41:18

Re: Slow startup of mariadb

Post by TodoInTX » 2022/04/25 03:52:52

I just wanted to add something to look at when encountering long restart times for MariaDB/MySQL.

MariaDB [(none)]> pager grep History
PAGER set to 'grep History'
MariaDB [(none)]> show engine innodb status \G
History list length 579453868. <-- THIS NUMBER
1 row in set (0.001 sec)

If the length of the history list (number of unpurged transactions) is large the service restart time can be extended as crash recovery will need to scan across all of these. This history list can grow into the 100s of millions on busy servers that also handles any long running transactions (like reporting queries, mysqldump, or CHECK TABLES on large innodb tables).

I had a database take nearly 5 hours to restart after a CHECK TABLE was allowed to run for a month.

Jean-Pierre
Posts: 12
Joined: 2020/05/31 16:36:25

Re: Slow startup of mariadb

Post by Jean-Pierre » 2022/04/25 14:08:16

Thank you for unearthing this report. This issue is still unsolved (now on Alma Linux 8.5), and I am surprised to be the only one to have to face it.

My mariadb data base is mostly read-only, with about one update session per month. So if you mean consolidating the committed transactions which were not consolidated before the previous shutdown, I feel this as unlikely.

Mariadb still takes 15s to initialize :

Code: Select all

[linux@optiplex doc]$ systemd-analyze blame
         25.801s mariadb.service
         10.905s udisks2.service
         10.564s vdo.service
          9.792s sssd.service
          9.287s etc. 
I have this on several computers, and this was not the case on Centos 7 (I have no Centos 7 configuration any more to show the difference).

And the critical chain shows :

Code: Select all

graphical.target @55.158s
└─multi-user.target @55.158s
  └─mariadb.service @29.356s +25.801s
    └─network.target @29.323s
      └─NetworkManager.service @28.870s +451ms
        └─network-pre.target @28.869s
          └─firewalld.service @25.907s +2.962s
            └─polkit.service @16.598s +9.287s
              └─basic.target @16.554s
So mariadb looks like it depends on the network. I do not need that, the data base is only accessed through a local application (which is accessed through the network, but has to be started manually). Therefore I have disabled the network access in /etc/my.cnf.d/mariadb-server.cnf :

Code: Select all

# This group is only read by MariaDB servers, not by MySQL.
# If you use the same .cnf file for MySQL and MariaDB,
# you can put MariaDB-only options here
[mariadb]
skip-networking
But this made no difference whatsoever. Does mariadb want to call home ?

The critical chain also looks like it shows the multi-user target depends on mariadb. This is sort of confirmed in /var/log/messages, with the multi-user target waiting for the database to be started :

Code: Select all

Apr 25 07:50:31 optiplex systemd[1]: NetworkManager-dispatcher.service: Succeeded.
Apr 25 07:50:32 optiplex systemd[1]: Started MariaDB 10.5 database server.
Apr 25 07:50:32 optiplex systemd[1]: Reached target Multi-User System.
Apr 25 07:50:32 optiplex systemd[1]: Reached target Graphical Interface.
Why can it be so ? The applications which use the data base have to be started manually.

How could I get mariadb to be initialized in the background, with the multi-user target not having to wait for it ?

And am I really the only one to face this behavior ?

EDIT : I should have added :

Code: Select all

Trx id counter 46021367
Purge done for trx's n:o < 46021365 undo n:o < 0 state: running
History list length 2
So nothing suspicious there.

User avatar
TrevorH
Site Admin
Posts: 33216
Joined: 2009/09/24 10:40:56
Location: Brighton, UK

Re: Slow startup of mariadb

Post by TrevorH » 2022/04/25 15:28:30

└─firewalld.service @25.907s +2.962s
Is firewalld set up to use a giant ipset of some description?
The future appears to be RHEL or Debian. I think I'm going Debian.
Info for USB installs on http://wiki.centos.org/HowTos/InstallFromUSBkey
CentOS 5 and 6 are deadest, do not use them.
Use the FAQ Luke

Jean-Pierre
Posts: 12
Joined: 2020/05/31 16:36:25

Re: Slow startup of mariadb

Post by Jean-Pierre » 2022/04/25 16:26:08

Thanks for helping.
Is firewalld set up to use a giant ipset of some description?
The firewall has the default set up (allowing inbound ssh, dhcp6-client and cockpit), to which I have added ftp. Cockpit is not installed, and no inbound connection is routed by the public access router, these services are for local use only. Access to mariadb is not open in the firewall.

Starting the firewall may have some impact on opening the network services, but the mariadb server needs no network service, the more as it is (supposed to be) configured as "skip-networking".

User avatar
TrevorH
Site Admin
Posts: 33216
Joined: 2009/09/24 10:40:56
Location: Brighton, UK

Re: Slow startup of mariadb

Post by TrevorH » 2022/04/25 17:14:13

Yeah but in the chain of things here, mariadb is taking 29-30s and at least part of that appears to be waiting for the network and from that analyze-blame output, it would seem that more than 25s of that is waiting for firewalld. So the thing to fix here seems to be firewalld and then see if everything else improves as a result.
The future appears to be RHEL or Debian. I think I'm going Debian.
Info for USB installs on http://wiki.centos.org/HowTos/InstallFromUSBkey
CentOS 5 and 6 are deadest, do not use them.
Use the FAQ Luke

Post Reply