MySQL Bugs: #98983: mysqld startup very slowly

Bug #98983	mysqld startup very slowly
Submitted:	18 Mar 2020 4:28	Modified:	27 Mar 2020 2:08
Reporter:	Samson Lin	Email Updates:
Status:	Not a Bug	Impact on me:	None
Category:	MySQL Server	Severity:	S5 (Performance)
Version:	5.7.29	OS:	Red Hat (7.7)
Assigned to:		CPU Architecture:	x86 (64-bit)

Description:
I encountered a performance issue when starting mysqld.  

I have reported a bug #98644 before which relates to it.  There may be a bug in mysql v5.7.29 which may result in slow startup after installation.  It required 14 mins to start up.  At first, we suspected there may be performance issue in disk.  Later, my system admin colleague installed a new version of RedHat 7.7 using his own method.  mysqld started in seconds normally.

As the RHEL version my colleague installed is in text mode but I need GUI interface, I re-installed it in server GUI mode myself.  Then after installing mysql, the slow startup issue happened again.

Here below are the configuration...

(1) Disk mapping:
NAME            MAJ:MIN RM  SIZE RO TYPE MOUNTPOINT
sda               8:0    0  300G  0 disk
├─sda1            8:1    0    1G  0 part /boot
└─sda2            8:2    0  201G  0 part
  ├─rhel-root   253:0    0   20G  0 lvm  /
  ├─rhel-swap   253:1    0    8G  0 lvm  [SWAP]
  ├─rhel-usr    253:2    0   10G  0 lvm  /usr
  ├─rhel-home   253:3    0    5G  0 lvm  /home
  ├─rhel-var    253:4    0  110G  0 lvm  /var
  ├─rhel-opt    253:5    0    5G  0 lvm  /opt
  ├─rhel-tmp    253:6    0    5G  0 lvm  /tmp
  └─rhel-splunk 253:7    0    5G  0 lvm  /opt/splunkforwarder
sr0              11:0    1 1024M  0 rom

/home									5120MiB	LVM	xfs  VG: rhel
/opt									5120MiB	LVM	xfs  VG: rhel
/opt/splunkforwarder	5120MiB	LVM	xfs  VG: rhel
/var									110GiB	LVM xfs  VG: rhel
/tmp									5120MiB LVM xfs  VG: rhel
/usr									10GiB   LVM xfs  VG: rhel
/boot									1024MiB Standard xfs
/											20GiB   LVM xfs  VG: rhel
swap									8192MiB LVM xfs  VG: rhel

(2) Software Selection

 - Server with GUI
   - Performance Tools
   - Compatibility Libraries
   - Development Tools
   - Systems Administration Tools

(3) Security Policy

- ‘United States Government Configuration Baseline’

(4) Hardware config
- ESXi 6.0 virtual machine
- 4 CPU
- 8192 MB Ram
- 300 GB hard disk

It is hard to tell whether it is RHEL issue or mysql.  But disk performance should not be the cause.

# dd if=/dev/zero of=/var/lib/mysql/deleteme.random bs=1024 count=137216
137216+0 records in
137216+0 records out
140509184 bytes (141 MB) copied, 0.951179 s, 148 MB/s

# dd if=/dev/zero of=/var/lib/mysql/deleteme.random bs=1024 count=137216 conv=sync
137216+0 records in
137216+0 records out
140509184 bytes (141 MB) copied, 1.00152 s, 140 MB/s

How to repeat:
Install RHEL 7.7 in the above hardware and software configuration.

When there is mysql slow startup issue, I will find the following entry in /var/log/mysqld.log:

InnoDB: page_cleaner: 1000ms intended loop took 22285ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)

Hi Mr. Lin,

Thank you for your bug report.

Our server does not have text version or GUI version. Hence, I truly do not know what are you writing about.

Also, as a message from server states clearly, you have not configured your server correctly.

Hence, as far as I can see, this does not look like a bug at all. At least not MySQL bug.

Hi Sinisa,

Thank you for your advice.  Actually I already made a support call to RedHat yesterday.  I am not a newbie in RHEL and mysql.  I have several years' experience in both of them.  This issue was encountered by me the very first time.

I am waiting for RedHat response.

Hi Sinisa,

For RedHat setup, there are not much tuning you may do during installation.  I have installed and used many versions of mysql in these years.  I didn't need to tune RedHat before mysql installation and they ran smoothly.

Does mysql version v5.7.29 need OS or software tuning before installation?

Hi Mr. Lin,

In general, tuning MySQL is necessary and tuning OS is desirable.

