[MDEV-28222] Performance regression in MariaDB 10.4 when iterating over many tables with large table_definition_cache, in comparison to MariaDB 10.3 Created: 2022-04-02  Updated: 2022-04-18  Resolved: 2022-04-18

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - Aria
Affects Version/s: 10.4.17, 10.4.25
Fix Version/s: N/A

Type: Bug Priority: Critical
Reporter: Valerii Kravchuk Assignee: Unassigned
Resolution: Cannot Reproduce Votes: 0
Labels: regression-10.4
Environment:

macOS 10.13.6, Windows (suspected)


 Description   

Consider the following MTR test case:

Yuliyas-MacBook-Air:mysql-test Valerii$ cat suite/innodb/t/tdc.test 
source include/have_innodb.inc;
 
set default_storage_engine=innodb;
 
delimiter ||;
 
set use_stat_tables=NEVER||
 
for i in 1..50000 do execute immediate concat('create table if not exists t_', i,' as select ', i, ' as a'); end for||
 
set global table_definition_cache=50000||
 
select @@table_definition_cache||
 
flush tables||
 
flush status||
 
# load tables into cache
 
for i in 1..50000 do execute immediate concat('update t_', i,' set a=a+1'); end for||
 
show status like 'open%'||
 
# verify that they're in the cache now
 
select now()||
 
for i in 1..50000 do execute immediate concat('update t_', i,' set a=a+1'); end for||
 
select now()||
 
show status like 'open%'||
 
set session profiling = ON||
 
flush tables||
 
set session profiling = OFF||
 
set global table_definition_cache=500000||
 
select @@table_definition_cache||
 
flush status||
 
for i in 1..50000 do execute immediate concat('update t_', i,' set a=a+1'); end for||
 
show status like 'open%'||
 
select now()||
 
for i in 1..50000 do execute immediate concat('update t_', i,' set a=a+1'); end for||
 
select now()||
 
show status like 'open%'||
 
set session profiling = ON||
 
flush tables||
 
set session profiling = OFF||
 
set global table_definition_cache=default||
 
show profiles||
 
show profile all for query 1||
 
show profile all for query 2||
 
select now()||
 
for i in 1..50000 do execute immediate concat('drop table t_', i); end for||
 
select now()||

that is essentially https://jira.mariadb.org/secure/attachment/62808/flush_benchmark_1.test with few selects added to measure time spent on second UPDATE and DROP TABLE steps.

On 10.3 I get:

Yuliyas-MacBook-Air:mysql-test Valerii$ ./mtr --suite=innodb tdc
 
Logging: ./mtr  --suite=innodb tdc
 
VS config: 
vardir: /Users/Valerii/dbs/maria10.3/mysql-test/var
 
Checking leftover processes...
 
Removing old var directory...
 
Creating var directory '/Users/Valerii/dbs/maria10.3/mysql-test/var'...
 
Checking supported features...
 
MariaDB Version 10.3.35-MariaDB
 
 - SSL connections supported
 
 - binaries built with wsrep patch
 
Collecting tests...
 
Installing system database...
 
 
 
==============================================================================
 
 
 
TEST                                      RESULT   TIME (ms) or COMMENT
 
--------------------------------------------------------------------------
 
 
 
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
 
set default_storage_engine=innodb;
 
set use_stat_tables=NEVER||
 
for i in 1..50000 do execute immediate concat('create table if not exists t_', i,' as select ', i, ' as a'); end for||
 
set global table_definition_cache=50000||
 
select @@table_definition_cache||
 
@@table_definition_cache
 
50000
 
flush tables||
 
flush status||
 
for i in 1..50000 do execute immediate concat('update t_', i,' set a=a+1'); end for||
 
show status like 'open%'||
 
Variable_name	Value
 
Open_files	7
 
Open_streams	0
 
Open_table_definitions	50000
 
Open_tables	421
 
Opened_files	150138
 
Opened_plugin_libraries	0
 
Opened_table_definitions	50000
 
Opened_tables	50000
 
Opened_views	0
 
select now()||
 
now()
 
2022-04-02 17:16:09
 
