WT-3243 Reorder log slot release so joins don't wait on IO (#3360)

7 files changed, 221 insertions, 192 deletions

diff --git a/dist/stat_data.py b/dist/stat_data.py
index 8fed3f3ac4a..ac79ffd029a 100644
--- a/dist/stat_data.py
+++ b/dist/stat_data.py
@@ -324,10 +324,12 @@ connection_stats = [
     LogStat('log_scan_records', 'records processed by log scan'),
     LogStat('log_scan_rereads', 'log scan records requiring two reads'),
     LogStat('log_scans', 'log scan operations'),
+    LogStat('log_slot_active_closed', 'consolidated slot join active slot closed'),
     LogStat('log_slot_closes', 'consolidated slot closures'),
     LogStat('log_slot_coalesced', 'written slots coalesced'),
     LogStat('log_slot_consolidated', 'logging bytes consolidated', 'size'),
     LogStat('log_slot_joins', 'consolidated slot joins'),
+    LogStat('log_slot_no_free_slots', 'consolidated slot transitions unable to find free slot'),
     LogStat('log_slot_races', 'consolidated slot join races'),
     LogStat('log_slot_switch_busy', 'busy returns attempting to switch slots'),
     LogStat('log_slot_transitions', 'consolidated slot join transitions'),
diff --git a/src/include/extern.h b/src/include/extern.h
index 47b4e03a7b7..c0a6087e9b1 100644
--- a/src/include/extern.h
+++ b/src/include/extern.h
@@ -405,7 +405,6 @@ extern int __wt_logop_row_truncate_print(WT_SESSION_IMPL *session, const uint8_t
 extern int __wt_txn_op_printlog(WT_SESSION_IMPL *session, const uint8_t **pp, const uint8_t *end, uint32_t flags) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)) WT_GCC_FUNC_DECL_ATTRIBUTE((visibility("hidden")));
 extern void __wt_log_slot_activate(WT_SESSION_IMPL *session, WT_LOGSLOT *slot) WT_GCC_FUNC_DECL_ATTRIBUTE((visibility("hidden")));
 extern int __wt_log_slot_switch( WT_SESSION_IMPL *session, WT_MYSLOT *myslot, bool retry, bool forced) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)) WT_GCC_FUNC_DECL_ATTRIBUTE((visibility("hidden")));
-extern int __wt_log_slot_new(WT_SESSION_IMPL *session) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)) WT_GCC_FUNC_DECL_ATTRIBUTE((visibility("hidden")));
 extern int __wt_log_slot_init(WT_SESSION_IMPL *session) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)) WT_GCC_FUNC_DECL_ATTRIBUTE((visibility("hidden")));
 extern int __wt_log_slot_destroy(WT_SESSION_IMPL *session) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)) WT_GCC_FUNC_DECL_ATTRIBUTE((visibility("hidden")));
 extern int __wt_log_slot_join(WT_SESSION_IMPL *session, uint64_t mysize, uint32_t flags, WT_MYSLOT *myslot) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)) WT_GCC_FUNC_DECL_ATTRIBUTE((visibility("hidden")));
diff --git a/src/include/log.h b/src/include/log.h
index f0999ba316b..fb3c961417f 100644
--- a/src/include/log.h
+++ b/src/include/log.h
@@ -193,7 +193,8 @@ struct __wt_myslot {
 	wt_off_t	 end_offset;	/* My end offset in buffer */
 	wt_off_t	 offset;	/* Slot buffer offset */
 #define	WT_MYSLOT_CLOSE		0x01	/* This thread is closing the slot */
-#define	WT_MYSLOT_UNBUFFERED	0x02	/* Write directly */
+#define	WT_MYSLOT_NEEDS_RELEASE	0x02	/* This thread is releasing the slot */
+#define	WT_MYSLOT_UNBUFFERED	0x04	/* Write directly */
 	uint32_t flags;			/* Flags */
 };
 
