Import wiredtiger: 154719f3ff736872f67f2b3e9f4d8b396d2d8adf from branch mongodb-4.4

ref: bf1d78126c..154719f3ff
for: 4.5.1

WT-6185       Insert full updates into the history store in some corner cases and add a history store c test
WT-6257       Fix rows out-of-order in history store file
WT-6339       Stop creating snapshots for history store cursors
WT-6396       Fix wrong assert when inserting updates to the history store

1 files changed, 36 insertions, 44 deletions

diff --git a/src/third_party/wiredtiger/test/format/ops.c b/src/third_party/wiredtiger/test/format/ops.c
index 82aa22d5f40..0d4692f0472 100644
--- a/src/third_party/wiredtiger/test/format/ops.c
+++ b/src/third_party/wiredtiger/test/format/ops.c
@@ -154,7 +154,7 @@ operations(u_int ops_seconds, bool lastrun)
     }
 
     testutil_check(conn->open_session(conn, NULL, NULL, &session));
-    tracemsg("%s", "=============== thread ops start");
+    trace_msg("%s", "=============== thread ops start");
 
     /* Initialize locks to single-thread backups, failures, and timestamp updates. */
     lock_init(session, &g.backup_lock);
@@ -277,12 +277,14 @@ operations(u_int ops_seconds, bool lastrun)
     lock_destroy(session, &g.backup_lock);
     lock_destroy(session, &g.ts_lock);
 