for i in 1..50000 do execute immediate concat('update t_', i,' set a=a+1'); end for||
 
select now()||
 
now()
 
2022-04-02 17:19:13
 
show status like 'open%'||
 
Variable_name	Value
 
Open_files	7
 
Open_streams	0
 
Open_table_definitions	50000
 
Open_tables	421
 
Opened_files	150138
 
Opened_plugin_libraries	0
 
Opened_table_definitions	50000
 
Opened_tables	100000
 
Opened_views	0
 
set session profiling = ON||
 
flush tables||
 
set session profiling = OFF||
 
set global table_definition_cache=500000||
 
select @@table_definition_cache||
 
@@table_definition_cache
 
500000
 
flush status||
 
for i in 1..50000 do execute immediate concat('update t_', i,' set a=a+1'); end for||
 
show status like 'open%'||
 
Variable_name	Value
 
Open_files	7
 
Open_streams	0
 
Open_table_definitions	50000
 
Open_tables	421
 
Opened_files	200138
 
Opened_plugin_libraries	0
 
Opened_table_definitions	50000
 
Opened_tables	50000
 
Opened_views	0
 
select now()||
 
now()
 
2022-04-02 17:22:53
 
for i in 1..50000 do execute immediate concat('update t_', i,' set a=a+1'); end for||
 
worker[1] Test still running: innodb.tdc
 
select now()||
 
now()
 
2022-04-02 17:25:58
 
show status like 'open%'||
 
Variable_name	Value
 
Open_files	7
 
Open_streams	0
 
Open_table_definitions	50000
 
Open_tables	421
 
Opened_files	200138
 
Opened_plugin_libraries	0
 
Opened_table_definitions	50000
 
Opened_tables	100000
 
Opened_views	0
 
set session profiling = ON||
 
flush tables||
 
set session profiling = OFF||
 
set global table_definition_cache=default||
 
show profiles||
 
Query_ID	Duration	Query
 
1	0.17661200	flush tables
 
2	0.22418900	flush tables
 
show profile all for query 1||
 
Status	Duration	CPU_user	CPU_system	Context_voluntary	Context_involuntary	Block_ops_in	Block_ops_out	Messages_sent	Messages_received	Page_faults_major	Page_faults_minor	Swaps	Source_function	Source_file	Source_line
 
Starting	0.176541	0.149710	0.024630	0	94	NULL	NULL	NULL
 
Query end	0.000013	0.000008	0.000005	0	0	<unknown>	sql_parse.cc	6085
 
Commit	0.000005	0.000003	0.000002	0	0	0	<unknown>	sql_parse.cc	6149
 
Closing tables	0.000004	0.000003	0.000001	0	0	<unknown>	sql_base.cc	728
 
Commit_implicit	0.000003	0.000003	0.000000	0	0	<unknown>	sql_parse.cc	6193
 
Starting cleanup	0.000004	0.000002	0.000001	0	<unknown>	sql_parse.cc	6221
 
Freeing items	0.000005	0.000004	0.000001	0	0	<unknown>	sql_parse.cc	7887
 
Updating status	0.000022	0.000008	0.000015	0	0	<unknown>	sql_parse.cc	2405
 
Reset for next command	0.000015	0.000014	0.000001	0	<unknown>	sql_parse.cc	2429
 
show profile all for query 2||
 
Status	Duration	CPU_user	CPU_system	Context_voluntary	Context_involuntary	Block_ops_in	Block_ops_out	Messages_sent	Messages_received	Page_faults_major	Page_faults_minor	Swaps	Source_function	Source_file	Source_line
 
Starting	0.224081	0.168832	0.052962	0	131	NULL	NULL	NULL
 
Query end	0.000016	0.000009	0.000007	0	0	<unknown>	sql_parse.cc	6085
 
Commit	0.000009	0.000005	0.000004	0	0	0	<unknown>	sql_parse.cc	6149
 
Closing tables	0.000008	0.000005	0.000003	0	0	<unknown>	sql_base.cc	728
 
Commit_implicit	0.000007	0.000004	0.000002	0	0	<unknown>	sql_parse.cc	6193
 
