Import wiredtiger: 1a29eac4dc8cf82de437292da546e3f4039268a4 from branch mongodb-3.8

ref: 596a3c7c01..1a29eac4dc
for: 3.7.1

WT-3079       Make sure eviction visits all trees
WT-3133       Detect or track long latency operations
WT-3295       Allow LSM to merge into custom data sources
WT-3587       Remove HAVE_VERBOSE conditional compilation
WT-3654       Fix warning in Windows build on evergreen
WT-3716       Restore the WT_VERB_TEMPORARY verbose flag.
WT-3720       flags macros cast flags to unsigned values, hiding warnings.
WT-3732       Handle adding WT indices while cursors on the table are open
WT-3734       Fix undefined behavior in verbose output
WT-3738       Review internal session allocation accounting
WT-3753       Building on Windows --enable-java
WT-3772       Hot backup causes uncontrolled growth of WiredTigerPreplog files
WT-3774       Enhance Python lookaside testing to cover cursor modify
WT-3776       Cursor remove operation unpins page too early
WT-3780       Improve error messages on invalid WT_CURSOR::modify usage
WT-3783       Fix transaction isolation to use the correct enum
WT-3786       Transactions with timestamps should read their writes
WT-3787       test_compact02 failed as compaction halted due to eviction pressure
WT-3790       Switch statistics to rdtsc from epoch calls
WT-3793       WiredTiger page debug dump functions should unpack integer keys
WT-3794       Coverity 1383547 and lint
WT-3795       lint cleanups for the op-tracking software, reduce record write size.

2 files changed, 77 insertions, 52 deletions

diff --git a/src/third_party/wiredtiger/src/evict/evict_lru.c b/src/third_party/wiredtiger/src/evict/evict_lru.c
index 343d29d47cf..03f11f29b01 100644
--- a/src/third_party/wiredtiger/src/evict/evict_lru.c
+++ b/src/third_party/wiredtiger/src/evict/evict_lru.c
@@ -230,7 +230,6 @@ __wt_evict_server_wake(WT_SESSION_IMPL *session)
 	conn = S2C(session);
 	cache = conn->cache;
 
-#ifdef HAVE_VERBOSE
 	if (WT_VERBOSE_ISSET(session, WT_VERB_EVICTSERVER)) {
 		uint64_t bytes_inuse, bytes_max;
 
@@ -244,7 +243,6 @@ __wt_evict_server_wake(WT_SESSION_IMPL *session)
 		    bytes_inuse <= bytes_max ? "<=" : ">",
 		    bytes_max / WT_MEGABYTE);
 	}
-#endif
 
 	__wt_cond_signal(session, cache->evict_cond);
 }