-    tracemsg("%s", "=============== thread ops stop");
+    trace_msg("%s", "=============== thread ops stop");
     testutil_check(session->close(session, NULL));
 
     for (i = 0; i < g.c_threads; ++i) {
         tinfo = tinfo_list[i];
 
+        __wt_buf_free(NULL, &tinfo->vprint);
+
         /*
          * Assert records were not removed unless configured to do so, otherwise subsequent runs can
          * incorrectly report scan errors.
@@ -334,7 +336,7 @@ begin_transaction_ts(TINFO *tinfo, u_int *iso_configp)
         ret = session->timestamp_transaction(session, buf);
         if (ret == 0) {
             snap_init(tinfo, ts, true);
-            traceop(tinfo, "begin snapshot read-ts=%" PRIu64 " (repeatable)", ts);
+            trace_op(tinfo, "begin snapshot read-ts=%" PRIu64 " (repeatable)", ts);
             return;
         }
         if (ret != EINVAL)
@@ -362,7 +364,7 @@ begin_transaction_ts(TINFO *tinfo, u_int *iso_configp)
     lock_writeunlock(session, &g.ts_lock);
 
     snap_init(tinfo, ts, false);
-    traceop(tinfo, "begin snapshot read-ts=%" PRIu64 " (not repeatable)", ts);
+    trace_op(tinfo, "begin snapshot read-ts=%" PRIu64 " (not repeatable)", ts);
 }
 
 /*
@@ -374,7 +376,7 @@ begin_transaction(TINFO *tinfo, u_int *iso_configp)
 {
     WT_SESSION *session;
     u_int v;
-    const char *config, *log;
+    const char *config;
 
     session = tinfo->session;
 
@@ -383,18 +385,15 @@ begin_transaction(TINFO *tinfo, u_int *iso_configp)
     switch (v) {
     case 1:
         v = ISOLATION_READ_UNCOMMITTED;
-        log = "read-uncommitted";
         config = "isolation=read-uncommitted";
         break;
     case 2:
         v = ISOLATION_READ_COMMITTED;
-        log = "read-committed";
         config = "isolation=read-committed";
         break;
     case 3:
     default:
         v = ISOLATION_SNAPSHOT;
-        log = "snapshot";
         config = "isolation=snapshot";
         break;
     }
@@ -403,7 +402,7 @@ begin_transaction(TINFO *tinfo, u_int *iso_configp)
     wiredtiger_begin_transaction(session, config);
 
     snap_init(tinfo, WT_TS_NONE, false);
-    traceop(tinfo, "begin %s", log);
+    trace_op(tinfo, "begin %s", config);
 }
 
 /*
@@ -442,7 +441,7 @@ commit_transaction(TINFO *tinfo, bool prepared)
     /* Remember our oldest commit timestamp. */
     tinfo->commit_ts = ts;
 
-    traceop(
+    trace_op(
       tinfo, "commit read-ts=%" PRIu64 ", commit-ts=%" PRIu64, tinfo->read_ts, tinfo->commit_ts);
 }
 
@@ -461,7 +460,7 @@ rollback_transaction(TINFO *tinfo)
 
     testutil_check(session->rollback_transaction(session, NULL));
 
-    traceop(tinfo, "abort read-ts=%" PRIu64, tinfo->read_ts);
+    trace_op(tinfo, "abort read-ts=%" PRIu64, tinfo->read_ts);
 }
 
 /*
@@ -497,7 +496,7 @@ prepare_transaction(TINFO *tinfo)
     testutil_check(__wt_snprintf(buf, sizeof(buf), "prepare_timestamp=%" PRIx64, ts));
     ret = session->prepare_transaction(session, buf);
 
-    traceop(tinfo, "prepare ts=%" PRIu64, ts);
+    trace_op(tinfo, "prepare ts=%" PRIu64, ts);
 
     lock_writeunlock(session, &g.ts_lock);
 
@@ -1130,20 +1129,17 @@ read_row_worker(
         switch (g.type) {
         case FIX:
             if (tinfo == NULL && g.trace_all)
-                tracemsg("%-10s%" PRIu64 " {0x%02x}", "read", keyno, ((char *)value->data)[0]);
+                trace_msg("read %" PRIu64 " {0x%02x}", keyno, ((char *)value->data)[0]);
             if (tinfo != NULL)
-                traceop(
-                  tinfo, "%-10s%" PRIu64 " {0x%02x}", "read", keyno, ((char *)value->data)[0]);
+                trace_op(tinfo, "read %" PRIu64 " {0x%02x}", keyno, ((char *)value->data)[0]);
 
             break;
         case ROW:
         case VAR:
             if (tinfo == NULL && g.trace_all)
-                tracemsg(
-                  "%-10s%" PRIu64 " {%.*s}", "read", keyno, (int)value->size, (char *)value->data);
+                trace_msg("read %" PRIu64 " {%.*s}", keyno, (int)value->size, (char *)value->data);
             if (tinfo != NULL)
-                traceop(tinfo, "%-10s%" PRIu64 " {%.*s}", "read", keyno, (int)value->size,
-                  (char *)value->data);
+                trace_op(tinfo, "read %" PRIu64 " {%s}", keyno, trace_item(tinfo, value));
             break;
         }
 
@@ -1279,15 +1275,14 @@ order_error_row:
     if (g.trace_all && ret == 0)
         switch (g.type) {
         case FIX:
-            traceop(tinfo, "%-10s%" PRIu64 " {0x%02x}", which, keyno, ((char *)value.data)[0]);
+            trace_op(tinfo, "%s %" PRIu64 " {0x%02x}", which, keyno, ((char *)value.data)[0]);
             break;
         case ROW:
-            traceop(tinfo, "%-10s%" PRIu64 " {%.*s}, {%.*s}", which, keyno, (int)key.size,
-              (char *)key.data, (int)value.size, (char *)value.data);
+            trace_op(tinfo, "%s %" PRIu64 " {%.*s}, {%s}", which, keyno, (int)key.size,
+              (char *)key.data, trace_item(tinfo, &value));
             break;
         case VAR:
-            traceop(
-              tinfo, "%-10s%" PRIu64 " {%.*s}", which, keyno, (int)value.size, (char *)value.data);
+            trace_op(tinfo, "%s %" PRIu64 " {%s}", which, keyno, trace_item(tinfo, &value));
             break;
         }
 
@@ -1311,7 +1306,7 @@ row_reserve(TINFO *tinfo, WT_CURSOR *cursor, bool positioned)
     if ((ret = cursor->reserve(cursor)) != 0)
         return (ret);
 
-    traceop(tinfo, "%-10s%" PRIu64 " {%.*s}", "reserve", tinfo->keyno, (int)tinfo->key->size,
+    trace_op(tinfo, "reserve %" PRIu64 " {%.*s}", tinfo->keyno, (int)tinfo->key->size,
       (char *)tinfo->key->data);
 
     return (0);
@@ -1332,7 +1327,7 @@ col_reserve(TINFO *tinfo, WT_CURSOR *cursor, bool positioned)
     if ((ret = cursor->reserve(cursor)) != 0)
         return (ret);
 
-    traceop(tinfo, "%-10s%" PRIu64, "reserve", tinfo->keyno);
+    trace_op(tinfo, "reserve %" PRIu64, tinfo->keyno);
 
     return (0);
 }
@@ -1383,8 +1378,8 @@ row_modify(TINFO *tinfo, WT_CURSOR *cursor, bool positioned)
 
     testutil_check(cursor->get_value(cursor, tinfo->value));
 
-    traceop(tinfo, "%-10s%" PRIu64 " {%.*s}, {%.*s}", "modify", tinfo->keyno, (int)tinfo->key->size,
-      (char *)tinfo->key->data, (int)tinfo->value->size, (char *)tinfo->value->data);
+    trace_op(tinfo, "modify %" PRIu64 " {%.*s}, {%s}", tinfo->keyno, (int)tinfo->key->size,
+      (char *)tinfo->key->data, trace_item(tinfo, tinfo->value));
 
     return (0);
 }
@@ -1409,8 +1404,7 @@ col_modify(TINFO *tinfo, WT_CURSOR *cursor, bool positioned)
 
     testutil_check(cursor->get_value(cursor, tinfo->value));
 
-    traceop(tinfo, "%-10s%" PRIu64 ", {%.*s}", "modify", tinfo->keyno, (int)tinfo->value->size,
-      (char *)tinfo->value->data);
+    trace_op(tinfo, "modify %" PRIu64 ", {%s}", tinfo->keyno, trace_item(tinfo, tinfo->value));
 
     return (0);
 }
@@ -1457,7 +1451,7 @@ row_truncate(TINFO *tinfo, WT_CURSOR *cursor)
     if (ret != 0)
         return (ret);
 
-    traceop(tinfo, "%-10s%" PRIu64 ", %" PRIu64, "truncate", tinfo->keyno, tinfo->last);
+    trace_op(tinfo, "truncate %" PRIu64 ", %" PRIu64, "truncate", tinfo->keyno, tinfo->last);
 
     return (0);
 }
@@ -1499,7 +1493,7 @@ col_truncate(TINFO *tinfo, WT_CURSOR *cursor)
     if (ret != 0)
         return (ret);
 
-    traceop(tinfo, "%-10s%" PRIu64 "-%" PRIu64, "truncate", tinfo->keyno, tinfo->last);
+    trace_op(tinfo, "truncate %" PRIu64 "-%" PRIu64, tinfo->keyno, tinfo->last);
 
     return (0);
 }
@@ -1523,8 +1517,8 @@ row_update(TINFO *tinfo, WT_CURSOR *cursor, bool positioned)
     if ((ret = cursor->update(cursor)) != 0)
         return (ret);
 
-    traceop(tinfo, "%-10s%" PRIu64 " {%.*s}, {%.*s}", "update", tinfo->keyno, (int)tinfo->key->size,
-      (char *)tinfo->key->data, (int)tinfo->value->size, (char *)tinfo->value->data);
+    trace_op(tinfo, "update %" PRIu64 " {%.*s}, {%s}", tinfo->keyno, (int)tinfo->key->size,
+      (char *)tinfo->key->data, trace_item(tinfo, tinfo->value));
 
     return (0);
 }
@@ -1550,11 +1544,10 @@ col_update(TINFO *tinfo, WT_CURSOR *cursor, bool positioned)
         return (ret);
 
     if (g.type == FIX)
-        traceop(tinfo, "%-10s%" PRIu64 " {0x%02" PRIx8 "}", "update", tinfo->keyno,
+        trace_op(tinfo, "update %" PRIu64 " {0x%02" PRIx8 "}", tinfo->keyno,
           ((uint8_t *)tinfo->value->data)[0]);
     else
-        traceop(tinfo, "%-10s%" PRIu64 " {%.*s}", "update", tinfo->keyno, (int)tinfo->value->size,
-          (char *)tinfo->value->data);
+        trace_op(tinfo, "update %" PRIu64 " {%s}", tinfo->keyno, trace_item(tinfo, tinfo->value));
 
     return (0);
 }
@@ -1583,8 +1576,8 @@ row_insert(TINFO *tinfo, WT_CURSOR *cursor, bool positioned)
         return (ret);
 
     /* Log the operation */