Since this sounds like a Red Hat bug, I am setting it as not a bug.

In order to verify the report as a bug, we would need a repeatable test case with our official binaries. What you are reporting is a bug in Red Hat.

Not a bug.

I uninstalled mysql 5.7.29.  And then I installed mysql 5.6.47 in the same server without any OS or software tuning.

There is no slow startup issue!

# systemctl status mysql
● mysql.service - LSB: start and stop MySQL
   Loaded: loaded (/etc/rc.d/init.d/mysql; bad; vendor preset: disabled)
   Active: active (running) since Fri 2020-03-20 18:11:04 HKT; 2min 29s ago
     Docs: man:systemd-sysv-generator(8)
  Process: 3569 ExecStop=/etc/rc.d/init.d/mysql stop (code=exited, status=0/SUCCESS)
  Process: 3598 ExecStart=/etc/rc.d/init.d/mysql start (code=exited, status=0/SUCCESS)
    Tasks: 23
   CGroup: /system.slice/mysql.service
           ├─3604 /bin/sh /usr/bin/mysqld_safe --datadir=/var/lib/mysql --pid-file=/var/lib/mysql/jira87x.pid
           └─3702 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugi...

Mar 20 18:11:03 jira87x systemd[1]: Starting LSB: start and stop MySQL...
Mar 20 18:11:04 jira87x mysql[3598]: Starting MySQL. SUCCESS!
Mar 20 18:11:04 jira87x systemd[1]: Started LSB: start and stop MySQL.

One second is used to start mysqld.

Here attached is a document (20200320 mysql 5.6.47 installation.txt) with mysql 5.6.47 installation output.

mysql 5.6.47 installation output

Attachment: 20200320 mysql 5.6.47 installation.txt (text/plain), 6.84 KiB.

May you install a VM environment like us and have a try and test?

Hi Mr. Lin,

Try installing our latest 5.7 official package ...... you should not have problems either.

I downloaded again the mysql community version mysql-5.7.29-1.el7.x86_64.rpm-bundle.tar.  MD5 checksum correct.  I uninstalled mysql 5.6.47 by 'rpm -e', deleted the directory, '/var/lib/mysql', manually. Then I started v5.7.29 installation.

The first time start used 26 mins.  Then I stopped and started it again.  This time used 28 mins.

When mysqld was starting, I grep mysql process and found the following entry:

root     11501     1  0 10:57 ?        00:00:00 /bin/bash /usr/bin/mysqld_pre_systemd

What is the function of mysqld_pre_systemd?  It seems starting process stuck here.

Here attached is the mysql v5.7.29 installation result and mysqld.log.  Please have a look.

5.7.29 installation log

Attachment: 20200323 Install mysql 5.7.29.txt (text/plain), 4.89 KiB.

mysqld.log on 5.7.29

Attachment: mysqld.zip (application/x-zip-compressed, text), 4.45 KiB.

Hi Mr. Lin,

Have you followed my recommendation from March 20th ???

Your comment on Mar 20 is "Try installing our latest 5.7 official package", not Enterprise version.

The latest 5.7 version is 5.7.29.  I downloaded from the following url:
https://dev.mysql.com/downloads/mysql/

Please see my attachment.

URL and options I selected to download mysql 5.7.29

Attachment: 20200324 mysql download 1.JPG (image/jpeg, text), 46.07 KiB.

Installation tar file downloaded

Attachment: 20200324 mysql download 2.JPG (image/jpeg, text), 41.95 KiB.

As I have mentioned on [23 Mar 3:43], when mysqld was starting, I grep mysql process and found the following entry:

root     11501     1  0 10:57 ?        00:00:00 /bin/bash /usr/bin/mysqld_pre_systemd

What is the function of mysqld_pre_systemd?  During the 26 mins starting period, I only found this process running.  It seems process stuck here.

related: https://bugs.mysql.com/bug.php?id=96340

Thank you, Shane.

The bug you have mentioned is mysql installed with a large amount of user tables.  But for my case, I haven't created any user tables.  Just installed mysql 5.7.29 and started up very slowly.

See if putting innodb_flush_log_at_trx_commit=0 and sync_binlog=0 in my.cnf helps.
If that helps,  the issue is too slow fsync on your system.

I have added those parameters into /etc/my.cnf as follows:

[mysqld]
innodb_flush_log_at_trx_commit=0
sync_binlog=0

Before updating the above parameters, mysqld startup needed 30 mins.  After adding the parameters, it needed 26 mins.  No big difference.

