Import wiredtiger: b33708d7d9b2971cda05e71fcba6067b230b97cc from branch mongodb-3.8

ref: 60a06941b8..b33708d7d9
for: 3.7.4

WT-3913       Enhance cursor operations to account for prepare state
WT-3950       Add some rollback_to_stable statistics
WT-3958       Add query API to get most recent checkpoint's stable timestamp
WT-3969       enhance format tester to account for prepare state
WT-3972       Allow more than 64K cursors to be open on a data source simultaneously
WT-3975       arg format mismatch after rwlock changes

1 files changed, 145 insertions, 266 deletions

diff --git a/src/third_party/wiredtiger/test/format/ops.c b/src/third_party/wiredtiger/test/format/ops.c
index 4c54972516e..2466fe4d64d 100644
--- a/src/third_party/wiredtiger/test/format/ops.c
+++ b/src/third_party/wiredtiger/test/format/ops.c
@@ -403,10 +403,8 @@ snap_check(WT_CURSOR *cursor,
 			break;
 		case WT_NOTFOUND:
 			break;
-		case WT_ROLLBACK:
-			return (WT_ROLLBACK);
 		default:
-			testutil_die(ret, "WT_CURSOR.search");
+			return (ret);
 		}
 
 		/* Check for simple matches. */
@@ -644,6 +642,19 @@ prepare_transaction(TINFO *tinfo, WT_SESSION *session)
 }
 
 /*
+ * OP_FAILED --
+ *	General error handling.
+ */
+#define	OP_FAILED(notfound_ok) do {					\
+	positioned = false;						\
+	if (intxn && (ret == WT_CACHE_FULL || ret == WT_ROLLBACK))	\
+		goto deadlock;						\
+	testutil_assert((notfound_ok && ret == WT_NOTFOUND) ||		\
+	    ret == WT_CACHE_FULL ||					\
+	    ret == WT_PREPARE_CONFLICT || ret == WT_ROLLBACK);		\
+} while (0)
+
+/*
  * ops --
  *     Per-thread operations.
  */
@@ -825,11 +836,8 @@ ops(void *arg)
 			if (ret == 0) {
 				positioned = true;
 				SNAP_TRACK(READ, tinfo);
-			} else {
-				if (ret == WT_ROLLBACK && intxn)
-					goto deadlock;
-				testutil_assert(ret == WT_NOTFOUND);
-			}
+			} else
+				OP_FAILED(true);
 		}
 
 		/* Optionally reserve a row. */
@@ -847,12 +855,8 @@ ops(void *arg)
 				positioned = true;
 
 				__wt_yield();	/* Let other threads proceed. */
-			} else {
-				positioned = false;
-				if (ret == WT_ROLLBACK && intxn)
-					goto deadlock;
-				testutil_assert(ret == WT_NOTFOUND);
-			}
+			} else
+				OP_FAILED(true);
 		}
 
 		/* Perform the operation. */
@@ -881,11 +885,8 @@ ops(void *arg)
 			if (ret == 0) {
 				++tinfo->insert;
 				SNAP_TRACK(INSERT, tinfo);
-			} else {
-				if (ret == WT_ROLLBACK && intxn)
-					goto deadlock;
-				testutil_assert(ret == WT_ROLLBACK);
-			}
+			} else
+				OP_FAILED(false);
 			break;
 		case MODIFY:
 			/*
@@ -907,13 +908,8 @@ ops(void *arg)
 			if (ret == 0) {
 				positioned = true;
 				SNAP_TRACK(MODIFY, tinfo);
-			} else {
-				positioned = false;
-				if (ret == WT_ROLLBACK && intxn)
-					goto deadlock;
-				testutil_assert(
-				    ret == WT_NOTFOUND || ret == WT_ROLLBACK);
-			}
+			} else
+				OP_FAILED(true);
 			break;
 		case READ:
 			++tinfo->search;
@@ -921,12 +917,8 @@ ops(void *arg)
 			if (ret == 0) {
 				positioned = true;
 				SNAP_TRACK(READ, tinfo);
-			} else {
-				positioned = false;
-				if (ret == WT_ROLLBACK && intxn)
-					goto deadlock;
-				testutil_assert(ret == WT_NOTFOUND);
-			}
+			} else
+				OP_FAILED(true);
 			break;
 		case REMOVE:
 remove_instead_of_truncate:
@@ -946,12 +938,8 @@ remove_instead_of_truncate:
 				 * previous state, but not necessarily set.
 				 */
 				SNAP_TRACK(REMOVE, tinfo);
