maria-developers team mailing list archive

[Axel Schwenke <axel@xxxxxxxxxxxx>]

Hi,

Michael Widenius wrote:

> 10.0.4 should be very soon ready for benchmarking (Tuesday or
> Wednesday). We are in the final stage of fixing the failing test cases
> after our last merge with MySQL 5.6 GA.
> 
> I would just prefer to see Sergei Vojtovich push his code that changes
> how the table cache works.
> 
> This solves the same problem as the split table cache in 5.6,
> but is a much simpler and better implementation.
> 
> After this, I would expect that MariaDB 10.0 performance would be
> closer to 5.6 performance for this benchmark.

> Axel, could you at some point run the same benchmark with MariaDB
> 10.0.4 and MySQL 5.6 with gprof to see where time is spent?

I have now beefed up my knowledge of performance_schema and used it to look
at Mutex/RW-lock contention for readonly OLTP benchmark.

-----

TL;DR: 10.0.4 spends very long time in LOCK_PLUGIN, LOCK_OPEN is indeed much
better than 10.0.3 but not(?) nearly as good as MySQL-5.6.

-----

Contestants:

- MySQL-5.6.13 (release)
- MariaDB-10.0.3 (release)
- MariaDB-10.0 r3799 (bzr trunk)

all 3 compiled from source on benchmark machine using the same build script


Environment:

- many core machine (32 cores, 64 threads)
- sysbench-0.5 OLTP readonly, 10M rows, single table
- mysqld bound to 48 cores (sysbench to the other 8)
- tested with 64 threads (this is the sweet spot)
- using tcmalloc (preloaded)
- mutexes and rw locks fully instrumented via performance_schema, see my.cnf


Benchmark results (transactions per second):

	P_S on		P_S off
MySQL:	~15K		~18K
10.0.3:	~7K		~7.5K
10.0.4:	~6.5K		~9K

After stabilizing I took 3 probes from P_S, sorting by sum_timer_wait desc.
Times shown by P_S are picoseconds. If this were seconds, the decimal point
would be in the column between "m" and "_" in "sum_timer_wait". So i.e.
10.0.4 waited 242 seconds for LOCK_PLUGIN during the 10 second measurement
interval. Since we have 48 cores, there are total 480 seconds and 10.0.4
wasted about 50% of that.


Questions:

- what is protected by LOCK_PLUGIN?
- how is LOCK_OPEN split in MySQL-5.6?If some of that is now covered by
THR_LOCK::mutex, then it would explain why this is the busiest mutex in
MySQL-5.6.


Let me know if you need more data from me or if you have ideas what else I
should test.


XL


Top 20 Mutexes/RW-locks


MySQL-5.6.13

+---------------------------------------------+------------+-----------------+
| event_name                                  | count_star | sum_timer_wait  |
+---------------------------------------------+------------+-----------------+
| wait/synch/mutex/mysys/THR_LOCK::mutex      |    3397732 | 123367802416236 |
| wait/synch/rwlock/innodb/btr_search_latch   |    1632176 |  22207357475142 |
| wait/synch/rwlock/sql/LOCK_grant            |    1682983 |   1526912505972 |
| wait/synch/mutex/sql/LOCK_table_cache       |    3397786 |   1247140492941 |
| wait/synch/mutex/sql/THD::LOCK_thd_data     |    9219327 |   1076510130276 |
| wait/synch/rwlock/innodb/hash_table_locks   |    4086413 |   1026755227155 |
| wait/synch/mutex/innodb/trx_sys_mutex       |     364146 |    639270297372 |
| wait/synch/mutex/innodb/os_mutex            |     149491 |    630758755641 |
| wait/synch/rwlock/innodb/index_tree_rw_lock |    1016436 |    344264365074 |
| wait/synch/rwlock/sql/MDL_lock::rwlock      |     242778 |    183463650006 |
| wait/synch/mutex/sql/MDL_map::mutex         |     121342 |     69121460394 |
| wait/synch/mutex/mysys/BITMAP::mutex        |     242667 |     54426177477 |
| wait/synch/mutex/innodb/fil_system_mutex    |     179586 |     20229032103 |
| wait/synch/mutex/sql/LOCK_plugin            |     121352 |     15004585617 |
| wait/synch/mutex/innodb/trx_mutex           |     121475 |     13105527141 |
| wait/synch/mutex/innodb/lock_mutex          |     121374 |     12627692868 |
| wait/synch/mutex/innodb/buf_pool_mutex      |       2240 |       228234006 |
| wait/synch/mutex/innodb/log_sys_mutex       |        540 |       119752122 |
| wait/synch/mutex/innodb/flush_list_mutex    |        704 |        86802870 |
| wait/synch/mutex/innodb/buf_dblwr_mutex     |        640 |        30728817 |
+---------------------------------------------+------------+-----------------+