diff --git a/src/include/stat.h b/src/include/stat.h
index bc7a7cab7ce..6c274484bcb 100644
--- a/src/include/stat.h
+++ b/src/include/stat.h
@@ -405,9 +405,11 @@ struct __wt_connection_stats {
 	int64_t lock_table_wait_internal;
 	int64_t log_slot_switch_busy;
 	int64_t log_slot_closes;
+	int64_t log_slot_active_closed;
 	int64_t log_slot_races;
 	int64_t log_slot_transitions;
 	int64_t log_slot_joins;
+	int64_t log_slot_no_free_slots;
 	int64_t log_slot_unbuffered;
 	int64_t log_bytes_payload;
 	int64_t log_bytes_written;
diff --git a/src/include/wiredtiger.in b/src/include/wiredtiger.in
index ced6df3d29d..ddecb2ac765 100644
--- a/src/include/wiredtiger.in
+++ b/src/include/wiredtiger.in
@@ -4640,206 +4640,210 @@ extern int wiredtiger_extension_terminate(WT_CONNECTION *connection);
 #define	WT_STAT_CONN_LOG_SLOT_SWITCH_BUSY		1146
 /*! log: consolidated slot closures */
 #define	WT_STAT_CONN_LOG_SLOT_CLOSES			1147
+/*! log: consolidated slot join active slot closed */
+#define	WT_STAT_CONN_LOG_SLOT_ACTIVE_CLOSED		1148
 /*! log: consolidated slot join races */
-#define	WT_STAT_CONN_LOG_SLOT_RACES			1148
+#define	WT_STAT_CONN_LOG_SLOT_RACES			1149
 /*! log: consolidated slot join transitions */
-#define	WT_STAT_CONN_LOG_SLOT_TRANSITIONS		1149
+#define	WT_STAT_CONN_LOG_SLOT_TRANSITIONS		1150
 /*! log: consolidated slot joins */
-#define	WT_STAT_CONN_LOG_SLOT_JOINS			1150
+#define	WT_STAT_CONN_LOG_SLOT_JOINS			1151
+/*! log: consolidated slot transitions unable to find free slot */
+#define	WT_STAT_CONN_LOG_SLOT_NO_FREE_SLOTS		1152
 /*! log: consolidated slot unbuffered writes */
-#define	WT_STAT_CONN_LOG_SLOT_UNBUFFERED		1151
+#define	WT_STAT_CONN_LOG_SLOT_UNBUFFERED		1153
 /*! log: log bytes of payload data */
-#define	WT_STAT_CONN_LOG_BYTES_PAYLOAD			1152
+#define	WT_STAT_CONN_LOG_BYTES_PAYLOAD			1154
 /*! log: log bytes written */
-#define	WT_STAT_CONN_LOG_BYTES_WRITTEN			1153
+#define	WT_STAT_CONN_LOG_BYTES_WRITTEN			1155
 /*! log: log files manually zero-filled */
-#define	WT_STAT_CONN_LOG_ZERO_FILLS			1154
+#define	WT_STAT_CONN_LOG_ZERO_FILLS			1156
 /*! log: log flush operations */
-#define	WT_STAT_CONN_LOG_FLUSH				1155
+#define	WT_STAT_CONN_LOG_FLUSH				1157
 /*! log: log force write operations */
-#define	WT_STAT_CONN_LOG_FORCE_WRITE			1156
+#define	WT_STAT_CONN_LOG_FORCE_WRITE			1158
 /*! log: log force write operations skipped */
-#define	WT_STAT_CONN_LOG_FORCE_WRITE_SKIP		1157
+#define	WT_STAT_CONN_LOG_FORCE_WRITE_SKIP		1159
 /*! log: log records compressed */
-#define	WT_STAT_CONN_LOG_COMPRESS_WRITES		1158
+#define	WT_STAT_CONN_LOG_COMPRESS_WRITES		1160
 /*! log: log records not compressed */
-#define	WT_STAT_CONN_LOG_COMPRESS_WRITE_FAILS		1159
+#define	WT_STAT_CONN_LOG_COMPRESS_WRITE_FAILS		1161
 /*! log: log records too small to compress */
-#define	WT_STAT_CONN_LOG_COMPRESS_SMALL			1160
+#define	WT_STAT_CONN_LOG_COMPRESS_SMALL			1162
 /*! log: log release advances write LSN */
-#define	WT_STAT_CONN_LOG_RELEASE_WRITE_LSN		1161
+#define	WT_STAT_CONN_LOG_RELEASE_WRITE_LSN		1163
 /*! log: log scan operations */
-#define	WT_STAT_CONN_LOG_SCANS				1162
+#define	WT_STAT_CONN_LOG_SCANS				1164
 /*! log: log scan records requiring two reads */
-#define	WT_STAT_CONN_LOG_SCAN_REREADS			1163
+#define	WT_STAT_CONN_LOG_SCAN_REREADS			1165
 /*! log: log server thread advances write LSN */
-#define	WT_STAT_CONN_LOG_WRITE_LSN			1164
+#define	WT_STAT_CONN_LOG_WRITE_LSN			1166
 /*! log: log server thread write LSN walk skipped */
-#define	WT_STAT_CONN_LOG_WRITE_LSN_SKIP			1165
+#define	WT_STAT_CONN_LOG_WRITE_LSN_SKIP			1167
 /*! log: log sync operations */
-#define	WT_STAT_CONN_LOG_SYNC				1166
+#define	WT_STAT_CONN_LOG_SYNC				1168
 /*! log: log sync time duration (usecs) */
-#define	WT_STAT_CONN_LOG_SYNC_DURATION			1167
+#define	WT_STAT_CONN_LOG_SYNC_DURATION			1169
 /*! log: log sync_dir operations */
-#define	WT_STAT_CONN_LOG_SYNC_DIR			1168
+#define	WT_STAT_CONN_LOG_SYNC_DIR			1170
 /*! log: log sync_dir time duration (usecs) */
-#define	WT_STAT_CONN_LOG_SYNC_DIR_DURATION		1169
+#define	WT_STAT_CONN_LOG_SYNC_DIR_DURATION		1171
 /*! log: log write operations */
-#define	WT_STAT_CONN_LOG_WRITES				1170
+#define	WT_STAT_CONN_LOG_WRITES				1172
 /*! log: logging bytes consolidated */
-#define	WT_STAT_CONN_LOG_SLOT_CONSOLIDATED		1171
+#define	WT_STAT_CONN_LOG_SLOT_CONSOLIDATED		1173
 /*! log: maximum log file size */
-#define	WT_STAT_CONN_LOG_MAX_FILESIZE			1172
+#define	WT_STAT_CONN_LOG_MAX_FILESIZE			1174
 /*! log: number of pre-allocated log files to create */
-#define	WT_STAT_CONN_LOG_PREALLOC_MAX			1173
+#define	WT_STAT_CONN_LOG_PREALLOC_MAX			1175
 /*! log: pre-allocated log files not ready and missed */
-#define	WT_STAT_CONN_LOG_PREALLOC_MISSED		1174
+#define	WT_STAT_CONN_LOG_PREALLOC_MISSED		1176
 /*! log: pre-allocated log files prepared */
-#define	WT_STAT_CONN_LOG_PREALLOC_FILES			1175
+#define	WT_STAT_CONN_LOG_PREALLOC_FILES			1177
 /*! log: pre-allocated log files used */
-#define	WT_STAT_CONN_LOG_PREALLOC_USED			1176
+#define	WT_STAT_CONN_LOG_PREALLOC_USED			1178
 /*! log: records processed by log scan */
-#define	WT_STAT_CONN_LOG_SCAN_RECORDS			1177
+#define	WT_STAT_CONN_LOG_SCAN_RECORDS			1179
 /*! log: total in-memory size of compressed records */
-#define	WT_STAT_CONN_LOG_COMPRESS_MEM			1178
+#define	WT_STAT_CONN_LOG_COMPRESS_MEM			1180
 /*! log: total log buffer size */
-#define	WT_STAT_CONN_LOG_BUFFER_SIZE			1179
+#define	WT_STAT_CONN_LOG_BUFFER_SIZE			1181
 /*! log: total size of compressed records */
-#define	WT_STAT_CONN_LOG_COMPRESS_LEN			1180
+#define	WT_STAT_CONN_LOG_COMPRESS_LEN			1182
 /*! log: written slots coalesced */
-#define	WT_STAT_CONN_LOG_SLOT_COALESCED			1181
+#define	WT_STAT_CONN_LOG_SLOT_COALESCED			1183
 /*! log: yields waiting for previous log file close */
-#define	WT_STAT_CONN_LOG_CLOSE_YIELDS			1182
+#define	WT_STAT_CONN_LOG_CLOSE_YIELDS			1184
 /*! reconciliation: fast-path pages deleted */
-#define	WT_STAT_CONN_REC_PAGE_DELETE_FAST		1183
+#define	WT_STAT_CONN_REC_PAGE_DELETE_FAST		1185
 /*! reconciliation: page reconciliation calls */
-#define	WT_STAT_CONN_REC_PAGES				1184
+#define	WT_STAT_CONN_REC_PAGES				1186
 /*! reconciliation: page reconciliation calls for eviction */
-#define	WT_STAT_CONN_REC_PAGES_EVICTION			1185
+#define	WT_STAT_CONN_REC_PAGES_EVICTION			1187
 /*! reconciliation: pages deleted */
-#define	WT_STAT_CONN_REC_PAGE_DELETE			1186
+#define	WT_STAT_CONN_REC_PAGE_DELETE			1188
 /*! reconciliation: split bytes currently awaiting free */
-#define	WT_STAT_CONN_REC_SPLIT_STASHED_BYTES		1187
+#define	WT_STAT_CONN_REC_SPLIT_STASHED_BYTES		1189
 /*! reconciliation: split objects currently awaiting free */
-#define	WT_STAT_CONN_REC_SPLIT_STASHED_OBJECTS		1188
+#define	WT_STAT_CONN_REC_SPLIT_STASHED_OBJECTS		1190
 /*! session: open cursor count */
-#define	WT_STAT_CONN_SESSION_CURSOR_OPEN		1189
+#define	WT_STAT_CONN_SESSION_CURSOR_OPEN		1191
 /*! session: open session count */
-#define	WT_STAT_CONN_SESSION_OPEN			1190
+#define	WT_STAT_CONN_SESSION_OPEN			1192
 /*! session: table alter failed calls */
-#define	WT_STAT_CONN_SESSION_TABLE_ALTER_FAIL		1191
+#define	WT_STAT_CONN_SESSION_TABLE_ALTER_FAIL		1193
 /*! session: table alter successful calls */
-#define	WT_STAT_CONN_SESSION_TABLE_ALTER_SUCCESS	1192
+#define	WT_STAT_CONN_SESSION_TABLE_ALTER_SUCCESS	1194
 /*! session: table alter unchanged and skipped */
-#define	WT_STAT_CONN_SESSION_TABLE_ALTER_SKIP		1193
+#define	WT_STAT_CONN_SESSION_TABLE_ALTER_SKIP		1195
 /*! session: table compact failed calls */
-#define	WT_STAT_CONN_SESSION_TABLE_COMPACT_FAIL		1194
+#define	WT_STAT_CONN_SESSION_TABLE_COMPACT_FAIL		1196
 /*! session: table compact successful calls */
-#define	WT_STAT_CONN_SESSION_TABLE_COMPACT_SUCCESS	1195
+#define	WT_STAT_CONN_SESSION_TABLE_COMPACT_SUCCESS	1197
 /*! session: table create failed calls */
-#define	WT_STAT_CONN_SESSION_TABLE_CREATE_FAIL		1196
+#define	WT_STAT_CONN_SESSION_TABLE_CREATE_FAIL		1198
 /*! session: table create successful calls */
-#define	WT_STAT_CONN_SESSION_TABLE_CREATE_SUCCESS	1197
+#define	WT_STAT_CONN_SESSION_TABLE_CREATE_SUCCESS	1199
 /*! session: table drop failed calls */
-#define	WT_STAT_CONN_SESSION_TABLE_DROP_FAIL		1198
+#define	WT_STAT_CONN_SESSION_TABLE_DROP_FAIL		1200
 /*! session: table drop successful calls */
-#define	WT_STAT_CONN_SESSION_TABLE_DROP_SUCCESS		1199
+#define	WT_STAT_CONN_SESSION_TABLE_DROP_SUCCESS		1201
 /*! session: table rebalance failed calls */
-#define	WT_STAT_CONN_SESSION_TABLE_REBALANCE_FAIL	1200
+#define	WT_STAT_CONN_SESSION_TABLE_REBALANCE_FAIL	1202
 /*! session: table rebalance successful calls */
-#define	WT_STAT_CONN_SESSION_TABLE_REBALANCE_SUCCESS	1201
+#define	WT_STAT_CONN_SESSION_TABLE_REBALANCE_SUCCESS	1203
 /*! session: table rename failed calls */
-#define	WT_STAT_CONN_SESSION_TABLE_RENAME_FAIL		1202
+#define	WT_STAT_CONN_SESSION_TABLE_RENAME_FAIL		1204
 /*! session: table rename successful calls */
-#define	WT_STAT_CONN_SESSION_TABLE_RENAME_SUCCESS	1203
+#define	WT_STAT_CONN_SESSION_TABLE_RENAME_SUCCESS	1205
 /*! session: table salvage failed calls */
-#define	WT_STAT_CONN_SESSION_TABLE_SALVAGE_FAIL		1204
+#define	WT_STAT_CONN_SESSION_TABLE_SALVAGE_FAIL		1206
 /*! session: table salvage successful calls */
-#define	WT_STAT_CONN_SESSION_TABLE_SALVAGE_SUCCESS	1205
+#define	WT_STAT_CONN_SESSION_TABLE_SALVAGE_SUCCESS	1207
 /*! session: table truncate failed calls */
-#define	WT_STAT_CONN_SESSION_TABLE_TRUNCATE_FAIL	1206
+#define	WT_STAT_CONN_SESSION_TABLE_TRUNCATE_FAIL	1208
 /*! session: table truncate successful calls */
-#define	WT_STAT_CONN_SESSION_TABLE_TRUNCATE_SUCCESS	1207
+#define	WT_STAT_CONN_SESSION_TABLE_TRUNCATE_SUCCESS	1209
 /*! session: table verify failed calls */
-#define	WT_STAT_CONN_SESSION_TABLE_VERIFY_FAIL		1208
+#define	WT_STAT_CONN_SESSION_TABLE_VERIFY_FAIL		1210
 /*! session: table verify successful calls */
-#define	WT_STAT_CONN_SESSION_TABLE_VERIFY_SUCCESS	1209
+#define	WT_STAT_CONN_SESSION_TABLE_VERIFY_SUCCESS	1211
 /*! thread-state: active filesystem fsync calls */
-#define	WT_STAT_CONN_THREAD_FSYNC_ACTIVE		1210
+#define	WT_STAT_CONN_THREAD_FSYNC_ACTIVE		1212
 /*! thread-state: active filesystem read calls */
-#define	WT_STAT_CONN_THREAD_READ_ACTIVE			1211
+#define	WT_STAT_CONN_THREAD_READ_ACTIVE			1213
 /*! thread-state: active filesystem write calls */
-#define	WT_STAT_CONN_THREAD_WRITE_ACTIVE		1212
+#define	WT_STAT_CONN_THREAD_WRITE_ACTIVE		1214
 /*! thread-yield: application thread time evicting (usecs) */
-#define	WT_STAT_CONN_APPLICATION_EVICT_TIME		1213
+#define	WT_STAT_CONN_APPLICATION_EVICT_TIME		1215
 /*! thread-yield: application thread time waiting for cache (usecs) */
-#define	WT_STAT_CONN_APPLICATION_CACHE_TIME		1214
+#define	WT_STAT_CONN_APPLICATION_CACHE_TIME		1216
 /*! thread-yield: page acquire busy blocked */
-#define	WT_STAT_CONN_PAGE_BUSY_BLOCKED			1215
+#define	WT_STAT_CONN_PAGE_BUSY_BLOCKED			1217
 /*! thread-yield: page acquire eviction blocked */
-#define	WT_STAT_CONN_PAGE_FORCIBLE_EVICT_BLOCKED	1216
+#define	WT_STAT_CONN_PAGE_FORCIBLE_EVICT_BLOCKED	1218
 /*! thread-yield: page acquire locked blocked */
-#define	WT_STAT_CONN_PAGE_LOCKED_BLOCKED		1217
+#define	WT_STAT_CONN_PAGE_LOCKED_BLOCKED		1219
 /*! thread-yield: page acquire read blocked */
-#define	WT_STAT_CONN_PAGE_READ_BLOCKED			1218
+#define	WT_STAT_CONN_PAGE_READ_BLOCKED			1220
 /*! thread-yield: page acquire time sleeping (usecs) */
-#define	WT_STAT_CONN_PAGE_SLEEP				1219
+#define	WT_STAT_CONN_PAGE_SLEEP				1221
 /*! transaction: number of named snapshots created */
-#define	WT_STAT_CONN_TXN_SNAPSHOTS_CREATED		1220
+#define	WT_STAT_CONN_TXN_SNAPSHOTS_CREATED		1222
 /*! transaction: number of named snapshots dropped */
-#define	WT_STAT_CONN_TXN_SNAPSHOTS_DROPPED		1221
+#define	WT_STAT_CONN_TXN_SNAPSHOTS_DROPPED		1223
 /*! transaction: transaction begins */
-#define	WT_STAT_CONN_TXN_BEGIN				1222
+#define	WT_STAT_CONN_TXN_BEGIN				1224
 /*! transaction: transaction checkpoint currently running */
-#define	WT_STAT_CONN_TXN_CHECKPOINT_RUNNING		1223
+#define	WT_STAT_CONN_TXN_CHECKPOINT_RUNNING		1225
 /*! transaction: transaction checkpoint generation */
-#define	WT_STAT_CONN_TXN_CHECKPOINT_GENERATION		1224
+#define	WT_STAT_CONN_TXN_CHECKPOINT_GENERATION		1226
 /*! transaction: transaction checkpoint max time (msecs) */
-#define	WT_STAT_CONN_TXN_CHECKPOINT_TIME_MAX		1225
+#define	WT_STAT_CONN_TXN_CHECKPOINT_TIME_MAX		1227
 /*! transaction: transaction checkpoint min time (msecs) */
-#define	WT_STAT_CONN_TXN_CHECKPOINT_TIME_MIN		1226
+#define	WT_STAT_CONN_TXN_CHECKPOINT_TIME_MIN		1228
 /*! transaction: transaction checkpoint most recent time (msecs) */
-#define	WT_STAT_CONN_TXN_CHECKPOINT_TIME_RECENT		1227
+#define	WT_STAT_CONN_TXN_CHECKPOINT_TIME_RECENT		1229
 /*! transaction: transaction checkpoint scrub dirty target */
-#define	WT_STAT_CONN_TXN_CHECKPOINT_SCRUB_TARGET	1228
+#define	WT_STAT_CONN_TXN_CHECKPOINT_SCRUB_TARGET	1230
 /*! transaction: transaction checkpoint scrub time (msecs) */
-#define	WT_STAT_CONN_TXN_CHECKPOINT_SCRUB_TIME		1229
+#define	WT_STAT_CONN_TXN_CHECKPOINT_SCRUB_TIME		1231
 /*! transaction: transaction checkpoint total time (msecs) */
-#define	WT_STAT_CONN_TXN_CHECKPOINT_TIME_TOTAL		1230
+#define	WT_STAT_CONN_TXN_CHECKPOINT_TIME_TOTAL		1232
 /*! transaction: transaction checkpoints */
-#define	WT_STAT_CONN_TXN_CHECKPOINT			1231
+#define	WT_STAT_CONN_TXN_CHECKPOINT			1233
 /*!
  * transaction: transaction checkpoints skipped because database was
  * clean
  */
-#define	WT_STAT_CONN_TXN_CHECKPOINT_SKIPPED		1232
+#define	WT_STAT_CONN_TXN_CHECKPOINT_SKIPPED		1234
 /*! transaction: transaction failures due to cache overflow */
-#define	WT_STAT_CONN_TXN_FAIL_CACHE			1233
+#define	WT_STAT_CONN_TXN_FAIL_CACHE			1235
 /*!
  * transaction: transaction fsync calls for checkpoint after allocating
  * the transaction ID
  */
-#define	WT_STAT_CONN_TXN_CHECKPOINT_FSYNC_POST		1234
+#define	WT_STAT_CONN_TXN_CHECKPOINT_FSYNC_POST		1236
 /*!
  * transaction: transaction fsync duration for checkpoint after
  * allocating the transaction ID (usecs)
  */
-#define	WT_STAT_CONN_TXN_CHECKPOINT_FSYNC_POST_DURATION	1235
+#define	WT_STAT_CONN_TXN_CHECKPOINT_FSYNC_POST_DURATION	1237
 /*! transaction: transaction range of IDs currently pinned */
-#define	WT_STAT_CONN_TXN_PINNED_RANGE			1236
+#define	WT_STAT_CONN_TXN_PINNED_RANGE			1238
 /*! transaction: transaction range of IDs currently pinned by a checkpoint */
-#define	WT_STAT_CONN_TXN_PINNED_CHECKPOINT_RANGE	1237
+#define	WT_STAT_CONN_TXN_PINNED_CHECKPOINT_RANGE	1239
 /*!
  * transaction: transaction range of IDs currently pinned by named
  * snapshots
  */
-#define	WT_STAT_CONN_TXN_PINNED_SNAPSHOT_RANGE		1238
+#define	WT_STAT_CONN_TXN_PINNED_SNAPSHOT_RANGE		1240
 /*! transaction: transaction sync calls */
-#define	WT_STAT_CONN_TXN_SYNC				1239
+#define	WT_STAT_CONN_TXN_SYNC				1241
 /*! transaction: transactions committed */
-#define	WT_STAT_CONN_TXN_COMMIT				1240
+#define	WT_STAT_CONN_TXN_COMMIT				1242
 /*! transaction: transactions rolled back */
-#define	WT_STAT_CONN_TXN_ROLLBACK			1241
+#define	WT_STAT_CONN_TXN_ROLLBACK			1243
 
 /*!
  * @}
diff --git a/src/log/log_slot.c b/src/log/log_slot.c
index c685aec3ffc..512a84dbd13 100644
--- a/src/log/log_slot.c
+++ b/src/log/log_slot.c
@@ -195,103 +195,12 @@ retry:
 }
 
 /*
- * __log_slot_switch_internal --
- *	Switch out the current slot and set up a new one.
- */
-static int
-__log_slot_switch_internal(
-    WT_SESSION_IMPL *session, WT_MYSLOT *myslot, bool forced)
-{
-	WT_DECL_RET;
-	WT_LOG *log;
-	WT_LOGSLOT *slot;
-	bool free_slot, release;
-
-	log = S2C(session)->log;
-	release = false;
-	slot = myslot->slot;
-
-	WT_ASSERT(session, F_ISSET(session, WT_SESSION_LOCKED_SLOT));
-
-	/*
-	 * If someone else raced us to closing this specific slot, we're
-	 * done here.
-	 */
-	if (slot != log->active_slot)
-		return (0);
-
-	WT_RET(WT_SESSION_CHECK_PANIC(session));
-	/*
-	 * We may come through here multiple times if we were able to close
-	 * a slot but could not set up a new one.  If we closed it already,
-	 * don't try to do it again but still set up the new slot.
-	 */
-	if (!F_ISSET(myslot, WT_MYSLOT_CLOSE)) {
-		ret = __log_slot_close(session, slot, &release, forced);
-		/*
-		 * If close returns WT_NOTFOUND it means that someone else
-		 * is processing the slot change.
-		 */
-		if (ret == WT_NOTFOUND)
-			return (0);
-		WT_RET(ret);
-		if (release) {
-			WT_RET(__wt_log_release(session, slot, &free_slot));
-			if (free_slot)
-				__wt_log_slot_free(session, slot);
-		}
-	}
-	/*
-	 * Set that we have closed this slot because we may call in here
-	 * multiple times if we retry creating a new slot.
-	 */
-	F_SET(myslot, WT_MYSLOT_CLOSE);
-	WT_RET(__wt_log_slot_new(session));
-	F_CLR(myslot, WT_MYSLOT_CLOSE);
-	return (0);
-}
-
-/*
- * __wt_log_slot_switch --
- *	Switch out the current slot and set up a new one.
- */
-int
-__wt_log_slot_switch(
-    WT_SESSION_IMPL *session, WT_MYSLOT *myslot, bool retry, bool forced)
-{
-	WT_DECL_RET;
-	WT_LOG *log;
-
-	log = S2C(session)->log;
-	/*
-	 * !!! Since the WT_WITH_SLOT_LOCK macro is a do-while loop, the
-	 * compiler does not like it combined directly with the while loop
-	 * here.
-	 *
-	 * The loop conditional is a bit complex.  We have to retry if we
-	 * closed the slot but were unable to set up a new slot.  In that
-	 * case the flag indicating we have closed the slot will still be set.
-	 * We have to retry in that case regardless of the retry setting
-	 * because we are responsible for setting up the new slot.
-	 */
-	do {
-		WT_WITH_SLOT_LOCK(session, log,
-		    ret = __log_slot_switch_internal(session, myslot, forced));
-		if (ret == EBUSY) {
-			WT_STAT_CONN_INCR(session, log_slot_switch_busy);
-			__wt_yield();
-		}
-	} while (F_ISSET(myslot, WT_MYSLOT_CLOSE) || (retry && ret == EBUSY));
-	return (ret);
-}
-
-/*
- * __wt_log_slot_new --
+ * __log_slot_new --
  *	Find a free slot and switch it as the new active slot.
  *	Must be called holding the slot lock.
  */
-int
-__wt_log_slot_new(WT_SESSION_IMPL *session)
+static int
+__log_slot_new(WT_SESSION_IMPL *session)
 {
 	WT_CONNECTION_IMPL *conn;
 	WT_LOG *log;
@@ -351,6 +260,7 @@ __wt_log_slot_new(WT_SESSION_IMPL *session)
 		/*
 		 * If we didn't find any free slots signal the worker thread.
 		 */
+		WT_STAT_CONN_INCR(session, log_slot_no_free_slots);
 		__wt_cond_signal(session, conn->log_wrlsn_cond);
 		__wt_yield();
 #ifdef	HAVE_DIAGNOSTIC
@@ -371,6 +281,108 @@ __wt_log_slot_new(WT_SESSION_IMPL *session)
 }
 
 /*
+ * __log_slot_switch_internal --
+ *	Switch out the current slot and set up a new one.
+ */
+static int
+__log_slot_switch_internal(
+    WT_SESSION_IMPL *session, WT_MYSLOT *myslot, bool forced)
+{
+	WT_DECL_RET;
+	WT_LOG *log;
+	WT_LOGSLOT *slot;
+	bool free_slot, release;
+
+	log = S2C(session)->log;
+	release = false;
+	slot = myslot->slot;
+
+	WT_ASSERT(session, F_ISSET(session, WT_SESSION_LOCKED_SLOT));
+
+	/*
+	 * If someone else raced us to closing this specific slot, we're
+	 * done here.
+	 */
+	if (slot != log->active_slot)
+		return (0);
+	WT_RET(WT_SESSION_CHECK_PANIC(session));
+
+	/*
+	 * We may come through here multiple times if we were not able to
+	 * set up a new one.  If we closed it already,
+	 * don't try to do it again but still set up the new slot.
+	 */
+	if (!F_ISSET(myslot, WT_MYSLOT_CLOSE)) {
+		ret = __log_slot_close(session, slot, &release, forced);
+		/*
+		 * If close returns WT_NOTFOUND it means that someone else
+		 * is processing the slot change.
+		 */
+		if (ret == WT_NOTFOUND)
+			return (0);
+		WT_RET(ret);
+		/*
+		 * Set that we have closed this slot because we may call in here
+		 * multiple times if we retry creating a new slot.  Similarly
+		 * set retain whether this slot needs releasing so that we don't
+		 * lose that information if we retry.
+		 */
+		F_SET(myslot, WT_MYSLOT_CLOSE);
+		if (release)
+			F_SET(myslot, WT_MYSLOT_NEEDS_RELEASE);
+	}
+	/*
+	 * Now that the slot is closed, set up a new one so that joining
+	 * threads don't have to wait on writing the previous slot if we
+	 * release it.  Release after setting a new one.
+	 */
+	WT_RET(__log_slot_new(session));
+	F_CLR(myslot, WT_MYSLOT_CLOSE);
+	if (F_ISSET(myslot, WT_MYSLOT_NEEDS_RELEASE)) {
+		WT_RET(__wt_log_release(session, slot, &free_slot));
+		F_CLR(myslot, WT_MYSLOT_NEEDS_RELEASE);
+		if (free_slot)
+			__wt_log_slot_free(session, slot);
+	}
+	return (ret);
+}
+
+/*
+ * __wt_log_slot_switch --
+ *	Switch out the current slot and set up a new one.
+ */
+int
+__wt_log_slot_switch(
+    WT_SESSION_IMPL *session, WT_MYSLOT *myslot, bool retry, bool forced)
+{
+	WT_DECL_RET;
+	WT_LOG *log;
+
+	log = S2C(session)->log;
+
+	/*
+	 * !!! Since the WT_WITH_SLOT_LOCK macro is a do-while loop, the
+	 * compiler does not like it combined directly with the while loop
+	 * here.
+	 *
+	 * The loop conditional is a bit complex.  We have to retry if we
+	 * closed the slot but were unable to set up a new slot.  In that
+	 * case the flag indicating we have closed the slot will still be set.
+	 * We have to retry in that case regardless of the retry setting
+	 * because we are responsible for setting up the new slot.
+	 */
+	do {
+		WT_WITH_SLOT_LOCK(session, log,
+		    ret = __log_slot_switch_internal(session, myslot, forced));
+		if (ret == EBUSY) {
+			WT_STAT_CONN_INCR(session, log_slot_switch_busy);
+			__wt_yield();
+		}
+	} while (F_ISSET(myslot, WT_MYSLOT_CLOSE) || (retry && ret == EBUSY));
+	return (ret);
+}
+
+/*
  * __wt_log_slot_init --
  *	Initialize the slot array.
  */
@@ -531,12 +543,13 @@ __wt_log_slot_join(WT_SESSION_IMPL *session, uint64_t mysize,
 			if (__wt_atomic_casiv64(
 			    &slot->slot_state, old_state, new_state))
 				break;
-		}
+			WT_STAT_CONN_INCR(session, log_slot_races);
+		} else
+			WT_STAT_CONN_INCR(session, log_slot_active_closed);
 		/*
 		 * The slot is no longer open or we lost the race to
 		 * update it.  Yield and try again.
 		 */
