Created: 2009-04-07
Last modified: 2009-04-21




MySQL Performance: MySQL-5.4.0 and other InnoDB engines @dbSTRESS Benchmark (Apr.2009)






by Dimitri


SSC Team, 2009
Sun Microsystems Inc.





Ces informations sont données à titre indicatif et n'engagent pas Sun Microsystems.

Table of contents



Benchmark information
Customer Name(s): SSC Team

NDA: no

Contact Information:

Dates: Mar-Apr.2009

Keywords: MySQL 5.4, Perf Version , InnoDB, Percona, XtraDB, PostgreSQL, db_STRESS, M8000


Hardware Configuration
Server(s):
     - M8000 SPARC64-VI 16CPU (bi-core, bi-thread), 256GB RAM

Storage:
     - ST6540, 2x LUN (RAID1 16HDD, 950GB)


Software Configuration
System:

Application(s):


Abstract
Overview: Recently many changes came with new updates on XtraDB , InnoDB plugin and MySQL Perf Version - 5.4.0 is just announced and more experimental code is still in pipe! :-) Seeing a great performance improvements reached by XtraDB before (see: http://dimitrik.free.fr/db_STRESS_BMK_XtraDB_Percona_2009.html ), I was impatient to compare them all together and see where we are currently, and what is the next bottleneck :-)

All presented results here are "unofficial" and not engaging in any case Sun/MySQL. On the same time, benchmark testing gives us a way to learn (from bad or good), to see the whole result of improvements (if any), and provide information to make more efficient the next steps in development.

Goal(s): Even I was very curious to understand what's still blocking InnoDB to scale far better, but I tried to compare engine implementations first, and only then analyze contentions (all depends on time :-))

Result(s): on following pages :-)

Benchmark
As I expected to test all variations of InnoDB engine implementation I have to reduce the number of test cases to keep them within a given time slice :-)

I continue to use db_STRESS for the current testing too. A full db_STRESS description you may find here: http://dimitrik.free.fr/db_STRESS.html , and here some explanations about "active connections" and TPS graphs: http://dimitrik.free.fr/db_STRESS_BMK_2008.html#note_5220 . Current testing scenario will be limited only to the Stress scenario.

Stress scenario:



Variants of InnoDB engine
All following engines where compiled from source in 64bit binaries with GCC 4.3.2 (gcc43) and/or SunStudio 12 (ss12). The same configure/compile options were used everytime (-m64 -O3):

#
# GCC43 
#

CC=/usr/local/gcc4/bin/gcc CXX=/usr/local/gcc4/bin/g++ CFLAGS="-m64 -mcpu=v9 -O3" CXXFLAGS="-m64 -mcpu=v9 -O3" LDFLAGS="-lmtmalloc"
./configure --prefix=/apps/mysql --with-plugins="myisam,innobase"
gmake install

Quite curious: all engines demonstrated a higher performance if were compiled with GCC43 - seems to me it's due GCC atomics used within MySQL code - while they are used when compiling with GCC43 but ignored for SS12; and atomics become important once locking contention become hot.

NOTE: MySQL-5.4.0 and PerfVersion are using Solaris atomics if compiled with SS12 (great work of Tim Cook @Sun)


Benchmark Results Overview
Before to present here the final TPS level histograms, I want to attract your attention to the performance graphs tracing each engine activity during different workloads. Final histograms are agerage TPS values for each level of load (#sessions). But on performance stats graphs you may see a more detailed view of engine internals - for ex. if your performance jumping all the time between 2.000 and 6.000 TPS you'll miss it just by looking on the final avg 4.000 TPS result, and drop from 6.000 to 2.000 TPS usually means drop of the response time (divides by 3) which in some cases may be just innacceptable :-)

That's why I don't like too much only "avg" values - it reminds me an old joke about "average temperature in the hospital" (it may be 36.7C° for ex., and you'll miss say 3 persons having 42C° and which may die tomorrow if you do nothing).. So my final histograms are presenting also the MAX TPS level for every workload too, so you may see the gap between MAX and AVG, and if it's very big you may get an idea about performance stability :-)

But well, before some performance stats. Several engines are presented on the same "live" graph (the execution order of engines you may see in the graph title (each engines was stressed with the same workload one after other)). Workload is progressively increased from 1, 2, 4, .. to 256 concurrent sessions and you may easily recognize it by TPS level steps.

Some observations:



Full Benchmark Results
All benchmark results are presented like a following histogram.

Just click & enjoy! :-)


