Percona Server moved to https://jira.percona.com/projects/PS

Some InnoDB tests, at least those from innodb_fts suite, are 20-100+% slower when they are executed with XtraDB than with InnoDB plugin.

Bug #1298318 reported by Jan Lindström
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Percona Server moved to https://jira.percona.com/projects/PS
Status tracked in 5.7
5.5
Invalid
Undecided
Unassigned
5.6
Triaged
Medium
Unassigned
5.7
Triaged
Medium
Unassigned

Bug Description

Some InnoDB tests, at least those from innodb_fts suite, are 20-100+% slower when they are executed with XtraDB than with InnoDB plugin.
Absolute numbers can vary a lot between the machines, but the difference still holds; same for executing them normally vs --mem; same for debug vs non-debug builds.

Oracle MySQL 5.6.16

jan@jan-GE70-0NC-0ND ~/mysql-5.6.16/mysql-test $ ./mysql-test-run --repeat=10 --mem innodb_fts.fulltext
Logging: ./mysql-test-run --repeat=10 --mem innodb_fts.fulltext
2014-03-27 12:40:10 6708 [Warning] Buffered warning: Changed limits: max_open_files: 1024 (requested 5000)

2014-03-27 12:40:10 6708 [Warning] Buffered warning: Changed limits: table_cache: 431 (requested 2000)

2014-03-27 12:40:10 6708 [Note] Plugin 'FEDERATED' is disabled.
2014-03-27 12:40:10 6708 [Note] Binlog end
2014-03-27 12:40:10 6708 [Note] Shutting down plugin 'MyISAM'
2014-03-27 12:40:10 6708 [Note] Shutting down plugin 'CSV'
MySQL Version 5.6.16
Checking supported features...
 - SSL connections supported
Collecting tests...
Removing old var directory...
Creating var directory '/home/jan/mysql-5.6.16/mysql-test/var'...
 - symlinking 'var' to '/dev/shm/var_auto_rKVt'
Installing system database...
Using server port 51642

==============================================================================

TEST RESULT TIME (ms) or COMMENT
--------------------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
innodb_fts.fulltext [ pass ] 379
innodb_fts.fulltext [ pass ] 293
innodb_fts.fulltext [ pass ] 325
innodb_fts.fulltext [ pass ] 323
innodb_fts.fulltext [ pass ] 331
innodb_fts.fulltext [ pass ] 298
innodb_fts.fulltext [ pass ] 311
innodb_fts.fulltext [ pass ] 299
innodb_fts.fulltext [ pass ] 292
innodb_fts.fulltext [ pass ] 303
--------------------------------------------------------------------------
The servers were restarted 0 times
Spent 3.154 of 11 seconds executing testcases

Completed: All 10 tests were successful.

====

Percona Server 5.6:

jan@jan-GE70-0NC-0ND ~/Percona/5.6/mysql-test $ ./mysql-test-run --repeat=10 --mem innodb_fts.fulltext
Logging: ./mysql-test-run --repeat=10 --mem innodb_fts.fulltext
2014-03-27 13:23:08 1241 [Warning] Buffered warning: Changed limits: max_open_files: 1024 (requested 5000)

2014-03-27 13:23:08 1241 [Warning] Buffered warning: Changed limits: table_cache: 431 (requested 2000)

2014-03-27 13:23:08 1241 [Note] Plugin 'FEDERATED' is disabled.
2014-03-27 13:23:08 1241 [Note] Binlog end
2014-03-27 13:23:08 1241 [Note] Shutting down plugin 'MyISAM'
2014-03-27 13:23:08 1241 [Note] Shutting down plugin 'CSV'
MySQL Version 5.6.16
Checking supported features...
 - SSL connections supported
Collecting tests...
Removing old var directory...
Creating var directory '/home/jan/Percona/5.6/mysql-test/var'...
 - symlinking 'var' to '/dev/shm/var_auto_YvfC'
Installing system database...
Using server port 39227

==============================================================================

TEST RESULT TIME (ms) or COMMENT
--------------------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
innodb_fts.fulltext [ pass ] 1776
innodb_fts.fulltext [ pass ] 1165
innodb_fts.fulltext [ pass ] 1078
innodb_fts.fulltext [ pass ] 2337
innodb_fts.fulltext [ pass ] 1295
innodb_fts.fulltext [ pass ] 1149
innodb_fts.fulltext [ pass ] 1165
innodb_fts.fulltext [ pass ] 1207
innodb_fts.fulltext [ pass ] 1088
innodb_fts.fulltext [ pass ] 1226
--------------------------------------------------------------------------
The servers were restarted 0 times
Spent 13.486 of 20 seconds executing testcases

