Bug #93684 mysql innodb dump restore slows down after upgrade mysql 5.7 to 8.0
Submitted: 19 Dec 2018 12:28 Modified: 21 Jan 2019 13:17
Reporter: Florian Kopp Email Updates:
Status: Not a Bug Impact on me:
None 
Category:MySQL Server: mysqldump Command-line Client Severity:S5 (Performance)
Version:8.0.13 OS:Debian (9.6 Stretch)
Assigned to: CPU Architecture:x86 (Intel CPU)
Tags: mysql-8.0, mysqldump, mysqlrestore

[19 Dec 2018 12:28] Florian Kopp
Description:
Restoring a 25MB SQL dump with only innodb tables on a mysql 5.7 server takes about 10 seconds. With a mysql 8.0.13 server it takes about 8 minutes (with exactly the same hardware/software configuration).

The dump was created manually and executed with the following command:

$ mysql -uuser -p database < database.sql

This issue is tested on a virtual testserver with exactly the same hard- and software configuration in all test cases:

OS: Debian 9.6 / Kernel 4.9.0-8-amd64 / Proxmox 3.2
Disk: SSD
CPU: 4 CPU Cores / Intel(R) Xeon(R) CPU E3-1230 V2 @ 3.30GHz
RAM: 2 GB

Content of my.cnf on both servers (5.7 and 8.0.13):

[mysqld]
pid-file        = /var/run/mysqld/mysqld.pid
socket          = /var/run/mysqld/mysqld.sock
datadir         = /var/lib/mysql
log-error       = /var/log/mysql/error.log
innodb_buffer_pool_size = 2048M
innodb_log_buffer_size = 64M
innodb_log_file_size = 265M
innodb_flush_log_at_trx_commit=2
innodb_flush_method=O_DIRECT
max_allowed_packet = 512G

The used test database contains only the two tables "authors" and "posts" with randomly generated content (and a single foreign key). 

How to repeat:
1. Install two Debian 9.6 VMs with the same hardware specification like mentioned above.
2. Install mysql-5.7 on the one and mysql 8.0 on the other VM with the mysql-deb-file https://dev.mysql.com/get/mysql-apt-config_0.8.10-1_all.deb
3. Add the following lines to the /etc/mysql/mysql.conf.d/mysqld.cnf on both machines:

innodb_buffer_pool_size = 2048M
innodb_log_buffer_size = 64M
innodb_log_file_size = 265M
innodb_flush_log_at_trx_commit=2
innodb_flush_method=O_DIRECT
max_allowed_packet = 512G

4. Restart the mysql service
5. Create a SQL file with the follwoing content:

/*!40101 SET @OLD_CHARACTER_SET_CLIENT=@@CHARACTER_SET_CLIENT */;
/*!40101 SET @OLD_CHARACTER_SET_RESULTS=@@CHARACTER_SET_RESULTS */;
/*!40101 SET @OLD_COLLATION_CONNECTION=@@COLLATION_CONNECTION */;
/*!40101 SET NAMES utf8 */;
/*!40103 SET @OLD_TIME_ZONE=@@TIME_ZONE */;
/*!40103 SET TIME_ZONE='+00:00' */;
/*!40014 SET @OLD_UNIQUE_CHECKS=@@UNIQUE_CHECKS, UNIQUE_CHECKS=0 */;
/*!40014 SET @OLD_FOREIGN_KEY_CHECKS=@@FOREIGN_KEY_CHECKS, FOREIGN_KEY_CHECKS=0 */;
/*!40101 SET @OLD_SQL_MODE=@@SQL_MODE, SQL_MODE='NO_AUTO_VALUE_ON_ZERO' */;
/*!40111 SET @OLD_SQL_NOTES=@@SQL_NOTES, SQL_NOTES=0 */;

#
# TABLE STRUCTURE FOR: authors
#

DROP TABLE IF EXISTS `authors`;