# systemctl status mysqld
● mysqld.service - MySQL Server
   Loaded: loaded (/usr/lib/systemd/system/mysqld.service; enabled; vendor preset: disabled)
   Active: active (running) since Tue 2020-03-24 16:30:22 HKT; 25min ago
     Docs: man:mysqld(8)
           http://dev.mysql.com/doc/refman/en/using-systemd.html
  Process: 6663 ExecStart=/usr/sbin/mysqld --daemonize --pid-file=/var/run/mysqld/mysqld.pid $MYSQLD_OPTS (code=exited, status=0/SUCCESS)
  Process: 6254 ExecStartPre=/usr/bin/mysqld_pre_systemd (code=exited, status=0/SUCCESS)
 Main PID: 6666 (mysqld)
    Tasks: 27
   CGroup: /system.slice/mysqld.service
           └─6666 /usr/sbin/mysqld --daemonize --pid-file=/var/run/mysqld/mysqld.pid

Mar 24 16:04:37 jira87x systemd[1]: Starting MySQL Server...
Mar 24 16:30:22 jira87x systemd[1]: Started MySQL Server.

Here attached are files including my.cnf and mysqld.log

/etc/my.cnf with suggested parameters

Attachment: my.cnf (application/octet-stream, text), 1.00 KiB.

/var/log/mysqld.log

Attachment: mysqld.log (application/octet-stream, text), 42.86 KiB.

For every start of mysqld, it seems it must go through the process, 'mysqld_pre_systemd'.

After searching the web, I found 'mysqld_pre_systemd' is a bash script file that generates the data directory when mysqld is started for the first time via systemctl. This script is run by systemd before starting mysqld in order to check for the presence of a proper data/mysql directory within the data directory location specified. If the data/mysql directory doesn’t exist, then systemd runs mysqld with the --initialize option to create the data directory.

But after 1st data initialization, there was /var/lib/mysql created.  Why every time start still needs a long time on 'mysqld_pre_systemd'?

The following dd results do not show slow disk scenario.

# dd if=/dev/zero of=/var/lib/mysql/deleteme.random bs=1024 coun                      t=137216
137216+0 records in
137216+0 records out
140509184 bytes (141 MB) copied, 0.549477 s, 256 MB/s

# dd if=/dev/zero of=/var/lib/mysql/deleteme.random bs=1024 count=137216 conv=sync
137216+0 records in
137216+0 records out
140509184 bytes (141 MB) copied, 0.874502 s, 161 MB/s

Hi Mr. Lin,

What you are experiencing are problems starting MySQL with systemd and its tools. This forum is dedicated only to MySQL product and systemd and systemctl are not our products.

Try starting mysqld as a daemon from the command line, like this:

mysqld --defaults-file=/path_towards_my_cnf/my.cnf &

You must put all options in that my.cnf. Do not forget to define user under which the daemon is running and datadir, among all other stuff. Also, OS privileges on datadir should be set properly.

If MySQL server starts fast, then this bug is not ours.

I followed your advice and started mysqld:

# mysqld --user=root --defaults-file=/etc/my.cnf &

It couldn't be started.  From /var/log/mysqld.log, I found the following entry:

2020-03-25T03:09:35.964493Z 0 [ERROR] unknown variable 'defaults-file=/etc/my.cnf'

Then I started mysqld using the following command line:

# mysqld --user=root &

It worked.  No time lag.  I will inform RedHat support about it.

From mysql community download site (https://dev.mysql.com/downloads/mysql/), there are options for download, e.g. for redhat v6.x/v7.x.  It means mysql developers should have tailored-made mysqld for different OS and platforms.  And before production, they should have performed test on it, either starting mysqld alone or by systemctl.

Have you tested v5.7.29 on RHEL using systemctl command?

Hi,

I am advising you strongly to read our Reference Manual.

It states there, very clearly, that --defaults-file=..... must be a first argument.

I hope that you have already read in our RefMan about using systemd with MySQL.

Not a bug.

Hi Sinisa,

I am not complaining about the following command which does not work:
# mysqld --user=root --defaults-file=/etc/my.cnf &

I am asking for solution on how to solve the slow startup issue on mysql v5.7.29.  And I am querying about whether it is your responsiblility to test systemctl on starting/stopping mysqld, even though RHEL is not your product.  Does mysql manual mentions that user should not or must not start mysql in RHEL by systemctl command?

Hi Mr. Lin,

This is a forum for bugs that can be verified. This is not a forum for free support.

You can find all instructions you need in our 5.7 manual, paragraph 2.5.10.

Not a bug.