-			} else {
-				positioned = false;
-				if (ret == WT_ROLLBACK && intxn)
-					goto deadlock;
-				testutil_assert(ret == WT_NOTFOUND);
-			}
+			} else
+				OP_FAILED(true);
 			break;
 		case TRUNCATE:
 			/*
@@ -1020,11 +1008,8 @@ remove_instead_of_truncate:
 			if (ret == 0) {
 				++tinfo->truncate;
 				SNAP_TRACK(TRUNCATE, tinfo);
-			} else {
-				testutil_assert(ret == WT_ROLLBACK);
-				if (intxn)
-					goto deadlock;
-			}
+			} else
+				OP_FAILED(false);
 			break;
 		case UPDATE:
 update_instead_of_chosen_op:
@@ -1041,12 +1026,8 @@ update_instead_of_chosen_op:
 			if (ret == 0) {
 				positioned = true;
 				SNAP_TRACK(UPDATE, tinfo);
-			} else {
-				positioned = false;
-				if (ret == WT_ROLLBACK && intxn)
-					goto deadlock;
-				testutil_assert(ret == WT_ROLLBACK);
-			}
+			} else
+				OP_FAILED(false);
 			break;
 		}
 
@@ -1061,9 +1042,8 @@ update_instead_of_chosen_op:
 			for (i = 0; i < j; ++i) {
 				if ((ret = nextprev(tinfo, cursor, next)) == 0)
 					continue;
-				if (ret == WT_ROLLBACK && intxn)
-					goto deadlock;
-				testutil_assert(ret == WT_NOTFOUND);
+
+				OP_FAILED(true);
 				break;
 			}
 		}
@@ -1090,9 +1070,11 @@ update_instead_of_chosen_op:
 				goto deadlock;
 		}
 
-		/* Prepare the transaction 10% of the time. */
-		/* XXX: CONFIGURE PREPARE OFF FOR NOW */
-		if (mmrand(&tinfo->rnd, 1, 10) == 0) {
+		/*
+		 * Prepare the transaction 10% of the time.
+		 * Currently doesn't work with truncation, see WT-3922.
+		 */
+		if (g.c_truncate == 0 && mmrand(&tinfo->rnd, 1, 10) == 1) {
 			ret = prepare_transaction(tinfo, session);
 			testutil_assert(ret == 0 || ret == WT_PREPARE_CONFLICT);
 			if (ret == WT_PREPARE_CONFLICT)
@@ -1138,7 +1120,7 @@ deadlock:			++tinfo->deadlock;
 
 /*
  * wts_read_scan --
- *	Read and verify all elements in a file.
+ *	Read and verify a subset of the elements in a file.
  */
 void
 wts_read_scan(void)
@@ -1182,6 +1164,7 @@ wts_read_scan(void)
 		case 0:
 		case WT_NOTFOUND:
 		case WT_ROLLBACK:
+		case WT_PREPARE_CONFLICT:
 			break;
 		default:
 			testutil_die(
@@ -1209,11 +1192,6 @@ read_row_worker(
 
 	session = cursor->session;
 
-	/* Log the operation */
-	if (g.logging == LOG_OPS)
-		(void)g.wt_api->msg_printf(g.wt_api,
-		    session, "%-10s%" PRIu64, "read", keyno);
-
 	/* Retrieve the key/value pair by key. */
 	switch (g.type) {
 	case FIX:
@@ -1254,12 +1232,15 @@ read_row_worker(
 			value->size = 1;
 		}
 		break;
-	case WT_ROLLBACK:
-		return (WT_ROLLBACK);
 	default:
-		testutil_die(ret, "read_row: read row %" PRIu64, keyno);
+		return (ret);
 	}
 
+	/* Log the operation */
+	if (g.logging == LOG_OPS)
+		(void)g.wt_api->msg_printf(g.wt_api,
+		    session, "%-10s%" PRIu64, "read", keyno);
+
 #ifdef HAVE_BERKELEY_DB
 	if (!SINGLETHREADED)
 		return (ret);
@@ -1394,24 +1375,39 @@ nextprev(TINFO *tinfo, WT_CURSOR *cursor, bool next)
 		break;
 	case WT_NOTFOUND:
 		break;
-	case WT_ROLLBACK:
-		return (WT_ROLLBACK);
 	default:
-		testutil_die(ret, "%s", which);
+		return (ret);
 	}
 
+	if (g.logging == LOG_OPS)
+		switch (g.type) {
+		case FIX:
+			(void)g.wt_api->msg_printf(g.wt_api,
+			    cursor->session, "%-10s%" PRIu64 " {0x%02x}",
+			    which, keyno, ((char *)value.data)[0]);
+			break;
+		case ROW:
+			(void)g.wt_api->msg_printf(g.wt_api,
+			    cursor->session, "%-10s{%.*s}, {%.*s}",
+			    which, (int)key.size, (char *)key.data,
+			    (int)value.size, (char *)value.data);
+			break;
+		case VAR:
+			(void)g.wt_api->msg_printf(g.wt_api,
+			    cursor->session, "%-10s%" PRIu64 " {%.*s}",
+			    which, keyno, (int)value.size, (char *)value.data);
+			break;
+		}
+
 #ifdef HAVE_BERKELEY_DB
 	if (!SINGLETHREADED)
 		return (ret);
 
 	{
 	WT_ITEM bdb_key, bdb_value;
-	WT_SESSION *session;
 	int notfound;
 	char *p;
 
-	session = cursor->session;
-
 	/* Retrieve the BDB key/value. */
 	bdb_np(next, &bdb_key.data, &bdb_key.size,
 	    &bdb_value.data, &bdb_value.size, &notfound);
@@ -1444,26 +1440,6 @@ mismatch:	if (g.type == ROW) {
 		print_item(" wt-value", &value);
 		testutil_die(0, NULL);
 	}
-
-	if (g.logging == LOG_OPS)
-		switch (g.type) {
-		case FIX:
-			(void)g.wt_api->msg_printf(g.wt_api,
-			    session, "%-10s%" PRIu64 " {0x%02x}", which,
-			    keyno, ((char *)value.data)[0]);
-			break;
-		case ROW:
-			(void)g.wt_api->msg_printf(
-			    g.wt_api, session, "%-10s{%.*s}, {%.*s}", which,
-			    (int)key.size, (char *)key.data,
-			    (int)value.size, (char *)value.data);
-			break;
-		case VAR:
-			(void)g.wt_api->msg_printf(g.wt_api, session,
-			    "%-10s%" PRIu64 " {%.*s}", which,
-			    keyno, (int)value.size, (char *)value.data);
-			break;
-		}
 	}
 #endif
 	return (ret);
@@ -1483,24 +1459,14 @@ row_reserve(TINFO *tinfo, WT_CURSOR *cursor, bool positioned)
 		cursor->set_key(cursor, tinfo->key);
 	}
 
+	if ((ret = cursor->reserve(cursor)) != 0)
+		return (ret);
+
 	if (g.logging == LOG_OPS)
 		(void)g.wt_api->msg_printf(g.wt_api, cursor->session,
 		    "%-10s{%.*s}", "reserve",
 		    (int)tinfo->key->size, tinfo->key->data);
 
-	switch (ret = cursor->reserve(cursor)) {
-	case 0:
-		break;
-	case WT_CACHE_FULL:
-	case WT_ROLLBACK:
-		return (WT_ROLLBACK);
-	case WT_NOTFOUND:
-		return (WT_NOTFOUND);
-	default:
-		testutil_die(ret,
-		    "row_reserve: reserve row %" PRIu64 " by key",
-		    tinfo->keyno);
-	}
 	return (0);
 }
 
@@ -1516,21 +1482,13 @@ col_reserve(TINFO *tinfo, WT_CURSOR *cursor, bool positioned)
 	if (!positioned)
 		cursor->set_key(cursor, tinfo->keyno);
 
+	if ((ret = cursor->reserve(cursor)) != 0)
+		return (ret);
+
 	if (g.logging == LOG_OPS)
 		(void)g.wt_api->msg_printf(g.wt_api, cursor->session,
 		    "%-10s%" PRIu64, "reserve", tinfo->keyno);
 
-	switch (ret = cursor->reserve(cursor)) {
-	case 0:
-		break;
-	case WT_CACHE_FULL:
-	case WT_ROLLBACK:
-		return (WT_ROLLBACK);
-	case WT_NOTFOUND:
-		return (WT_NOTFOUND);
-	default:
-		testutil_die(ret, "col_reserve: %" PRIu64, tinfo->keyno);
-	}
 	return (0);
 }
 
