MySQL Bugs: #102238: log_writer uses too much CPU on small servers

Bug #102238	log_writer uses too much CPU on small servers
Submitted:	12 Jan 2021 20:35	Modified:	21 Dec 2023 8:49
Reporter:	Mark Callaghan	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S5 (Performance)
Version:	8.0.22	OS:	Any
Assigned to:		CPU Architecture:	Any

Description:
The InnoDB log_writer code uses too much CPU in 8.0.22. I previously filed https://bugs.mysql.com/bug.php?id=90890 but that was closed as fixed. I used sysbench to evaluate insert rates and innodb_log_writer_threads uses a lot more CPU without providing better insert rates.

I abbreviate innodb_log_writer_threads as ILWT.

In the legend below, when rel-CPU is < 1 then ILWT=OFF uses less CPU. And when rel-IPS > 1 then ILWT has a better insert rate. What I see is rel-CPU is much less than 1 while rel-IPS is ~1 (so much cost, but little gain from log_writer_threads=ON).

Legend:
* clients - number of concurrent inserters
* rel-CPU - (CPU overhead for ILWT=OFF) / (CPU overhead for ILWT=ON)
* rel-IPS - (insert rate for ILWT=OFF) / (insert rate for ILWT=ON)

clients rel-CPU rel-IPS
1       0.57    0.95
2       0.66    1.03
3       0.67    1.23

Absolute insert rates
1       2       3       #clients/config
8882    16837   22709   ILWT=OFF
9304    16390   18459   ILWT=ON

How to repeat:
With Lua scripts from from https://github.com/mdcallag/sysbench/tree/1.0/src/lua

# TODO - set this
sbp=/path/to/sysbench/lua/scripts

# prepare 1 table with 10M rows
sysbench --db-driver=mysql --mysql-storage-engine=innodb --range-size=100 --table-size=10000000 --tables=1 --events=0 --time=180 $sbp/oltp_point_select.lua prepare --mysql-user=root --mysql-password=pw --mysql-host=127.0.0.1 --mysql-db=test

# warmup with queries
sysbench --db-driver=mysql --range-size=100 --table-size=10000000 --tables=1 --threads=2 --events=0 --warmup-time=5 --time=180 $sbp/oltp_point_select.lua run --mysql-user=root --mysql-password=pw --mysql-host=127.0.0.1 --mysql-db=test --rand-type=uniform --skip-trx

# write back dirty pages, not sure this is needed, but my scripts do it
# reduce max-dirty-pages variables, wait a few minutes, reset variables

# do inserts
for dop in 1 2 3 ; do

sysbench --db-driver=mysql --range-size=100 --table-size=10000000 --tables=1 --threads=1 --events=0 --warmup-time=5 --time=180 $sbp/oltp_insert.lua run --mysql-user=root --mysql-password=pw --mysql-host=127.0.0.1 --mysql-db=test --rand-type=uniform

done

First I used this my.cnf that gets innodb_log_writer_threads=ON by default...
[mysqld]
sql_mode=no_engine_substitution,no_unsigned_subtraction
default_tmp_storage_engine=MyISAM
tmpdir=/data/m/my
#query_cache_size=0
#query_cache_type=0
# slow_query_log_file=/data/m/my/slow.log
long_query_time=5
# skip_log_bin
log_bin=/data/m/my/binlogs/bl
max_binlog_size=128M
server_id=77
binlog_format=ROW
datadir=/data/m/my/data

innodb_file_per_table=1

innodb_data_home_dir=/data/m/my/data
innodb_data_file_path=ibdata1:512M:autoextend
innodb_log_group_home_dir=/data/m/my/txlogs
slow_query_log=1

performance_schema=1
ssl=0
default_authentication_plugin=mysql_native_password
character_set_server=latin1
collation_server=latin1_swedish_ci
eq_range_index_dive_limit=10

innodb_fast_shutdown=1
innodb_doublewrite=1
innodb_buffer_pool_load_at_startup=OFF
innodb_buffer_pool_dump_at_shutdown=OFF
innodb_purge_threads=1

innodb_flush_log_at_trx_commit=2
sync_binlog=0

# x1
innodb_dedicated_server=ON
innodb_buffer_pool_size=10G

# x2b
innodb_log_files_in_group=40
innodb_log_file_size=1G

# x4
innodb_max_dirty_pages_pct_lwm=80
innodb_max_dirty_pages_pct=90

# x6d
innodb_idle_flush_pct=1
innodb_io_capacity=1000
innodb_io_capacity_max=2000

