[MDEV-5838] XtraDB more than x2 slower during create table / alter table compare to classic InnoDB Created: 2014-03-12  Updated: 2022-11-01  Resolved: 2022-11-01

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - XtraDB
Affects Version/s: 10.0.9
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: jocelyn fournier Assignee: Jan Lindström (Inactive)
Resolution: Won't Fix Votes: 0
Labels: upstream-fixed

Issue Links:
Relates
relates to MDEV-6241 MariaDB 10.0.11 (32-bit) Too Slow Cre... Closed

 Description   

Hi,

Since the switch from 10.0.8 to 10.0.9 I noticed my unit tests have been 2x slower.
Indeed, when comparing classical ALTER and CREATE operation, XtraDB is 2x slower than Oracle InnoDB plugin, on an empty table !

With native MySQL plugin :
(adding
ignore_builtin_innodb
plugin-load-add=ha_innodb
)

CREATE TABLE `queries` (
 
  `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
 
  `run` varchar(32) NOT NULL DEFAULT '',
 
  `query` text NOT NULL,
 
  `parsed_query_md5` varchar(32) NOT NULL DEFAULT '',
 
  `query_time` float(13,2) NOT NULL DEFAULT '0.00',
 
  `timeline` float(13,2) NOT NULL DEFAULT '0.00',
 
  `db_name` varchar(64) NOT NULL DEFAULT '',
 
  `id_db_access` int(10) unsigned NOT NULL DEFAULT '0',
 
  `id_backtrace` int(10) unsigned NOT NULL DEFAULT '0',
 
  `id_license_domain` int(10) unsigned NOT NULL DEFAULT '0',
 
  `id_license` int(10) unsigned NOT NULL DEFAULT '0',
 
  `type` tinyint(3) unsigned NOT NULL DEFAULT '0',
 
  `date` datetime NOT NULL DEFAULT '1980-01-01 00:00:00',
 
  `day` tinyint(3) unsigned NOT NULL DEFAULT '0',
 
  PRIMARY KEY (`id`,`day`),
 
  KEY `run` (`run`),
 
  KEY `query_time` (`id_license_domain`,`query_time`),
 
  KEY `date` (`id_license_domain`,`date`),
 
  KEY `date_2` (`date`),
 
  KEY `id_license_domain` (`id_license_domain`,`parsed_query_md5`,`date`),
 
  KEY `id_license_domain_2` (`id_license_domain`,`parsed_query_md5`,`query_time`)
 
) ENGINE=InnoDB DEFAULT CHARSET=utf8
 
/*!50100 PARTITION BY LIST ( day)
 
(PARTITION p0 VALUES IN (0) ENGINE = InnoDB,
 
 PARTITION p1 VALUES IN (1) ENGINE = InnoDB,
 
 PARTITION p2 VALUES IN (2) ENGINE = InnoDB,
 
 PARTITION p3 VALUES IN (3) ENGINE = InnoDB,
 
 PARTITION p4 VALUES IN (4) ENGINE = InnoDB,
 
 PARTITION p5 VALUES IN (5) ENGINE = InnoDB,
 
 PARTITION p6 VALUES IN (6) ENGINE = InnoDB,
 
 PARTITION p7 VALUES IN (7) ENGINE = InnoDB,
 
 PARTITION p8 VALUES IN (8) ENGINE = InnoDB,
 
 PARTITION p9 VALUES IN (9) ENGINE = InnoDB,
 
 PARTITION p10 VALUES IN (10) ENGINE = InnoDB,
 
 PARTITION p11 VALUES IN (11) ENGINE = InnoDB,
 
 PARTITION p12 VALUES IN (12) ENGINE = InnoDB,
 
 PARTITION p13 VALUES IN (13) ENGINE = InnoDB,
 
 PARTITION p14 VALUES IN (14) ENGINE = InnoDB,
 
 PARTITION p15 VALUES IN (15) ENGINE = InnoDB,
 
 PARTITION p16 VALUES IN (16) ENGINE = InnoDB,
 
 PARTITION p17 VALUES IN (17) ENGINE = InnoDB,
 
 PARTITION p18 VALUES IN (18) ENGINE = InnoDB,
 
 PARTITION p19 VALUES IN (19) ENGINE = InnoDB,
 
 PARTITION p20 VALUES IN (20) ENGINE = InnoDB,
 
 PARTITION p21 VALUES IN (21) ENGINE = InnoDB,
 
 PARTITION p22 VALUES IN (22) ENGINE = InnoDB,
 
 PARTITION p23 VALUES IN (23) ENGINE = InnoDB,
 
 PARTITION p24 VALUES IN (24) ENGINE = InnoDB,
 
 PARTITION p25 VALUES IN (25) ENGINE = InnoDB,
 
 PARTITION p26 VALUES IN (26) ENGINE = InnoDB,
 
 PARTITION p27 VALUES IN (27) ENGINE = InnoDB,
 
 PARTITION p28 VALUES IN (28) ENGINE = InnoDB,
 
 PARTITION p29 VALUES IN (29) ENGINE = InnoDB,
 
 PARTITION p30 VALUES IN (30) ENGINE = InnoDB,
 
 PARTITION p31 VALUES IN (31) ENGINE = InnoDB) */
 
Query OK, 0 rows affected (5.13 sec)
 
 
 
ALTER TABLE queries ENGINE=InnoDB;
 
Query OK, 0 rows affected (9.86 sec)               
Records: 0  Duplicates: 0  Warnings: 0
 
 
 
DROP TABLE queries;
 
Query OK, 0 rows affected (1.56 sec)

With XtraDB : 

CREATE TABLE `queries` (
 
  `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
 
  `run` varchar(32) NOT NULL DEFAULT '',
 
  `query` text NOT NULL,
 
  `parsed_query_md5` varchar(32) NOT NULL DEFAULT '',
 
  `query_time` float(13,2) NOT NULL DEFAULT '0.00',
 
  `timeline` float(13,2) NOT NULL DEFAULT '0.00',
 
  `db_name` varchar(64) NOT NULL DEFAULT '',
 
  `id_db_access` int(10) unsigned NOT NULL DEFAULT '0',
 
  `id_backtrace` int(10) unsigned NOT NULL DEFAULT '0',
 
  `id_license_domain` int(10) unsigned NOT NULL DEFAULT '0',
 
  `id_license` int(10) unsigned NOT NULL DEFAULT '0',
 
  `type` tinyint(3) unsigned NOT NULL DEFAULT '0',
 
  `date` datetime NOT NULL DEFAULT '1980-01-01 00:00:00',
 
  `day` tinyint(3) unsigned NOT NULL DEFAULT '0',
 
  PRIMARY KEY (`id`,`day`),
 
  KEY `run` (`run`),
 
  KEY `query_time` (`id_license_domain`,`query_time`),
 
  KEY `date` (`id_license_domain`,`date`),
 
  KEY `date_2` (`date`),
 
  KEY `id_license_domain` (`id_license_domain`,`parsed_query_md5`,`date`),
 
  KEY `id_license_domain_2` (`id_license_domain`,`parsed_query_md5`,`query_time`)
 
) ENGINE=InnoDB DEFAULT CHARSET=utf8
 
