WT-4733 change format to do longer-term repeatable read testing

SConstruct

@@ -508,6 +508,7 @@ t = env.Program("t_format",
     "test/format/ops.c",
     "test/format/rebalance.c",
     "test/format/salvage.c",
+    "test/format/snap.c",
     "test/format/t.c",
     "test/format/util.c",
     "test/format/wts.c"],

dist/s_define.list

@@ -46,6 +46,7 @@ WT_PACKED_STRUCT_END
 WT_PADDING_CHECK
 WT_PREPARE_INIT
 WT_READ_BARRIER
+WT_REF_SAVE_STATE_MAX
 WT_REF_SIZE
 WT_SESSION_LOCKED_CHECKPOINT
 WT_SESSION_LOCKED_HOTBACKUP

dist/s_string.ok

@@ -229,8 +229,6 @@ LZO
 LeafGreen
 LevelDB
 Levyx
-Llqr
-Llqrt
 LmT
 LoadLoad
 LockFile
@@ -948,6 +946,8 @@ lookaside
 lookup
 lookups
 lossy
+lqr
+lqrt
 lr
 lrt
 lru

src/docs/checkpoint.dox

@@ -55,11 +55,13 @@ archiving purposes.
 @section checkpoint_cursors Checkpoint cursors
 
 Cursors are normally opened in the most recent version of a data source.
-However, a checkpoint configuration string may be provided to
-WT_SESSION::open_cursor, opening a read-only, static view of the data
-source.  This provides a limited form of time-travel, as the static view
-is not changed by subsequent checkpoints, and will persist until the
-checkpoint cursor is closed.
+However, a checkpoint configuration string may be provided
+to WT_SESSION::open_cursor, opening a read-only, static view of the
+data source.  This provides a limited form of time-travel, as the static
+view is not changed by subsequent checkpoints and will persist until
+the checkpoint cursor is closed. While it is not an error to set a read
+timestamp in a transaction including a checkpoint cursor, it also has no
+effect on the checkpoint cursor's behavior.
 
 @section checkpoint_naming Checkpoint naming
 

src/include/btmem.h

@@ -901,22 +901,23 @@ struct __wt_ref {
 #define	WT_REF_CAS_STATE(session, ref, old_state, new_state)          \
 	__wt_ref_cas_state_int((session), (ref), (old_state), (new_state),\
 	__FILE__, __LINE__)
+#define	WT_REF_SAVE_STATE_MAX	3
 #ifdef HAVE_DIAGNOSTIC
 	/* Capture history of ref state changes. */
 	struct __wt_ref_hist {
 		WT_SESSION_IMPL *session;
 		const char *name;
 		const char *file;
-		int line;
-		uint32_t state;
-	} hist[3];
+		uint16_t line;
+		uint16_t state;
+	} hist[WT_REF_SAVE_STATE_MAX];
 	uint64_t histoff;
 #define	WT_REF_SAVE_STATE(ref, s, f, l) do {				\
 	(ref)->hist[(ref)->histoff].session = session;			\
 	(ref)->hist[(ref)->histoff].name = session->name;		\
 	(ref)->hist[(ref)->histoff].file = (f);				\
-	(ref)->hist[(ref)->histoff].line = (l);				\
-	(ref)->hist[(ref)->histoff].state = s;				\
+	(ref)->hist[(ref)->histoff].line = (uint16_t)(l);		\
+	(ref)->hist[(ref)->histoff].state = (uint16_t)(s);		\
 	(ref)->histoff =						\
 	    ((ref)->histoff + 1) % WT_ELEMENTS((ref)->hist);		\
 } while (0)