InnoDB Thread Concurrency: hack or feature?..
Before starting this discussion I'd remind you first about an impact of InnoDB concurrency value. As you may see from following graphs, all engines are impacted! Independently they have new or old concurrency implementation... By "impacted" I mean in most of cases it's the only option which gives you a way to keep workload on 64 or more concurrent sessions, and avoid a dramatic drop down of performance...

Current Hottest Lock contention during Read-Only workload
While InnoDB thread concurrency is set - the hottest lock contention will be on the concurrency management part (of course). So, to understand what is blocking InnoDB from scaling more far innodb_thread_concurrency should be set to zero :-)

I've tried to trace Read-Only workload locks that time (and it gave some ideas how to setup contention monitoring for the next tests)... BTW, it's a bad scalability on the Read-Only workload is the most hard to explain, as only reading data should not create any contention, isn't it? ;-))

So, I observed with "manually tracing" 2 cases on 16 cores:

Here are my "plockstat" outputs (first 5-7 lines, most hot contentions).

16 sessions
Count     nsec Lock                         Caller
-------------------------------------------------------------------------------
 4705    29481 mysqld`LOCK_open             mysqld`_Z10open_tableP3THDP10TABLE_LISTP11st_mem_rootPbj+0x3a8
 2188    25118 mysqld`LOCK_open             mysqld`_Z19close_thread_tablesP3THD+0xcc

     10 262840 0x100762b70 mysqld`os_mutex_enter+0x4
     27 12888 mysqld`LOCK_alarm mysqld`thr_end_alarm+0x10
     17 12276 mysqld`LOCK_alarm mysqld`thr_alarm+0x1c ...

32 sessions Count nsec Lock Caller ------------------------------------------------------------------------------- 33792 260383 mysqld`LOCK_open mysqld`_Z10open_tableP3THDP10TABLE_LISTP11st_mem_rootPbj+0x3a8 13850 156355 mysqld`LOCK_open mysqld`_Z19close_thread_tablesP3THD+0xcc 6357 199987 0x100762588 mysqld`os_mutex_enter+0x4 5202 167966 0x100762588 mysqld`os_mutex_enter+0x4 2091 208586 0x100762588 mysqld`os_mutex_enter+0x4 823 206320 0x100762588 mysqld`os_mutex_enter+0x4 624 198637 0x100762588 mysqld`os_mutex_enter+0x4 ...

64 sessions Count nsec Lock Caller ------------------------------------------------------------------------------- 48526 543352 mysqld`LOCK_open mysqld`_Z10open_tableP3THDP10TABLE_LISTP11st_mem_rootPbj+0x3a8 18989 241576 mysqld`LOCK_open mysqld`_Z19close_thread_tablesP3THD+0xcc 9441 284768 0x100762588 mysqld`os_mutex_enter+0x4 7791 249328 0x100762588 mysqld`os_mutex_enter+0x4 4064 284151 0x100762588 mysqld`os_mutex_enter+0x4 ...

128 sessions Count nsec Lock Caller ------------------------------------------------------------------------------- 61098 1200011 mysqld`LOCK_open mysqld`_Z10open_tableP3THDP10TABLE_LISTP11st_mem_rootPbj+0x3a8 25071 238692 mysqld`LOCK_open mysqld`_Z19close_thread_tablesP3THD+0xcc 11334 416758 0x100762588 mysqld`os_mutex_enter+0x4 4423 721319 0x100762588 mysqld`os_mutex_enter+0x4 8879 322576 0x100762588 mysqld`os_mutex_enter+0x4 5634 348857 0x100762588 mysqld`os_mutex_enter+0x4 ...

256 sessions Count nsec Lock Caller ------------------------------------------------------------------------------- 50536 3376433 mysqld`LOCK_open mysqld`_Z10open_tableP3THDP10TABLE_LISTP11st_mem_rootPbj+0x3a8 12760 1283299 0x100762588 mysqld`os_mutex_enter+0x4 9541 1309168 0x100762588 mysqld`os_mutex_enter+0x4 12658 903163 0x100762588 mysqld`os_mutex_enter+0x4 9801 1022544 0x100762588 mysqld`os_mutex_enter+0x4 21909 386888 mysqld`LOCK_open mysqld`_Z19close_thread_tablesP3THD+0xcc 9233 557634 0x100762588 mysqld`os_mutex_enter+0x4 ...



