WT-2955 Add statistics tracking the amount of time threads spend waiting for high level locks (#3086)

* WT-2955 Add statistics tracking the amount of time threads spend waiting for high level locks

Sort the statistics categories so it's easier to find stuff, no real change.

* Add counters and usec wait times to long-term locks (currently the
checkpoint, handle-list, metadata, schema and table locks).

* mutex.i:295:26: error: conversion to int64_t {aka long int} from long
unsigned int may change the sign of the result [-Werror=sign-conversion]
[t->slot_usecs] += WT_TIMEDIFF_US(leave, enter);

* Rename the lock statistics so they group together.

Split lock wait times between internal and application threads.

* Separate the connection's dummy session initialization out into its own
function, that way it's clear what we're doing.

* The session's connection statistics are fixed when the session ID is
allocated, so we can cache a pointer to them and avoid u_int divisions
(which are currently about the slowest thing you can do on a modern
architecture).

* A slightly different change: instead of caching a reference to the
connection statistics, cache the offset into the array of statistics
pointers, that way we can avoid the integer division when updating
almost all statistics.

* Review comments:

Add comments describing the use of statistics array offsets in lock
tracking.

Rename WT_STATS_FIELD_TO_SLOT to WT_STATS_FIELD_TO_OFFSET.

Whitespace cleanup.

* __wt_cache_create() doesn't need to call __wt_cache_destroy() explicitly,
if the connection open fails at any point, __wt_cache_destroy() will be
called as part of that cleanup.

* Append the suffix "_off" to the spinlock structure statistics field
names, clarify they're offsets into the statistics structures.

3 files changed, 57 insertions, 32 deletions

diff --git a/src/conn/conn_api.c b/src/conn/conn_api.c
index 0951fd4e58c..74c675d794d 100644
--- a/src/conn/conn_api.c
+++ b/src/conn/conn_api.c
@@ -1943,6 +1943,42 @@ __conn_chk_file_system(WT_SESSION_IMPL *session, bool readonly)
 }
 
 /*
+ * wiredtiger_dummy_session_init --
+ *	Initialize the connection's dummy session.
+ */
+static void
+wiredtiger_dummy_session_init(
+    WT_CONNECTION_IMPL *conn, WT_EVENT_HANDLER *event_handler)
+{
+	WT_SESSION_IMPL *session;
+
+	session = &conn->dummy_session;
+
+	/*
+	 * We use a fake session until we can allocate and initialize the real
+	 * ones. Initialize the necessary fields (unfortunately, the fields we
+	 * initialize have been selected by core dumps, we need to do better).
+	 */
+	session->iface.connection = &conn->iface;
+	session->name = "wiredtiger_open";
+
+	/* Standard I/O and error handling first. */
+	__wt_os_stdio(session);
+	__wt_event_handler_set(session, event_handler);
+
+	/* Statistics */
+	session->stat_bucket = 0;
+
+	/*
+	 * Set the default session's strerror method. If one of the extensions
+	 * being loaded reports an error via the WT_EXTENSION_API strerror
+	 * method, but doesn't supply that method a WT_SESSION handle, we'll
+	 * use the WT_CONNECTION_IMPL's default session and its strerror method.
+	 */
+	session->iface.strerror = __wt_session_strerror;
+}
+
+/*
  * wiredtiger_open --
  *	Main library entry point: open a new connection to a WiredTiger
  *	database.
@@ -2013,21 +2049,11 @@ wiredtiger_open(const char *home, WT_EVENT_HANDLER *event_handler,
 	TAILQ_INSERT_TAIL(&__wt_process.connqh, conn, q);
 	__wt_spin_unlock(NULL, &__wt_process.spinlock);
 
-	session = conn->default_session = &conn->dummy_session;
-	session->iface.connection = &conn->iface;
-	session->name = "wiredtiger_open";
-
-	/* Do standard I/O and error handling first. */
-	__wt_os_stdio(session);
-	__wt_event_handler_set(session, event_handler);
-
 	/*
-	 * Set the default session's strerror method. If one of the extensions
-	 * being loaded reports an error via the WT_EXTENSION_API strerror
-	 * method, but doesn't supply that method a WT_SESSION handle, we'll
-	 * use the WT_CONNECTION_IMPL's default session and its strerror method.
+	 * Initialize the fake session used until we can create real sessions.
 	 */
-	conn->default_session->iface.strerror = __wt_session_strerror;
+	wiredtiger_dummy_session_init(conn, event_handler);
+	session = conn->default_session = &conn->dummy_session;
 
 	/* Basic initialization of the connection structure. */
 	WT_ERR(__wt_connection_init(conn));
diff --git a/src/conn/conn_cache.c b/src/conn/conn_cache.c
index 1b8b3183d3c..fe5f94ea03d 100644
--- a/src/conn/conn_cache.c
+++ b/src/conn/conn_cache.c
@@ -183,26 +183,26 @@ __wt_cache_create(WT_SESSION_IMPL *session, const char *cfg[])
 	 * get any work done.
 	 */
 	if (cache->eviction_target >= cache->eviction_trigger)
