MySQL Bugs: #108430: performance degradation of DML operations comparing with MySQL 5.7

Bug #108430	performance degradation of DML operations comparing with MySQL 5.7
Submitted:	8 Sep 2022 13:52	Modified:	13 Dec 2022 9:19
Reporter:	Andrew Zhylenko	Email Updates:
Status:	Verified	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S5 (Performance)
Version:	8.0.29	OS:	Oracle Linux (Oracle Linux Server release 7.9 3.10.0-1160.76.1.0.1.el7.x86_64)
Assigned to:		CPU Architecture:	x86 ( Intel(R) Xeon(R) CPU E5-2630 v3 )

Description:

While performing stress performance tests of our product with different MySQL versions, we noticed that many DML operations work slower on MySQL 8.0 than on MySQL 5.7 with basically the same values of system variables and settings.

While further investigating the possible source of the performance degradation, we conducted several synthetical tests and tests resembling tiny but essential parts of our production workload. We also gathered some execution stats as well as values of the innodb metrics (all these tests were run with the system variable "innodb_monitor_enable" set to "all").

In our tests, which were executing simple inserts into a single table with several secondary indexes by 48 parallel client processes in the auto commit mode, MySQL 5.7.20 was showing better (by ~10% or ~20% depending on the value of the variable "innodb_log_writer_threads") results than MySQL 8.0.29, and with less IO load.

The increased IO load can be attributed to a soaring increase of some innodb metric values, probably caused by the log writer threads enabled by default and it can be a reason of the performance drop by 10%.

Here are the values of several metrics that differ significantly (MySQL 8.0.29 vs MySQL 5.7.20) and a ratio between values.

Metric name                              8.0.29               5.7.20               Ratio
------------------------------------    -------------        -------------        --------
dml_inserts                              9599930              9599944              1.000
innodb_activity_count                    9898955              9899013              1.000

os_log_bytes_written                     35026334208          12573356544          2.786
os_log_fsyncs                            5325936              1425654              3.736
log_writes                               62042167             1425404              43.526
log_write_requests                       114419888            18157978             6.301
log_padded                               0                    3804944384           

os_data_writes                           62760190             1873281              33.503
os_data_fsyncs                           5482863              1441964              3.802

The same tests run on MySQL 8.0.29 with the log writer threads disabled (innodb_log_writer_threads=off) showed a lesser in?rease of those metrics compared to MySQL 5.7 and the IO load was close to one during the tests with MySQL 5.7.

Metric name                              8.0.29               5.7.20               Ratio
------------------------------------    -------------        -------------        --------
dml_inserts                              9599912              9599944              1.000
innodb_activity_count                    9899055              9899013              1.000

os_log_bytes_written                     12257670144          12573356544          0.975
os_log_fsyncs                            1379307              1425654              0.967
log_writes                               3142725              1425404              2.205
log_write_requests                       114416923            18157978             6.301
log_padded                               0                    3804944384           0.000

os_data_writes                           3837029              1873281              2.048
os_data_fsyncs                           1530764              1441964              1.062

However, instead of an increase of performance, we observed a decrease by another 10% and it was 20% worse than on the MySQL 5.7 — while we didn't find changes in metrics that could explain such a drop, it seemed that transactions spent more time during the commit phase.

Here are the differences in those metric values depending on the values of the variable "innodb_log_writer_threads":

there are difference in those metric values depending on values of the variable "innodb_log_writer_threads":

Metric name                              ON                  OFF                  Ratio
------------------------------------    -------------        -------------        --------
dml_inserts                              9599930              9599912              1.000
innodb_activity_count                    9898955              9899055              1.000

os_log_bytes_written                     35026334208          12257670144          2.858
os_log_fsyncs                            5325936              1379307              3.861
log_writes                               62042167             3142725              19.742
log_write_requests                       114419888            114416923            1.000

os_data_writes                           62760190             3837029              16.356
os_data_fsyncs                           5482863              1530764              3.582

In general such increase of these metrics, number of redo log operations and IO load as well as performance drops comparing with MySQL 5.7 does not look normal and probably can be caused by a bug. Also, the longer transaction times and decreasing performance when the log writer threads are disabled are hardly normal.

How to repeat:
actually the same behavior is observed during inserts into tables with almost any structure, but more secondary indexes a table has got more severe degradation is observed. 

the following table structure was used during our test, it has the same set of columns and indexes as one of our most active production tables.

