| Bug #110793 | high cpu usage for was_stale call when benchmark single table point select | ||
|---|---|---|---|
| Submitted: | 25 Apr 2023 2:40 | Modified: | 25 Apr 2023 23:17 |
| Reporter: | Fangxin Flou (OCA) | Email Updates: | |
| Status: | Not a Bug | Impact on me: | |
| Category: | MySQL Server: Storage Engines | Severity: | S3 (Non-critical) |
| Version: | 8.0.31 | OS: | Any |
| Assigned to: | CPU Architecture: | Any | |
[25 Apr 2023 11:56]
MySQL Verification Team
Hi Mr. Flou, Thank you for your bug report. However, your bug report is not complete. We do not see any single loop in that inline function. Hence, we do not think that there is a spinlock involved here. Those two assert checks can not account for that big difference in the performance. Hence, what we need for you is the graph that clearly shows that DML spends most of it's time in the function that is calling this inline function. Otherwise, a difference in the performance could come from any of the many other factors. Regarding your question, yes, those asserts are highly important, so removing them or using ut_ad() is out of the question. If any of those condition is not true, you would experience data corruption. Not a bug.
[25 Apr 2023 22:57]
Fangxin Flou
Benchmark on a 128 cpu thread host
Samples: 71K of event 'cpu-clock:u', Event count (approx.): 17769500000
Children Self Command Shared Object Symbol
19.62% 19.62% mysqld mysqld [.] Buf_fetch<Buf_fetch_normal>::single_page
12.12% 12.12% mysqld mysqld [.] buf_page_t::was_stale
6.17% 6.17% mysqld mysqld [.] mtr_t::release_block_at_savepoint
3.50% 3.50% mysqld mysqld [.] Buf_fetch_normal::get
1.71% 1.71% mysqld mysqld [.] btr_cur_search_to_nth_level
1.63% 1.63% mysqld mysqld [.] dispatch_command
[25 Apr 2023 22:57]
Fangxin Flou
Benchmark on a 128 cpu thread host
Samples: 71K of event 'cpu-clock:u', Event count (approx.): 17769500000
Children Self Command Shared Object Symbol
19.62% 19.62% mysqld mysqld [.] Buf_fetch<Buf_fetch_normal>::single_page
12.12% 12.12% mysqld mysqld [.] buf_page_t::was_stale
6.17% 6.17% mysqld mysqld [.] mtr_t::release_block_at_savepoint
3.50% 3.50% mysqld mysqld [.] Buf_fetch_normal::get
1.71% 1.71% mysqld mysqld [.] btr_cur_search_to_nth_level
1.63% 1.63% mysqld mysqld [.] dispatch_command
[25 Apr 2023 22:58]
Fangxin Flou
QPS with ut_a [ 10s ] thds: 256 tps: 1340077.75 qps: 1340077.75 (r/w/o: 1340077.75/0.00/0.00) lat (ms,95%): 0.17 err/s: 0.00 reconn/s: 0.00 [ 20s ] thds: 256 tps: 1338469.16 qps: 1338468.96 (r/w/o: 1338468.96/0.00/0.00) lat (ms,95%): 0.17 err/s: 0.00 reconn/s: 0.00 [ 30s ] thds: 256 tps: 1332154.28 qps: 1332154.48 (r/w/o: 1332154.48/0.00/0.00) lat (ms,95%): 0.17 err/s: 0.00 reconn/s: 0.00
[25 Apr 2023 23:00]
Fangxin Flou
QPS with ut_ad [ 10s ] thds: 256 tps: 1614633.21 qps: 1614633.21 (r/w/o: 1614633.21/0.00/0.00) lat (ms,95%): 0.15 err/s: 0.00 reconn/s: 0.00 [ 20s ] thds: 256 tps: 1616044.85 qps: 1616044.55 (r/w/o: 1616044.55/0.00/0.00) lat (ms,95%): 0.14 err/s: 0.00 reconn/s: 0.00 [ 30s ] thds: 256 tps: 1619234.05 qps: 1619234.25 (r/w/o: 1619234.25/0.00/0.00) lat (ms,95%): 0.14 err/s: 0.00 reconn/s: 0.00
[25 Apr 2023 23:01]
Fangxin Flou
file runsysbench.sh
sysbench oltp_point_select \
--threads=${1} --report-interval=10 --time=60 --range-selects=1 \
--db-driver=mysql --mysql-host=xxxxx --mysql-port=8001 --mysql-socket=/tmp/mysql02.sock \
--mysql-db=test --mysql-user=test --mysql-password=test --db-ps-mode=auto \
--tables=1 --table-size=1000000 ${2}
run with
sh runsysbench.sh 256 run
[25 Apr 2023 23:01]
Fangxin Flou
QPS with ut_ad [ 10s ] thds: 256 tps: 1614633.21 qps: 1614633.21 (r/w/o: 1614633.21/0.00/0.00) lat (ms,95%): 0.15 err/s: 0.00 reconn/s: 0.00 [ 20s ] thds: 256 tps: 1616044.85 qps: 1616044.55 (r/w/o: 1616044.55/0.00/0.00) lat (ms,95%): 0.14 err/s: 0.00 reconn/s: 0.00 [ 30s ] thds: 256 tps: 1619234.05 qps: 1619234.25 (r/w/o: 1619234.25/0.00/0.00) lat (ms,95%): 0.14 err/s: 0.00 reconn/s: 0.00
[25 Apr 2023 23:09]
Fangxin Flou
after replace the "ut_a" with "ut_ad" of the following line ut_a(m_space != nullptr); I get better QPS result [ 10s ] thds: 256 tps: 1446620.08 qps: 1446620.08 (r/w/o: 1446620.08/0.00/0.00) lat (ms,95%): 0.16 err/s: 0.00 reconn/s: 0.00 [ 20s ] thds: 256 tps: 1445152.14 qps: 1445152.14 (r/w/o: 1445152.14/0.00/0.00) lat (ms,95%): 0.15 err/s: 0.00 reconn/s: 0.00 [ 30s ] thds: 256 tps: 1449935.76 qps: 1449935.76 (r/w/o: 1449935.76/0.00/0.00) lat (ms,95%): 0.15 err/s: 0.00 reconn/s: 0.00
[25 Apr 2023 23:17]
Fangxin Flou
Code:
inline bool was_stale() const {
ut_ad(m_space != nullptr);
ut_ad(id.space() == m_space->id);
/* If the the version is OK, then the space must not be deleted.
However, version is modified before the deletion flag is set, so reading
these values need to be executed in reversed order. The atomic reads
cannot be relaxed for it to work. */
if (m_version == m_space->get_recent_version()) {
ut_a(m_space->was_not_deleted());
return false;
} else {
return true;
}
}
Better Result:
[ 10s ] thds: 256 tps: 1632812.22 qps: 1632812.02 (r/w/o: 1632812.02/0.00/0.00) lat (ms,95%): 0.15 err/s: 0.00 reconn/s: 0.00
[ 20s ] thds: 256 tps: 1634524.17 qps: 1634524.27 (r/w/o: 1634524.27/0.00/0.00) lat (ms,95%): 0.14 err/s: 0.00 reconn/s: 0.00
[ 30s ] thds: 256 tps: 1640177.94 qps: 1640178.04 (r/w/o: 1640178.04/0.00/0.00) lat (ms,95%): 0.14 err/s: 0.00 reconn/s: 0.00
[2 May 2023 12:16]
MySQL Verification Team
Hi Mr. Flou, We answered all your questions. Those asserts are very much necessary. If we would replace all ut_a() with ut_ad() then performance would be probably twice better. However, integrity of data are more important then QPS.
Description: I was benchmarking oltp_point_select for single table (tables=1), found that the "was_stale" call used a lot of CPU (about 10% of mysqld process cpu usage). inline bool was_stale() const { ut_a(m_space != nullptr); ut_a(id.space() == m_space->id); /* If the the version is OK, then the space must not be deleted. However, version is modified before the deletion flag is set, so reading these values need to be executed in reversed order. The atomic reads cannot be relaxed for it to work. */ bool was_not_deleted = m_space->was_not_deleted(); if (m_version == m_space->get_recent_version()) { ut_a(was_not_deleted); return false; } else { return true; } } After replace the "ut_a" with "ut_ad", the QPS improved by 15%+. How to repeat: Start sysbench oltp_point_select for single table and analyze the perf record result. Suggested fix: The modified version. inline bool was_stale() const { ut_ad(m_space != nullptr); ut_ad(id.space() == m_space->id); /* If the the version is OK, then the space must not be deleted. However, version is modified before the deletion flag is set, so reading these values need to be executed in reversed order. The atomic reads cannot be relaxed for it to work. */ if (m_version == m_space->get_recent_version()) { ut_ad(m_space->was_not_deleted()); return false; } else { return true; } } Any special purpose to use "ut_a" here?