-    traceop(tinfo, "%-10s%" PRIu64 " {%.*s}, {%.*s}", "insert", tinfo->keyno, (int)tinfo->key->size,
-      (char *)tinfo->key->data, (int)tinfo->value->size, (char *)tinfo->value->data);
+    trace_op(tinfo, "insert %" PRIu64 " {%.*s}, {%s}", tinfo->keyno, (int)tinfo->key->size,
+      (char *)tinfo->key->data, trace_item(tinfo, tinfo->value));
 
     return (0);
 }
@@ -1669,11 +1662,10 @@ col_insert(TINFO *tinfo, WT_CURSOR *cursor)
     col_insert_add(tinfo); /* Extend the object. */
 
     if (g.type == FIX)
-        traceop(tinfo, "%-10s%" PRIu64 " {0x%02" PRIx8 "}", "insert", tinfo->keyno,
+        trace_op(tinfo, "insert %" PRIu64 " {0x%02" PRIx8 "}", tinfo->keyno,
           ((uint8_t *)tinfo->value->data)[0]);
     else
-        traceop(tinfo, "%-10s%" PRIu64 " {%.*s}", "insert", tinfo->keyno, (int)tinfo->value->size,
-          (char *)tinfo->value->data);
+        trace_op(tinfo, "insert %" PRIu64 " {%s}", tinfo->keyno, trace_item(tinfo, tinfo->value));
 
     return (0);
 }
@@ -1699,7 +1691,7 @@ row_remove(TINFO *tinfo, WT_CURSOR *cursor, bool positioned)
     if (ret != 0 && ret != WT_NOTFOUND)
         return (ret);
 
-    traceop(tinfo, "%-10s%" PRIu64, "remove", tinfo->keyno);
+    trace_op(tinfo, "remove %" PRIu64, tinfo->keyno);
 
     return (ret);
 }
@@ -1723,7 +1715,7 @@ col_remove(TINFO *tinfo, WT_CURSOR *cursor, bool positioned)
     if (ret != 0 && ret != WT_NOTFOUND)
         return (ret);
 
-    traceop(tinfo, "%-10s%" PRIu64, "remove", tinfo->keyno);
+    trace_op(tinfo, "remove %" PRIu64, tinfo->keyno);
 
     return (ret);
 }