[mysqld_safe]
malloc-lib=/usr/lib/x86_64-linux-gnu/libjemalloc.so

---

And then I just appended innodb_log_writer_threads=OFF to see the impact

My server is small, a NUC with 4 real CPU cores and HT disabled
http://smalldatum.blogspot.com/2018/12/new-small-servers-for-performance.html

Flamegraph to show CPU from log writer for 8.0.22

Attachment: sb.perf.data.insert.range100.pk1.Jan11.053448.perf.scr.svg (image/svg+xml, text), 343.86 KiB.

Flamegraph from 5.7.31 that doesn't have CPU problems from log writer

Attachment: sb.perf.data.insert.range100.pk1.Jan10.224916.perf.scr.svg (image/svg+xml, text), 270.28 KiB.

I think this is not a bug from 8.0.22.

We removed closer_thread at 8.0.22,
but writer_thread and flusher_thread are remained as innodb_log_writer_threads.
innodb_log_writer_threads is for redundant CPU cores scale.
It wastes CPU resource for more scale throughput,
and every fixes to reduce the CPU resource also reduced performance.

So, many of current use-cases (no redundant CPU cores) might be better to use innodb_log_writer_threads=OFF.

I think we cannot treat bad setting causes bad performance as a bug.
Please use innodb_log_writer_threads=OFF for them.

innodb_log_writer_threads=OFF of 8.0.22 is almost just revived from 5.7 code,
and might still have some performance incompatibility for some 8.0 specific cases.
I also adjusted innodb_log_writer_threads=OFF mode smoother for newer 8.0.
Please use innodb_log_writer_threads=OFF, again...

Hi Mr. Callaghan,

Thank you for reporting this bug to us.

We hope that you have read the comments from our developer, Yasufumi Kinoshita.

At this point, there are two possibilities. We either verify this report as a documentation bug, or as a feature request. In the case of the second option, it would be nice from you to define what would that new feature look like.

Many thanks in advance.

I am disappointed by this response and suspect I am wasting my time.

WRT to ...

-> "I think this is not a bug from 8.0.22."
...
I checked again and my results are from 8.0.22 -- both the QPS and flamegraphs

-> "I think we cannot treat bad setting causes bad performance as a bug.
Please use innodb_log_writer_threads=OFF for them."
...
I am not sure what this means. AFAIK the new redo log code works great when you have spare CPU, and otherwise is a problem. I prefer you make the feature more clever rather than blaming the user for not knowing which option to use. This gets even better because "spare CPU" isn't a static property of a deployment, it will change over time.

Hello Mr. Callaghan,

Thank you for your feedback.

What we can deduce from your comments is that you would prefer it to be a feature request or a performance improvement request, instead of just augmenting the documentation.

In that case, would you be so kind and define precisely the manner in which you would like that writer threads function when there are no redundant cores available. If you could devise (very) roughly that algorithm, that might lead to better performance of multiple log writer threads.

Thanks very much in advance.

This was filed as a performance but I don't decide what you do with it.

I don't know much about the implementation, nor am I willing to commit the time to figure it out. Expecting perf bug reports to provide an alternate implementation seems extreme. 

My summary is that the feature has problems in many scenarios and the MySQL community is better served if this is resolved. It seems unreasonable to assume there is spare CPU capacity available just for this feature. Maybe this works great for benchmarks to get results for keynote slides but it will be a problem elsewhere.

Though it is personal opinion, let me reply.

Personally, I think innodb_log_writer_threads=OFF should be default value for now
(most of current users might not need innodb_log_writer_threads=ON even for middle spec HW yet; too early at 2020-2021?),
to avoid such confusion among community.

If reduces the spinning opportunity at innodb_log_writer_threads to save cpu%,
just makes innodb_log_writer_threads=ON slower for "all cases". The regression at high-spec HW will not be accepted.
(Waking up another dedicated thread must be "always" slower than do it by the thread itself. (But better scale only at redundant CPU cores lower CPU%... max scale is preferred in history and still))

If we want to eliminate the such innodb_log_writer_threads=ON mode wasting CPU,
only way might be to improve innodb_log_writer_threads=OFF mode for "all cases".
So, complaint about innodb_log_writer_threads=ON for known/assumed case is no information, to improve innodb_log_writer_threads=OFF mode.

If you have problem innodb_log_writer_threads=OFF worse than ON, please report the bug rather.
Because making innodb_log_writer_threads=OFF better is the solution here, I think.

Thank you for reporting.

We have the way to avoid such problem innodb_log_writer_threads=OFF now.
Let me close this issue for now.