Starting cleanup	0.000006	0.000003	0.000002	0	<unknown>	sql_parse.cc	6221
 
Freeing items	0.000008	0.000007	0.000003	0	0	<unknown>	sql_parse.cc	7887
 
Updating status	0.000031	0.000010	0.000020	0	0	<unknown>	sql_parse.cc	2405
 
Reset for next command	0.000023	0.000020	0.000003	0	<unknown>	sql_parse.cc	2429
 
select now()||
 
now()
 
2022-04-02 17:25:59
 
for i in 1..50000 do execute immediate concat('drop table t_', i); end for||
 
select now()||
 
now()
 
2022-04-02 17:37:05
 
innodb.tdc 'innodb'                      [ pass ]  2012753
 
--------------------------------------------------------------------------
 
The servers were restarted 0 times
 
Spent 2012.753 of 2020 seconds executing testcases
 
 
 
Completed: All 1 tests were successful.

It means that total time to run is 2012 seconds, of them:

  • second UPDATE with smaller table_definition_cache takes 3 minutes and 4 seconds
  • second UPDATE with larger table_definition_cache takes 3 minutes and 5 seconds (no real difference)
  • DROP of 50000 tables with larger table_definition_cache takes 11 minutes 6 seconds.

Now, with recent 10.4 build from GitHub source, on the same system I get:

Yuliyas-MacBook-Air:mysql-test Valerii$ ./mtr --suite=innodb tdc
 
Logging: ./mtr  --suite=innodb tdc
 
VS config: 
vardir: /Users/Valerii/dbs/maria10.4/mysql-test/var
 
Checking leftover processes...
 
Removing old var directory...
 
Creating var directory '/Users/Valerii/dbs/maria10.4/mysql-test/var'...
 
Checking supported features...
 
MariaDB Version 10.4.25-MariaDB
 
 - SSL connections supported
 
Collecting tests...
 
Installing system database...
 
 
 
==============================================================================
 
 
 
TEST                                      RESULT   TIME (ms) or COMMENT
 
--------------------------------------------------------------------------
 
 
 
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
 
set default_storage_engine=innodb;
 
set use_stat_tables=NEVER||
 
for i in 1..50000 do execute immediate concat('create table if not exists t_', i,' as select ', i, ' as a'); end for||
 
set global table_definition_cache=50000||
 
select @@table_definition_cache||
 
@@table_definition_cache
 
50000
 
flush tables||
 
flush status||
 
for i in 1..50000 do execute immediate concat('update t_', i,' set a=a+1'); end for||
 
worker[1] Test still running: innodb.tdc
 
show status like 'open%'||
 
Variable_name	Value
 
Open_files	6
 
Open_streams	0
 
Open_table_definitions	50000
 
Open_tables	421
 
Opened_files	150141
 
Opened_plugin_libraries	0
 
Opened_table_definitions	50000
 
Opened_tables	50000
 
Opened_views	0
 
select now()||
 
now()
 
2022-04-02 18:11:57
 
for i in 1..50000 do execute immediate concat('update t_', i,' set a=a+1'); end for||
 
select now()||
 
now()
 
2022-04-02 18:15:16
 
show status like 'open%'||
 
Variable_name	Value
 
Open_files	6
 
Open_streams	0
 
Open_table_definitions	50000
 
Open_tables	421
 
Opened_files	150141
 
Opened_plugin_libraries	0
 
Opened_table_definitions	50000
 
Opened_tables	100000
 
Opened_views	0
 
set session profiling = ON||
 
flush tables||
 
set session profiling = OFF||
 
set global table_definition_cache=500000||
 
select @@table_definition_cache||
 
@@table_definition_cache
 
500000
 
flush status||
 
for i in 1..50000 do execute immediate concat('update t_', i,' set a=a+1'); end for||
 
show status like 'open%'||
 
Variable_name	Value
 
Open_files	6
 
Open_streams	0
 
Open_table_definitions	50000
 
Open_tables	421
 
Opened_files	200141
 
Opened_plugin_libraries	0
 
Opened_table_definitions	50000
 