/*!50100 PARTITION BY LIST ( day)
 
(PARTITION p0 VALUES IN (0) ENGINE = InnoDB,
 
 PARTITION p1 VALUES IN (1) ENGINE = InnoDB,
 
 PARTITION p2 VALUES IN (2) ENGINE = InnoDB,
 
 PARTITION p3 VALUES IN (3) ENGINE = InnoDB,
 
 PARTITION p4 VALUES IN (4) ENGINE = InnoDB,
 
 PARTITION p5 VALUES IN (5) ENGINE = InnoDB,
 
 PARTITION p6 VALUES IN (6) ENGINE = InnoDB,
 
 PARTITION p7 VALUES IN (7) ENGINE = InnoDB,
 
 PARTITION p8 VALUES IN (8) ENGINE = InnoDB,
 
 PARTITION p9 VALUES IN (9) ENGINE = InnoDB,
 
 PARTITION p10 VALUES IN (10) ENGINE = InnoDB,
 
 PARTITION p11 VALUES IN (11) ENGINE = InnoDB,
 
 PARTITION p12 VALUES IN (12) ENGINE = InnoDB,
 
 PARTITION p13 VALUES IN (13) ENGINE = InnoDB,
 
 PARTITION p14 VALUES IN (14) ENGINE = InnoDB,
 
 PARTITION p15 VALUES IN (15) ENGINE = InnoDB,
 
 PARTITION p16 VALUES IN (16) ENGINE = InnoDB,
 
 PARTITION p17 VALUES IN (17) ENGINE = InnoDB,
 
 PARTITION p18 VALUES IN (18) ENGINE = InnoDB,
 
 PARTITION p19 VALUES IN (19) ENGINE = InnoDB,
 
 PARTITION p20 VALUES IN (20) ENGINE = InnoDB,
 
 PARTITION p21 VALUES IN (21) ENGINE = InnoDB,
 
 PARTITION p22 VALUES IN (22) ENGINE = InnoDB,
 
 PARTITION p23 VALUES IN (23) ENGINE = InnoDB,
 
 PARTITION p24 VALUES IN (24) ENGINE = InnoDB,
 
 PARTITION p25 VALUES IN (25) ENGINE = InnoDB,
 
 PARTITION p26 VALUES IN (26) ENGINE = InnoDB,
 
 PARTITION p27 VALUES IN (27) ENGINE = InnoDB,
 
 PARTITION p28 VALUES IN (28) ENGINE = InnoDB,
 
 PARTITION p29 VALUES IN (29) ENGINE = InnoDB,
 
 PARTITION p30 VALUES IN (30) ENGINE = InnoDB,
 
 PARTITION p31 VALUES IN (31) ENGINE = InnoDB) */
 
Query OK, 0 rows affected (16.60 sec)
 
 
 
ALTER TABLE queries ENGINE=InnoDB;
 
Query OK, 0 rows affected (20.78 sec)              
Records: 0  Duplicates: 0  Warnings: 0
 
 
 
DROP TABLE queries;
 
