Connection Lock Profiling

A lock profiling method is implemented as a lightweight alternative to performance counters. eXtremeDB locks are wrapped in MCO_BEGIN_WAIT_EVENT / MCO_END_WAIT_EVENT macros that store the identifier of the lock inside an internal structure. It is done using a single assignment operation without any synchronization, meaning that the performance overhead is negligible. This makes it possible to find out where exactly a connection is blocked.

For convenience, a basic profiling facility is implemented which samples the states of the connections every n microseconds. It can be used to gather lock statistics and reveal the busiest locks. The eXtremeDB Performance Monitor does not reveal this information, since it deals with CPU consumption and does not take into account the time spent waiting on the locks.

It is possible to retrieve the lock profile in xSQL using the start_profile(rate_usec) and stop_profile() functions. The former launches the profiler thread with the specified sampling period. The latter stops profiling and prints out the result.

(Also note that connection status can be obtained by querying the ConnectionInfo table. Please see page xSQL Statistics Logging for further details.)

Lightweight lock profiling

The locking profile is output from the call to stop_profile()consists of the percent, number of hits and the current wait event.

For example, the following commands show the lock profile for creating a table, and inserting 100,000 rows:

 
    select start_profile(10);
    create table foo(x integer);
    insert into foo  select s ."#1" from generate_series(1,100000) s;
    select count(*) from foo where (x %% 2) = 1;
    select * from stop_profile();
    percent	hits	event
    ----------------------------------------------------------------
    96.3159222811002	3817	NONE
    1.86727226848347	74	MVCC_TREE_READ_LOCK
    0.656068634872571	26	MVCC_FRA_MUTEX
    0.403734544536967	16	MVCC_CS_LOCK
    0.353267726469846	14	MVCC_LEAF_WRITE_LOCK
    0.252334090335604	10	MVCC_LEAF_READ_LOCK
    0.126167045167802	5	MVCC_TREE_WRITE_LOCK
    0.0252334090335604	1	MVCC_PM_MUTEX
    0	0	READ
    0	0	WRITE
    0	0	FLUSH
    0	0	MURSIW_TM_LOCK
    0	0	MURSIW_TRANS_LOCK
    0	0	MURSIW_READER_LOCK
    0	0	MURSIW_WRITER_LOCK
    0	0	MVCC_TM_LOCK
    0	0	MVCC_EXCLUSIVE_LOCK
    0	0	MVCC_SERIALIZABLE_LOCK
    0	0	MVCC_BLOB_MUTEX
    0	0	MVCC_HASH_WRITE_LOCK
    0	0	MVCC_HASH_READ_LOCK
    0	0	MVCC_KDTREE_WRITE_LOCK
    0	0	MVCC_KDTREE_READ_LOCK
    0	0	MVCC_PTREE_WRITE_LOCK
    0	0	MVCC_PTREE_READ_LOCK
    0	0	MVCC_RTREE_WRITE_LOCK
    0	0	MVCC_RTREE_READ_LOCK
    0	0	MVCC_DB_MUTEX
    0	0	DM_MUTEX
    0	0	DM_PAGE_MUTEX
    0	0	DM_ALLOC_MUTEX
    0	0	EXCLUSIVE_COMMIT_LOCK
    0	0	SHARED_COMMIT_LOCK
    0	0	ASYNC_LOCK
    0	0	ASYNC_MUTEX
    0	0	HEADER_LOCK
    0	0	WCHAR_BUF_MUTEX
    0	0	SOCKET_RECV
    0	0	SOCKET_SEND
     
    Selected records: 39