Opened_tables	50000
 
Opened_views	0
 
select now()||
 
now()
 
2022-04-02 18:18:49
 
for i in 1..50000 do execute immediate concat('update t_', i,' set a=a+1'); end for||
 
select now()||
 
now()
 
2022-04-02 18:21:53
 
show status like 'open%'||
 
Variable_name	Value
 
Open_files	6
 
Open_streams	0
 
Open_table_definitions	50000
 
Open_tables	421
 
Opened_files	200141
 
Opened_plugin_libraries	0
 
Opened_table_definitions	50000
 
Opened_tables	100000
 
Opened_views	0
 
set session profiling = ON||
 
flush tables||
 
set session profiling = OFF||
 
set global table_definition_cache=default||
 
show profiles||
 
Query_ID	Duration	Query
 
1	0.16105500	flush tables
 
2	0.22038200	flush tables
 
show profile all for query 1||
 
Status	Duration	CPU_user	CPU_system	Context_voluntary	Context_involuntary	Block_ops_in	Block_ops_out	Messages_sent	Messages_received	Page_faults_major	Page_faults_minor	Swaps	Source_function	Source_file	Source_line
 
Starting	0.160942	0.134530	0.023944	0	338	1920	0	NULL	NULL	NULL
 
Query end	0.000011	0.000005	0.000005	0	0	<unknown>	sql_parse.cc	6218
 
Commit	0.000005	0.000004	0.000002	0	0	0	<unknown>	sql_parse.cc	6264
 
Closing tables	0.000004	0.000003	0.000001	0	0	<unknown>	sql_base.cc	882
 
Commit_implicit	0.000004	0.000003	0.000001	0	0	<unknown>	sql_parse.cc	6303
 
Starting cleanup	0.000004	0.000002	0.000001	0	<unknown>	sql_parse.cc	6331
 
Freeing items	0.000005	0.000005	0.000001	0	0	<unknown>	sql_parse.cc	8028
 
Updating status	0.000033	0.000009	0.000024	0	0	<unknown>	sql_parse.cc	2452
 
Reset for next command	0.000047	0.000022	0.000019	0	<unknown>	sql_parse.cc	2476
 
show profile all for query 2||
 
Status	Duration	CPU_user	CPU_system	Context_voluntary	Context_involuntary	Block_ops_in	Block_ops_out	Messages_sent	Messages_received	Page_faults_major	Page_faults_minor	Swaps	Source_function	Source_file	Source_line
 
Starting	0.220290	0.158555	0.069353	74	1296	173	0	NULL	NULL	NULL
 
Query end	0.000011	0.000006	0.000004	0	0	<unknown>	sql_parse.cc	6218
 
Commit	0.000005	0.000003	0.000002	0	0	0	<unknown>	sql_parse.cc	6264
 
Closing tables	0.000004	0.000003	0.000000	0	0	<unknown>	sql_base.cc	882
 
Commit_implicit	0.000003	0.000003	0.000001	0	0	<unknown>	sql_parse.cc	6303
 
Starting cleanup	0.000004	0.000003	0.000001	0	<unknown>	sql_parse.cc	6331
 
Freeing items	0.000005	0.000004	0.000001	0	0	<unknown>	sql_parse.cc	8028
 
Updating status	0.000021	0.000016	0.000014	0	0	<unknown>	sql_parse.cc	2452
 
Reset for next command	0.000039	0.000017	0.000013	0	<unknown>	sql_parse.cc	2476
 
select now()||
 
now()
 
2022-04-02 18:21:53
 
for i in 1..50000 do execute immediate concat('drop table t_', i); end for||
 
worker[1] Test still running: innodb.tdc
 
select now()||
 
now()
 
2022-04-02 18:33:05
 
innodb.tdc 'innodb'                      [ pass ]  3318735
 
--------------------------------------------------------------------------
 
The servers were restarted 0 times
 
Spent 3318.735 of 3296 seconds executing testcases
 
 
 
Completed: All 1 tests were successful.