Query OK, 0 rows affected (1.56 sec)

=> CREATE TABLE : 5,13s => 16,6s (x3 degradation !)
=> ALTER TABLE : 9,89s => 20,78s (x2 degradation)
=> DROP TABLE : no change

Thanks and regards,
Jocelyn Fournier

 Comments   
Comment by Elena Stepanova [ 2014-03-12 ]

Hi,

Could you please also provide the complete .cnf file(s)? (or output of SHOW GLOBAL VARIABLES if you prefer)

Thanks

Comment by jocelyn fournier [ 2014-03-12 ]

Yes sure, main variables : 

skip-external-locking
 
skip-name-resolve
 
ignore_builtin_innodb
 
plugin-load-add=ha_innodb
 
transaction-isolation="READ-UNCOMMITTED"
 
plugin-load-add=ha_tokudb
 
tokudb_commit_sync="OFF"
 
tokudb_cache_size=14G
 
tokudb_lock_timeout=120000
 
tokudb_row_format="tokudb_small"
 
innodb_lock_wait_timeout=120
 
default_storage_engine=InnoDB
 
max_allowed_packet=16M
 
key_buffer_size=128M
 
table_cache=4096
 
read_buffer_size=4M
 
read_rnd_buffer_size=2M
 
thread_cache_size=80
 
delayed_insert_limit=500
 
max_delayed_threads=60
 
join_buffer_size=2M
 
sort_buffer_size=2M
 
delayed_insert_timeout=20
 
wait_timeout=1800
 
max_connections=400
 
back_log=1300
 
myisam_sort_buffer_size=512M
 
thread_concurrency=8
 
tmp_table_size=1G
 
table_definition_cache = 8192
 
concurrent_insert=2
 
innodb_buffer_pool_size=4G
 
innodb_log_file_size=128M
 
innodb_log_files_in_group=2
 
innodb_log_buffer_size=8M
 
innodb_flush_log_at_trx_commit=2
 
innodb_thread_concurrency=16
 
innodb_read_io_threads=8
 
innodb_write_io_threads=8
 
innodb_flush_method=O_DIRECT
 
innodb_file_per_table=1
 
innodb_io_capacity=2000
 
innodb_file_format=Barracuda
 
myisam-recover         = BACKUP
 
query_cache_limit=2M
 
query_cache_size=32M
 
log-error       = /home/mysql/log/log-error.log

Comment by Elena Stepanova [ 2014-03-13 ]

I can reproduce it. The ratio doesn't always hold, but the difference is definitely observable.
It exists even with default options, but there (mostly due to innodb_flush_at_trx_commit, as it seems) the operations take much longer both on XtraDB and InnoDB, so the ratio is less profound. But with the given options, it is very obvious.

I tried to do some initial profiling, but didn't get anything evident for me.
The test is:

  • bootstrap the data dir;
  • clean caches;
  • start server;
  • connect to the server;
  • create one table;
  • start profiler;
  • create 3 tables;
  • stop profiler, collect results;

Here are the results (I reduced the number of partitions to 16 to make the tests more dynamic):

Default server configuration

XtraDB

Query OK, 0 rows affected (58.59 sec)
 
Query OK, 0 rows affected (58.22 sec)
 
Query OK, 0 rows affected (59.20 sec)
 

11388    53.6790  /no-vmlinux              /no-vmlinux
 
3240     15.2722  /home/elenst/bzr/10.0-rel/sql/mysqld buf_calc_page_new_checksum(unsigned char const*)
 
730       3.4410  /lib/x86_64-linux-gnu/libc-2.15.so __memset_sse2
 
544       2.5642  /home/elenst/bzr/10.0-rel/sql/mysqld ut_delay(unsigned long)
 
408       1.9232  /home/elenst/bzr/10.0-rel/sql/mysqld os_aio_linux_handle(unsigned long, fil_node_t**, void**, unsigned long*, unsigned long*)
 
244       1.1501  /home/elenst/bzr/10.0-rel/sql/mysqld _Z14buf_flush_listmmPm.constprop.23
 
230       1.0841  /home/elenst/bzr/10.0-rel/sql/mysqld yylex()
 
212       0.9993  /lib/x86_64-linux-gnu/libc-2.15.so __memcpy_ssse3_back
 
179       0.8437  /home/elenst/bzr/10.0-rel/sql/mysqld log_block_calc_checksum_innodb(unsigned char const*)
 
108       0.5091  /home/elenst/bzr/10.0-rel/sql/mysqld yyparse()
 
108       0.5091  /lib/x86_64-linux-gnu/libpthread-2.15.so pthread_mutex_lock
 
104       0.4902  /home/elenst/bzr/10.0-rel/sql/mysqld buf_page_get_gen(unsigned long, unsigned long, unsigned long, unsigned long, buf_block_t*, unsigned long, char const*, unsigned long, mtr_t*)
 
102       0.4808  /home/elenst/bzr/10.0-rel/sql/mysqld dict_table_schema_check(dict_table_schema_t*, char*, unsigned long)
 
97        0.4572  /lib/x86_64-linux-gnu/libc-2.15.so __strlen_sse2_pminub
 