Completed: All 10 tests were successful.

See original description
Revision history for this message
Jan Lindström (jplindst) wrote :

Relates to: https://mariadb.atlassian.net/browse/MDEV-5808

Jan Lindström (jplindst)
description: updated
Laurynas Biveinis (laurynas-biveinis)
tags: added: performance regression xtradb
Revision history for this message
Nilnandan Joshi (nilnandan-joshi) wrote :
Download full text (4.5 KiB)

Able to reproduce the same test case with MySQL 5.6.16 and PS 5.6.16

nilnandan@nilnandan-Dell-XPS:~/Downloads/mysql-5.6.16/mysql-test$ ./mysql-test-run --repeat=10 --mem innodb_fts.fulltext
defined(@array) is deprecated at lib/mtr_cases.pm line 339.
 (Maybe you should just omit the defined()?)
defined(@array) is deprecated at ./mysql-test-run line 495.
 (Maybe you should just omit the defined()?)
Logging: ./mysql-test-run --repeat=10 --mem innodb_fts.fulltext
2014-06-16 11:30:53 24353 [Warning] Buffered warning: Changed limits: max_open_files: 1024 (requested 5000)

2014-06-16 11:30:53 24353 [Warning] Buffered warning: Changed limits: table_cache: 431 (requested 2000)

2014-06-16 11:30:53 24353 [Note] Plugin 'FEDERATED' is disabled.
2014-06-16 11:30:53 24353 [Note] Binlog end
2014-06-16 11:30:53 24353 [Note] Shutting down plugin 'CSV'
2014-06-16 11:30:53 24353 [Note] Shutting down plugin 'MyISAM'
MySQL Version 5.6.16
Checking supported features...
 - SSL connections supported
Collecting tests...
Removing old var directory...
Creating var directory '/home/nilnandan/Downloads/mysql-5.6.16/mysql-test/var'...
 - symlinking 'var' to '/dev/shm/var_auto_J7AZ'
Installing system database...
Using server port 59764

==============================================================================

TEST RESULT TIME (ms) or COMMENT
--------------------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
innodb_fts.fulltext [ pass ] 443
innodb_fts.fulltext [ pass ] 403
innodb_fts.fulltext [ pass ] 440
innodb_fts.fulltext [ pass ] 506
innodb_fts.fulltext [ pass ] 507
innodb_fts.fulltext [ pass ] 464
innodb_fts.fulltext [ pass ] 478
innodb_fts.fulltext [ pass ] 412
innodb_fts.fulltext [ pass ] 489
innodb_fts.fulltext [ pass ] 456
--------------------------------------------------------------------------
The servers were restarted 0 times
Spent 4.598 of 9 seconds executing testcases

Completed: All 10 tests were successful.

nilnandan@nilnandan-Dell-XPS:~/Downloads/mysql-5.6.16/mysql-test$

nilnandan@nilnandan-Dell-XPS:~/Downloads/PS-5.6.16/mysql-test$ ./mysql-test-run --repeat=10 --mem innodb_fts.fulltext
defined(@array) is deprecated at lib/mtr_cases.pm line 339.
 (Maybe you should just omit the defined()?)
defined(@array) is deprecated at ./mysql-test-run line 497.
 (Maybe you should just omit the defined()?)
Logging: ./mysql-test-run --repeat=10 --mem innodb_fts.fulltext
2014-06-16 10:38:09 6859 [Warning] Buffered warning: Changed limits: max_open_files: 1024 (requested 5000)

2014-06-16 10:38:09 6859 [Warning] Buffered warning: Changed limits: table_cache: 431 (requested 2000)

2014-06-16 10:38:09 6859 [Note] Plugin 'FEDERATED' is disabled.
2014-06-16 10:38:09 6859 [Note] Binlog end
2014-06-16 10:38:09 6859 [Note] Shutting down plugin 'MyISAM'
2014-06-16 10:38:09 6859 [Note] Shutting down plugin 'CSV'
MyS...

Read more...

Revision history for this message
Krunal Bauskar (krunal-bauskar) wrote :