@@ -371,9 +369,7 @@ err:		WT_PANIC_MSG(session, ret, "cache eviction thread error");
 static int
 __evict_server(WT_SESSION_IMPL *session, bool *did_work)
 {
-#if defined(HAVE_DIAGNOSTIC) || defined(HAVE_VERBOSE)
 	struct timespec now;
-#endif
 	WT_CACHE *cache;
 	WT_CONNECTION_IMPL *conn;
 	WT_DECL_RET;
@@ -421,13 +417,19 @@ __evict_server(WT_SESSION_IMPL *session, bool *did_work)
 
 	/* Eviction is stuck, check if we have made progress. */
 	if (*did_work) {
-#if defined(HAVE_DIAGNOSTIC) || defined(HAVE_VERBOSE)
-		__wt_epoch(session, &cache->stuck_time);
+#if !defined(HAVE_DIAGNOSTIC)
+		/* Need verbose check only if not in diagnostic build */
+		if (WT_VERBOSE_ISSET(session, WT_VERB_EVICT_STUCK))
 #endif
+			__wt_epoch(session, &cache->stuck_time);
 		return (0);
 	}
 
-#if defined(HAVE_DIAGNOSTIC) || defined(HAVE_VERBOSE)
+#if !defined(HAVE_DIAGNOSTIC)
+	/* Need verbose check only if not in diagnostic build */
+	if (!WT_VERBOSE_ISSET(session, WT_VERB_EVICT_STUCK))
+		return (0);
+#endif
 	/*
 	 * If we're stuck for 5 minutes in diagnostic mode, or the verbose
 	 * evict_stuck flag is configured, log the cache and transaction state.
@@ -447,11 +449,10 @@ __evict_server(WT_SESSION_IMPL *session, bool *did_work)
 #if defined(HAVE_DIAGNOSTIC)
 		__wt_err(session, ETIMEDOUT,
 		    "Cache stuck for too long, giving up");
-		ret = ETIMEDOUT;
-		WT_TRET(__wt_verbose_dump_txn(session));
-		WT_TRET(__wt_verbose_dump_cache(session));
-		return (ret);
-#elif defined(HAVE_VERBOSE)
+		WT_RET(__wt_verbose_dump_txn(session));
+		WT_RET(__wt_verbose_dump_cache(session));
+		return (ETIMEDOUT);
+#else
 		if (WT_VERBOSE_ISSET(session, WT_VERB_EVICT_STUCK)) {
 			WT_RET(__wt_verbose_dump_txn(session));
 			WT_RET(__wt_verbose_dump_cache(session));
@@ -461,7 +462,6 @@ __evict_server(WT_SESSION_IMPL *session, bool *did_work)
 		}
 #endif
 	}
-#endif
 	return (0);
 }
 
@@ -492,12 +492,14 @@ __wt_evict_create(WT_SESSION_IMPL *session)
 	    session_flags, __wt_evict_thread_chk, __wt_evict_thread_run,
 	    __wt_evict_thread_stop));
 
-#if defined(HAVE_DIAGNOSTIC) || defined(HAVE_VERBOSE)
 	/*
 	 * Ensure the cache stuck timer is initialized when starting eviction.
 	 */
-	__wt_epoch(session, &conn->cache->stuck_time);
+#if !defined(HAVE_DIAGNOSTIC)
+	/* Need verbose check only if not in diagnostic build */
+	if (WT_VERBOSE_ISSET(session, WT_VERB_EVICTSERVER))
 #endif
+		__wt_epoch(session, &conn->cache->stuck_time);
 
 	/*
 	 * Allow queues to be populated now that the eviction threads
@@ -651,11 +653,11 @@ __evict_update_work(WT_SESSION_IMPL *session)
 static int
 __evict_pass(WT_SESSION_IMPL *session)
 {
-	struct timespec now, prev;
 	WT_CACHE *cache;
 	WT_CONNECTION_IMPL *conn;
 	WT_TXN_GLOBAL *txn_global;
 	uint64_t eviction_progress, oldest_id, prev_oldest_id;
+	uint64_t time_now, time_prev;
 	u_int loop;
 
 	conn = S2C(session);
@@ -665,13 +667,13 @@ __evict_pass(WT_SESSION_IMPL *session)
 	/* Track whether pages are being evicted and progress is made. */
 	eviction_progress = cache->eviction_progress;
 	prev_oldest_id = txn_global->oldest_id;
-	WT_CLEAR(prev);
+	time_now = time_prev = 0;
 
 	/* Evict pages from the cache. */
 	for (loop = 0; cache->pass_intr == 0; loop++) {
-		__wt_epoch(session, &now);
+		time_now = __wt_rdtsc(session);
 		if (loop == 0)
-			prev = now;
+			time_prev = time_now;
 
 		__evict_tune_workers(session);
 		/*
@@ -739,7 +741,7 @@ __evict_pass(WT_SESSION_IMPL *session)
 		 * transactions and writing updates to the lookaside table.
 		 */
 		if (eviction_progress == cache->eviction_progress) {
-			if (WT_TIMEDIFF_MS(now, prev) >= 20 &&
+			if (WT_TSCDIFF_MS(session, time_now, time_prev) >= 20 &&
 			    F_ISSET(cache, WT_CACHE_EVICT_CLEAN_HARD |
 			    WT_CACHE_EVICT_DIRTY_HARD)) {
 				if (cache->evict_aggressive_score < 100)
@@ -749,7 +751,7 @@ __evict_pass(WT_SESSION_IMPL *session)
 				    txn_global->current != oldest_id &&
 				    cache->evict_aggressive_score < 100)
 					++cache->evict_aggressive_score;
-				prev = now;
+				time_prev = time_now;
 				prev_oldest_id = oldest_id;
 			}
 
@@ -1158,7 +1160,9 @@ __evict_lru_pages(WT_SESSION_IMPL *session, bool is_server)
 {
 	WT_CONNECTION_IMPL *conn;
 	WT_DECL_RET;
+	WT_TRACK_OP_DECL;
 
+	WT_TRACK_OP_INIT(session);
 	conn = S2C(session);
 
 	/*
@@ -1175,6 +1179,7 @@ __evict_lru_pages(WT_SESSION_IMPL *session, bool is_server)
 		__wt_cond_wait(
 		    session, conn->evict_threads.wait_cond, 10000, NULL);
 
+	WT_TRACK_OP_END(session);
 	return (ret == WT_NOTFOUND ? 0 : ret);
 }
 
@@ -1188,9 +1193,11 @@ __evict_lru_walk(WT_SESSION_IMPL *session)
 	WT_CACHE *cache;
 	WT_DECL_RET;
 	WT_EVICT_QUEUE *queue, *other_queue;
+	WT_TRACK_OP_DECL;
 	uint64_t read_gen_oldest;
 	uint32_t candidates, entries;
 
+	WT_TRACK_OP_INIT(session);
 	cache = S2C(session)->cache;
 
 	/* Age out the score of how much the queue has been empty recently. */
@@ -1212,12 +1219,14 @@ __evict_lru_walk(WT_SESSION_IMPL *session)
 	 */
 	if (__evict_queue_full(queue) &&
 	    cache->evict_empty_score < WT_EVICT_SCORE_CUTOFF)
-		return (0);
+		goto err;
 
 	/* Get some more pages to consider for eviction. */
-	if ((ret = __evict_walk(cache->walk_session, queue)) == EBUSY)
-		return (0);	/* An interrupt was requested, give up. */
-	WT_RET_NOTFOUND_OK(ret);
+	if ((ret = __evict_walk(cache->walk_session, queue)) == EBUSY) {
+		ret = 0;
+		goto err;     /* An interrupt was requested, give up. */
+	}
+	WT_ERR_NOTFOUND_OK(ret);
 
 	/*
 	 * If the queue we are filling is empty, pages are being requested
@@ -1271,7 +1280,7 @@ __evict_lru_walk(WT_SESSION_IMPL *session)
 		queue->evict_candidates = 0;
 		queue->evict_current = NULL;
 		__wt_spin_unlock(session, &queue->evict_lock);
-		return (0);
+		goto err;
 	}
 
 	/* Decide how many of the candidates we're going to try and evict. */
@@ -1330,7 +1339,8 @@ __evict_lru_walk(WT_SESSION_IMPL *session)
 	 */
 	__wt_cond_signal(session, S2C(session)->evict_threads.wait_cond);
 
-	return (0);
+err:	WT_TRACK_OP_END(session);
+	return (ret);
 }
 
 /*
@@ -1345,9 +1355,12 @@ __evict_walk(WT_SESSION_IMPL *session, WT_EVICT_QUEUE *queue)
 	WT_CONNECTION_IMPL *conn;
 	WT_DATA_HANDLE *dhandle;
 	WT_DECL_RET;
+	WT_TRACK_OP_DECL;
 	u_int max_entries, retries, slot, start_slot, total_candidates;
 	bool dhandle_locked, incr;
 
+	WT_TRACK_OP_INIT(session);
+
 	conn = S2C(session);
 	cache = conn->cache;
 	btree = NULL;
@@ -1527,9 +1540,10 @@ err:	if (dhandle_locked)
 	 * let our caller know.
 	 */
 	if (queue->evict_entries == slot && cache->pass_intr == 0)
-		return (WT_NOTFOUND);
+		ret = WT_NOTFOUND;
 
 	queue->evict_entries = slot;
+	WT_TRACK_OP_END(session);
 	return (ret);
 }
 
@@ -2242,18 +2256,22 @@ __evict_get_ref(
 static int
 __evict_page(WT_SESSION_IMPL *session, bool is_server)
 {
-	struct timespec enter, leave;
 	WT_BTREE *btree;
 	WT_CACHE *cache;
 	WT_DECL_RET;
 	WT_REF *ref;
+	WT_TRACK_OP_DECL;
+	uint64_t time_start, time_stop;
 	bool app_timer;
 
+	WT_TRACK_OP_INIT(session);
+
 	WT_RET(__evict_get_ref(session, is_server, &btree, &ref));
 	WT_ASSERT(session, ref->state == WT_REF_LOCKED);
 
 	app_timer = false;
 	cache = S2C(session)->cache;
+	time_start = time_stop = 0;
 
 	/*
 	 * An internal session flags either the server itself or an eviction
@@ -2272,7 +2290,7 @@ __evict_page(WT_SESSION_IMPL *session, bool is_server)
 		cache->app_evicts++;
 		if (WT_STAT_ENABLED(session)) {
 			app_timer = true;
-			__wt_epoch(session, &enter);
+			time_start = __wt_rdtsc(session);
 		}
 	}
 
@@ -2292,10 +2310,12 @@ __evict_page(WT_SESSION_IMPL *session, bool is_server)
 	(void)__wt_atomic_subv32(&btree->evict_busy, 1);
 
 	if (app_timer) {
-		__wt_epoch(session, &leave);
+		time_stop = __wt_rdtsc(session);
 		WT_STAT_CONN_INCRV(session,
-		    application_evict_time, WT_TIMEDIFF_US(leave, enter));
+		    application_evict_time,
+		    WT_TSCDIFF_US(session, time_stop, time_start));
 	}
+	WT_TRACK_OP_END(session);
 	return (ret);
 }
 
@@ -2308,17 +2328,20 @@ int
 __wt_cache_eviction_worker(
     WT_SESSION_IMPL *session, bool busy, bool readonly, u_int pct_full)
 {
-	struct timespec enter, leave;
 	WT_CACHE *cache;
 	WT_CONNECTION_IMPL *conn;
 	WT_DECL_RET;
+	WT_TRACK_OP_DECL;
 	WT_TXN_GLOBAL *txn_global;
 	WT_TXN_STATE *txn_state;
-	uint64_t initial_progress, max_progress;
+	uint64_t initial_progress, max_progress, time_start, time_stop;
 	bool timer;
 
+	WT_TRACK_OP_INIT(session);
+
 	conn = S2C(session);
 	cache = conn->cache;
+	time_start = time_stop = 0;
 	txn_global = &conn->txn_global;
 	txn_state = WT_SESSION_TXN_STATE(session);
 
@@ -2326,11 +2349,8 @@ __wt_cache_eviction_worker(
 	 * It is not safe to proceed if the eviction server threads aren't
 	 * setup yet.
 	 */
-	if (!conn->evict_server_running)
-		return (0);
-
-	if (busy && pct_full < 100)
-		return (0);
+	if (!conn->evict_server_running || (busy && pct_full < 100))
+		goto done;
 
 	/* Wake the eviction server if we need to do work. */
 	__wt_evict_server_wake(session);
@@ -2339,7 +2359,7 @@ __wt_cache_eviction_worker(
 	timer =
 	    WT_STAT_ENABLED(session) && !F_ISSET(session, WT_SESSION_INTERNAL);
 	if (timer)
-		__wt_epoch(session, &enter);
+		time_start = __wt_rdtsc(session);
 
 	for (initial_progress = cache->eviction_progress;; ret = 0) {
 		/*
@@ -2406,11 +2426,13 @@ __wt_cache_eviction_worker(
 	}
 
 err:	if (timer) {
-		__wt_epoch(session, &leave);
+		time_stop = __wt_rdtsc(session);
 		WT_STAT_CONN_INCRV(session,
-		    application_cache_time, WT_TIMEDIFF_US(leave, enter));
+		    application_cache_time,
+		    WT_TSCDIFF_US(session, time_stop, time_start));
 	}
 
+done:	WT_TRACK_OP_END(session);
 	return (ret);
 	/* NOTREACHED */
 }
@@ -2605,6 +2627,7 @@ __wt_verbose_dump_cache(WT_SESSION_IMPL *session)
 	WT_DECL_RET;
 	uint64_t total_bytes, total_dirty_bytes;
 	u_int pct;
+	bool needed;
 
 	conn = S2C(session);
 	total_bytes = total_dirty_bytes = 0;
@@ -2615,10 +2638,12 @@ __wt_verbose_dump_cache(WT_SESSION_IMPL *session)
 
 	WT_RET(__wt_msg(session,
 	    "cache full: %s", __wt_cache_full(session) ? "yes" : "no"));
-	WT_RET(__wt_msg(session, "cache clean check: %s (%u%%)",
-	    __wt_eviction_clean_needed(session, &pct) ? "yes" : "no", pct));
-	WT_RET(__wt_msg(session, "cache dirty check: %s (%u%%)",
-	    __wt_eviction_dirty_needed(session, &pct) ? "yes" : "no", pct));
+	needed = __wt_eviction_clean_needed(session, &pct);
+	WT_RET(__wt_msg(session,
+	    "cache clean check: %s (%u%%)", needed ? "yes" : "no", pct));
+	needed = __wt_eviction_dirty_needed(session, &pct);
+	WT_RET(__wt_msg(session,
+	    "cache dirty check: %s (%u%%)", needed ? "yes" : "no", pct));
 
 	for (dhandle = NULL;;) {
 		WT_WITH_HANDLE_LIST_READ_LOCK(session,
diff --git a/src/third_party/wiredtiger/src/evict/evict_page.c b/src/third_party/wiredtiger/src/evict/evict_page.c
index 7a84f90eb81..269fbaeaac8 100644
--- a/src/third_party/wiredtiger/src/evict/evict_page.c
+++ b/src/third_party/wiredtiger/src/evict/evict_page.c
@@ -52,15 +52,15 @@ __evict_exclusive(WT_SESSION_IMPL *session, WT_REF *ref)
 int
 __wt_page_release_evict(WT_SESSION_IMPL *session, WT_REF *ref)
 {
-	struct timespec start, stop;
 	WT_BTREE *btree;
 	WT_DECL_RET;
 	WT_PAGE *page;
+	uint64_t time_start, time_stop;
 	bool locked, too_big;
 
 	btree = S2BT(session);
 	page = ref->page;
-	__wt_epoch(session, &start);
+	time_start = __wt_rdtsc(session);
 
 	/*
 	 * Take some care with order of operations: if we release the hazard
@@ -83,12 +83,12 @@ __wt_page_release_evict(WT_SESSION_IMPL *session, WT_REF *ref)
 	 * we have one of two pairs of stats to increment.
 	 */
 	ret = __wt_evict(session, ref, false);
-	__wt_epoch(session, &stop);
+	time_stop = __wt_rdtsc(session);
 	if (ret == 0) {
 		if (too_big) {
 			WT_STAT_CONN_INCR(session, cache_eviction_force);
 			WT_STAT_CONN_INCRV(session, cache_eviction_force_time,
-			    WT_TIMEDIFF_US(stop, start));
+			    WT_TSCDIFF_US(session, time_stop, time_start));
 		} else {
 			/*
 			 * If the page isn't too big, we are evicting it because
@@ -98,12 +98,12 @@ __wt_page_release_evict(WT_SESSION_IMPL *session, WT_REF *ref)
 			WT_STAT_CONN_INCR(session, cache_eviction_force_delete);
 			WT_STAT_CONN_INCRV(session,
 			    cache_eviction_force_delete_time,
-			    WT_TIMEDIFF_US(stop, start));
+			    WT_TSCDIFF_US(session, time_stop, time_start));
 		}
 	} else {
 		WT_STAT_CONN_INCR(session, cache_eviction_force_fail);
 		WT_STAT_CONN_INCRV(session, cache_eviction_force_fail_time,
-		    WT_TIMEDIFF_US(stop, start));
+		    WT_TSCDIFF_US(session, time_stop, time_start));
 	}
 
 	(void)__wt_atomic_subv32(&btree->evict_busy, 1);