Bug #111353 3x Performance Regression from 5.7 to 8.0 on ALTER TABLE FORCE.
Submitted: 11 Jun 2023 22:04 Modified: 29 Apr 6:38
Reporter: Jean-François Gagné Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S2 (Serious)
Version:8.0, 8.0.33 OS:Any
Assigned to: CPU Architecture:Any
Tags: performance regression

[11 Jun 2023 22:04] Jean-François Gagné
Description:
Hi,

while doing some benchmarks on 5.7 and 8.0, I observed significant more time for running ALTER TABLE FROCE on 8.0 than 5.7.  In my tests, it is taking at least 3x the time in 8.0 (1m50.049s) than in 5.7 (0m31.139s).  Details in How to repeat.

Normally, because ALTER TABLE FORCE is not something I run very often, I would classify this as S3 / Non-Critical, but the magnitude of this regression makes me classify this as S2 / Serious.

Many thanks for looking into this,

Jean-François Gagné

How to repeat:
# Create a 8.0.33 sandbox (we need mysql_native_password for sysbench).
dbdc="-c skip-log-bin"
dbdc="$dbdc -c innodb_buffer_pool_size=$((128*1024*1024))"
dbdc="$dbdc -c default-authentication-plugin=mysql_native_password"
dbdeployer deploy single mysql_8.0.33 $dbdc

# Create a schema for sysbench and fill it.
# The table size is computed for having a 2 GB table with 4 rows per 16KB page.
# (sba: sysbench arguments.)
./use <<< "CREATE DATABASE sbtest"
nb_rows=$((2*1024*1024))
socket=$(awk '$1=="socket"{print $3; exit}' my.sandbox.cnf)
sba="oltp_point_select --rand-type=uniform --mysql-socket=$socket"
sba="$sba --mysql-user=msandbox --mysql-password=msandbox --mysql-db=sbtest"
sba="$sba --tables=1 --table_size=$nb_rows"
time sysbench $sba prepare --create_secondary=off

# Make the table bigger by padding rows with data.
# This is done in such a way as each InnoDB Page contains 16 rows
#   (the table was created with two CHAR of size 120 and 60).
time { echo "ALTER TABLE sbtest1 ADD COLUMN c0 CHAR(60) DEFAULT ''"
       seq -f " ADD COLUMN c%.0f CHAR(240) DEFAULT ''" 1 3
} | paste -s -d "," | ./use sbtest
real    2m12.885s
user    0m0.009s
sys     0m0.000s

# Because of instant ADD COLUMN, force-rebuild the table.
time ./use sbtest <<< "ALTER TABLE sbtest1 FORCE"
real    2m10.540s
user    0m0.002s
sys     0m0.005s

# Making sure all pages are flushed.
time ./use sbtest <<< "FLUSH TABLE sbtest1 FOR EXPORT"
real    0m0.013s
user    0m0.002s
sys     0m0.004s

# Rebuild the table 5 times and look at the time it is taking.
# pv for making sure the table is in the Linux Page Cache.
# The fastest time is 1m50.049s.
for i in {1..5}; do pv data/sbtest/sbtest1.ibd > /dev/null;  time ./use sbtest <<< "ALTER TABLE sbtest1 force"; done
2.47GiB 0:00:00 [7.88GiB/s] [=...=>] 100%

real    1m51.173s
user    0m0.000s
sys     0m0.006s
2.47GiB 0:00:00 [7.87GiB/s] [=...=>] 100%

real    1m54.659s
user    0m0.004s
sys     0m0.002s
2.47GiB 0:00:00 [7.77GiB/s] [=...=>] 100%

real    1m54.327s
user    0m0.006s
sys     0m0.000s
2.47GiB 0:00:00 [7.91GiB/s] [=...=>] 100%

real    1m50.049s
user    0m0.002s
sys     0m0.004s
2.47GiB 0:00:00 [8.07GiB/s] [=...=>] 100%

real    1m53.543s
user    0m0.005s
sys     0m0.001s

# Doing exactly the same as above but with 5.7.42, I get below.
# The slowest time is 0m31.139s.
for i in {1..5}; do pv data/sbtest/sbtest1.ibd > /dev/null; time ./use sbtest <<< "ALTER TABLE sbtest1 force"; done
2.48GiB 0:00:00 [8.28GiB/s] [=...=>] 100%