MariaDB-10.0.3


+------------------------------------------------+------------+-----------------+
| event_name                                     | count_star | sum_timer_wait  |
+------------------------------------------------+------------+-----------------+
| wait/synch/mutex/sql/LOCK_open                 |    3334966 | 251668176449112 |
| wait/synch/mutex/mysys/THR_LOCK::mutex         |    2206782 |   2761461343332 |
| wait/synch/mutex/sql/LOCK_plugin               |    2540899 |   1471913471196 |
| wait/synch/mutex/sql/THD::LOCK_thd_data        |    6485120 |    770989733856 |
| wait/synch/rwlock/innodb/hash table locks      |    3315788 |    674878255920 |
| wait/synch/rwlock/innodb/btr_search_latch      |    1358771 |    540950632524 |
| wait/synch/mutex/innodb/trx_sys_mutex          |     380210 |    245662486416 |
| wait/synch/rwlock/sql/MDL_lock::rwlock         |     191698 |    125257499748 |
| wait/synch/mutex/sql/TABLE_SHARE::LOCK_ha_data |    1067704 |     95258676492 |
| wait/synch/mutex/mysys/THR_LOCK_lock           |     157621 |     52329482172 |
| wait/synch/mutex/mysys/BITMAP::mutex           |     154870 |     49415303736 |
| wait/synch/mutex/sql/MDL_map::mutex            |      79173 |     41936664096 |
| wait/synch/mutex/innodb/fil_system_mutex       |     129610 |     40258209024 |
| wait/synch/mutex/innodb/lock_mutex             |      93667 |     26848457928 |
| wait/synch/mutex/innodb/trx_mutex              |      94131 |     11398946760 |
| wait/synch/mutex/innodb/buf_pool_mutex         |      12672 |       571983480 |
| wait/synch/mutex/innodb/buf_dblwr_mutex        |       9152 |       312365052 |
| wait/synch/mutex/innodb/log_sys_mutex          |        456 |       138632868 |
| wait/synch/mutex/innodb/flush_list_mutex       |        480 |       109226268 |
| wait/synch/mutex/innodb/os_mutex               |        350 |        71117100 |
+------------------------------------------------+------------+-----------------+


MariaDB-10.0-r3799

+---------------------------------------------+------------+-----------------+
| event_name                                  | count_star | sum_timer_wait  |
+---------------------------------------------+------------+-----------------+
| wait/synch/mutex/sql/LOCK_plugin            |    4194896 | 242595666533160 |
| wait/synch/mutex/sql/LOCK_open              |    1835243 |  33790056812460 |
| wait/synch/mutex/mysys/THR_LOCK::mutex      |    1835221 |   3136249420092 |
| wait/synch/rwlock/sql/LOCK_tdc              |     911928 |   1088553356028 |
| wait/synch/mutex/sql/THD::LOCK_thd_data     |    5766813 |    695664363024 |
| wait/synch/rwlock/innodb/hash table locks   |    2144715 |    513517462020 |
| wait/synch/rwlock/innodb/btr_search_latch   |     915043 |    399309801912 |
| wait/synch/rwlock/sql/MDL_lock::rwlock      |     131171 |    176610102480 |
| wait/synch/mutex/innodb/trx_sys_mutex       |     196751 |    154609451460 |
| wait/synch/rwlock/innodb/index_tree_rw_lock |     527543 |    137903039712 |
| wait/synch/mutex/sql/MDL_map::mutex         |     158268 |     95133455712 |
| wait/synch/mutex/innodb/fil_system_mutex    |      97493 |     27285605172 |
| wait/synch/mutex/mysys/BITMAP::mutex        |     131099 |     26589125196 |
| wait/synch/mutex/mysys/THR_LOCK_lock        |     131105 |     23952666708 |
| wait/synch/mutex/innodb/lock_mutex          |      65579 |     10355822676 |
| wait/synch/mutex/innodb/trx_mutex           |      65812 |      9790097724 |
| wait/synch/mutex/innodb/buf_pool_mutex      |      11550 |       644569236 |
| wait/synch/rwlock/innodb/checkpoint_lock    |          2 |       236298492 |
| wait/synch/mutex/innodb/buf_dblwr_mutex     |       3880 |       156907368 |
| wait/synch/mutex/innodb/flush_list_mutex    |        692 |       124740900 |
+---------------------------------------------+------------+-----------------+