-		WT_ERR_MSG(session, EINVAL,
+		WT_RET_MSG(session, EINVAL,
 		    "eviction target must be lower than the eviction trigger");
 
-	WT_ERR(__wt_cond_auto_alloc(session, "cache eviction server",
+	WT_RET(__wt_cond_auto_alloc(session, "cache eviction server",
 	    false, 10000, WT_MILLION, &cache->evict_cond));
-	WT_ERR(__wt_spin_init(session, &cache->evict_pass_lock, "evict pass"));
-	WT_ERR(__wt_spin_init(session,
+	WT_RET(__wt_spin_init(session, &cache->evict_pass_lock, "evict pass"));
+	WT_RET(__wt_spin_init(session,
 	    &cache->evict_queue_lock, "cache eviction queue"));
-	WT_ERR(__wt_spin_init(session, &cache->evict_walk_lock, "cache walk"));
+	WT_RET(__wt_spin_init(session, &cache->evict_walk_lock, "cache walk"));
 	if ((ret = __wt_open_internal_session(conn, "evict pass",
 	    false, WT_SESSION_NO_DATA_HANDLES, &cache->walk_session)) != 0)
-		WT_ERR_MSG(NULL, ret,
+		WT_RET_MSG(NULL, ret,
 		    "Failed to create session for eviction walks");
 
 	/* Allocate the LRU eviction queue. */
 	cache->evict_slots = WT_EVICT_WALK_BASE + WT_EVICT_WALK_INCR;
 	for (i = 0; i < WT_EVICT_QUEUE_MAX; ++i) {
-		WT_ERR(__wt_calloc_def(session,
+		WT_RET(__wt_calloc_def(session,
 		    cache->evict_slots, &cache->evict_queues[i].evict_queue));
-		WT_ERR(__wt_spin_init(session,
+		WT_RET(__wt_spin_init(session,
 		    &cache->evict_queues[i].evict_lock, "cache eviction"));
 	}
 
@@ -218,9 +218,6 @@ __wt_cache_create(WT_SESSION_IMPL *session, const char *cfg[])
 	 */
 	__wt_cache_stats_update(session);
 	return (0);
-
-err:	WT_RET(__wt_cache_destroy(session));
-	return (ret);
 }
 
 /*
diff --git a/src/conn/conn_handle.c b/src/conn/conn_handle.c
index 5ff8b7f798b..5104624523b 100644
--- a/src/conn/conn_handle.c
+++ b/src/conn/conn_handle.c
@@ -50,21 +50,23 @@ __wt_connection_init(WT_CONNECTION_IMPL *conn)
 	/* Statistics. */
 	__wt_stat_connection_init(conn);
 
-	/* Locks. */
+	/* Spinlocks. */
 	WT_RET(__wt_spin_init(session, &conn->api_lock, "api"));
-	WT_RET(__wt_spin_init(session, &conn->checkpoint_lock, "checkpoint"));
-	WT_RET(__wt_spin_init(session, &conn->dhandle_lock, "data handle"));
+	WT_SPIN_INIT_TRACKED(session, &conn->checkpoint_lock, checkpoint);
+	WT_SPIN_INIT_TRACKED(session, &conn->dhandle_lock, handle_list);
 	WT_RET(__wt_spin_init(session, &conn->encryptor_lock, "encryptor"));
 	WT_RET(__wt_spin_init(session, &conn->fh_lock, "file list"));
-	WT_RET(__wt_rwlock_alloc(session,
-	    &conn->hot_backup_lock, "hot backup"));
 	WT_RET(__wt_spin_init(session, &conn->las_lock, "lookaside table"));
-	WT_RET(__wt_spin_init(session, &conn->metadata_lock, "metadata"));
+	WT_SPIN_INIT_TRACKED(session, &conn->metadata_lock, metadata);
 	WT_RET(__wt_spin_init(session, &conn->reconfig_lock, "reconfigure"));
-	WT_RET(__wt_spin_init(session, &conn->schema_lock, "schema"));
-	WT_RET(__wt_spin_init(session, &conn->table_lock, "table creation"));
+	WT_SPIN_INIT_TRACKED(session, &conn->schema_lock, schema);
+	WT_SPIN_INIT_TRACKED(session, &conn->table_lock, table);
 	WT_RET(__wt_spin_init(session, &conn->turtle_lock, "turtle file"));
 
+	/* Read-write locks */
+	WT_RET(__wt_rwlock_alloc(
+	    session, &conn->hot_backup_lock, "hot backup"));
+
 	WT_RET(__wt_calloc_def(session, WT_PAGE_LOCKS, &conn->page_lock));
 	WT_CACHE_LINE_ALIGNMENT_VERIFY(session, conn->page_lock);
 	for (i = 0; i < WT_PAGE_LOCKS; ++i)