@@ -1577,19 +1535,10 @@ row_modify(TINFO *tinfo, WT_CURSOR *cursor, bool positioned)
 	}
 
 	modify_build(tinfo, entries, &nentries);
-	switch (ret = cursor->modify(cursor, entries, nentries)) {
-	case 0:
-		testutil_check(cursor->get_value(cursor, tinfo->value));
-		break;
-	case WT_CACHE_FULL:
-	case WT_ROLLBACK:
-		return (WT_ROLLBACK);
-	case WT_NOTFOUND:
-		return (WT_NOTFOUND);
-	default:
-		testutil_die(ret,
-		    "row_modify: modify row %" PRIu64 " by key", tinfo->keyno);
-	}
+	if ((ret = cursor->modify(cursor, entries, nentries)) != 0)
+		return (ret);
+
+	testutil_check(cursor->get_value(cursor, tinfo->value));
 
 	if (g.logging == LOG_OPS)
 		(void)g.wt_api->msg_printf(g.wt_api, cursor->session,
@@ -1624,25 +1573,16 @@ col_modify(TINFO *tinfo, WT_CURSOR *cursor, bool positioned)
 		cursor->set_key(cursor, tinfo->keyno);
 
 	modify_build(tinfo, entries, &nentries);
-	switch (ret = cursor->modify(cursor, entries, nentries)) {
-	case 0:
-		testutil_check(cursor->get_value(cursor, tinfo->value));
-		break;
-	case WT_CACHE_FULL:
-	case WT_ROLLBACK:
-		return (WT_ROLLBACK);
-	case WT_NOTFOUND:
-		return (WT_NOTFOUND);
-	default:
-		testutil_die(ret,
-		    "col_modify: modify row %" PRIu64, tinfo->keyno);
-	}
+	if ((ret = cursor->modify(cursor, entries, nentries)) != 0)
+		return (ret);
+
+	testutil_check(cursor->get_value(cursor, tinfo->value));
 
 	if (g.logging == LOG_OPS)
 		(void)g.wt_api->msg_printf(g.wt_api, cursor->session,
-		    "%-10s{%.*s}, {%.*s}",
+		    "%-10s%" PRIu64 ", {%.*s}",
 		    "modify",
-		    (int)tinfo->key->size, tinfo->key->data,
+		    tinfo->keyno,
 		    (int)tinfo->value->size, tinfo->value->data);
 
 #ifdef HAVE_BERKELEY_DB
@@ -1698,24 +1638,15 @@ row_truncate(TINFO *tinfo, WT_CURSOR *cursor)
 		testutil_check(c2->close(c2));
 	}
 