real    0m31.139s
user    0m0.005s
sys     0m0.000s
2.48GiB 0:00:00 [7.93GiB/s] [=...=>] 100%

real    0m30.992s
user    0m0.005s
sys     0m0.000s
2.48GiB 0:00:00 [7.91GiB/s] [=...=>] 100%

real    0m31.071s
user    0m0.003s
sys     0m0.002s
2.48GiB 0:00:00 [7.91GiB/s] [=...=>] 100%

real    0m30.893s
user    0m0.002s
sys     0m0.003s
2.48GiB 0:00:00 [7.95GiB/s] [=...=>] 100%

real    0m30.317s
user    0m0.003s
sys     0m0.002s
[13 Jun 2023 9:54] MySQL Verification Team
Hello Jean-François,

Thank you for the report and feedback.
Verified as described.

regards,
Umesh
[15 Oct 2024 11:04] MySQL Verification Team
5.7.42 & 8.0.33 test results

Attachment: 111353_8.0.33_5.7.42.results.txt (text/plain), 11.00 KiB.

[5 Mar 9:46] Edward Gilmore
Posted by developer:
 
Duplicate of 36433301. Closing.
[6 Mar 17:16] Jean-François Gagné
The previous comment indicates this is a duplicate of an internal / private bug.

It also indicates "Closing", but I still see this bug as opened and Verified, so the status of this bug is unclear.

IMHO, public bugs should not be closed as duplicate of internal bugs.  These bugs should stay opened until they are fixed.  Closing a bug referencing an internal bug prevents people to know when the bug is fixed and in which version, hence my reasoning about "should say open".

Thanks in advance for bringing clarity about the status of this bug.
[4 Apr 7:01] MySQL Verification Team
Hello Jean-François,

Sorry for the delayed response on this. I fully understand your concern on this.
Confirmed internally that this Bug#111353 is marked as a duplicate of Bug #114420 (internal Bug#36433301). Development has added closure details in the Bug #114420. Please let me know if any further clarification needed and I'll get back to you after discussing with development.  

If you have no objections then I would like to close this bug as a duplicate of Bug #114420. Thank you.

Sincerely,
Umesh
[28 Apr 19:41] Jean-François Gagné
Hello Umesh, my turn for a delayed response.

> I would like to close this bug as a duplicate of Bug #114420

Bug #114420 having been opened on 20 Mar 2024, and this (Bug #111353) having been opened on 11 Jun 2023, I think #114420 is a duplicate of #111353, not the other way around.  But this is not a big deal...

Just for tracing things, Bug #114420 is about the default for innodb_doublewrite_pages being suboptimal in 8.0, but ok in 8.4.

With innodb_doublewrite_pages=128 in 8.0, I indeed get the same timing as 5.7, see tests below.

IMHO, the justification in Bug #114420 for only fixing this as a documentation bug is a little light: I think such regression justifies changing a default in 8.0, even if this breaks LTS stability (in this case, this is a LTS instability / regression, so I would not consider this "breaking" but actually "fixing").  Beside that and the comment above (about the other bug being the duplicated), ok for closing this as a duplicate.

And FYI, I blogged about this in https://jfg-mysql.blogspot.com/2025/04/performance-regression-in-mysql-80-fixed-in-84-easy....

# Tests below done on an AWS m6i.large vm with gp3 disks (using a m6id.large vm with local SSDs, there is no regression from 5.7 to 8.0, probably because fast fsync).

##########################################
# Utility functions common to 8.0 and 5.7.