CREATE TABLE `authors` (
  `id` int(11) NOT NULL AUTO_INCREMENT,
  `first_name` varchar(50) COLLATE utf8_unicode_ci NOT NULL,
  `last_name` varchar(50) COLLATE utf8_unicode_ci NOT NULL,
  `email` varchar(100) COLLATE utf8_unicode_ci NOT NULL,
  `birthdate` date NOT NULL,
  `added` timestamp NOT NULL DEFAULT current_timestamp(),
  PRIMARY KEY (`id`),
  UNIQUE KEY `email` (`email`)
) ENGINE=InnoDB AUTO_INCREMENT=1001 DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci;

INSERT INTO `authors` (`id`, `first_name`, `last_name`, `email`, `birthdate`, `added`) VALUES (1, 'Aaliyah', 'Zulauf', 'vanessa.wiza@example.com', '1973-04-26', '1994-04-01 02:34:35');
INSERT INTO `authors` (`id`, `first_name`, `last_name`, `email`, `birthdate`, `added`) VALUES (2, 'Renee', 'Becker', 'twalker@example.net', '1986-10-02', '1971-12-15 23:37:10');
[... and other 1.000 random inserts like this... ]

#
# TABLE STRUCTURE FOR: posts
#

DROP TABLE IF EXISTS `posts`;