32 sessions
Count     nsec Lock                         Caller
-------------------------------------------------------------------------------
31168   259453 mysqld`LOCK_open             mysqld`_Z10open_tableP3THDP10TABLE_LISTP11st_mem_rootPbj+0x3a8
12925   154502 mysqld`LOCK_open             mysqld`_Z19close_thread_tablesP3THD+0xcc
 7347   203271 0x100762588                  mysqld`os_mutex_enter+0x4
 6002   172267 0x100762588                  mysqld`os_mutex_enter+0x4
 2524   204915 0x100762588                  mysqld`os_mutex_enter+0x4
...

64 sessions Count nsec Lock Caller ------------------------------------------------------------------------------- 32003 304938 mysqld`LOCK_open mysqld`_Z10open_tableP3THDP10TABLE_LISTP11st_mem_rootPbj+0x3a8 12930 170752 mysqld`LOCK_open mysqld`_Z19close_thread_tablesP3THD+0xcc 7799 235271 0x100762588 mysqld`os_mutex_enter+0x4 6640 193273 0x100762588 mysqld`os_mutex_enter+0x4 2993 237082 0x100762588 mysqld`os_mutex_enter+0x4 1208 283836 0x100762588 mysqld`os_mutex_enter+0x4 ...

128 sessions Count nsec Lock Caller ------------------------------------------------------------------------------- 59778 973223 mysqld`LOCK_open mysqld`_Z10open_tableP3THDP10TABLE_LISTP11st_mem_rootPbj+0x3a8 24707 241628 mysqld`LOCK_open mysqld`_Z19close_thread_tablesP3THD+0xcc 10412 422900 0x100762588 mysqld`os_mutex_enter+0x4 4890 755574 0x100762588 mysqld`os_mutex_enter+0x4 8266 331302 0x100762588 mysqld`os_mutex_enter+0x4 3465 745314 0x100762588 mysqld`os_mutex_enter+0x4 3613 645061 0x100762588 mysqld`os_mutex_enter+0x4 5114 321406 0x100762588 mysqld`os_mutex_enter+0x4 1803 620108 0x100762588 mysqld`os_mutex_enter+0x4 ...