It means that total time to run is 3319 seconds (1,5 times more), of them:

  • second UPDATE with smaller table_definition_cache takes 3 minutes and 19 seconds
  • second UPDATE with larger table_definition_cache takes 3 minutes and 4 seconds (even faster)
  • DROP of 50000 tables with larger table_definition_cache takes 11 minutes 12 seconds.

So, it seems most of the difference is coming either from the first runs of UPDATE, or from CREATE TABLE with table_definition_cache of 50K.

In any case, 10.4 being slower than 10.3 with large table_definition_cache (both 50K and 500K are "large" for this purpose) while "iterating" over many (50K, 100K, 500K) tables was reported elsewhere for Windows environment as well. This performance regression is something to study.

 Comments   
Comment by Valerii Kravchuk [ 2022-04-03 ]

New results with extra ALTER TABLE ... engine=Aria step added, and time recorded for each major step.

With 10.3.35:

Yuliyas-MacBook-Air:mysql-test Valerii$ ./mtr --suite=innodb tdc
 
Logging: ./mtr  --suite=innodb tdc
 
VS config: 
vardir: /Users/Valerii/dbs/maria10.3/mysql-test/var
 
Checking leftover processes...
 
Removing old var directory...
 
Creating var directory '/Users/Valerii/dbs/maria10.3/mysql-test/var'...
 
Checking supported features...
 
MariaDB Version 10.3.35-MariaDB
 
 - SSL connections supported
 
 - binaries built with wsrep patch
 
Collecting tests...
 
Installing system database...
 
 
 
==============================================================================
 
 
 
TEST                                      RESULT   TIME (ms) or COMMENT
 
--------------------------------------------------------------------------
 
 
 
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
 
set default_storage_engine=innodb;
 
set use_stat_tables=NEVER||
 
set global table_definition_cache=500000||
 
select @@table_definition_cache||
 
@@table_definition_cache
 
500000
 
select now()||
 
now()
 
2022-04-03 12:56:42
 
for i in 1..50000 do execute immediate concat('create table if not exists t_', i,' as select ', i, ' as a'); end for||
 
select now()||
 
now()
 
2022-04-03 13:05:29
 
set global table_definition_cache=50000||
 
select @@table_definition_cache||
 
@@table_definition_cache
 
50000
 
flush tables||
 
flush status||
 
select now()||
 
now()
 
2022-04-03 13:05:30
 
for i in 1..50000 do execute immediate concat('update t_', i,' set a=a+1'); end for||
 
show status like 'open%'||
 
Variable_name	Value
 
Open_files	7
 
Open_streams	0
 
Open_table_definitions	50000
 
Open_tables	421
 
Opened_files	150138
 
Opened_plugin_libraries	0
 
Opened_table_definitions	50000
 
Opened_tables	50000
 
Opened_views	0
 
select now()||
 
now()
 
2022-04-03 13:08:59
 
for i in 1..50000 do execute immediate concat('update t_', i,' set a=a+1'); end for||
 
select now()||
 
now()
 
2022-04-03 13:12:10
 
show status like 'open%'||
 
Variable_name	Value
 
Open_files	7
 
Open_streams	0
 
Open_table_definitions	50000
 
Open_tables	421
 
Opened_files	150138
 
Opened_plugin_libraries	0
 
Opened_table_definitions	50000
 
Opened_tables	100000
 
Opened_views	0
 
set session profiling = ON||
 
flush tables||
 
set session profiling = OFF||
 
set global table_definition_cache=500000||
 
select @@table_definition_cache||
 
@@table_definition_cache
 
500000
 
flush status||
 
select now()||
 
now()
 
2022-04-03 13:12:10
 
for i in 1..50000 do execute immediate concat('update t_', i,' set a=a+1'); end for||
 
show status like 'open%'||
 
Variable_name	Value
 
Open_files	7
 
Open_streams	0
 
Open_table_definitions	50000
 
Open_tables	421
 
Opened_files	200138
 
Opened_plugin_libraries	0
 
Opened_table_definitions	50000
 
Opened_tables	50000
 
Opened_views	0
 
select now()||
 
now()
 
2022-04-03 13:15:44
 
for i in 1..50000 do execute immediate concat('update t_', i,' set a=a+1'); end for||
 