+	if (ret != 0)
+		return (ret);
+
 	if (g.logging == LOG_OPS)
 		(void)g.wt_api->msg_printf(g.wt_api, session,
 		    "%-10s%" PRIu64 ", %" PRIu64,
 		    "truncate",
 		    tinfo->keyno, tinfo->last);
 
-	switch (ret) {
-	case 0:
-		break;
-	case WT_CACHE_FULL:
-	case WT_ROLLBACK:
-		return (WT_ROLLBACK);
-	default:
-		testutil_die(ret,
-		    "row_truncate: row %" PRIu64 "-%" PRIu64,
-		    tinfo->keyno, tinfo->last);
-	}
-
 #ifdef HAVE_BERKELEY_DB
 	if (SINGLETHREADED)
 		bdb_truncate(tinfo->keyno, tinfo->last);
@@ -1724,49 +1655,6 @@ row_truncate(TINFO *tinfo, WT_CURSOR *cursor)
 }
 
 /*
- * row_update --
- *	Update a row in a row-store file.
- */
-static int
-row_update(TINFO *tinfo, WT_CURSOR *cursor, bool positioned)
-{
-	WT_DECL_RET;
-
-	if (!positioned) {
-		key_gen(tinfo->key, tinfo->keyno);
-		cursor->set_key(cursor, tinfo->key);
-	}
-	val_gen(&tinfo->rnd, tinfo->value, tinfo->keyno);
-	cursor->set_value(cursor, tinfo->value);
-
-	if (g.logging == LOG_OPS)
-		(void)g.wt_api->msg_printf(g.wt_api, cursor->session,
-		    "%-10s{%.*s}, {%.*s}",
-		    "put",
-		    (int)tinfo->key->size, tinfo->key->data,
-		    (int)tinfo->value->size, tinfo->value->data);
-
-	switch (ret = cursor->update(cursor)) {
-	case 0:
-		break;
-	case WT_CACHE_FULL:
-	case WT_ROLLBACK:
-		return (WT_ROLLBACK);
-	default:
-		testutil_die(ret,
-		    "row_update: update row %" PRIu64 " by key", tinfo->keyno);
-	}
-
-#ifdef HAVE_BERKELEY_DB
-	if (SINGLETHREADED)
-		bdb_update(
-		    tinfo->key->data, tinfo->key->size,
-		    tinfo->value->data, tinfo->value->size);
-#endif
-	return (0);
-}
-
-/*
  * col_truncate --
  *	Truncate rows in a column-store file.
  */