92        0.4337  /lib/x86_64-linux-gnu/libc-2.15.so vfprintf
 
88        0.4148  /home/elenst/bzr/10.0-rel/sql/mysqld free
 
83        0.3912  /home/elenst/bzr/10.0-rel/sql/mysqld malloc

InnoDB

Query OK, 0 rows affected (44.49 sec)
 
Query OK, 0 rows affected (40.70 sec)
 
Query OK, 0 rows affected (42.47 sec)
 

8833     55.3273  /no-vmlinux              /no-vmlinux
 
2918     18.2775  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so buf_calc_page_new_checksum(unsigned char const*)
 
247       1.5471  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so yylex()
 
189       1.1838  /lib/x86_64-linux-gnu/libc-2.15.so __memcpy_ssse3_back
 
135       0.8456  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so ut_delay(unsigned long)
 
134       0.8393  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so log_group_write_buf(log_group_t*, unsigned char*, unsigned long, unsigned long, unsigned long)
 
117       0.7329  /lib/x86_64-linux-gnu/libc-2.15.so __memset_sse2
 
97        0.6076  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so yyparse()
 
97        0.6076  /lib/x86_64-linux-gnu/libc-2.15.so vfprintf
 
87        0.5449  /home/elenst/bzr/10.0-rel/sql/mysqld free
 
86        0.5387  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so buf_page_get_gen(unsigned long, unsigned long, unsigned long, unsigned long, buf_block_t*, unsigned long, char const*, unsigned long, mtr_t*)
 
84        0.5262  /home/elenst/bzr/10.0-rel/sql/mysqld malloc
 
83        0.5199  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so dict_table_schema_check(dict_table_schema_t*, char*, unsigned long)
 
82        0.5136  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so rec_get_offsets_func(unsigned char const*, dict_index_t const*, unsigned long*, unsigned long, mem_block_info_t**, char const*, unsigned long)
 
69        0.4322  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so mlog_write_ulint(unsigned char*, unsigned long, unsigned char, mtr_t*)
 
60        0.3758  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so mtr_commit(mtr_t*)
 
60        0.3758  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so os_aio_linux_handle(unsigned long, fil_node_t**, void**, unsigned long*)

Parameters from bug report

XtraDB

Query OK, 0 rows affected (7.98 sec)
 
Query OK, 0 rows affected (7.95 sec)
 
Query OK, 0 rows affected (8.04 sec)
 

2100     27.6571  /home/elenst/bzr/10.0-rel/sql/mysqld _Z14buf_flush_listmmPm.constprop.23
 
1955     25.7474  /no-vmlinux              /no-vmlinux
 
618       8.1391  /home/elenst/bzr/10.0-rel/sql/mysqld buf_calc_page_new_checksum(unsigned char const*)
 
175       2.3048  /home/elenst/bzr/10.0-rel/sql/mysqld yylex()
 
145       1.9097  /lib/x86_64-linux-gnu/libc-2.15.so __memset_sse2
 
141       1.8570  /home/elenst/bzr/10.0-rel/sql/mysqld log_block_calc_checksum_innodb(unsigned char const*)
 
116       1.5277  /lib/x86_64-linux-gnu/libc-2.15.so __memcpy_ssse3_back
 
80        1.0536  /lib/x86_64-linux-gnu/libc-2.15.so vfprintf
 
78        1.0273  /home/elenst/bzr/10.0-rel/sql/mysqld rec_get_offsets_func(unsigned char const*, dict_index_t const*, unsigned long*, unsigned long, mem_block_info_t**, char const*, unsigned long)
 
72        0.9482  /home/elenst/bzr/10.0-rel/sql/mysqld buf_page_get_gen(unsigned long, unsigned long, unsigned long, unsigned long, buf_block_t*, unsigned long, char const*, unsigned long, mtr_t*)
 
71        0.9351  /home/elenst/bzr/10.0-rel/sql/mysqld dict_table_schema_check(dict_table_schema_t*, char*, unsigned long)
 
70        0.9219  /home/elenst/bzr/10.0-rel/sql/mysqld free
 
60        0.7902  /home/elenst/bzr/10.0-rel/sql/mysqld mtr_commit(mtr_t*)
 
58        0.7639  /lib/x86_64-linux-gnu/libc-2.15.so __strcmp_sse42
 
56        0.7375  /home/elenst/bzr/10.0-rel/sql/mysqld yyparse()
 
52        0.6848  /home/elenst/bzr/10.0-rel/sql/mysqld mlog_write_ulint(unsigned char*, unsigned long, unsigned char, mtr_t*)
 
51        0.6717  /lib/x86_64-linux-gnu/libc-2.15.so __strlen_sse2_pminub

InnoDB

Query OK, 0 rows affected (3.99 sec)
 
Query OK, 0 rows affected (4.15 sec)
 
Query OK, 0 rows affected (4.09 sec)
 

1778     35.2288  /no-vmlinux              /no-vmlinux
 
622      12.3242  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so buf_calc_page_new_checksum(unsigned char const*)
 