Seems like this has to do with create/drop statement.

Following reduced TC will help you see the effect

use test;
#
delimiter |;
create procedure populate_t1()
begin
        declare i int default 1;
        while (i <= 50) DO
                CREATE TABLE t1 (a int(11), b text, FULLTEXT KEY (b)) ENGINE = InnoDB;
                drop table t1;
                set i = i + 1;
        end while;
end|
delimiter ;|
call populate_t1;
drop procedure populate_t1;

MS-5.6
innodb.fulltext_create [ pass ] 412
innodb.fulltext_create [ pass ] 437
innodb.fulltext_create [ pass ] 418
innodb.fulltext_create [ pass ] 411
innodb.fulltext_create [ pass ] 470

PS-5.6
innodb.fulltext_create [ pass ] 2516
innodb.fulltext_create [ pass ] 1714
innodb.fulltext_create [ pass ] 3165
innodb.fulltext_create [ pass ] 1945
innodb.fulltext_create [ pass ] 1806

-------------------

Interestingly, the effect is observed only if you run the test through mtr. Normal execution of script through mysql client with server independently started gives on-par result.
(It may be possible that mtr is using some settings/configurations that are different between PS and MS).

Revision history for this message
Krunal Bauskar (krunal-bauskar) wrote :

Ok .. so after lot of more experiments it turned out that the issue is not code related but configuration related.

PS default configuration is slightly different from MS (especially w.r.t to flushing) and so this difference is observed.
Restoring the configuration infact gives results better than MS

PS: innodb_fts.fulltext --mysqld=--innodb_foreground_preflush=sync_preflush --mysqld=--innodb_empty_free_list_algorithm=legacy --mysqld=--innodb_cleaner_lsn_age_acy --repeat=10

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
innodb_fts.fulltext [ pass ] 359
innodb_fts.fulltext [ pass ] 366
innodb_fts.fulltext [ pass ] 270
innodb_fts.fulltext [ pass ] 275
innodb_fts.fulltext [ pass ] 277
innodb_fts.fulltext [ pass ] 278
innodb_fts.fulltext [ pass ] 273
innodb_fts.fulltext [ pass ] 275
innodb_fts.fulltext [ pass ] 277
innodb_fts.fulltext [ pass ] 280

---------------

MS: innodb_fts.fulltext --repeat=10
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
innodb_fts.fulltext [ pass ] 341
innodb_fts.fulltext [ pass ] 355
innodb_fts.fulltext [ pass ] 334
innodb_fts.fulltext [ pass ] 366
innodb_fts.fulltext [ pass ] 345
innodb_fts.fulltext [ pass ] 365
innodb_fts.fulltext [ pass ] 344
innodb_fts.fulltext [ pass ] 358
innodb_fts.fulltext [ pass ] 329
innodb_fts.fulltext [ pass ] 366

Krunal Bauskar (krunal-bauskar)
Changed in percona-server:
assignee: Krunal Bauskar (krunal-bauskar) → nobody
status: In Progress → Triaged
Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote :

The regression is gone with 5.6.36, likely as a result of a fix for bug 1631309, but PS run shows something resembling a stall on the 6th testcase execution, very consistently.

MS 5.6.36:

innodb_fts.fulltext [ pass ] 385
innodb_fts.fulltext [ pass ] 381
innodb_fts.fulltext [ pass ] 339
innodb_fts.fulltext [ pass ] 367
innodb_fts.fulltext [ pass ] 344
innodb_fts.fulltext [ pass ] 347
innodb_fts.fulltext [ pass ] 367
innodb_fts.fulltext [ pass ] 372
innodb_fts.fulltext [ pass ] 323
innodb_fts.fulltext [ pass ] 378

PS 5.6.36:

innodb_fts.fulltext [ pass ] 376
innodb_fts.fulltext [ pass ] 369
innodb_fts.fulltext [ pass ] 290
innodb_fts.fulltext [ pass ] 251
innodb_fts.fulltext [ pass ] 273
innodb_fts.fulltext [ pass ] 897 <- stall
innodb_fts.fulltext [ pass ] 258
innodb_fts.fulltext [ pass ] 277
innodb_fts.fulltext [ pass ] 330
innodb_fts.fulltext [ pass ] 277

Keeping this bug to investigate this stall

Revision history for this message
Shahriyar Rzayev (rzayev-sehriyar) wrote :

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-1490

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.