CREATE TABLE `posts` (
  `id` int(11) NOT NULL AUTO_INCREMENT,
  `author_id` int(11) NOT NULL,
  `title` varchar(255) COLLATE utf8_unicode_ci NOT NULL,
  `description` varchar(500) COLLATE utf8_unicode_ci NOT NULL,
  `content` text COLLATE utf8_unicode_ci NOT NULL,
  `date` date NOT NULL,
  PRIMARY KEY (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=57901 DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci;

INSERT INTO `posts` (`id`, `author_id`, `title`, `description`, `content`, `date`) VALUES (1, 1, 'Quia aspernatur ea laboriosam blanditiis ut tempore.', 'Eius sit quia est quo sed molestiae. Fugiat molestiae illo omnis id fugiat voluptatibus tempore. Sed vitae velit doloribus animi autem.', 'Temporibus aut voluptates et vel reiciendis sapiente praesentium. Qui in quasi provident dolor eligendi praesentium vel. Autem aut consequatur culpa et.', '1996-09-23');
INSERT INTO `posts` (`id`, `author_id`, `title`, `description`, `content`, `date`) VALUES (2, 2, 'Modi doloribus dolorum sed id et ut voluptate.', 'Incidunt porro voluptatum earum id voluptatem sit aliquam. Qui voluptatem aut et est doloribus. Molestiae repellendus facere ratione est nostrum necessitatibus nam. Dolor velit consequuntur nisi cum ab.', 'Aut reprehenderit nostrum eum qui molestias. Maxime aut ut modi enim. At qui labore rem.', '1984-01-07');
[... and other round about 58.000 random insert entries like this... ]

6. create an empty database "test" and execute the SQL-file with the following command on both machines:

$ mysql -u root -p test < SQLFILE.sql
[19 Dec 2018 12:48] Florian Kopp
there is a typo in the decription: innodb_buffer_pool_size is 1024M on a 2G RAM VM and not 2048M.
[19 Dec 2018 14:28] MySQL Verification Team
Hi,

Thank you for your bug report.

We believe you that you experience performance problems on the restore of data. However, we must be able to repeat your problem in order to verify your report.

Hence, please upload the entire dump file, either gzipped or zipped. Use tab "Files" for that operation. Data will be visible only to us, Oracle employees.

Before proceeding to uploading the dump, please try mysqlpump program. It has a very similar set of options as mysqldump, but it is much faster, especially for InnoDB tables.

So, please, inform us first of the speed differences that you get with mysqlpump program.

Many thanks in advance.
[19 Dec 2018 15:14] Florian Kopp
Thanks for reply. Indeed importing a dump created with mysqlpump can be restored much faster than created with mysqldump. But restoring the mysqlpump-file to the mysql 5.7 server is still round about 3 times faster than restoring on the mysql 8.0.13 server. Now, i uploaded the original simple SQL-file (manually created, not by mysqlpump), it shows the massive import performance difference between 5.7 and 8.0.13 best. Please let me know if you need more information about my configuration.
[19 Dec 2018 15:20] MySQL Verification Team
Hi,

What you experience, can be due to change in the data dictionary.

Can you try dumping all databases, except `mysql` database. Then, with 5.7 and 8.0 first initialise the mysql database with --initialize option.

There is one more item. How many tables do you have in total ???

I am asking this because 8.0 does not use FRM file. All metadata are stored in the InnoDB data dictionary, which is MUCH slower then simple FRM file. If you have many tables, then this is expected behaviour.
[19 Dec 2018 15:21] MySQL Verification Team
One more item.

I do not see your file, so where is it actually uploaded ????
[19 Dec 2018 16:20] Florian Kopp
I uploaded the file via sftp as "mysql-bug-data-93684.zip" to /support/incoming/. 

The original database conatins about 370 tables. But the uploaded test dump has only 2 tables and restoring is very slow in mysql 8.0.13 too.
[19 Dec 2018 16:43] MySQL Verification Team
Hi,

One more notice.

On 8.0 you need skip-log-bin in my.cnf to disable the binlog to be
comparable to 5.7.  else the sync_binlog=1 and single-row inserts will
kill performance on non-write-cache disk.
[19 Dec 2018 16:49] MySQL Verification Team
I must note that you made a big mistake by using single-row inserts ....... 

Those are so much slower then multi-row ones .......
[19 Dec 2018 16:52] MySQL Verification Team
Hi,

This is the output from the command `time` when used on feeding that SQLFILE into 5.7.24:

real	0m30.456s
user	0m1.860s
sys	0m0.863s
[19 Dec 2018 17:01] MySQL Verification Team
Hi,

And these are the times when applying the same SQLFILE into 8.0.14:

real	0m31.441s
user	0m1.450s
sys	0m0.622s

As you can see , differences in the speed are minimal.

So, you try all the recommendations that were given you in this bug report and your difference will be small too. There are many other ways to gap the difference, but those are beyond a bug report.

Also, I have 2 Tb of SSD on my iMac, which I used for the databases and tables. If you have a slow disk, then this can be turned into a documentation bug.
[20 Jan 2019 1:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".
[5 Dec 2023 13:54] MySQL Verification Team
Hi Mr. Kopo,

We have some new measurements for you .....

We tried this with the latest 5.7.44-linux-glibc2.12-x86_64 package on the following OCI shape:
Shape: VM.Standard.E3.Flex
Shape Cfg: Ocpus: 4 - Mem: 4 GB

running OL8.

We get:

[mysql-5.7.44-linux-glibc2.12-x86_64]$ time bin/mysql -u root -S
mysqld.sock < x.sql

real    0m20.024s
user    0m0.005s
sys     0m0.002s

[mysql-8.0.35-linux-glibc2.12-x86_64]$ time bin/mysql -u root -S mysqld.sock < ../mysql-5.7.44-linux-glibc2.12-x86_64/x.sql

real    0m25.753s
user    0m0.003s
sys     0m0.005s

Using the following config on both:
[mysqld]
innodb_buffer_pool_size = 2048M
innodb_log_buffer_size = 64M
innodb_log_file_size = 265M
innodb_flush_log_at_trx_commit=2
innodb_flush_method=O_DIRECT
max_allowed_packet = 512G

If I disable binlog by adding (as suggested) "skip-bin-log" to 8.0's
my.cnf we get:

[mysql-8.0.35-linux-glibc2.12-x86_64]$ bin/mysql -u root -S mysqld.sock
-e "select @@log_bin"
+-----------+
| @@log_bin |
+-----------+
|         0 |
+-----------+
[mysql-8.0.35-linux-glibc2.12-x86_64]$ time bin/mysql -u root -S
mysqld.sock < ../mysql-5.7.44-linux-glibc2.12-x86_64/x.sql

real    0m15.564s
user    0m0.006s
sys     0m0.003s

So, by our measurements, 8.0.35 is faster than 5.7.44 by about 5 secs (about 30%) in OCI.

Not a bug.