164       3.2495  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so log_group_write_buf(log_group_t*, unsigned char*, unsigned long, unsigned long, unsigned long)
 
158       3.1306  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so yylex()
 
90        1.7832  /lib/x86_64-linux-gnu/libc-2.15.so __memcpy_ssse3_back
 
90        1.7832  /lib/x86_64-linux-gnu/libc-2.15.so vfprintf
 
79        1.5653  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so yyparse()
 
74        1.4662  /home/elenst/bzr/10.0-rel/sql/mysqld free
 
68        1.3473  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so dict_table_schema_check(dict_table_schema_t*, char*, unsigned long)
 
60        1.1888  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so buf_page_get_gen(unsigned long, unsigned long, unsigned long, unsigned long, buf_block_t*, unsigned long, char const*, unsigned long, mtr_t*)
 
59        1.1690  /lib/x86_64-linux-gnu/libc-2.15.so _IO_default_xsputn
 
58        1.1492  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so rec_get_offsets_func(unsigned char const*, dict_index_t const*, unsigned long*, unsigned long, mem_block_info_t**, char const*, unsigned long)
 
58        1.1492  /lib/x86_64-linux-gnu/libc-2.15.so __memset_sse2
 
54        1.0699  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so mtr_commit(mtr_t*)
 
49        0.9709  /lib/x86_64-linux-gnu/libc-2.15.so __strcmp_sse42
 
40        0.7926  /home/elenst/bzr/10.0-rel/sql/mysqld malloc
 
37        0.7331  /lib/x86_64-linux-gnu/libc-2.15.so __strlen_sse2_pminub

I removed flush_method=O_DIRECT and got rid of buf_flush_list on top of XtraDB profile, but the numbers became even worse:

Without O_DIRECT:

XtraDB

Query OK, 0 rows affected (8.90 sec)
 
Query OK, 0 rows affected (8.14 sec)
 
Query OK, 0 rows affected (8.17 sec)
 

2165     38.4615  /no-vmlinux              /no-vmlinux
 
659      11.7072  /home/elenst/bzr/10.0-rel/sql/mysqld buf_calc_page_new_checksum(unsigned char const*)
 
194       3.4464  /lib/x86_64-linux-gnu/libc-2.15.so __memset_sse2
 
164       2.9135  /home/elenst/bzr/10.0-rel/sql/mysqld yylex()
 
140       2.4871  /home/elenst/bzr/10.0-rel/sql/mysqld log_block_calc_checksum_innodb(unsigned char const*)
 
112       1.9897  /lib/x86_64-linux-gnu/libc-2.15.so __memcpy_ssse3_back
 
79        1.4034  /home/elenst/bzr/10.0-rel/sql/mysqld buf_page_get_gen(unsigned long, unsigned long, unsigned long, unsigned long, buf_block_t*, unsigned long, char const*, unsigned long, mtr_t*)
 
74        1.3146  /home/elenst/bzr/10.0-rel/sql/mysqld rec_get_offsets_func(unsigned char const*, dict_index_t const*, unsigned long*, unsigned long, mem_block_info_t**, char const*, unsigned long)
 
73        1.2969  /home/elenst/bzr/10.0-rel/sql/mysqld dict_table_schema_check(dict_table_schema_t*, char*, unsigned long)
 
70        1.2436  /lib/x86_64-linux-gnu/libc-2.15.so vfprintf
 
56        0.9948  /home/elenst/bzr/10.0-rel/sql/mysqld free
 
56        0.9948  /lib/x86_64-linux-gnu/libc-2.15.so __strcmp_sse42
 
54        0.9593  /home/elenst/bzr/10.0-rel/sql/mysqld mtr_commit(mtr_t*)
 
51        0.9060  /home/elenst/bzr/10.0-rel/sql/mysqld yyparse()
 
50        0.8883  /lib/x86_64-linux-gnu/libc-2.15.so _IO_default_xsputn
 
45        0.7994  /home/elenst/bzr/10.0-rel/sql/mysqld os_aio_linux_handle(unsigned long, fil_node_t**, void**, unsigned long*, unsigned long*)
 
44        0.7817  /lib/x86_64-linux-gnu/libc-2.15.so __strlen_sse2_pminub

InnoDB

Query OK, 0 rows affected (2.74 sec)
 
Query OK, 0 rows affected (2.37 sec)
 
Query OK, 0 rows affected (2.86 sec)
 

1538     32.5709  /no-vmlinux              /no-vmlinux
 
611      12.9394  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so buf_calc_page_new_checksum(unsigned char const*)
 
178       3.7696  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so yylex()
 
176       3.7272  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so log_group_write_buf(log_group_t*, unsigned char*, unsigned long, unsigned long, unsigned long)
 
82        1.7366  /lib/x86_64-linux-gnu/libc-2.15.so __memcpy_ssse3_back
 
81        1.7154  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so dict_table_schema_check(dict_table_schema_t*, char*, unsigned long)
 
80        1.6942  /lib/x86_64-linux-gnu/libc-2.15.so vfprintf
 
73        1.5460  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so rec_get_offsets_func(unsigned char const*, dict_index_t const*, unsigned long*, unsigned long, mem_block_info_t**, char const*, unsigned long)
 