-		WT_STAT_CONN_INCR(session, log_slot_races);
 		__wt_yield();
 	}
 	/*
diff --git a/src/support/stat.c b/src/support/stat.c
index 57c1ee06000..2c2217f8c20 100644
--- a/src/support/stat.c
+++ b/src/support/stat.c
@@ -772,9 +772,11 @@ static const char * const __stats_connection_desc[] = {
 	"lock: table lock internal thread time waiting for the table lock (usecs)",
 	"log: busy returns attempting to switch slots",
 	"log: consolidated slot closures",
+	"log: consolidated slot join active slot closed",
 	"log: consolidated slot join races",
 	"log: consolidated slot join transitions",
 	"log: consolidated slot joins",
+	"log: consolidated slot transitions unable to find free slot",
 	"log: consolidated slot unbuffered writes",
 	"log: log bytes of payload data",
 	"log: log bytes written",
@@ -1056,9 +1058,11 @@ __wt_stat_connection_clear_single(WT_CONNECTION_STATS *stats)
 	stats->lock_table_wait_internal = 0;
 	stats->log_slot_switch_busy = 0;
 	stats->log_slot_closes = 0;
+	stats->log_slot_active_closed = 0;
 	stats->log_slot_races = 0;
 	stats->log_slot_transitions = 0;
 	stats->log_slot_joins = 0;
+	stats->log_slot_no_free_slots = 0;
 	stats->log_slot_unbuffered = 0;
 	stats->log_bytes_payload = 0;
 	stats->log_bytes_written = 0;
@@ -1370,9 +1374,13 @@ __wt_stat_connection_aggregate(
 	    WT_STAT_READ(from, lock_table_wait_internal);
 	to->log_slot_switch_busy += WT_STAT_READ(from, log_slot_switch_busy);
 	to->log_slot_closes += WT_STAT_READ(from, log_slot_closes);
+	to->log_slot_active_closed +=
+	    WT_STAT_READ(from, log_slot_active_closed);
 	to->log_slot_races += WT_STAT_READ(from, log_slot_races);
 	to->log_slot_transitions += WT_STAT_READ(from, log_slot_transitions);
 	to->log_slot_joins += WT_STAT_READ(from, log_slot_joins);
+	to->log_slot_no_free_slots +=
+	    WT_STAT_READ(from, log_slot_no_free_slots);
 	to->log_slot_unbuffered += WT_STAT_READ(from, log_slot_unbuffered);
 	to->log_bytes_payload += WT_STAT_READ(from, log_bytes_payload);
 	to->log_bytes_written += WT_STAT_READ(from, log_bytes_written);