worker[1] Test still running: innodb.tdc
 
select now()||
 
now()
 
2022-04-03 13:18:56
 
show status like 'open%'||
 
Variable_name	Value
 
Open_files	7
 
Open_streams	0
 
Open_table_definitions	50000
 
Open_tables	421
 
Opened_files	200138
 
Opened_plugin_libraries	0
 
Opened_table_definitions	50000
 
Opened_tables	100000
 
Opened_views	0
 
set session profiling = ON||
 
flush tables||
 
set session profiling = OFF||
 
set global table_definition_cache=default||
 
show profiles||
 
Query_ID	Duration	Query
 
1	0.34822600	flush tables
 
2	0.28296800	flush tables
 
show profile all for query 1||
 
Status	Duration	CPU_user	CPU_system	Context_voluntary	Context_involuntary	Block_ops_in	Block_ops_out	Messages_sent	Messages_received	Page_faults_major	Page_faults_minor	Swaps	Source_function	Source_file	Source_line
 
Starting	0.348125	0.195479	0.113468	183	1394	3863	0	NULL	NULL	NULL
 
Query end	0.000020	0.000008	0.000011	0	0	<unknown>	sql_parse.cc	6085
 
Commit	0.000005	0.000003	0.000002	0	0	0	<unknown>	sql_parse.cc	6149
 
Closing tables	0.000003	0.000003	0.000001	0	0	<unknown>	sql_base.cc	728
 
Commit_implicit	0.000003	0.000002	0.000001	0	0	<unknown>	sql_parse.cc	6193
 
Starting cleanup	0.000004	0.000002	0.000000	0	<unknown>	sql_parse.cc	6221
 
Freeing items	0.000013	0.000013	0.000001	0	0	<unknown>	sql_parse.cc	7887
 
Updating status	0.000019	0.000007	0.000013	0	0	<unknown>	sql_parse.cc	2405
 
Reset for next command	0.000034	0.000015	0.000018	0	<unknown>	sql_parse.cc	2429
 
show profile all for query 2||
 
Status	Duration	CPU_user	CPU_system	Context_voluntary	Context_involuntary	Block_ops_in	Block_ops_out	Messages_sent	Messages_received	Page_faults_major	Page_faults_minor	Swaps	Source_function	Source_file	Source_line
 
Starting	0.282852	0.201568	0.089823	77	833	903	0	NULL	NULL	NULL
 
Query end	0.000019	0.000011	0.000009	0	0	<unknown>	sql_parse.cc	6085
 
Commit	0.000010	0.000006	0.000004	0	0	0	<unknown>	sql_parse.cc	6149
 
Closing tables	0.000009	0.000005	0.000003	0	0	<unknown>	sql_base.cc	728
 
Commit_implicit	0.000007	0.000003	0.000003	0	0	<unknown>	sql_parse.cc	6193
 
Starting cleanup	0.000007	0.000005	0.000003	0	<unknown>	sql_parse.cc	6221
 
Freeing items	0.000008	0.000006	0.000002	0	0	<unknown>	sql_parse.cc	7887
 
Updating status	0.000030	0.000012	0.000018	0	0	<unknown>	sql_parse.cc	2405
 
Reset for next command	0.000026	0.000022	0.000005	0	<unknown>	sql_parse.cc	2429
 
select now()||
 
now()
 
2022-04-03 13:18:57
 
for i in 1..50000 do execute immediate concat('alter table t_', i, ' engine=Aria'); end for||
 
worker[1] Test still running: innodb.tdc
 
select now()||
 
now()
 
2022-04-03 13:39:42
 
for i in 1..50000 do execute immediate concat('drop table t_', i); end for||
 
select now()||
 
now()
 
2022-04-03 13:45:48
 
innodb.tdc 'innodb'                      [ pass ]  2946428
 
--------------------------------------------------------------------------
 
The servers were restarted 0 times
 
Spent 2946.428 of 2954 seconds executing testcases
 
 
 
Completed: All 1 tests were successful.

With 10.4.25:

Yuliyas-MacBook-Air:mysql-test Valerii$ ./mtr --suite=innodb tdc
 
Logging: ./mtr  --suite=innodb tdc
 
VS config: 
vardir: /Users/Valerii/dbs/maria10.4/mysql-test/var
 
Checking leftover processes...
 
Removing old var directory...
 
Creating var directory '/Users/Valerii/dbs/maria10.4/mysql-test/var'...
 
Checking supported features...
 
MariaDB Version 10.4.25-MariaDB
 
 - SSL connections supported
 
Collecting tests...
 
Installing system database...
 
 
 
==============================================================================
 
 
 
TEST                                      RESULT   TIME (ms) or COMMENT
 
--------------------------------------------------------------------------
 
 
 
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
 
set default_storage_engine=innodb;
 
set use_stat_tables=NEVER||
 
set global table_definition_cache=500000||
 
select @@table_definition_cache||
 
@@table_definition_cache
 
500000
 
select now()||
 
now()
 
2022-04-03 13:51:15
 
for i in 1..50000 do execute immediate concat('create table if not exists t_', i,' as select ', i, ' as a'); end for||
 
select now()||
 
now()
 
2022-04-03 14:00:18
 
set global table_definition_cache=50000||
 
select @@table_definition_cache||
 
@@table_definition_cache
 
50000
 
flush tables||
 
flush status||
 
select now()||
 
now()
 
2022-04-03 14:00:18
 
for i in 1..50000 do execute immediate concat('update t_', i,' set a=a+1'); end for||
 
show status like 'open%'||
 
Variable_name	Value
 
Open_files	6
 
Open_streams	0
 
Open_table_definitions	50000
 
Open_tables	421
 
Opened_files	150141
 
Opened_plugin_libraries	0
 
Opened_table_definitions	50000
 
Opened_tables	50000
 
Opened_views	0
 
select now()||
 
now()
 
2022-04-03 14:04:33
 
for i in 1..50000 do execute immediate concat('update t_', i,' set a=a+1'); end for||
 
select now()||
 
now()
 
2022-04-03 14:08:05
 
show status like 'open%'||
 
Variable_name	Value
 
Open_files	6
 
Open_streams	0
 
Open_table_definitions	50000
 
Open_tables	421
 
Opened_files	150141
 
Opened_plugin_libraries	0
 
Opened_table_definitions	50000
 
Opened_tables	100000
 
Opened_views	0
 
set session profiling = ON||
 
flush tables||
 
set session profiling = OFF||
 
set global table_definition_cache=500000||
 
select @@table_definition_cache||
 
@@table_definition_cache
 
500000
 
flush status||
 
select now()||
 
now()
 
2022-04-03 14:08:05
 
for i in 1..50000 do execute immediate concat('update t_', i,' set a=a+1'); end for||
 
worker[1] Test still running: innodb.tdc
 
show status like 'open%'||
 
Variable_name	Value
 
Open_files	6
 
Open_streams	0
 
Open_table_definitions	50000
 
Open_tables	421
 
Opened_files	200141
 
Opened_plugin_libraries	0
 
Opened_table_definitions	50000
 
Opened_tables	50000
 
Opened_views	0
 
select now()||
 
now()
 
2022-04-03 14:12:06
 
for i in 1..50000 do execute immediate concat('update t_', i,' set a=a+1'); end for||
 
select now()||
 
now()
 
2022-04-03 14:15:32
 
show status like 'open%'||
 
Variable_name	Value
 
Open_files	6
 
Open_streams	0
 
Open_table_definitions	50000
 
Open_tables	421
 
Opened_files	200141
 
Opened_plugin_libraries	0
 
Opened_table_definitions	50000
 
Opened_tables	100000
 
Opened_views	0
 
set session profiling = ON||
 
flush tables||
 
set session profiling = OFF||
 
set global table_definition_cache=default||
 
show profiles||
 
Query_ID	Duration	Query
 
1	0.18913100	flush tables
 
2	0.19044400	flush tables
 
show profile all for query 1||
 
