Patch for mutex contention statistics is ready

Code and details are here.

Use it for performance debugging rather rather than for performance. It may not make the server run faster, but it can show you where there are problems in the server code and you can fix those problems or report them to others.

The patch is for MySQL 5.1.26 and builds on x86_64 servers running Linux 2.6. It might not build elsewhere.

More on mutex contention

I have more mutex contention stats from MySQL 5.0.37 running sysbench on servers with 8 and 16 cores. The fast mutex option was backported from MySQL 5.1 by Larry Zhou and I added contention stats to it. The mutex contention stats are exported by a new command -- SHOW GLOBAL MUTEX STATS.

Note:

• These results do not include contention on rw-locks used by MySQL. That requires more hacking.
• Fast mutexes used by this test spin for 4 microseconds using pthread_mutex_trylock before blocking with pthread_mutex_lock.
• The fast mutex version of the server is no faster than the version that always uses pthread_mutex_lock. However, I am more interested in using fast mutexes to get mutex contention stats. We can then use the stats to find bottlenecks in the server and make it faster.
  

Results from the 8-core server for the sysbench oltp test with 64-threads and a CPU-bound workload. This lists the number of times that the caller probably went to sleep waiting for the lock.

1. 18474212 --> LOCK_open
2. 1882317 --> prepare_commit_mutex
3. 1662725 --> LOCK_global_client_user_stats
4. 523034  --> THR_LOCK_heap
5. 446372 --> LOCK_alarm

Results from the 16-core server for the sysbench oltp test with 64 threads and a CPU-bound workload. This lists the number of times that the caller probably went to sleep waiting for the lock.

1. 48687529 --> LOCK_open
2. 5759089 --> LOCK_alarm
3. 2922732 --> prepare_commit_mutex
4. 1958603 --> THR_lock_heap
5. 1808405 --> LOCK_global_client_user_stats
   

Notes on the hotspots:

• Antony Curtis has a proposed change that reduces contention for LOCK_open. I will look at it soon. This is by far the worst hotspot.
  
• LOCK_alarm is a known problem. It is used to implement timeouts for network IO. That is not needed on most platforms as there are system calls that do network read/write with a timeout. Drizzle may have already changed this.
• prepare_commit_mutex is locked in innobase_xa_prepare. XA is used internally when the binlog is enabled to guarantee that the binlog and InnoDB agree during crash recovery. If group commit is fixed for InnoDB then contention for this might be reduced.
• LOCK_global_client_user_stats is used for data produced by SHOW USER_STATISTICS. This is only in the Google patch. We think we can reduce contention on it.
• THR_LOCK_heap is used for allocation by the HEAP storage engine.
  

Mutex contention in MySQL

If you run MySQL on an SMP server and your server is busy, it is good to understand where the bottlenecks are in the server. Mutex contention is one such source. InnoDB provides mutex contention statistics via the SHOW MUTEX STATUS command. Alas, there are no statistics for the mutexes in the rest of MySQL -- unless you are willing to do a lot of refactoring. I used my favorite refactoring tool, sed, to replace many of the uses of pthread_mutex with my_mutex. my_mutex is a simple wrapper for pthread_mutex that provides contention and usage statistics and uses spin waiting prior to blocking on the pthread_mutex.

People who get to use MySQL on Solaris tell me that dtrace and mpstat provide information similar to this. Can someone post details with sample output on a blog post?

Sample output from a recently started server.

• Locks - number of times the mutex was locked
• Spins - number of times the caller tried to get the lock before returning or blocking on the pthread_mutex. Must be >= Locks.
• Sleeps - number of times the caller possibly blocked by calling pthread_mutex_lock after failing to lock the mutex with pthread_mutex_trylock and spinning for ~20 microseconds.
  

# mysql -e 'show global mutex status'
+-------+-------+--------+----------------------------+
| Locks | Spins | Sleeps | Name           |
+-------+-------+--------+----------------------------+
|    21 |    21 |      0 | LOCK_open          |
|    18 |    18 |      0 | LOCK_thread_count|
|     0 |     0 |      0 | LOCK_status          |
|     4 |     4 |      0 | LOCK_error_log     |

Sample output from a benchmark that reloads tables using 16 database connections on an 8 core server. The mutexes are ranked by the number of Sleeps. The test runs for a few minutes. Contention doesn't appear to be that bad in this case. A mutex for the binlog has the most contention. This is what I hoped for as the statements used for the test insert ~1000 rows, so there is a lot of work done per statement. A benchmark with simpler/faster statements would likely have more contention.

        Locks    Spins     Sleeps  Name

816258  883234  2995    LOCK_log for bin log
544304  558754  602     LOCK_open
548667  552807  189     LOCK_thread_count
273654  274334  12      LOCK_global_user_stats
1088548 1088803 1       LOCK_global_read_lock
544000  544000  0       LOCK_prep_xids
459     459     0       LOCK_xid_cache
4       4       0       LOCK_error_log
274533  274581  0       LOCK_user_conn
272004  272004  0       LOCK_global_table_stats