@@ -1802,6 +1690,8 @@ col_truncate(TINFO *tinfo, WT_CURSOR *cursor)
 		ret = session->truncate(session, NULL, cursor, c2, NULL);
 		testutil_check(c2->close(c2));
 	}
+	if (ret != 0)
+		return (ret);
 
 	if (g.logging == LOG_OPS)
 		(void)g.wt_api->msg_printf(g.wt_api, session,
@@ -1809,21 +1699,44 @@ col_truncate(TINFO *tinfo, WT_CURSOR *cursor)
 		    "truncate",
 		    tinfo->keyno, tinfo->last);
 
-	switch (ret) {
-	case 0:
-		break;
-	case WT_CACHE_FULL:
-	case WT_ROLLBACK:
-		return (WT_ROLLBACK);
-	default:
-		testutil_die(ret,
-		    "col_truncate: row %" PRIu64 "-%" PRIu64,
-		    tinfo->keyno, tinfo->last);
+#ifdef HAVE_BERKELEY_DB
+	if (SINGLETHREADED)
+		bdb_truncate(tinfo->keyno, tinfo->last);
+#endif
+	return (0);
+}
+
+/*
+ * row_update --
+ *	Update a row in a row-store file.
+ */
+static int
+row_update(TINFO *tinfo, WT_CURSOR *cursor, bool positioned)
+{
+	WT_DECL_RET;
+
+	if (!positioned) {
+		key_gen(tinfo->key, tinfo->keyno);
+		cursor->set_key(cursor, tinfo->key);
 	}
+	val_gen(&tinfo->rnd, tinfo->value, tinfo->keyno);
+	cursor->set_value(cursor, tinfo->value);
+
+	if ((ret = cursor->update(cursor)) != 0)
+		return (ret);
+
+	if (g.logging == LOG_OPS)
+		(void)g.wt_api->msg_printf(g.wt_api, cursor->session,
+		    "%-10s{%.*s}, {%.*s}",
+		    "put",
+		    (int)tinfo->key->size, tinfo->key->data,
+		    (int)tinfo->value->size, tinfo->value->data);
 
 #ifdef HAVE_BERKELEY_DB
 	if (SINGLETHREADED)
-		bdb_truncate(tinfo->keyno, tinfo->last);
+		bdb_update(
+		    tinfo->key->data, tinfo->key->size,
+		    tinfo->value->data, tinfo->value->size);
 #endif
 	return (0);
 }
@@ -1845,6 +1758,9 @@ col_update(TINFO *tinfo, WT_CURSOR *cursor, bool positioned)
 	else
 		cursor->set_value(cursor, tinfo->value);
 
+	if ((ret = cursor->update(cursor)) != 0)
+		return (ret);
+
 	if (g.logging == LOG_OPS) {
 		if (g.type == FIX)
 			(void)g.wt_api->msg_printf(g.wt_api, cursor->session,
@@ -1859,16 +1775,6 @@ col_update(TINFO *tinfo, WT_CURSOR *cursor, bool positioned)
 			    (char *)tinfo->value->data);
 	}
 