@@ -933,7 +934,7 @@ struct __wt_ref {
  * the compiler hasn't inserted padding which would break the world.
  */
 #ifdef HAVE_DIAGNOSTIC
-#define	WT_REF_SIZE	(56 + 3 * sizeof(WT_REF_HIST) + 8)
+#define	WT_REF_SIZE	(56 + WT_REF_SAVE_STATE_MAX * sizeof(WT_REF_HIST) + 8)
 #else
 #define	WT_REF_SIZE	56
 #endif

src/reconcile/rec_visibility.c

@@ -424,9 +424,9 @@ __wt_rec_upd_select(WT_SESSION_IMPL *session, WT_RECONCILE *r, WT_INSERT *ins,
 			r->unstable_txn = first_upd->txnid;
 		if (first_ts_upd != NULL) {
 			WT_ASSERT(session,
-			   first_ts_upd->prepare_state ==
-			   WT_PREPARE_INPROGRESS ||
-			   first_ts_upd->start_ts <= first_ts_upd->durable_ts);
+			    first_ts_upd->prepare_state ==
+			    WT_PREPARE_INPROGRESS ||
+			    first_ts_upd->start_ts <= first_ts_upd->durable_ts);
 
 			if (r->unstable_timestamp < first_ts_upd->start_ts)
 				r->unstable_timestamp = first_ts_upd->start_ts;
@@ -452,8 +452,8 @@ __wt_rec_upd_select(WT_SESSION_IMPL *session, WT_RECONCILE *r, WT_INSERT *ins,
 			 * both will be set.
 			 */
 			WT_ASSERT(session,
-			   upd->prepare_state == WT_PREPARE_INPROGRESS ||
-			   upd->durable_ts >= upd->start_ts);
+			    upd->prepare_state == WT_PREPARE_INPROGRESS ||
+			    upd->durable_ts >= upd->start_ts);
 
 			if (r->unstable_timestamp > upd->start_ts)
 				r->unstable_timestamp = upd->start_ts;

src/txn/txn.c

@@ -843,7 +843,7 @@ __wt_txn_commit(WT_SESSION_IMPL *session, const char *cfg[])
 			    "transaction");
 
 		WT_ASSERT(session,
-		   txn->prepare_timestamp <= txn->commit_timestamp);
+		    txn->prepare_timestamp <= txn->commit_timestamp);
 	} else {
 		if (F_ISSET(txn, WT_TXN_HAS_TS_PREPARE))
 			WT_ERR_MSG(session, EINVAL,

test/format/Makefile.am

@@ -11,7 +11,7 @@ noinst_PROGRAMS = t
 noinst_SCRIPTS = s_dumpcmp
 t_SOURCES =\
 	backup.c bulk.c compact.c config.c lrt.c ops.c rebalance.c \
-	salvage.c t.c util.c wts.c
+	salvage.c snap.c t.c util.c wts.c
 
 if HAVE_BERKELEY_DB
 t_SOURCES += bdb.c

test/format/bulk.c

@@ -28,6 +28,49 @@
 
 #include "format.h"
 
+/*
+ * bulk_begin_transaction --
+ *	Begin a bulk-load transaction.
+ */
+static void
+bulk_begin_transaction(WT_SESSION *session)
+{
+	uint64_t ts;
+	char buf[64];
+
+	wiredtiger_begin_transaction(session, "isolation=snapshot");
+	ts = __wt_atomic_addv64(&g.timestamp, 1);
+	testutil_check(__wt_snprintf(
+	    buf, sizeof(buf), "read_timestamp=%" PRIx64, ts));
+	testutil_check(session->timestamp_transaction(session, buf));
+}
+
+/*
+ * bulk_commit_transaction --
+ *	Commit a bulk-load transaction.
+ */
+static void
+bulk_commit_transaction(WT_SESSION *session)
+{
+	uint64_t ts;
+	char buf[64];
+
+	ts = __wt_atomic_addv64(&g.timestamp, 1);
+	testutil_check(__wt_snprintf(
+	    buf, sizeof(buf), "commit_timestamp=%" PRIx64, ts));
+	testutil_check(session->commit_transaction(session, buf));
+}
+
+/*
+ * bulk_rollback_transaction --
+ *	Rollback a bulk-load transaction.
+ */
+static void
+bulk_rollback_transaction(WT_SESSION *session)
+{
+	testutil_check(session->rollback_transaction(session, NULL));
+}
+
 void
 wts_load(void)
 {
@@ -42,9 +85,7 @@ wts_load(void)
 
 	testutil_check(conn->open_session(conn, NULL, NULL, &session));
 
-	if (g.logging != 0)
-		(void)g.wt_api->msg_printf(g.wt_api, session,
-		    "=============== bulk load start ===============");
+	logop(session, "%s", "=============== bulk load start");
 
 	/*
 	 * No bulk load with data-sources.
@@ -71,16 +112,25 @@ wts_load(void)
 	key_gen_init(&key);
 	val_gen_init(&value);
 
+	if (g.c_txn_timestamps)
+		bulk_begin_transaction(session);
+
 	for (;;) {
 		if (++g.key_cnt > g.c_rows) {
 			g.key_cnt = g.rows = g.c_rows;
 			break;
 		}
 
 		/* Report on progress every 100 inserts. */
-		if (g.key_cnt % 1000 == 0)
+		if (g.key_cnt % 10000 == 0) {
 			track("bulk load", g.key_cnt, NULL);
 
+			if (g.c_txn_timestamps) {
+				bulk_commit_transaction(session);
+				bulk_begin_transaction(session);
+			}
+		}
+
 		key_gen(&key, g.key_cnt);
 		val_gen(NULL, &value, g.key_cnt);
 
@@ -89,34 +139,24 @@ wts_load(void)
 			if (!is_bulk)
 				cursor->set_key(cursor, g.key_cnt);
 			cursor->set_value(cursor, *(uint8_t *)value.data);
-			if (g.logging == LOG_OPS)
-				(void)g.wt_api->msg_printf(g.wt_api, session,
-				    "%-10s %" PRIu64 " {0x%02" PRIx8 "}",
-				    "bulk V",
-				    g.key_cnt, ((uint8_t *)value.data)[0]);
+			logop(session, "%-10s %" PRIu64 " {0x%02" PRIx8 "}",
+			    "bulk", g.key_cnt, ((uint8_t *)value.data)[0]);
 			break;
 		case VAR:
 			if (!is_bulk)
 				cursor->set_key(cursor, g.key_cnt);
 			cursor->set_value(cursor, &value);
-			if (g.logging == LOG_OPS)
-				(void)g.wt_api->msg_printf(g.wt_api, session,
-				    "%-10s %" PRIu64 " {%.*s}", "bulk V",
-				    g.key_cnt,
-				    (int)value.size, (char *)value.data);
+			logop(session, "%-10s %" PRIu64 " {%.*s}", "bulk",
+			    g.key_cnt, (int)value.size, (char *)value.data);
 			break;
 		case ROW:
 			cursor->set_key(cursor, &key);
-			if (g.logging == LOG_OPS)
-				(void)g.wt_api->msg_printf(g.wt_api, session,
-				    "%-10s %" PRIu64 " {%.*s}", "bulk K",
-				    g.key_cnt, (int)key.size, (char *)key.data);
 			cursor->set_value(cursor, &value);
-			if (g.logging == LOG_OPS)
-				(void)g.wt_api->msg_printf(g.wt_api, session,
-				    "%-10s %" PRIu64 " {%.*s}", "bulk V",
-				    g.key_cnt,
-				    (int)value.size, (char *)value.data);
+			logop(session,
+			    "%-10s %" PRIu64 " {%.*s}, {%.*s}", "bulk",
+			    g.key_cnt,
+			    (int)key.size, (char *)key.data,
+			    (int)value.size, (char *)value.data);
 			break;
 		}
 
@@ -132,8 +172,14 @@ wts_load(void)
 		 * extra space once the run starts.
 		 */
 		if ((ret = cursor->insert(cursor)) != 0) {
-			if (ret != WT_CACHE_FULL)
-				testutil_die(ret, "cursor.insert");
+			testutil_assert(
+			    ret == WT_CACHE_FULL || ret == WT_ROLLBACK);
+
+			if (g.c_txn_timestamps) {
+				bulk_rollback_transaction(session);
+				bulk_begin_transaction(session);
+			}
+
 			g.rows = --g.key_cnt;
 			g.c_rows = (uint32_t)g.key_cnt;
 
@@ -150,11 +196,12 @@ wts_load(void)
 #endif
 	}
 
+	if (g.c_txn_timestamps)
+		bulk_commit_transaction(session);
+
 	testutil_check(cursor->close(cursor));
 
-	if (g.logging != 0)
-		(void)g.wt_api->msg_printf(g.wt_api, session,
-		    "=============== bulk load stop ===============");
+	logop(session, "%s", "=============== bulk load stop");
 
 	testutil_check(session->close(session, NULL));