Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Won't Fix
-
10.2.35, 10.4.17
Description
Try to run sysbench oltp_read_write test on 10.4.17 vs 10.4.15 and 10.5.8 vs 10.5.6, with several tables and notably more concurrent threads than you have cores, while total size of tables created is notably smaller than the buffer pool.
For short runs (100 or 300 seconds) at least you'll notice a clear drop in throughput in QPS and TPS, around 15%, and notable increase in 95th percentile latency.
Consider the following example when MariaDB is started with only the following non-default settings besides port/socket:
MariaDB [(none)]> select @@innodb_buffer_pool_size, @@innodb_flush_log_at_trx_commit;
|
+---------------------------+----------------------------------+
|
| @@innodb_buffer_pool_size | @@innodb_flush_log_at_trx_commit |
|
+---------------------------+----------------------------------+
|
| 1073741824 | 2 |
|
+---------------------------+----------------------------------+
|
1 row in set (0.000 sec)
|
and 5 tables 100000 rows each are created:
[openxs@fc31 maria10.4.17]$ sysbench oltp_read_write --db-driver=mysql --tables=5 --table-size=100000 --mysql-user=openxs --mysql-socket=/tmp/mariadb.sock --mysql-db=sbtest --threads=4 prepare
|
|
|
...
|
|
|
MariaDB [(none)]> show table status from sbtest like 'sbtest1'\G
|
*************************** 1. row ***************************
|
Name: sbtest1
|
Engine: InnoDB
|
Version: 10
|
Row_format: Dynamic
|
Rows: 100000
|
Avg_row_length: 225
|
Data_length: 22593536
|
Max_data_length: 0
|
Index_length: 1589248
|
Data_free: 2097152
|
Auto_increment: 100001
|
Create_time: 2020-11-24 10:44:53
|
Update_time: 2020-11-24 10:44:51
|
Check_time: NULL
|
Collation: latin1_swedish_ci
|
Checksum: NULL
|
Create_options:
|
Comment:
|
Max_index_length: 0
|
Temporary: N
|
1 row in set (0.000 sec)
|
With 10.4.15 on Fedora 31 I get the following on my old quadcore test box:
[openxs@fc31 maria10.4.15]$ sysbench oltp_read_write --db-driver=mysql --tables=5 --table-size=100000 --mysql-user=openxs --mysql-socket=/tmp/mariadb.sock --mysql-db=sbtest --threads=32 --time=100 run
|
sysbench 1.1.0-174f3aa (using bundled LuaJIT 2.1.0-beta2)
|
|
|
Running the test with following options:
|
Number of threads: 32
|
Initializing random number generator from current time
|
|
|
|
|
Initializing worker threads...
|
|
|
Threads started!
|
|
|
SQL statistics:
|
queries performed:
|
read: 1226148
|
write: 350328
|
other: 175164
|
total: 1751640
|
transactions: 87582 (875.32 per sec.)
|
queries: 1751640 (17506.49 per sec.)
|
ignored errors: 0 (0.00 per sec.)
|
reconnects: 0 (0.00 per sec.)
|
|
|
Throughput:
|
events/s (eps): 875.3245
|
time elapsed: 100.0566s
|
total number of events: 87582
|
|
|
Latency (ms):
|
min: 2.13
|
avg: 36.54
|
max: 1614.12
|
95th percentile: 125.52
|
...
|
while with 10.4.17:
[openxs@fc31 maria10.4.17]$ sysbench oltp_read_write --db-driver=mysql --tables=5 --table-size=100000 --mysql-user=openxs --mysql-socket=/tmp/mariadb.sock --mysql-db=sbtest --threads=32 --time=100 run
|
sysbench 1.1.0-174f3aa (using bundled LuaJIT 2.1.0-beta2)
|
|
|
Running the test with following options:
|
Number of threads: 32
|
Initializing random number generator from current time
|
|
|
|
|
Initializing worker threads...
|
|
|
Threads started!
|
|
|
SQL statistics:
|
queries performed:
|
read: 1058232
|
write: 302352
|
other: 151176
|
total: 1511760
|
transactions: 75588 (755.07 per sec.)
|
queries: 1511760 (15101.33 per sec.)
|
ignored errors: 0 (0.00 per sec.)
|
reconnects: 0 (0.00 per sec.)
|
|
|
Throughput:
|
events/s (eps): 755.0666
|
time elapsed: 100.1077s
|
total number of events: 75588
|
|
|
Latency (ms):
|
min: 2.14
|
avg: 42.34
|
max: 1113.80
|
95th percentile: 170.48
|
...
|
The difference is visible with 8 and 16 threads as well. So, there is a systematic notable performance regression in recent 10.4.x (and 10.5.x, for that matter) for this test.
Attachments
Issue Links
- relates to
-
-
- Closed
-
Activity
The page flushing was basically rewritten in MDEV-23399 and MDEV-23855, and as noted in MDEV-23855, some parameters may have to be configured differently to get good performance.
I think that we would need more detailed graphs to identify the cause of the performance regression, similar to those that axel attached to MDEV-23855 on 2020-11-04. Hopefully he can share his scripts for collecting the data.
My comment from yesterday is not applicable to the observed regression in 10.4.
mihaQ, if you want to make 10.5 fast in write workloads, I would suggest to consider the following (as I noted in MDEV-23855 already):
- If your storage is fast (SSD), make innodb_log_file_size (much) bigger than innodb_buffer_pool_size. Thanks to
MDEV-12353,MDEV-19514, andMDEV-21351, crash recovery should be fast and not run out of memory. - Minimize "background flushing": SET GLOBAL innodb_io_capacity=100; SET GLOBAL innodb_max_dirty_pages_pct_lwm=99; (or a bit less extreme values).
I just reviewed all InnoDB code changes between 10.4.15 and 10.4.17 (excluding merges from earlier series), and all changes look rather innocent to me, should not be touching code paths that sysbench would exercise.
However, the code diff is rather large, and much of it could be due to MDEV-23693. If the regression is due to InnoDB changes, then that would be my primary suspect. I hope that valerii can repeat the test on the 10.2 series.
We are on 10.2 series and noticed that since 10.2.35 a daily 10 Go dump reload is two times slower than before (all tables in innodb).
I don't know if it's linked to the same problem.
The 10.2.36 patch doesn't solve the problem.
Greg1258, the unscheduled 10.2.36 release intentionally (to reduce any risk) only included fixes for a small number of critical regressions. Only the 10.4.17 and 10.5.8 releases included an InnoDB fix, of the serious corruption issue MDEV-24096 which was introduced in the 10.4.16 and 10.5.7 releases. But it should not be observable in sysbench at all, because sysbench does not exercise indexed virtual columns.
Either way, I believe that the performance regression should exist between 10.2.34 and 10.2.35, not between 10.2.35 and 10.2.36 (and so on).
Thanks for your precisions, I confirm the performance regression exists between 10.2.34 and 10.2.35 (impact is on all of our MariaDB instances)
Greg1258, thank you. I would use the following command as the starting point:
git log --first-parent --oneline mariadb-10.2.34..mariadb-10.2.35 storage/innobase
|
It reports 80 commits. We would have to test 7 commits to narrow it down to a smaller interval (which can contain non-InnoDB commits).
I can confirm (on other hardware) that 10.2.34 is notably faster than 10.2.37 from current GitHub source. I'll try to proceed with checking commits based on Marko's comment.
From what I can see 10.2.34 is "fast" and the very first commit from the list generated Marko's command above:
72eea39 MDEV-23991 fixup: Initialize the memory
makes the result "slow". In my today's hardware case "slow" is this for the same test and 16 threads (just 2 slow cores and slow HDD, so don't mind the absolute values):
...
|
transactions: 18927 (188.83 per sec.)
|
queries: 378540 (3776.69 per sec.)
|
ignored errors: 0 (0.00 per sec.)
|
reconnects: 0 (0.00 per sec.)
|
|
|
Throughput:
|
events/s (eps): 188.8346
|
time elapsed: 100.2306s
|
total number of events: 18927
|
|
|
Latency (ms):
|
min: 2.83
|
avg: 84.61
|
max: 1385.10
|
95th percentile: 344.08
|
...
|
while "fast" 10.2.34 gives this:
openxs@ao756:~/dbs/maria10.2.34t$ sysbench oltp_read_write --db-driver=mysql --tables=5 --table-size=100000 --mysql-user=root --mysql-socket=/tmp/mariadb.sock --mysql-db=sbtest --threads=16 --time=100 run
|
sysbench 1.1.0-faaff4f (using bundled LuaJIT 2.1.0-beta3)
|
|
|
Running the test with following options:
|
Number of threads: 16
|
Initializing random number generator from current time
|
|
|
|
|
Initializing worker threads...
|
|
|
Threads started!
|
|
|
SQL statistics:
|
queries performed:
|
read: 373296
|
write: 106656
|
other: 53328
|
total: 533280
|
transactions: 26664 (264.46 per sec.)
|
queries: 533280 (5289.28 per sec.)
|
ignored errors: 0 (0.00 per sec.)
|
reconnects: 0 (0.00 per sec.)
|
|
|
Throughput:
|
events/s (eps): 264.4641
|
time elapsed: 100.8228s
|
total number of events: 26664
|
|
|
Latency (ms):
|
min: 2.77
|
avg: 60.46
|
max: 2011.89
|
95th percentile: 207.82
|
sum: 1612220.36
|
|
|
Threads fairness:
|
events (avg/stddev): 1666.5000/29.10
|
execution time (avg/stddev): 100.7638/0.04
|
Disregard my previous comment, I indeed checked in "wrong direction" Today's checks ended up confirming that these commits on top of 10.2.34 are fast:
+ 1509363 MDEV-23484 Rollback unnecessarily acquires dict_operation_lock for every row
+ 4c50120d MDEV-23474 InnoDB fails to restart after SET GLOBAL innodb_log_checksums=OFF
+ 362b18c MDEV-23380 InnoDB reads a page from disk despite parsing MLOG_INIT_FILE_PAGE2 record
...
but this one and later are already slow:
- 309302a
MDEV-23475InnoDB performance regression for write-heavy workloads
"fast" means this:
openxs@ao756:~/dbs/maria10.2.34t$ sysbench oltp_read_write --db-driver=mysql --tables=5 --table-size=100000 --mysql-user=root --mysql-socket=/tmp/mariadb.sock --mysql-db=sbtest --threads=16 --time=300 --report-interval=10 run
|
sysbench 1.1.0-faaff4f (using bundled LuaJIT 2.1.0-beta3)
|
|
|
Running the test with following options:
|
Number of threads: 16
|
Report intermediate results every 10 second(s)
|
Initializing random number generator from current time
|
|
|
|
|
Initializing worker threads...
|
|
|
Threads started!
|
|
|
[ 10s ] thds: 16 tps: 191.23 qps: 3849.06 (r/w/o: 2698.55/766.44/384.07) lat (ms,95%): 253.35 err/s: 0.00 reconn/s: 0.00
|
[ 20s ] thds: 16 tps: 213.40 qps: 4267.88 (r/w/o: 2987.56/853.52/426.81) lat (ms,95%): 262.64 err/s: 0.00 reconn/s: 0.00
|
[ 30s ] thds: 16 tps: 266.56 qps: 5326.77 (r/w/o: 3728.12/1065.53/533.12) lat (ms,95%): 204.11 err/s: 0.00 reconn/s: 0.00
|
[ 40s ] thds: 16 tps: 238.62 qps: 4779.58 (r/w/o: 3345.64/956.70/477.25) lat (ms,95%): 244.38 err/s: 0.00 reconn/s: 0.00
|
[ 50s ] thds: 16 tps: 277.10 qps: 5527.36 (r/w/o: 3867.47/1105.69/554.19) lat (ms,95%): 189.93 err/s: 0.00 reconn/s: 0.00
|
[ 60s ] thds: 16 tps: 284.22 qps: 5690.33 (r/w/o: 3984.00/1137.89/568.44) lat (ms,95%): 207.82 err/s: 0.00 reconn/s: 0.00
|
[ 70s ] thds: 16 tps: 100.07 qps: 2009.70 (r/w/o: 1407.98/401.58/200.14) lat (ms,95%): 419.45 err/s: 0.00 reconn/s: 0.00
|
[ 80s ] thds: 16 tps: 86.80 qps: 1733.35 (r/w/o: 1213.93/345.81/173.60) lat (ms,95%): 1376.60 err/s: 0.00 reconn/s: 0.00
|
[ 90s ] thds: 16 tps: 257.57 qps: 5150.65 (r/w/o: 3604.71/1030.79/515.14) lat (ms,95%): 219.36 err/s: 0.00 reconn/s: 0.00
|
[ 100s ] thds: 16 tps: 287.50 qps: 5749.30 (r/w/o: 4024.60/1149.70/575.00) lat (ms,95%): 186.54 err/s: 0.00 reconn/s: 0.00
|
[ 110s ] thds: 16 tps: 276.17 qps: 5525.95 (r/w/o: 3868.41/1105.19/552.34) lat (ms,95%): 204.11 err/s: 0.00 reconn/s: 0.00
|
[ 120s ] thds: 16 tps: 280.12 qps: 5600.04 (r/w/o: 3920.34/1119.47/560.23) lat (ms,95%): 219.36 err/s: 0.00 reconn/s: 0.00
|
[ 130s ] thds: 16 tps: 287.17 qps: 5745.86 (r/w/o: 4022.22/1149.29/574.35) lat (ms,95%): 207.82 err/s: 0.00 reconn/s: 0.00
|
[ 140s ] thds: 16 tps: 288.24 qps: 5765.16 (r/w/o: 4035.90/1152.77/576.49) lat (ms,95%): 189.93 err/s: 0.00 reconn/s: 0.00
|
[ 150s ] thds: 16 tps: 286.04 qps: 5722.30 (r/w/o: 4004.49/1145.74/572.07) lat (ms,95%): 211.60 err/s: 0.00 reconn/s: 0.00
|
[ 160s ] thds: 16 tps: 296.39 qps: 5921.41 (r/w/o: 4145.27/1183.36/592.78) lat (ms,95%): 183.21 err/s: 0.00 reconn/s: 0.00
|
[ 170s ] thds: 16 tps: 124.10 qps: 2489.11 (r/w/o: 1741.61/499.30/248.20) lat (ms,95%): 303.33 err/s: 0.00 reconn/s: 0.00
|
[ 180s ] thds: 16 tps: 158.78 qps: 3168.60 (r/w/o: 2219.19/631.84/317.57) lat (ms,95%): 434.83 err/s: 0.00 reconn/s: 0.00
|
[ 190s ] thds: 16 tps: 257.41 qps: 5150.18 (r/w/o: 3605.03/1030.34/514.82) lat (ms,95%): 248.83 err/s: 0.00 reconn/s: 0.00
|
[ 200s ] thds: 16 tps: 317.17 qps: 6344.34 (r/w/o: 4439.94/1270.07/634.33) lat (ms,95%): 176.73 err/s: 0.00 reconn/s: 0.00
|
[ 210s ] thds: 16 tps: 292.13 qps: 5845.67 (r/w/o: 4092.77/1168.63/584.27) lat (ms,95%): 186.54 err/s: 0.00 reconn/s: 0.00
|
[ 220s ] thds: 16 tps: 304.85 qps: 6094.53 (r/w/o: 4266.65/1218.19/609.69) lat (ms,95%): 161.51 err/s: 0.00 reconn/s: 0.00
|
[ 230s ] thds: 16 tps: 291.53 qps: 5829.19 (r/w/o: 4080.81/1165.32/583.06) lat (ms,95%): 200.47 err/s: 0.00 reconn/s: 0.00
|
[ 240s ] thds: 16 tps: 301.34 qps: 6027.16 (r/w/o: 4218.30/1206.17/602.69) lat (ms,95%): 186.54 err/s: 0.00 reconn/s: 0.00
|
[ 250s ] thds: 16 tps: 289.63 qps: 5795.49 (r/w/o: 4057.02/1159.22/579.26) lat (ms,95%): 186.54 err/s: 0.00 reconn/s: 0.00
|
[ 260s ] thds: 16 tps: 312.39 qps: 6241.81 (r/w/o: 4368.87/1248.16/624.78) lat (ms,95%): 167.44 err/s: 0.00 reconn/s: 0.00
|
[ 270s ] thds: 16 tps: 286.46 qps: 5732.95 (r/w/o: 4013.47/1146.55/572.92) lat (ms,95%): 204.11 err/s: 0.00 reconn/s: 0.00
|
[ 280s ] thds: 16 tps: 245.09 qps: 4904.73 (r/w/o: 3432.98/981.57/490.18) lat (ms,95%): 215.44 err/s: 0.00 reconn/s: 0.00
|
[ 290s ] thds: 16 tps: 198.55 qps: 3971.73 (r/w/o: 2779.65/794.99/397.09) lat (ms,95%): 196.89 err/s: 0.00 reconn/s: 0.00
|
[ 300s ] thds: 16 tps: 269.38 qps: 5385.31 (r/w/o: 3769.93/1076.72/538.66) lat (ms,95%): 204.11 err/s: 0.00 reconn/s: 0.00
|
SQL statistics:
|
queries performed:
|
read: 1059464
|
write: 302704
|
other: 151352
|
total: 1513520
|
transactions: 75676 (252.16 per sec.)
|
queries: 1513520 (5043.12 per sec.)
|
ignored errors: 0 (0.00 per sec.)
|
reconnects: 0 (0.00 per sec.)
|
|
|
Throughput:
|
events/s (eps): 252.1560
|
time elapsed: 300.1158s
|
total number of events: 75676
|
|
|
Latency (ms):
|
min: 2.73
|
avg: 63.44
|
max: 5128.21
|
95th percentile: 211.60
|
sum: 4801181.55
|
|
|
Threads fairness:
|
events (avg/stddev): 4729.7500/65.42
|
execution time (avg/stddev): 300.0738/0.03
|
"Slow" in turn means this:
...
|
transactions: 53723 (178.95 per sec.)
|
queries: 1074460 (3578.90 per sec.)
|
ignored errors: 0 (0.00 per sec.)
|
reconnects: 0 (0.00 per sec.)
|
|
|
Throughput:
|
events/s (eps): 178.9451
|
time elapsed: 300.2206s
|
total number of events: 53723
|
...
|
valerii, thank you for your effort. MDEV-23475 was rather counter-intuitive. In 10.2, 10.3, 10.4 (but not the 10.5 series), we reverted a cleanup (MDEV-20638) that we had expected to improve performance. However, extensive benchmarking by axel suggested that it was better to revert MDEV-20638.
It is plausible that MDEV-23475 would cause a regression compared to 10.2.33 or 10.2.34, which is where the MDEV-20638 fix was present. I am afraid that we cannot do much about this in the older release series. By the way, did anyone see a performance regression compared to 10.2.32 or earlier?
Within the 10.5 series, the background tasks and the buffer pool have been heavily refactored and the data flow is much more logical. The convoluted code in earlier releases seems to introduce a chaos factor to supposedly simple performance tweaks: What is good in one test scenario would destroy the performance in another one.
Even if MDEV-23475 is the only cause of the performance regression within the 10.2, 10.3 and 10.4 release series, some performance degradation was claimed also within the 10.5 series. Because we did not revert any MDEV-20638 changes in 10.5, we must find another explanation for the 10.5 performance regression. While doing this, we must take into account the changes to default parameters and the page flushing logic that were done as part of MDEV-23399 and MDEV-23855.
I checked these commits:
git log --first-parent --oneline mariadb-10.5.6..mariadb-10.5.7 storage/innobase
|
to find out which one on the way to 10.5.7 release made things slow. I will not share a lot of details, but based on these my notes:
...
|
- 118e258 MDEV-23855: Shrink fil_space_t
|
|
|
transactions: 56167 (187.20 per sec.)
|
queries: 1123340 (3744.01 per sec.)
|
ignored errors: 0 (0.00 per sec.)
|
reconnects: 0 (0.00 per sec.)
|
|
|
Throughput:
|
events/s (eps): 187.2005
|
time elapsed: 300.0366s
|
total number of events: 56167
|
|
|
Latency (ms):
|
min: 3.09
|
avg: 85.46
|
max: 3804.31
|
95th percentile: 404.61
|
|
|
|
|
45ed9dd MDEV-23855: Remove fil_system.LRU and reduce fil_system.mutex contention
|
- 3a9a3be MDEV-23855: Improve InnoDB log checkpoint performance
|
|
|
transactions: 59389 (197.64 per sec.)
|
queries: 1187780 (3952.88 per sec.)
|
ignored errors: 0 (0.00 per sec.)
|
reconnects: 0 (0.00 per sec.)
|
|
|
Throughput:
|
events/s (eps): 197.6441
|
time elapsed: 300.4846s
|
total number of events: 59389
|
|
|
Latency (ms):
|
min: 3.09
|
avg: 80.90
|
max: 4213.04
|
95th percentile: 404.61
|
...
|
transactions: 62337 (207.77 per sec.)
|
queries: 1246740 (4155.44 per sec.)
|
ignored errors: 0 (0.00 per sec.)
|
reconnects: 0 (0.00 per sec.)
|
|
|
Throughput:
|
events/s (eps): 207.7721
|
time elapsed: 300.0259s
|
total number of events: 62337
|
|
|
Latency (ms):
|
min: 3.12
|
avg: 77.00
|
max: 1135.82
|
95th percentile: 390.30
|
|
|
+ bd67cb9 MDEV-23399 fixup: Assertion bpage->in_file() failed
|
|
|
transactions: 108482 (361.48 per sec.)
|
queries: 2169640 (7229.55 per sec.)
|
ignored errors: 0 (0.00 per sec.)
|
reconnects: 0 (0.00 per sec.)
|
|
|
Throughput:
|
events/s (eps): 361.4775
|
time elapsed: 300.1072s
|
total number of events: 108482
|
|
|
Latency (ms):
|
min: 3.12
|
avg: 44.26
|
max: 1146.91
|
95th percentile: 104.84
|
|
|
59a0236 Cleanup: Speed up mariabackup --prepare
|
|
|
+ 5999d51 MDEV-23399 fixup: Avoid crash on Mariabackup shutdown
|
|
|
transactions: 107202 (357.30 per sec.)
|
queries: 2144040 (7146.09 per sec.)
|
ignored errors: 0 (0.00 per sec.)
|
reconnects: 0 (0.00 per sec.)
|
|
|
Throughput:
|
events/s (eps): 357.3044
|
time elapsed: 300.0299s
|
total number of events: 107202
|
|
|
Latency (ms):
|
min: 3.11
|
avg: 44.77
|
max: 1683.51
|
95th percentile: 106.75
|
|
|
1657b7a Merge 10.4 to 10.5
|
1668465 MDEV-23998 Race between buf_page_optimistic_get() and buf_page_t::init()
|
|
|
+ 05cd5ac MDEV-23986: fil_page_type_validate() fails on crash recovery
|
|
|
transactions: 107366 (357.50 per sec.)
|
queries: 2147320 (7150.00 per sec.)
|
ignored errors: 0 (0.00 per sec.)
|
reconnects: 0 (0.00 per sec.)
|
|
|
Throughput:
|
events/s (eps): 357.5002
|
time elapsed: 300.3243s
|
total number of events: 107366
|
|
|
Latency (ms):
|
min: 3.13
|
avg: 44.74
|
max: 1482.35
|
95th percentile: 106.75
|
|
|
6dc037a MDEV-23399 fixup: Remove double-free of a buffer page
|
bdbec5a MDEV-23973 Change buffer corruption when reallocating an recently freed page
|
9028cc6 Cleanup: Make InnoDB page numbers uint32_t
|
61161d5 Cleanup: Remove export_vars.innodb_num_open_files
|
ecb913c Cleanup: Compare page_id_t directly
|
+ abb678b MDEV-19514 fixup: Simplify buf_page_read_complete()
|
|
|
transactions: 106916 (356.36 per sec.)
|
queries: 2138320 (7127.16 per sec.)
|
ignored errors: 0 (0.00 per sec.)
|
reconnects: 0 (0.00 per sec.)
|
|
|
Throughput:
|
events/s (eps): 356.3578
|
time elapsed: 300.0243s
|
total number of events: 106916
|
|
|
Latency (ms):
|
min: 3.08
|
avg: 44.89
|
max: 1607.38
|
95th percentile: 104.84
|
|
|
|
|
7cffb5f MDEV-23399: Performance regression with write workloads
|
...
|
882ce20 Merge 10.4 into 10.5
|
+ ccbe6bb MDEV-19935 Create unified CRC-32 interface
|
|
|
transactions: 76047 (253.47 per sec.)
|
queries: 1520940 (5069.33 per sec.)
|
ignored errors: 0 (0.00 per sec.)
|
reconnects: 0 (0.00 per sec.)
|
|
|
Throughput:
|
events/s (eps): 253.4663
|
time elapsed: 300.0281s
|
total number of events: 76047
|
|
|
Latency (ms):
|
min: 3.08
|
avg: 63.12
|
max: 932.00
|
95th percentile: 287.38
|
|
the problem was introduced in 3a9a3be:
3a9a3be MDEV-23855: Improve InnoDB log checkpoint performance
As a legend, "+" means I checked the commit and it's "fast", while "-" means I checked it and it is "slow", with some sysbench outputs shared. I hope this finding makes some sense for you.
I checked the results from the performance regression test suite for MariaDB 10.2.34 vs. 10.2.35. My results look completely different. Have a look:
- graphical results MDEV-24272.pdf
- textual results MDEV-24272.txt
- the my.cnf I'm using for OLTP read/write MDEV-24272.my.cnf
10.2.35 behaves much better than 10.2.34. The hardware is capable of running 32 threads (16 cores with hyperthreading) and I test up to 256 benchmark threads. Datadir resides on a local SSD.
The only difference is, that I test local builds (from released source tarballs) and not released binaries. Maybe the problem is with builds?
I've used my own builds from source for everything presented here. Specifically:
cmake . -DCMAKE_BUILD_TYPE=RelWithDebInfo -DWITH_SSL=system -DWITH_ZLIB=bundled -DMYSQL_MAINTAINER_MODE=OFF -DENABLED_LOCAL_INFILE=1 -DWITH_JEMALLOC=system -DWITH_INNODB_DISALLOW_WRITES=ON -DCMAKE_INSTALL_PREFIX=/home/openxs/dbs/maria10.2.34t -DWITHOUT_TOKUDB=1
|
|
|
cmake .. -DCMAKE_BUILD_TYPE=RelWithDebInfo -DWITH_SSL=system -DWITH_ZLIB=bundled -DMYSQL_MAINTAINER_MODE=OFF -DENABLED_LOCAL_INFILE=1 -DWITH_JEMALLOC=system -DWITH_INNODB_DISALLOW_WRITES=ON -DCMAKE_INSTALL_PREFIX=/home/openxs/dbs/maria10.5
|
and I tested with 16 threads on a very slow 2 core netbook with slow encrypted HDD capable to provide at most 260 IOPS for random sync writes of 16K pages:
openxs@ao756:~$ pt-summary
|
# Percona Toolkit System Summary Report ######################
|
Date | 2020-12-11 12:11:10 UTC (local TZ: EET +0200)
|
Hostname | ao756
|
Uptime | 3 days, 2:18, 2 users, load average: 0,14, 0,40, 0,31
|
Platform | Linux
|
Release | Ubuntu 16.04.7 LTS (xenial)
|
Kernel | 4.4.0-197-generic
|
Architecture | CPU = 64-bit, OS = 64-bit
|
Threading | NPTL 2.23
|
SELinux | No SELinux detected
|
Virtualized | No virtualization detected
|
# Processor ##################################################
|
Processors | physical = 1, cores = 2, virtual = 2, hyperthreading = no
|
Speeds | 1x1421.367, 1x1474.042
|
Models | 2xIntel(R) Pentium(R) CPU 987 @ 1.50GHz
|
Caches | 2x2048 KB
|
# Memory #####################################################
|
Total | 3,7G
|
Free | 173,1M
|
Used | physical = 189,5M, swap allocated = 3,8G, swap used = 133,9M, virtual = 323,4M
|
Shared | 11,7M
|
Buffers | 3,3G
|
Caches | 3,2G
|
Dirty | 152 kB
|
UsedRSS | 438,6M
|
Swappiness | 60
|
DirtyPolicy | 20, 10
|
DirtyStatus | 0, 0
|
...
|
For the original report I've also checked 10.4 similar builds on faster quad core system but with up to 32 threads, but the most detailed study of 10.2 and 10.5 commits was performed on the "slow" system above.
The test used was always this one:
sysbench oltp_read_write --db-driver=mysql --tables=5 --table-size=100000 --mysql-user=root --mysql-socket=/tmp/mariadb.sock --mysql-db=sbtest --threads=16 --time=300 --report-interval=10 run
|
and MariaDB was started as follo2ws, all defaults but few settings:
bin/mysqld_safe --no-defaults --port=3309 --socket=/tmp/mariadb.sock --skip-grant-tables --innodb_buffer_pool_size=1G --innodb_flush_log_at_trx_commit=2 &
|
I do not claim anything outside of these conditions. But the drop in performance I noted in 10.5.8 vs 10.5.6 and 10.4.17 vs 10.4.15 is of the same level as in much "larger" tests customer performed on real hardware and with MariaDB's official binaries. That's why I decided it makes sense to study the performance difference for commits under my restricted testing conditions.
I filed MDEV-24537 for the 10.5 performance regression. Let us retain this ticket for the 10.2, 10.3, 10.4 regressions only, related to MDEV-23475 and MDEV-20638.
I leave it to axel to decide what the correct action for 10.2, 10.3, 10.4 should be. My personal opinion is that anyone who wants performance should consider upgrading to 10.5.9 once it becomes available.
Do we have any clear theory of the reason of regression in 10.2 ... 10.4 case (I still see current 10.4.19 from GitHub providing less TPS than 10.4.15, this time on current Ubuntu 20.04)? Looks like we purge more, but why exactly?
valerii, MDEV-23475 reverted MDEV-20638 in 10.2.35, 10.3.26, 10.4.16 due to an observed performance regression in some types of workloads. The srv_inc_activity_count() should affect both purging and page flushing.
Your observation could suggest that actually, MDEV-20638 (which appeared in 10.2.33, 10.3.24, 10.4.14) delivered an overall improvement of performance.
What we could do is to run new benchmarks, possibly also on RAM disk, to eliminate any fluctuation caused by the storage layer. We would need some details from performance counters to understand what is actually going on. Based on only one overall measure (such as the throughput), we can only see that there is a problem, not what that problem is.
This issue is about regression in 10.2–10.4, as Marko moved 10.5 related part to MDEV-24537.
Closing as 10.4 is EOL now
We tested 10.5.6 and 10.5.8 standalones on identical HW and configuration
sysbench_result_standalone_10.5.6_innodb_thread_concurrency_0.txt
sysbench_result_standalone_10.5.8_innodb_thread_concurrency_0.txt
10.5.8 is indeed slower than 10.5.6