-	switch (ret = cursor->update(cursor)) {
-	case 0:
-		break;
-	case WT_CACHE_FULL:
-	case WT_ROLLBACK:
-		return (WT_ROLLBACK);
-	default:
-		testutil_die(ret, "col_update: %" PRIu64, tinfo->keyno);
-	}
-
 #ifdef HAVE_BERKELEY_DB
 	if (SINGLETHREADED) {
 		key_gen(tinfo->key, tinfo->keyno);
@@ -1999,6 +1905,9 @@ row_insert(TINFO *tinfo, WT_CURSOR *cursor, bool positioned)
 	val_gen(&tinfo->rnd, tinfo->value, tinfo->keyno);
 	cursor->set_value(cursor, tinfo->value);
 
+	if ((ret = cursor->insert(cursor)) != 0)
+		return (ret);
+
 	/* Log the operation */
 	if (g.logging == LOG_OPS)
 		(void)g.wt_api->msg_printf(g.wt_api, cursor->session,
@@ -2007,17 +1916,6 @@ row_insert(TINFO *tinfo, WT_CURSOR *cursor, bool positioned)
 		    (int)tinfo->key->size, tinfo->key->data,
 		    (int)tinfo->value->size, tinfo->value->data);
 
-	switch (ret = cursor->insert(cursor)) {
-	case 0:
-		break;
-	case WT_CACHE_FULL:
-	case WT_ROLLBACK:
-		return (WT_ROLLBACK);
-	default:
-		testutil_die(ret,
-		    "row_insert: insert row %" PRIu64 " by key", tinfo->keyno);
-	}
-
 #ifdef HAVE_BERKELEY_DB
 	if (SINGLETHREADED)
 		bdb_update(
@@ -2041,15 +1939,10 @@ col_insert(TINFO *tinfo, WT_CURSOR *cursor)
 		cursor->set_value(cursor, *(uint8_t *)tinfo->value->data);
 	else
 		cursor->set_value(cursor, tinfo->value);
-	switch (ret = cursor->insert(cursor)) {
-	case 0:
-		break;
-	case WT_CACHE_FULL:
-	case WT_ROLLBACK:
-		return (WT_ROLLBACK);
-	default:
-		testutil_die(ret, "cursor.insert");
-	}
+
+	if ((ret = cursor->insert(cursor)) != 0)
+		return (ret);
+
 	testutil_check(cursor->get_key(cursor, &tinfo->keyno));
 
 	table_append(tinfo->keyno);			/* Extend the object. */
@@ -2093,23 +1986,16 @@ row_remove(TINFO *tinfo, WT_CURSOR *cursor, bool positioned)
 		cursor->set_key(cursor, tinfo->key);
 	}
 
-	if (g.logging == LOG_OPS)
-		(void)g.wt_api->msg_printf(g.wt_api,
-		    cursor->session, "%-10s%" PRIu64, "remove", tinfo->keyno);
-
 	/* We use the cursor in overwrite mode, check for existence. */
 	if ((ret = cursor->search(cursor)) == 0)
 		ret = cursor->remove(cursor);
-	switch (ret) {
-	case 0:
-	case WT_NOTFOUND:
-		break;
-	case WT_ROLLBACK:
-		return (WT_ROLLBACK);
-	default:
-		testutil_die(ret,
-		    "row_remove: remove %" PRIu64 " by key", tinfo->keyno);
-	}
+
+	if (ret != 0 && ret != WT_NOTFOUND)
+		return (ret);
+
+	if (g.logging == LOG_OPS)
+		(void)g.wt_api->msg_printf(g.wt_api,
+		    cursor->session, "%-10s%" PRIu64, "remove", tinfo->keyno);
 
 #ifdef HAVE_BERKELEY_DB
 	if (SINGLETHREADED) {
@@ -2134,23 +2020,16 @@ col_remove(TINFO *tinfo, WT_CURSOR *cursor, bool positioned)
 	if (!positioned)
 		cursor->set_key(cursor, tinfo->keyno);
 
-	if (g.logging == LOG_OPS)
-		(void)g.wt_api->msg_printf(g.wt_api,
-		    cursor->session, "%-10s%" PRIu64, "remove", tinfo->keyno);
-
 	/* We use the cursor in overwrite mode, check for existence. */
 	if ((ret = cursor->search(cursor)) == 0)
 		ret = cursor->remove(cursor);
-	switch (ret) {
-	case 0:
-	case WT_NOTFOUND:
-		break;
-	case WT_ROLLBACK:
-		return (WT_ROLLBACK);
-	default:
-		testutil_die(ret,
-		    "col_remove: remove %" PRIu64 " by key", tinfo->keyno);
-	}
+
+	if (ret != 0 && ret != WT_NOTFOUND)
+		return (ret);
+
+	if (g.logging == LOG_OPS)
+		(void)g.wt_api->msg_printf(g.wt_api,
+		    cursor->session, "%-10s%" PRIu64, "remove", tinfo->keyno);
 
 #ifdef HAVE_BERKELEY_DB
 	if (SINGLETHREADED) {