Status	Duration	CPU_user	CPU_system	Context_voluntary	Context_involuntary	Block_ops_in	Block_ops_out	Messages_sent	Messages_received	Page_faults_major	Page_faults_minor	Swaps	Source_function	Source_file	Source_line
 
Starting	0.189036	0.148972	0.038801	0	84	279	0	NULL	NULL	NULL
 
Query end	0.000015	0.000007	0.000007	0	0	<unknown>	sql_parse.cc	6218
 
Commit	0.000007	0.000005	0.000002	0	0	0	<unknown>	sql_parse.cc	6264
 
Closing tables	0.000005	0.000004	0.000002	0	0	<unknown>	sql_base.cc	882
 
Commit_implicit	0.000005	0.000004	0.000001	0	0	<unknown>	sql_parse.cc	6303
 
Starting cleanup	0.000006	0.000004	0.000002	0	<unknown>	sql_parse.cc	6331
 
Freeing items	0.000007	0.000006	0.000001	0	0	<unknown>	sql_parse.cc	8028
 
Updating status	0.000030	0.000010	0.000019	0	0	<unknown>	sql_parse.cc	2452
 
Reset for next command	0.000020	0.000018	0.000002	0	<unknown>	sql_parse.cc	2476
 
show profile all for query 2||
 
Status	Duration	CPU_user	CPU_system	Context_voluntary	Context_involuntary	Block_ops_in	Block_ops_out	Messages_sent	Messages_received	Page_faults_major	Page_faults_minor	Swaps	Source_function	Source_file	Source_line
 
Starting	0.190325	0.153720	0.051566	72	287	NULL	NULL	NULL
 
Query end	0.000011	0.000006	0.000012	0	0	<unknown>	sql_parse.cc	6218
 
Commit	0.000006	0.000016	0.000002	0	0	0	<unknown>	sql_parse.cc	6264
 
Closing tables	0.000004	0.000003	0.000002	0	0	<unknown>	sql_base.cc	882
 
Commit_implicit	0.000005	0.000003	0.000010	0	0	<unknown>	sql_parse.cc	6303
 
Starting cleanup	0.000004	0.000004	0.000002	0	<unknown>	sql_parse.cc	6331
 
Freeing items	0.000005	0.000003	0.000008	0	0	<unknown>	sql_parse.cc	8028
 
Updating status	0.000034	0.000022	0.000037	0	1	<unknown>	sql_parse.cc	2452
 
Reset for next command	0.000050	0.000038	0.000047	0	<unknown>	sql_parse.cc	2476
 
select now()||
 
now()
 
2022-04-03 14:15:33
 
for i in 1..50000 do execute immediate concat('alter table t_', i, ' engine=Aria'); end for||
 
worker[1] Test still running: innodb.tdc
 
select now()||
 
now()
 
2022-04-03 14:37:58
 
for i in 1..50000 do execute immediate concat('drop table t_', i); end for||
 
select now()||
 
now()
 
2022-04-03 14:44:10
 
innodb.tdc 'innodb'                      [ pass ]  3209108
 
--------------------------------------------------------------------------
 
The servers were restarted 0 times
 
Spent 3209.108 of 3184 seconds executing testcases
 
 
 
Completed: All 1 tests were successful.

It seems the difference is no that big, but still visible. Note ALTER taking 22 minutes 25 seconds on 10.4 vs 20 minutes 45 seconds with 10.3.

Comment by Sergei Golubchik [ 2022-04-04 ]

I've run that flush_benchmark_1.test on Windows (with set @now:=now(6) and timestampdiff(microsecond, @now, now(6)) around every for and every flush tables. 10.3.35 was not faster than 10.4.25. In most measurements 10.4 was insignificantly faster. In a couple of for ... update 10.3 was faster. Everything was well within the error margin.

Comment by Valerii Kravchuk [ 2022-04-11 ]

I have nothing to say. I see what was copy/pasted, on my builds on macOS 10.13.6 (unsupported, I know, but that's all I have at the moment). For me it looked like there is a problem to work on.

If no one else can reproduce any substantial difference on 10.4 vs 10.3 on Windows or Linux, then I have nothing to add.

Generated at Thu Feb 08 09:59:02 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.