# Test init.
# (the pv are a trick to have a timer)
function init() {
  # Create a schema for sysbench and fill it.
  # The table size is computed for having a 2 GB table with 4 rows per 16KB page.
  # (sba: sysbench arguments)
  ./use <<< "CREATE DATABASE sbtest"
  nb_rows=$((2*1024*1024))
  socket=$(awk '$1=="socket"{print $3; exit}' my.sandbox.cnf)
  sba="oltp_point_select --rand-type=uniform --mysql-socket=$socket"
  sba="$sba --mysql-user=msandbox --mysql-password=msandbox --mysql-db=sbtest"
  sba="$sba --tables=1 --table_size=$nb_rows"
  sysbench $sba prepare --create_secondary=off | pv -t -N "$(printf %12s sysbench)" > /dev/null

  # Make the table bigger by padding rows with data.
  # This is done in such a way as each InnoDB Page contains 16 rows
  # (the table was created with two CHAR of size 120 and 60).
  { echo "ALTER TABLE sbtest1 ADD COLUMN c0 CHAR(60) DEFAULT ''"
         seq -f " ADD COLUMN c%.0f CHAR(240) DEFAULT ''" 1 3
  } | paste -s -d "," | ./use sbtest | pv -t -N "$(printf %12s alter_add)" > /dev/null

  # Because of instant ADD COLUMN, force-rebuild the table.
  ./use sbtest <<< "ALTER TABLE sbtest1 FORCE" | pv -t -N "$(printf %12s alter_force)" > /dev/null

  # Making sure all pages are flushed.
  ./use sbtest <<< "FLUSH TABLE sbtest1 FOR EXPORT" | pv -t -N "$(printf %12s flush)" > /dev/null
}

# Rebuild the table N times and get the time it is taking.
# (1st pv for making sure the table is in the Linux Page Cache)
# (other pv as a timer)    
function rebuild() {
  for i in $(seq $1); do
    pv data/sbtest/sbtest1.ibd -t -N "$(printf %12s cache)" > /dev/null
    ./use sbtest <<< "ALTER TABLE sbtest1 force" | pv -t -N "$(printf %12s alter_force)" > /dev/null
  done
}

##############
# With 8.0.42.

mv=8.0.42
dbdc="-c skip-log-bin"
dbdc="$dbdc -c innodb_buffer_pool_size=$((128*1024*1024))"
dbdc="$dbdc -c default-authentication-plugin=mysql_native_password"
dbdeployer deploy single mysql_$mv $dbdc

init
    sysbench: 0:00:23
   alter_add: 0:00:00
 alter_force: 0:01:58
       flush: 0:00:00

# The fastest time is 1:47.
./use -N <<< "show global variables like 'innodb_doublewrite_pages'"; \
  rebuild 5
innodb_doublewrite_pages        4
       cache: 0:00:00
 alter_force: 0:01:48
       cache: 0:00:00
 alter_force: 0:01:47
       cache: 0:00:00
 alter_force: 0:02:01
       cache: 0:00:00
 alter_force: 0:02:04
       cache: 0:00:00
 alter_force: 0:02:04

# With the 8.4 value for innodb_doublewrite_pages.
# The fastest time is 1:01.
echo "innodb_doublewrite_pages=128" >> my.sandbox.cnf
{ ./stop; ./start; } > /dev/null
./use -N <<< "show global variables like 'innodb_doublewrite_pages'"; \
  rebuild 5
innodb_doublewrite_pages        128
       cache: 0:00:00
 alter_force: 0:01:05
       cache: 0:00:00
 alter_force: 0:01:03
       cache: 0:00:00
 alter_force: 0:01:02
       cache: 0:00:00
 alter_force: 0:01:01
       cache: 0:00:00
 alter_force: 0:01:02

##############
# With 5.7.44.

mv=5.7.44
dbdc="-c skip-log-bin"
dbdc="$dbdc -c innodb_buffer_pool_size=$((128*1024*1024))"
dbdeployer deploy single mysql_$mv $dbdc

init
    sysbench: 0:00:19
   alter_add: 0:00:57
 alter_force: 0:00:56
       flush: 0:00:00

# The fastest time is 0:56.
rebuild 5
 alter_force: 0:00:56
       cache: 0:00:00
 alter_force: 0:00:56
       cache: 0:00:00
 alter_force: 0:00:56
       cache: 0:00:00
 alter_force: 0:00:56
       cache: 0:00:00
 alter_force: 0:00:56
[29 Apr 6:38] MySQL Verification Team
Hello Jean-François,

Thank you for the feedback, and testing once again. I will convey your message to the development team.
For now, as agreed closing this as a duplicate of Bug #114420. Thank you.

Sincerely,
Umesh