maria-developers team mailing list archive
-
maria-developers team
-
Mailing list archive
-
Message #06118
Re: MariaDB mutex contention (was: Re: MariaDB 10.0 benchmarks on upcoming IVB-EP processors ...)
Hi Monty,
me and Axel did additional analysis of LOCK_open wait time in 10.0.4.
Below are a few interesting things that we discovered:
- with 1 CPU LOCK_open and THR_LOCK::mutex wait times are very close
- with 4 CPU LOCK_open wait time is about 5.5 * THR_LOCK::mutex wait time
- 5.6 with 4 CPU and table-cache-instances=1THR_LOCK::mutex wait time
is about 1.7% of execution time, with table-cache-instances=16 it is 9.8%
- tc_acquire_table/tc_release_table update 3 lists each, which is ~20 pointer updates
per query
- thr_lock/thr_unlock seem to do less pointer updates under read-only load
I guess every pointer update invalidates corresponding CPU cache lines of
other CPU's and causing expensive main memory reads.
So now I'm trying to find alternative cache algorithm that will either read or
update less pointers.
Regards,
Sergey
16.08.2013, в 18:11, 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 |
> +---------------------------------------------+------------+-----------------+------------+-----------------+------------+-----------------+
>
> <files.zip>
References