CREATE TABLE tt1 (
  ui_pk int(10) unsigned NOT NULL AUTO_INCREMENT,
  vc_id1 varchar(36) CHARACTER SET utf8 DEFAULT NULL,
  vc_fill1 varchar(36) DEFAULT NULL,
  vc_id2 varchar(100) CHARACTER SET utf8 DEFAULT NULL,
  ui_id1 int(10) unsigned NOT NULL DEFAULT '0',
  ui_id2 int(10) unsigned NOT NULL DEFAULT '0',
  vc_id3 varchar(32) CHARACTER SET utf8 NOT NULL,
  dt_fill1 datetime NOT NULL,
  dt_fill2 datetime DEFAULT NULL,
  dt_fill3 datetime NOT NULL,
  dt_fill4 datetime DEFAULT NULL,
  vc_l1 varchar(255) CHARACTER SET utf8 DEFAULT NULL,
  vc_l2 varchar(255) CHARACTER SET utf8 DEFAULT NULL,
  vc_l3 varchar(255) DEFAULT NULL,
  ii_i1 int(10) unsigned DEFAULT NULL,
  ii_i2 int(10) unsigned DEFAULT NULL,
  ii_id1 int(10) unsigned DEFAULT NULL,
  ti_id1 tinyint(3) unsigned NOT NULL DEFAULT '3',
  dt_exp datetime NOT NULL,
  vc_l3 int(10) unsigned DEFAULT NULL,
  ui_fill1 int(10) unsigned DEFAULT NULL,
  ui_fill2 int(10) unsigned DEFAULT NULL,
  ui_fill3 int(10) unsigned DEFAULT NULL,
  ti_id2 tinyint(3) unsigned DEFAULT NULL,
  ti_fill1 tinyint(3) unsigned NOT NULL DEFAULT '0',
  fl_fill1 decimal(15,5) DEFAULT NULL,
  ti_fill2 tinyint(3) unsigned NOT NULL DEFAULT '0',
  ui_fill4 int(10) unsigned DEFAULT NULL,
  ti_id3 tinyint(3) unsigned NOT NULL DEFAULT '0',
  ti_id4 tinyint(3) unsigned NOT NULL DEFAULT '0',
  vc_fill2 varchar(100) DEFAULT NULL,
  PRIMARY KEY (ui_pk),
  KEY vc_id2_idx (vc_id2),
  KEY ui_idx (ui_id1,i_id1),
  KEY dt_expx (dt_exp) USING BTREE,
  KEY mc_idx1 (ui_id1,ti_id1,vc_id1,ti_id4,ti_id3,ui_id2,vc_id3,vc_l2),
  KEY vc_id1__idx (vc_id1),
  KEY mc_idx2 (ui_id1,ii_i2,ui_fill3,ti_id2) USING BTREE,
  KEY vc_l3_idx (vc_l3)
) ENGINE=InnoDB DEFAULT CHARSET=latin1;

mysql 5.7 global vars

Attachment: vars_5.7.txt (text/plain), 14.24 KiB.

mysql 8.0 global vars

Attachment: vars_8.0.txt (text/plain), 18.66 KiB.

Hello Andrew Zhylenko,

Thank you for the bug report and feedback.
We would like to know few things here:
(i) Example of INSERT query and how exactly it was executed? one by one or in batches? Thank you.

Related - Bug #94387, Bug #93734, Bug #94283, Bug #100811

regards,
Umesh

the basically the insert statement looks like 

    INSERT INTO tt1 (
        ui_pk,
        vc_id1, vc_id2,
        vc_fill1,
        ui_id1, ui_id2, ti_id3, ti_id4, vc_id3,
        dt_fill1, dt_fill2, dt_fill3, dt_fill4, vc_l1,
        vc_l2, vc_l3,
        ii_i1, ui_fill4,
        ii_i2,
        vc_l3, ui_fill1, ui_fill2,
        ui_fill3, ti_id2,
        ti_fill1, fl_fill1, ti_fill2,
        i_id1, ti_id1,
        vc_fill2,
        dt_exp)
    VALUES(
        NULL,
        ?, ?,
        ?,
        ?, ?, ?, ?, IFNULL(?,''),
        ?, ?, IFNULL(?,NOW()), ?, ?,
        ?, ?,
        ?, ?,
        ?,
        ?, ?, ?,
        ?, ?,
        ?, ?, IFNULL(?,0),
        ?, ?,
        ?,
        ?);

such inserts are executed by a simple perl script with the DBI::mysql package as a db interface in a loop by issuing "execute()" method with all the bind variable on an once prepared cursor in the auto commit mode.

Thank you, Andrew for the details.
I'll get back to you if anything further needed(really appreciate if you can attach both configuration files my.cnf i.e from 5.7 and 8.0 instance instead of o/p of show global variables. If  you prefer then please attach as a private).

the same mysql config file was used for the both MySQL 5.8 and 8.0

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

I've attached the mysql config file and the same file was used for the both MySQL 5.7 and 8.0.

Please also take in account that earlier I'd attached the files with the actual content of global variables of the mysql state  dumped via 'show global variables; ' just before running the tests.

Thank you for the feedback.

Hello,

is there any progress with this bug report ?

Although this bug is verifed, but I could not find any suggestion to this specific bug. This bug is very similar with to our case. If you have any suggestion, please share it. Thanks.