Comparison
----------

                                                MariaDB-10.0-r3799             MariaDB-10.0.3                 MySQL-5.6.13
+---------------------------------------------+------------+-----------------+------------+-----------------+------------+-----------------+
| event_name                                  | count_star | sum_timer_wait  | count_star | sum_timer_wait  | count_star | sum_timer_wait  |
+---------------------------------------------+------------+-----------------+------------+-----------------+------------+-----------------+
| wait/synch/mutex/sql/LOCK_plugin            |    4194896 | 242595666533160 |    2540899 |   1471913471196 |     121352 |     15004585617 |
| wait/synch/mutex/sql/LOCK_open              |    1835243 |  33790056812460 |    3334966 | 251668176449112 |
| wait/synch/mutex/mysys/THR_LOCK::mutex      |    1835221 |   3136249420092 |    2206782 |   2761461343332 |    3397732 | 123367802416236 |
| wait/synch/rwlock/sql/LOCK_tdc              |     911928 |   1088553356028 |
| wait/synch/mutex/sql/THD::LOCK_thd_data     |    5766813 |    695664363024 |    6485120 |    770989733856 |    9219327 |   1076510130276 |
| wait/synch/rwlock/innodb/hash table locks   |    2144715 |    513517462020 |    3315788 |    674878255920 |    4086413 |   1026755227155 |
| wait/synch/rwlock/innodb/btr_search_latch   |     915043 |    399309801912 |    1358771 |    540950632524 |    1632176 |  22207357475142 |
| wait/synch/rwlock/sql/MDL_lock::rwlock      |     131171 |    176610102480 |     191698 |    125257499748 |     242778 |    183463650006 |
| wait/synch/mutex/innodb/trx_sys_mutex       |     196751 |    154609451460 |     380210 |    245662486416 |     364146 |    639270297372 |
| wait/synch/rwlock/innodb/index_tree_rw_lock |     527543 |    137903039712 |                                   1016436 |    344264365074 |
| wait/synch/mutex/sql/MDL_map::mutex         |     158268 |     95133455712 |      79173 |     41936664096 |     121342 |     69121460394 |
| wait/synch/mutex/innodb/fil_system_mutex    |      97493 |     27285605172 |     129610 |     40258209024 |     179586 |     20229032103 |
| wait/synch/mutex/mysys/BITMAP::mutex        |     131099 |     26589125196 |     154870 |     49415303736 |     242667 |     54426177477 |
| wait/synch/mutex/mysys/THR_LOCK_lock        |     131105 |     23952666708 |     157621 |     52329482172 |
| wait/synch/mutex/innodb/lock_mutex          |      65579 |     10355822676 |      93667 |     26848457928 |     121374 |     12627692868 |
| wait/synch/mutex/innodb/trx_mutex           |      65812 |      9790097724 |      94131 |     11398946760 |     121475 |     13105527141 |
| wait/synch/mutex/innodb/buf_pool_mutex      |      11550 |       644569236 |      12672 |       571983480 |       2240 |       228234006 |
| wait/synch/rwlock/innodb/checkpoint_lock    |          2 |       236298492 |
| wait/synch/mutex/innodb/buf_dblwr_mutex     |       3880 |       156907368 |       9152 |       312365052 |        640 |        30728817 |
| wait/synch/mutex/innodb/flush_list_mutex    |        692 |       124740900 |        480 |       109226268 |        704 |        86802870 |
+---------------------------------------------+------------+-----------------+------------+-----------------+------------+-----------------+

Attachment: files.zip
Description: Zip archive