66        1.3977  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so yyparse()
 
62        1.3130  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so buf_page_get_gen(unsigned long, unsigned long, unsigned long, unsigned long, buf_block_t*, unsigned long, char const*, unsigned long, mtr_t*)
 
61        1.2918  /home/elenst/bzr/10.0-rel/sql/mysqld free
 
59        1.2495  /lib/x86_64-linux-gnu/libc-2.15.so __memset_sse2
 
47        0.9953  /lib/x86_64-linux-gnu/libc-2.15.so __strcmp_sse42
 
41        0.8683  /lib/x86_64-linux-gnu/libc-2.15.so _IO_default_xsputn
 
40        0.8471  /home/elenst/bzr/10.0-rel/sql/mysqld malloc
 
40        0.8471  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so mtr_commit(mtr_t*)
 
39        0.8259  /home/elenst/bzr/10.0-rel/storage/innobase/ha_innodb.so mlog_write_ulint(unsigned char*, unsigned long, unsigned char, mtr_t*)

Assigning to Jan for expert ideas. If I can do anything to help investigating it, please let me know.

Comment by Jan Lindström (Inactive) [ 2014-03-18 ]

Hi,

Can you also provide a value of innodb_use_fallocate ?

R: Jan

Comment by jocelyn fournier [ 2014-03-18 ]

Hi Jan,

innodb_use_fallocate is off in this case.

Jocelyn

Comment by Jan Lindström (Inactive) [ 2014-03-20 ]

Elena,

Is it possible to get similar output from 10.0.8 and XtraDB, I just would like to understand is there some clear difference, from above I only see that some buf functions are more used on XtraDB.

R: Jan

Comment by Elena Stepanova [ 2014-03-23 ]

revno 4049, XtraDB (same as before, control run)

Query OK, 0 rows affected (7.64 sec)
 
Query OK, 0 rows affected (8.52 sec)
 
Query OK, 0 rows affected (8.92 sec)
 

1849     37.0244  /no-vmlinux              /no-vmlinux
 
356       7.1286  /home/elenst/bzr/10.0-rel/sql/mysqld buf_calc_page_new_checksum(unsigned char const*)
 
167       3.3440  /lib/x86_64-linux-gnu/libc-2.15.so __memset_sse2
 
165       3.3040  /home/elenst/bzr/10.0-rel/sql/mysqld yylex()
 
159       3.1838  /home/elenst/bzr/10.0-rel/sql/mysqld log_block_calc_checksum_innodb(unsigned char const*)
 
101       2.0224  /lib/x86_64-linux-gnu/libc-2.15.so __memcpy_ssse3_back
 
85        1.7020  /home/elenst/bzr/10.0-rel/sql/mysqld rec_get_offsets_func(unsigned char const*, dict_index_t const*, unsigned long*, unsigned long, mem_block_info_t**, char const*, unsigned long)
 
83        1.6620  /home/elenst/bzr/10.0-rel/sql/mysqld buf_page_get_gen(unsigned long, unsigned long, unsigned long, unsigned long, buf_block_t*, unsigned long, char const*, unsigned long, mtr_t*)
 
81        1.6219  /lib/x86_64-linux-gnu/libc-2.15.so vfprintf
 
78        1.5619  /home/elenst/bzr/10.0-rel/sql/mysqld dict_table_schema_check(dict_table_schema_t*, char*, unsigned long)
 
61        1.2215  /home/elenst/bzr/10.0-rel/sql/mysqld free
 
61        1.2215  /home/elenst/bzr/10.0-rel/sql/mysqld yyparse()
 
54        1.0813  /home/elenst/bzr/10.0-rel/sql/mysqld mtr_commit(mtr_t*)
 
51        1.0212  /home/elenst/bzr/10.0-rel/sql/mysqld malloc
 
51        1.0212  /lib/x86_64-linux-gnu/libc-2.15.so _IO_default_xsputn
 
48        0.9612  /lib/x86_64-linux-gnu/libc-2.15.so __strlen_sse2_pminub
 
42        0.8410  /home/elenst/bzr/10.0-rel/sql/mysqld os_aio_linux_handle(unsigned long, fil_node_t**, void**, unsigned long*, unsigned long*)

revno 3994 (10.0.8), InnoDB:

Query OK, 0 rows affected (2.57 sec)
 
Query OK, 0 rows affected (3.23 sec)
 
Query OK, 0 rows affected (3.11 sec)
 

1825     35.0827  /no-vmlinux              /no-vmlinux
 
611      11.7455  /home/elenst/bzr/10.0-rel/sql/mysqld buf_calc_page_new_checksum(unsigned char const*)
 
335       6.4398  /home/elenst/bzr/10.0-rel/sql/mysqld sync_array_print_long_waits(unsigned long*, void const**)
 
156       2.9988  /home/elenst/bzr/10.0-rel/sql/mysqld log_group_write_buf(log_group_t*, unsigned char*, unsigned long, unsigned long, unsigned long)
 
144       2.7682  /home/elenst/bzr/10.0-rel/sql/mysqld yylex()
 
103       1.9800  /lib/x86_64-linux-gnu/libc-2.15.so __memcpy_ssse3_back
 
94        1.8070  /lib/x86_64-linux-gnu/libc-2.15.so vfprintf
 
82        1.5763  /home/elenst/bzr/10.0-rel/sql/mysqld buf_page_get_gen(unsigned long, unsigned long, unsigned long, unsigned long, buf_block_t*, unsigned long, char const*, unsigned long, mtr_t*)
 
82        1.5763  /lib/x86_64-linux-gnu/libc-2.15.so __memset_sse2
 
75        1.4418  /home/elenst/bzr/10.0-rel/sql/mysqld dict_table_schema_check(dict_table_schema_t*, char*, unsigned long)
 
68        1.3072  /home/elenst/bzr/10.0-rel/sql/mysqld free
 
68        1.3072  /home/elenst/bzr/10.0-rel/sql/mysqld rec_get_offsets_func(unsigned char const*, dict_index_t const*, unsigned long*, unsigned long, mem_block_info_t**, char const*, unsigned long)
 
66        1.2687  /home/elenst/bzr/10.0-rel/sql/mysqld yyparse()
 
43        0.8266  /lib/x86_64-linux-gnu/libc-2.15.so __strcmp_sse42
 
40        0.7689  /lib/x86_64-linux-gnu/libc-2.15.so __strlen_sse2_pminub
 
39        0.7497  /home/elenst/bzr/10.0-rel/sql/mysqld malloc
 
38        0.7305  /lib/x86_64-linux-gnu/libc-2.15.so _IO_default_xsputn

revno 3994 (MariaDB 10.0.8), XtraDB:

Query OK, 0 rows affected (9.31 sec)
 
Query OK, 0 rows affected (8.99 sec)
 
Query OK, 0 rows affected (9.61 sec)
 

1552     36.9260  /no-vmlinux              /no-vmlinux
 
319       7.5898  /home/elenst/bzr/10.0-rel/storage/xtradb/ha_xtradb.so sync_array_print_long_waits(unsigned long*, void const**)
 
256       6.0909  /lib/x86_64-linux-gnu/libc-2.15.so __memset_sse2
 
201       4.7823  /home/elenst/bzr/10.0-rel/storage/xtradb/ha_xtradb.so buf_calc_page_new_checksum(unsigned char const*)
 
111       2.6410  /home/elenst/bzr/10.0-rel/storage/xtradb/ha_xtradb.so yylex()
 
103       2.4506  /home/elenst/bzr/10.0-rel/storage/xtradb/ha_xtradb.so log_block_calc_checksum_innodb(unsigned char const*)
 
70        1.6655  /home/elenst/bzr/10.0-rel/storage/xtradb/ha_xtradb.so os_aio_linux_handle(unsigned long, fil_node_t**, void**, unsigned long*, unsigned long*)
 
66        1.5703  /lib/x86_64-linux-gnu/libc-2.15.so __memcpy_ssse3_back
 
60        1.4276  /home/elenst/bzr/10.0-rel/storage/xtradb/ha_xtradb.so buf_page_get_gen(unsigned long, unsigned long, unsigned long, unsigned long, buf_block_t*, unsigned long, char const*, unsigned long, mtr_t*)
 
57        1.3562  /lib/x86_64-linux-gnu/libc-2.15.so vfprintf
 
55        1.3086  /home/elenst/bzr/10.0-rel/storage/xtradb/ha_xtradb.so yyparse()
 
49        1.1658  /home/elenst/bzr/10.0-rel/storage/xtradb/ha_xtradb.so rec_get_offsets_func(unsigned char const*, dict_index_t const*, unsigned long*, unsigned long, mem_block_info_t**, char const*, unsigned long)
 
48        1.1420  /home/elenst/bzr/10.0-rel/storage/xtradb/ha_xtradb.so dict_table_schema_check(dict_table_schema_t*, char*, unsigned long)
 
41        0.9755  /home/elenst/bzr/10.0-rel/sql/mysqld free
 
34        0.8089  /home/elenst/bzr/10.0-rel/sql/mysqld malloc
 
30        0.7138  /lib/x86_64-linux-gnu/libc-2.15.so _IO_default_xsputn
 
29        0.6900  /home/elenst/bzr/10.0-rel/storage/xtradb/ha_xtradb.so mtr_commit(mtr_t*)

revno 4077 (the latest), XtraDB

Query OK, 0 rows affected (10.18 sec)
 
Query OK, 0 rows affected (9.25 sec)
 
Query OK, 0 rows affected (8.83 sec)
 

2256     38.2179  /no-vmlinux              /no-vmlinux
 
709      12.0108  /home/elenst/bzr/10.0-rel/sql/mysqld buf_calc_page_new_checksum(unsigned char const*)
 
201       3.4050  /lib/x86_64-linux-gnu/libc-2.15.so __memset_sse2
 
180       3.0493  /home/elenst/bzr/10.0-rel/sql/mysqld yylex()
 
147       2.4903  /home/elenst/bzr/10.0-rel/sql/mysqld log_block_calc_checksum_innodb(unsigned char const*)
 
89        1.5077  /lib/x86_64-linux-gnu/libc-2.15.so __memcpy_ssse3_back
 
81        1.3722  /home/elenst/bzr/10.0-rel/sql/mysqld os_aio_linux_handle(unsigned long, fil_node_t**, void**, unsigned long*, unsigned long*)
 
77        1.3044  /home/elenst/bzr/10.0-rel/sql/mysqld buf_page_get_gen(unsigned long, unsigned long, unsigned long, unsigned long, buf_block_t*, unsigned long, char const*, unsigned long, mtr_t*)
 
72        1.2197  /home/elenst/bzr/10.0-rel/sql/mysqld dict_table_schema_check(dict_table_schema_t*, char*, unsigned long)
 
67        1.1350  /home/elenst/bzr/10.0-rel/sql/mysqld yyparse()
 
66        1.1181  /lib/x86_64-linux-gnu/libc-2.15.so vfprintf
 
62        1.0503  /home/elenst/bzr/10.0-rel/sql/mysqld rec_get_offsets_func(unsigned char const*, dict_index_t const*, unsigned long*, unsigned long, mem_block_info_t**, char const*, unsigned long)
 
51        0.8640  /home/elenst/bzr/10.0-rel/sql/mysqld free
 
49        0.8301  /home/elenst/bzr/10.0-rel/sql/mysqld mtr_commit(mtr_t*)
 
49        0.8301  /lib/x86_64-linux-gnu/libc-2.15.so __strlen_sse2_pminub
 
47        0.7962  /lib/x86_64-linux-gnu/libc-2.15.so _IO_default_xsputn
 
45        0.7623  /home/elenst/bzr/10.0-rel/sql/mysqld malloc

Comment by Jan Lindström (Inactive) [ 2014-03-24 ]

As seen there is not significant change on XtraDB create table speed between 10.0.8 and latest but there is significant difference to InnoDB create table speed.

Comment by Jan Lindström (Inactive) [ 2014-03-24 ]

Percona Server was also very slow on create table.

https://bugs.launchpad.net/percona-server/+bug/1296551

Comment by Jan Lindström (Inactive) [ 2014-03-24 ]

Only clear difference between InnoDB and XtraDB seems to be this function

41 1.8570 /home/elenst/bzr/10.0-rel/sql/mysqld log_block_calc_checksum_innodb(unsigned char const*)

In InnoDB this is not evident but on XtraDB it is.

Comment by jocelyn fournier [ 2014-03-24 ]

Since XtraDB is using a function pointer 'log_checksum_algorithm_ptr' introduced by https://code.launchpad.net/~alexey2k/percona-server/5.6-log-checksum/+merge/191918 to call log_block_calc_checksum_innodb, I think it breaks the inlining which is done in standard InnoDB code.

Comment by Jan Lindström (Inactive) [ 2014-03-24 ]

Very slow create/alter table also with Oracle MySQL 5.6.16:

http://bugs.mysql.com/bug.php?id=72115

Comment by Jan Lindström (Inactive) [ 2014-03-25 ]

InnoDB

 
MariaDB [test]> show profile for query 2;
 
+----------------------+-----------+
 
| Status               | Duration  |
 
+----------------------+-----------+
 
| starting             |  0.000354 |
 
| checking permissions |  0.000018 |
 
| Opening tables       |  0.000039 |
 
| System lock          |  0.000006 |
 
| Table lock           |  0.000099 |
 
| creating table       | 29.697951 |
 
| After create         |  0.000032 |
 
| Writing to binlog    |  0.000104 |
 
| query end            |  0.000018 |
 
| closing tables       |  0.000017 |
 
| freeing items        |  0.000016 |
 
| updating status      |  0.000033 |
 
| logging slow query   |  0.000009 |
 
| cleaning up          |  0.000046 |
 
+----------------------+-----------+
 
14 rows in set (0.00 sec)

XtraDB

 
MariaDB [test]> show profile for query 1;
 
+----------------------+-----------+
 
| Status               | Duration  |
 
+----------------------+-----------+
 
| starting             |  0.000486 |
 
| checking permissions |  0.000032 |
 
| Opening tables       |  0.000030 |
 
| System lock          |  0.000006 |
 
| Table lock           |  0.000098 |
 
| creating table       | 30.469348 |
 
| After create         |  0.000031 |
 
| Writing to binlog    |  0.000099 |
 
| query end            |  0.000015 |
 
| closing tables       |  0.000017 |
 
| freeing items        |  0.000016 |
 
| updating status      |  0.000037 |
 
| logging slow query   |  0.000008 |
 
| cleaning up          |  0.000037 |
 
+----------------------+-----------+
 
14 rows in set (0.00 sec)

Comment by Jan Lindström (Inactive) [ 2014-04-24 ]

Decreasing the importance because only partitioned tables are affected.

Comment by Daniel Black [ 2018-01-01 ]

fixed upstream per a43085cf677b7d9f1693bfd7f002462943370b66 and f64bc45505dcd8ca59d52e4091f14fff092a37e5

Generated at Thu Feb 08 07:07:26 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.