256 sessions Count nsec Lock Caller ------------------------------------------------------------------------------- 64029 7220793 mysqld`LOCK_open mysqld`_Z10open_tableP3THDP10TABLE_LISTP11st_mem_rootPbj+0x3a8 8193 1546318 0x100762588 mysqld`os_mutex_enter+0x4 6672 1595149 0x100762588 mysqld`os_mutex_enter+0x4 27380 288497 mysqld`LOCK_open mysqld`_Z19close_thread_tablesP3THD+0xcc 6113 1279058 0x100762588 mysqld`os_mutex_enter+0x4 9664 781844 0x100762588 mysqld`os_mutex_enter+0x4 7460 539336 0x100762588 mysqld`os_mutex_enter+0x4 5092 559434 0x100762588 mysqld`os_mutex_enter+0x4 2233 1120384 0x100762588 mysqld`os_mutex_enter+0x4 ...

As you may see, the most hottest lock contention is on the LOCK_open mutex in both cases!
On the same time, "unnamed" mutex 0x100762588 (coming from sync_array functions) become more and more hot while rows are no more read from disk, and probably even more hot if we combine all time spent on it!

But the main problem is LOCK_open for the moment, and only once it'll be resloved (by splitting or recoding) makes sense to resolve other problems :-)

(BTW, my open table cache is set to 8000 (just in case))...

Comparing to PostgreSQL
I realized I did not test PostgreSQL for more than one year now, and was curious to see how performs the current latest PostgreSQL version 8.3.7. Two years ago PostgreSQL was twice better than MySQL (see http://dimitrik.free.fr/db_STRESS_BMK_Part1.html for details) I've compiled ProstgreSQL 64 bit binaries from the sources with GCC43 (similar as MySQL).

To adapt flush (fsync) option (comparable with InnoDB's innodb_flush_log_at_trx_commit=2) I've used synchronous_commit=off .

On 16cores performance was quite low on the read-only workload (5.000 TPS only), so I quickly switched to 32cores - as PostgreSQL did not suffer in the past such high locking problems as MySQL, the result should be only better on 32cores. And it's true - 6.500 TPS reached on 32cores.

Initially I used DIRECTIO mount option to see how high will be a caching impact. I set shared_buffers=12G (as InnoDB), but seeing still a lot of reading from the disk, I've increased it to 24GB, and it did not help either. Finally, I got impression the mix of shared buffers + partially delegating I/O buffering to the filesystem will be more optimal :-) Without DIRECTIO and 12GB shared buffers there was no read I/O anymore. However, in the same conditions increasing shared buffers to 24GB still helped too! - 7.500 TPS on the read-only (vs 6.500 with 12GB), 7.000 TPS on the read+write (vs 6.000 with 12GB).

Observations:

I did not have more time to investigate farther, but hope it was not the last test :-))
Workload activity graphs (best cases) are presented in appendix in the end of report..


Last updates
MySQL 5.1.33

Default 5.1.33 is not performing better comparing to default 5.1.32

XtraDB-4

While I was finishing this report, Percona shipped the new version of XtraDB based on the latest 1.0.3 InnoDB plugin: http://www.mysqlperformanceblog.com/2009/04/08/xtradb-storage-engine-release-4/

And I got a solution to run another test on the same platform! But I cannot add new XtraDB results into the final list because XtraDB is still suffering of rw_lock problem - database was freezed several times with giving a following message in the log file:

–Thread 1080 has waited at btr/btr0cur.c line 508 for 241.00 seconds the semaphore:
 X-lock on RW-latch at fffffffc72f811f8 created in file buf/buf0buf.c line 683
 a writer (thread id 1080) has reserved it in mode wait exclusive
 number of readers 0, s_waiters flag 0, x_waiters flag 1, lock_word: 100000
 Last time read locked in file btr/btr0cur.c line 508
 Last time write locked in file btr/btr0cur.c line 508

Analyzing mysql log file, I may suppose that freeze arriving during read+write workload when several sessions trying to access/modify different but neighbor rows (if I remember well InnoDB sometime also locking neighbors). And it's not an InnoDB bug as it not happens with InnoDB plugin or Perf Version. I've posted a question about freezes on comments, but did not have a fix on time..

The only thing I may confirm now - XtraDB-4 is not better on the Read-Only workload comparing to XtraDB-3 (and, honestly, I expected it'll perform at least as well as InnoDB plugin). And there is even a slight performance degradation on concurency=0 (but probably all it's due "rw_lock" problem). Regarding freezes - hope it'll be fixed soon...


SUMMARY
Final notes:
Appendix: Workload STATs
I've added here the most interesting STAT graphs observed during dbSTRESS workloads on different engines. You may find here a lot of other interesting details if you're not seeking just for a final result :-)

Few "decoding" notes for titles: