diff options
author | Jie Chen <jie.chen@mongodb.com> | 2023-03-01 23:37:13 +0000 |
---|---|---|
committer | Evergreen Agent <no-reply@evergreen.mongodb.com> | 2023-03-02 05:06:53 +0000 |
commit | 1f9140a14bd375c6e4d64ef03ea116626f032809 (patch) | |
tree | 6b3b5fcbff4af5e1ce130a9cb56f2f17ddc709d8 | |
parent | 5ce9bb9b25c5aa88404b3704195605a246f80e87 (diff) | |
download | mongo-1f9140a14bd375c6e4d64ef03ea116626f032809.tar.gz |
Import wiredtiger: f125692273310ae6f623d03fc84eb0540b92d90e from branch mongodb-master
ref: d57d317000..f125692273
for: 7.0.0-rc0
WT-10290 RTS verifier
68 files changed, 1377 insertions, 290 deletions
diff --git a/src/third_party/wiredtiger/dist/s_all b/src/third_party/wiredtiger/dist/s_all index c59c63b211f..4f544138503 100755 --- a/src/third_party/wiredtiger/dist/s_all +++ b/src/third_party/wiredtiger/dist/s_all @@ -112,7 +112,8 @@ COMMANDS=" 2>&1 ./s_whitespace > ${t_pfx}s_whitespace 2>&1 python3 function.py > ${t_pfx}py_function 2>&1 python3 style.py > ${t_pfx}py_style -2>&1 python3 comment_style.py ${fast} > ${t_pfx}py_comment_style" +2>&1 python3 comment_style.py ${fast} > ${t_pfx}py_comment_style +2>&1 python3 type_to_str.py > ${t_pfx}py_type_to_str" # Parallelize if possible. xp="" diff --git a/src/third_party/wiredtiger/dist/s_string.ok b/src/third_party/wiredtiger/dist/s_string.ok index aa4bb542654..7fabca6b88e 100644 --- a/src/third_party/wiredtiger/dist/s_string.ok +++ b/src/third_party/wiredtiger/dist/s_string.ok @@ -249,6 +249,7 @@ NetBSD NoAddr Noll Nul +ONDISK OOB OPLOG OPTRACK diff --git a/src/third_party/wiredtiger/dist/type_to_str.py b/src/third_party/wiredtiger/dist/type_to_str.py new file mode 100755 index 00000000000..47ade43fa19 --- /dev/null +++ b/src/third_party/wiredtiger/dist/type_to_str.py @@ -0,0 +1,66 @@ +#!/usr/bin/env python3 + +import os, re + +from dist import compare_srcfile, format_srcfile + +""" +* docstring: The documentation to attach to the generated function. +* name: The name to use for the generated function, i.e. `__wt_name_str`. +* define_regex: The regular expression to use for capturing the names of the + macros. Note that this must also include the capture group. +* srcfile: The source file to look through when searching for `define_regex`. +* out: The output file handle. +""" +def generate_string_conversion(docstring, name, define_regex, srcfile, out): + srcfile = '../' + srcfile + pattern = re.compile(define_regex) + + out.write('/*\n') + out.write(' * __wt_{}_str --\n'.format(name)) + out.write(' * {}\n'.format(docstring)) + out.write(' */\n') + out.write('static inline const char *\n') + out.write('__wt_{}_str(uint8_t val)\n'.format(name)) + out.write('{\n') + out.write(' switch (val) {\n') + + found = False + with open(srcfile, 'r') as src: + for line in src: + matches = pattern.search(line) + if matches: + found = True + out.write(' case {}:\n'.format(matches.group(1))) + out.write(' return ("{}");\n'.format(matches.group(1))) + + if not found: + raise Exception("generate_string_conversion: Failed to find {} in {}" + .format(define_regex, srcfile)) + + out.write(' }\n') + out.write('\n') + out.write(' return ("{}_INVALID");\n'.format(name.upper())) + out.write('}\n') + +if __name__ == '__main__': + src = '../src/include/str_inline.h' + tmp = '__tmp' + str(os.getpid()) + + with open(tmp, 'w') as tfile: + generate_string_conversion('Convert a prepare state to its string representation.', + 'prepare_state', + r'^#define\s+(WT_PREPARE_[A-Z0-9_]+)\s+[0-9]+', + 'src/include/btmem.h', + tfile) + tfile.write('\n') + + generate_string_conversion('Convert an update type to its string representation.', + 'update_type', + # Also match comments/space at end to avoid e.g. WT_UPDATE_SIZE. + r'^#define\s+(WT_UPDATE_[A-Z0-9_]+)\s+[0-9]+\s+/\*', + 'src/include/btmem.h', + tfile) + + format_srcfile(tmp) + compare_srcfile(tmp, src) diff --git a/src/third_party/wiredtiger/import.data b/src/third_party/wiredtiger/import.data index 29d4de7313e..7696e0ad73e 100644 --- a/src/third_party/wiredtiger/import.data +++ b/src/third_party/wiredtiger/import.data @@ -2,5 +2,5 @@ "vendor": "wiredtiger", "github": "wiredtiger/wiredtiger.git", "branch": "mongodb-master", - "commit": "d57d317000d70f0ad4da6f59773bd02e753ae2e0" + "commit": "f125692273310ae6f623d03fc84eb0540b92d90e" } diff --git a/src/third_party/wiredtiger/src/include/btmem.h b/src/third_party/wiredtiger/src/include/btmem.h index a5a57474759..620b8219c2a 100644 --- a/src/third_party/wiredtiger/src/include/btmem.h +++ b/src/third_party/wiredtiger/src/include/btmem.h @@ -805,10 +805,9 @@ struct __wt_page { * Prepare state will not be updated during rollback and will continue to * have the state as INPROGRESS. */ -#define WT_PREPARE_INIT \ - 0 /* Must be 0, as structures \ - will be default initialized \ - with 0. */ + +/* Must be 0, as structures will be default initialized with 0. */ +#define WT_PREPARE_INIT 0 #define WT_PREPARE_INPROGRESS 1 #define WT_PREPARE_LOCKED 2 #define WT_PREPARE_RESOLVED 3 diff --git a/src/third_party/wiredtiger/src/include/extern.h b/src/third_party/wiredtiger/src/include/extern.h index c4b5bc51a55..b0a81f0702e 100644 --- a/src/third_party/wiredtiger/src/include/extern.h +++ b/src/third_party/wiredtiger/src/include/extern.h @@ -2088,6 +2088,10 @@ static inline bool __wt_txn_visible_all(WT_SESSION_IMPL *session, uint64_t id, wt_timestamp_t timestamp) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); static inline bool __wt_txn_visible_id_snapshot(uint64_t id, uint64_t snap_min, uint64_t snap_max, uint64_t *snapshot, uint32_t snapshot_count) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); +static inline const char *__wt_prepare_state_str(uint8_t val) + WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); +static inline const char *__wt_update_type_str(uint8_t val) + WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); static inline double __wt_eviction_dirty_target(WT_CACHE *cache) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); static inline int __wt_btcur_bounds_early_exit(WT_SESSION_IMPL *session, WT_CURSOR_BTREE *cbt, diff --git a/src/third_party/wiredtiger/src/include/rollback_to_stable.h b/src/third_party/wiredtiger/src/include/rollback_to_stable.h index 773bbd59892..98a65f74809 100644 --- a/src/third_party/wiredtiger/src/include/rollback_to_stable.h +++ b/src/third_party/wiredtiger/src/include/rollback_to_stable.h @@ -6,6 +6,37 @@ * See the file LICENSE for redistribution information. */ +/* + * Helper macros for finer-grained RTS verbose messaging categories. + */ +#define WT_RTS_VERB_TAG_FILE_SKIP "[FILE_SKIP] " +#define WT_RTS_VERB_TAG_HS_ABORT_STOP "[HS_ABORT_STOP] " +#define WT_RTS_VERB_TAG_HS_GT_ONDISK "[HS_GT_ONDISK] " +#define WT_RTS_VERB_TAG_HS_RESTORE_TOMBSTONE "[HS_RESTORE_TOMBSTONE] " +#define WT_RTS_VERB_TAG_HS_STOP_OBSOLETE "[HS_STOP_OBSOLETE] " +#define WT_RTS_VERB_TAG_HS_TREE_ROLLBACK "[HS_TREE_ROLLBACK] " +#define WT_RTS_VERB_TAG_HS_TREE_SKIP "[HS_TREE_SKIP] " +#define WT_RTS_VERB_TAG_HS_UPDATE_ABORT "[HS_UPDATE_ABORT] " +#define WT_RTS_VERB_TAG_HS_UPDATE_RESTORED "[HS_UPDATE_RESTORED] " +#define WT_RTS_VERB_TAG_HS_UPDATE_VALID "[HS_UPDATE_VALID] " +#define WT_RTS_VERB_TAG_INIT "[INIT] " +#define WT_RTS_VERB_TAG_KEY_CLEAR_REMOVE "[KEY_CLEAR_REMOVE] " +#define WT_RTS_VERB_TAG_KEY_REMOVED "[KEY_REMOVED] " +#define WT_RTS_VERB_TAG_ONDISK_ABORT_TW "[ONDISK_ABORT_TW] " +#define WT_RTS_VERB_TAG_ONDISK_KEY_ROLLBACK "[ONDISK_KEY_ROLLBACK] " +#define WT_RTS_VERB_TAG_ONDISK_KV_REMOVE "[ONDISK_KV_REMOVE] " +#define WT_RTS_VERB_TAG_PAGE_ABORT_CHECK "[PAGE_ABORT_CHECK] " +#define WT_RTS_VERB_TAG_PAGE_ROLLBACK "[PAGE_ROLLBACK] " +#define WT_RTS_VERB_TAG_RECOVER_CKPT "[RECOVER_CKPT] " +#define WT_RTS_VERB_TAG_SKIP_DAMAGE "[SKIP_DAMAGE] " +#define WT_RTS_VERB_TAG_SKIP_DEL_NULL "[SKIP_DEL_NULL] " +#define WT_RTS_VERB_TAG_SKIP_UNMODIFIED "[SKIP_UNMODIFIED] " +#define WT_RTS_VERB_TAG_STABLE_PG_WALK_SKIP "[STABLE_PG_WALK_SKIP] " +#define WT_RTS_VERB_TAG_TREE "[TREE] " +#define WT_RTS_VERB_TAG_TREE_LOGGING "[TREE_LOGGING] " +#define WT_RTS_VERB_TAG_TREE_SKIP "[TREE_SKIP] " +#define WT_RTS_VERB_TAG_UPDATE_ABORT "[UPDATE_ABORT] " + #define WT_CHECK_RECOVERY_FLAG_TXNID(session, txnid) \ (F_ISSET(S2C(session), WT_CONN_RECOVERING) && S2C(session)->recovery_ckpt_snap_min != 0 && \ (txnid) >= S2C(session)->recovery_ckpt_snap_min) diff --git a/src/third_party/wiredtiger/src/include/str_inline.h b/src/third_party/wiredtiger/src/include/str_inline.h new file mode 100644 index 00000000000..424845542d9 --- /dev/null +++ b/src/third_party/wiredtiger/src/include/str_inline.h @@ -0,0 +1,43 @@ +/* + * __wt_prepare_state_str -- + * Convert a prepare state to its string representation. + */ +static inline const char * +__wt_prepare_state_str(uint8_t val) +{ + switch (val) { + case WT_PREPARE_INIT: + return ("WT_PREPARE_INIT"); + case WT_PREPARE_INPROGRESS: + return ("WT_PREPARE_INPROGRESS"); + case WT_PREPARE_LOCKED: + return ("WT_PREPARE_LOCKED"); + case WT_PREPARE_RESOLVED: + return ("WT_PREPARE_RESOLVED"); + } + + return ("PREPARE_STATE_INVALID"); +} + +/* + * __wt_update_type_str -- + * Convert an update type to its string representation. + */ +static inline const char * +__wt_update_type_str(uint8_t val) +{ + switch (val) { + case WT_UPDATE_INVALID: + return ("WT_UPDATE_INVALID"); + case WT_UPDATE_MODIFY: + return ("WT_UPDATE_MODIFY"); + case WT_UPDATE_RESERVE: + return ("WT_UPDATE_RESERVE"); + case WT_UPDATE_STANDARD: + return ("WT_UPDATE_STANDARD"); + case WT_UPDATE_TOMBSTONE: + return ("WT_UPDATE_TOMBSTONE"); + } + + return ("UPDATE_TYPE_INVALID"); +} diff --git a/src/third_party/wiredtiger/src/include/wt_internal.h b/src/third_party/wiredtiger/src/include/wt_internal.h index 46aa95c4d16..8d1a6be550f 100644 --- a/src/third_party/wiredtiger/src/include/wt_internal.h +++ b/src/third_party/wiredtiger/src/include/wt_internal.h @@ -495,6 +495,7 @@ typedef uint64_t wt_timestamp_t; #include "packing_inline.h" #include "reconcile_inline.h" #include "serial_inline.h" +#include "str_inline.h" #include "time_inline.h" #if defined(__cplusplus) diff --git a/src/third_party/wiredtiger/src/rollback_to_stable/rts.c b/src/third_party/wiredtiger/src/rollback_to_stable/rts.c index 7a0f35f5164..099152c6c16 100644 --- a/src/third_party/wiredtiger/src/rollback_to_stable/rts.c +++ b/src/third_party/wiredtiger/src/rollback_to_stable/rts.c @@ -134,8 +134,9 @@ __wt_rts_btree_apply_all(WT_SESSION_IMPL *session, wt_timestamp_t rollback_times */ if (ret == ENOENT || (ret == WT_ERROR && F_ISSET(S2C(session), WT_CONN_DATA_CORRUPTION))) { __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session), - "%s: skipped performing rollback to stable because the file %s", uri, - ret == ENOENT ? "does not exist" : "is corrupted."); + WT_RTS_VERB_TAG_SKIP_DAMAGE + "%s: skipped performing rollback to stable because the file %s", + uri, ret == ENOENT ? "does not exist" : "is corrupted."); continue; } WT_ERR(ret); diff --git a/src/third_party/wiredtiger/src/rollback_to_stable/rts_api.c b/src/third_party/wiredtiger/src/rollback_to_stable/rts_api.c index 66b3773a57a..95263b0c0b4 100644 --- a/src/third_party/wiredtiger/src/rollback_to_stable/rts_api.c +++ b/src/third_party/wiredtiger/src/rollback_to_stable/rts_api.c @@ -74,14 +74,15 @@ __rollback_to_stable_int(WT_SESSION_IMPL *session, bool no_ckpt) WT_ORDERED_READ(rollback_timestamp, txn_global->stable_timestamp); WT_ORDERED_READ(pinned_timestamp, txn_global->pinned_timestamp); __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session), - "performing rollback to stable with stable timestamp: %s and oldest timestamp: %s", + WT_RTS_VERB_TAG_INIT + "performing rollback to stable with stable_timestamp=%s and oldest_timestamp=%s", __wt_timestamp_to_string(rollback_timestamp, ts_string[0]), __wt_timestamp_to_string(txn_global->oldest_timestamp, ts_string[1])); if (F_ISSET(conn, WT_CONN_RECOVERING)) __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session), - "recovered checkpoint snapshot min: %" PRIu64 ", snapshot max: %" PRIu64 - ", snapshot count: %" PRIu32, + WT_RTS_VERB_TAG_RECOVER_CKPT "recovered checkpoint snapshot_min=%" PRIu64 + ", snapshot_max=%" PRIu64 ", snapshot_count=%" PRIu32, conn->recovery_ckpt_snap_min, conn->recovery_ckpt_snap_max, conn->recovery_ckpt_snapshot_count); diff --git a/src/third_party/wiredtiger/src/rollback_to_stable/rts_btree.c b/src/third_party/wiredtiger/src/rollback_to_stable/rts_btree.c index c20d982a00e..4ba3b778da8 100644 --- a/src/third_party/wiredtiger/src/rollback_to_stable/rts_btree.c +++ b/src/third_party/wiredtiger/src/rollback_to_stable/rts_btree.c @@ -48,14 +48,15 @@ __rts_btree_abort_update(WT_SESSION_IMPL *session, WT_ITEM *key, WT_UPDATE *firs if (!txn_id_visible || rollback_timestamp < upd->durable_ts || upd->prepare_state == WT_PREPARE_INPROGRESS) { __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session), - "rollback to stable update aborted with txnid: %" PRIu64 - ", txnid not visible: %s, or stable timestamp (%s) < durable timestamp (%s): %s, or " - "prepare state (%d) is in progress: %s", + WT_RTS_VERB_TAG_UPDATE_ABORT + "rollback to stable update aborted with txnid=%" PRIu64 + ", txnid_not_visible=%s" + ", stable_timestamp=%s < durable_timestamp=%s: %s, prepare_state=%s", upd->txnid, !txn_id_visible ? "true" : "false", __wt_timestamp_to_string(rollback_timestamp, ts_string[1]), __wt_timestamp_to_string(upd->durable_ts, ts_string[0]), - rollback_timestamp < upd->durable_ts ? "true" : "false", upd->prepare_state, - upd->prepare_state == WT_PREPARE_INPROGRESS ? "true" : "false"); + rollback_timestamp < upd->durable_ts ? "true" : "false", + __wt_prepare_state_str(upd->prepare_state)); if (!dryrun) upd->txnid = WT_TXN_ABORTED; @@ -295,7 +296,7 @@ __rts_btree_ondisk_fixup_key(WT_SESSION_IMPL *session, WT_REF *ref, WT_ROW *rip, WT_ERR(__wt_scr_alloc(session, 0, &key_string)); __wt_verbose_level_multi(session, WT_VERB_RECOVERY_RTS(session), WT_VERBOSE_DEBUG_2, - "rolling back the on-disk key: %s", + WT_RTS_VERB_TAG_ONDISK_KEY_ROLLBACK "rolling back the on-disk key=%s", __wt_key_string(session, key->data, key->size, S2BT(session)->key_format, key_string)); WT_ERR(__wt_scr_alloc(session, 0, &full_value)); @@ -354,7 +355,8 @@ __rts_btree_ondisk_fixup_key(WT_SESSION_IMPL *session, WT_REF *ref, WT_ROW *rip, if (__wt_rts_visibility_txn_visible_id(session, hs_tw->stop_txn) && hs_tw->durable_stop_ts <= pinned_ts) { __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session), - "history store stop is obsolete with time window: %s and pinned timestamp: %s", + WT_RTS_VERB_TAG_HS_STOP_OBSOLETE + "history store stop is obsolete with time_window=%s and pinned_timestamp=%s", __wt_time_window_to_string(hs_tw, tw_string), __wt_timestamp_to_string(pinned_ts, ts_string[0])); if (!dryrun) @@ -386,9 +388,10 @@ __rts_btree_ondisk_fixup_key(WT_SESSION_IMPL *session, WT_REF *ref, WT_ROW *rip, } } else __wt_verbose_level_multi(session, WT_VERB_RECOVERY_RTS(session), WT_VERBOSE_DEBUG_2, - "history store update more recent than on-disk update with time window: %s and type: " - "%" PRIu8, - __wt_time_window_to_string(hs_tw, tw_string), type); + WT_RTS_VERB_TAG_HS_GT_ONDISK + "history store update more recent than on-disk update with time_window=%s and " + "type=%s", + __wt_time_window_to_string(hs_tw, tw_string), __wt_update_type_str(type)); /* * Verify the history store timestamps are in order. The start timestamp may be equal to the @@ -439,9 +442,9 @@ __rts_btree_ondisk_fixup_key(WT_SESSION_IMPL *session, WT_REF *ref, WT_ROW *rip, if (__wt_rts_visibility_txn_visible_id(session, hs_tw->start_txn) && hs_tw->durable_start_ts <= rollback_timestamp) { __wt_verbose_level_multi(session, WT_VERB_RECOVERY_RTS(session), WT_VERBOSE_DEBUG_2, - "history store update valid with time window: %s, type: %" PRIu8 - " and stable timestamp: %s", - __wt_time_window_to_string(hs_tw, tw_string), type, + WT_RTS_VERB_TAG_HS_UPDATE_VALID + "history store update valid with time_window=%s, type=%s and stable_timestamp=%s", + __wt_time_window_to_string(hs_tw, tw_string), __wt_update_type_str(type), __wt_timestamp_to_string(rollback_timestamp, ts_string[0])); WT_ASSERT(session, unpack->tw.prepare || hs_tw->start_ts <= unpack->tw.start_ts); valid_update_found = true; @@ -449,9 +452,9 @@ __rts_btree_ondisk_fixup_key(WT_SESSION_IMPL *session, WT_REF *ref, WT_ROW *rip, } __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session), - "history store update aborted with time window: %s, type: %" PRIu8 - " and stable timestamp: %s", - __wt_time_window_to_string(hs_tw, tw_string), type, + WT_RTS_VERB_TAG_HS_UPDATE_ABORT + "history store update aborted with time_window=%s, type=%s and stable_timestamp=%s", + __wt_time_window_to_string(hs_tw, tw_string), __wt_update_type_str(type), __wt_timestamp_to_string(rollback_timestamp, ts_string[3])); /* @@ -492,7 +495,8 @@ __rts_btree_ondisk_fixup_key(WT_SESSION_IMPL *session, WT_REF *ref, WT_ROW *rip, upd->durable_ts = hs_tw->durable_start_ts; upd->start_ts = hs_tw->start_ts; __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session), - "history store update restored txnid: %" PRIu64 ", start_ts: %s and durable_ts: %s", + WT_RTS_VERB_TAG_HS_UPDATE_RESTORED "history store update restored txnid=%" PRIu64 + ", start_ts=%s and durable_ts=%s", upd->txnid, __wt_timestamp_to_string(upd->start_ts, ts_string[0]), __wt_timestamp_to_string(upd->durable_ts, ts_string[1])); @@ -531,8 +535,8 @@ __rts_btree_ondisk_fixup_key(WT_SESSION_IMPL *session, WT_REF *ref, WT_ROW *rip, tombstone->durable_ts = hs_tw->durable_stop_ts; tombstone->start_ts = hs_tw->stop_ts; __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session), - "history store tombstone restored txnid: %" PRIu64 - ", start_ts: %s and durable_ts: %s", + WT_RTS_VERB_TAG_HS_RESTORE_TOMBSTONE + "history store tombstone restored, txnid=%" PRIu64 ", start_ts=%s and durable_ts=%s", tombstone->txnid, __wt_timestamp_to_string(tombstone->start_ts, ts_string[0]), __wt_timestamp_to_string(tombstone->durable_ts, ts_string[1])); @@ -549,8 +553,8 @@ __rts_btree_ondisk_fixup_key(WT_SESSION_IMPL *session, WT_REF *ref, WT_ROW *rip, } else { WT_ERR(__wt_upd_alloc_tombstone(session, &upd, NULL)); WT_RTS_STAT_CONN_DATA_INCR(session, txn_rts_keys_removed); - __wt_verbose_level_multi( - session, WT_VERB_RECOVERY_RTS(session), WT_VERBOSE_DEBUG_3, "%s", "key removed"); + __wt_verbose_level_multi(session, WT_VERB_RECOVERY_RTS(session), WT_VERBOSE_DEBUG_3, + WT_RTS_VERB_TAG_KEY_REMOVED "%s", "key removed"); } if (rip != NULL) @@ -625,8 +629,9 @@ __rts_btree_abort_ondisk_kv(WT_SESSION_IMPL *session, WT_REF *ref, WT_ROW *rip, */ if (vpack->tw.durable_stop_ts > rollback_timestamp || vpack->tw.stop_ts == WT_TS_MAX) { __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session), - "history store update aborted with start durable/commit timestamp: %s, %s, stop " - "durable/commit timestamp: %s, %s and stable timestamp: %s", + WT_RTS_VERB_TAG_HS_ABORT_STOP + "history store update aborted with start_durable/commit_timestamp=%s, %s, " + "stop_durable/commit_timestamp=%s, %s and stable_timestamp=%s", __wt_timestamp_to_string(vpack->tw.durable_start_ts, ts_string[0]), __wt_timestamp_to_string(vpack->tw.start_ts, ts_string[1]), __wt_timestamp_to_string(vpack->tw.durable_stop_ts, ts_string[2]), @@ -640,8 +645,10 @@ __rts_btree_abort_ondisk_kv(WT_SESSION_IMPL *session, WT_REF *ref, WT_ROW *rip, !__wt_rts_visibility_txn_visible_id(session, vpack->tw.start_txn) || (!WT_TIME_WINDOW_HAS_STOP(&vpack->tw) && prepared)) { __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session), - "on-disk update aborted with time window %s. Start durable timestamp > stable timestamp: " - "%s, or txnid is not visible: %s, or tw has not stop and is prepared: %s", + WT_RTS_VERB_TAG_ONDISK_ABORT_TW + "on-disk update aborted with time_window=%s. " + "Start durable_timestamp > stable_timestamp: %s, or txnid_not_visible=%s, " + "or tw_has_no_stop_and_is_prepared=%s", __wt_time_point_to_string( vpack->tw.start_ts, vpack->tw.durable_start_ts, vpack->tw.start_txn, time_string), vpack->tw.durable_start_ts > rollback_timestamp ? "true" : "false", @@ -709,11 +716,11 @@ __rts_btree_abort_ondisk_kv(WT_SESSION_IMPL *session, WT_REF *ref, WT_ROW *rip, F_SET(upd, WT_UPDATE_RESTORED_FROM_DS); WT_RTS_STAT_CONN_DATA_INCR(session, txn_rts_keys_restored); __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session), - "key restored with commit timestamp: %s, durable timestamp: %s, stable timestamp: " - "%s, " - "txnid: %" PRIu64 - " and removed commit timestamp: %s, durable timestamp: %s, txnid: %" PRIu64 - ", prepared: %s", + WT_RTS_VERB_TAG_KEY_CLEAR_REMOVE + "key restored with commit_timestamp=%s, durable_timestamp=%s, stable_timestamp=%s, " + "txnid=%" PRIu64 + " and removed commit_timestamp=%s, durable_timestamp=%s, txnid=%" PRIu64 + ", prepared=%s", __wt_timestamp_to_string(upd->start_ts, ts_string[0]), __wt_timestamp_to_string(upd->durable_ts, ts_string[1]), __wt_timestamp_to_string(rollback_timestamp, ts_string[2]), upd->txnid, @@ -746,7 +753,8 @@ __rts_btree_abort_ondisk_kv(WT_SESSION_IMPL *session, WT_REF *ref, WT_ROW *rip, WT_ERR(__wt_scr_alloc(session, 0, &key_string)); __wt_verbose_level_multi(session, WT_VERB_RECOVERY_RTS(session), WT_VERBOSE_DEBUG_2, - "removing the key%s: %s", upd->type == WT_UPDATE_TOMBSTONE ? "" : " tombstone", + WT_RTS_VERB_TAG_ONDISK_KV_REMOVE "removing the key, tombstone=%s, key=%s", + upd->type == WT_UPDATE_TOMBSTONE ? "true" : "false", __wt_key_string(session, key->data, key->size, S2BT(session)->key_format, key_string)); if (rip != NULL) @@ -1064,13 +1072,14 @@ __wt_rts_btree_abort_updates( modified = __wt_page_is_modified(page); if (!modified && !__wt_rts_visibility_page_needs_abort(session, ref, rollback_timestamp)) { __wt_verbose_level_multi(session, WT_VERB_RECOVERY_RTS(session), WT_VERBOSE_DEBUG_3, - "%p: unmodified stable page skipped", (void *)ref); + WT_RTS_VERB_TAG_SKIP_UNMODIFIED "ref=%p: unmodified stable page skipped", (void *)ref); return (0); } WT_STAT_CONN_INCR(session, txn_rts_pages_visited); __wt_verbose_level_multi(session, WT_VERB_RECOVERY_RTS(session), WT_VERBOSE_DEBUG_2, - "%p: roll back %s page", (void *)ref, modified ? "modified" : "clean"); + WT_RTS_VERB_TAG_PAGE_ROLLBACK "roll back page, addr=%p modified=%s", (void *)ref, + modified ? "true" : "false"); switch (page->type) { case WT_PAGE_COL_FIX: diff --git a/src/third_party/wiredtiger/src/rollback_to_stable/rts_btree_walk.c b/src/third_party/wiredtiger/src/rollback_to_stable/rts_btree_walk.c index 7045e2d2950..c220c33b0d1 100644 --- a/src/third_party/wiredtiger/src/rollback_to_stable/rts_btree_walk.c +++ b/src/third_party/wiredtiger/src/rollback_to_stable/rts_btree_walk.c @@ -64,7 +64,7 @@ __rts_btree_walk_page_skip( if (page_del == NULL) __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session), - "%p: deleted page walk skipped", (void *)ref); + WT_RTS_VERB_TAG_SKIP_DEL_NULL "ref=%p: deleted page walk skipped", (void *)ref); else { __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session), "%p: deleted page walk skipped page_del %s", (void *)ref, @@ -90,8 +90,8 @@ __rts_btree_walk_page_skip( */ if (!__wt_rts_visibility_page_needs_abort(session, ref, rollback_timestamp)) { *skipp = true; - __wt_verbose_multi( - session, WT_VERB_RECOVERY_RTS(session), "%p: stable page walk skipped", (void *)ref); + __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session), + WT_RTS_VERB_TAG_STABLE_PG_WALK_SKIP "ref=%p: stable page walk skipped", (void *)ref); WT_STAT_CONN_INCR(session, txn_rts_tree_walk_skip_pages); } @@ -211,7 +211,7 @@ __wt_rts_btree_walk_btree_apply( F_ISSET(S2C(session), WT_CONN_CLOSING_CHECKPOINT)) && (addr_size == 0 || (rollback_timestamp == WT_TS_NONE && max_durable_ts != WT_TS_NONE))) { __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session), - "skip rollback to stable on file %s because %s", uri, + WT_RTS_VERB_TAG_FILE_SKIP "skip rollback to stable on file=%s because %s", uri, addr_size == 0 ? "its checkpoint address length is 0" : "it has timestamped updates and the stable timestamp is 0"); return (0); @@ -244,11 +244,10 @@ __wt_rts_btree_walk_btree_apply( dhandle_allocated = true; __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session), - "tree rolled back because it is modified: %s, or its durable timestamp (%s) > stable " - "timestamp (%s): " - "%s, or it has prepared updates: %s, or durable " - "timestamp is not found: %s, or txnid (%" PRIu64 - ") > recovery checkpoint snap min (%" PRIu64 "): %s", + WT_RTS_VERB_TAG_TREE + "tree rolled back. modified=%s, durable_timestamp=%s > stable_timestamp=%s: %s, " + "has_prepared_updates=%s, durable_timestamp_not_found=%s, txnid=%" PRIu64 + " > recovery_checkpoint_snap_min=%" PRIu64 ": %s", S2BT(session)->modified ? "true" : "false", __wt_timestamp_to_string(max_durable_ts, ts_string[0]), __wt_timestamp_to_string(rollback_timestamp, ts_string[1]), @@ -260,7 +259,8 @@ __wt_rts_btree_walk_btree_apply( WT_ERR(__wt_rts_btree_walk_btree(session, rollback_timestamp)); } else __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session), - "%s: tree skipped with durable timestamp: %s and stable timestamp: %s or txnid: %" PRIu64, + WT_RTS_VERB_TAG_TREE_SKIP + "%s: tree skipped with durable_timestamp=%s and stable_timestamp=%s or txnid=%" PRIu64, uri, __wt_timestamp_to_string(max_durable_ts, ts_string[0]), __wt_timestamp_to_string(rollback_timestamp, ts_string[1]), rollback_txnid); @@ -300,7 +300,8 @@ __wt_rts_btree_walk_btree(WT_SESSION_IMPL *session, wt_timestamp_t rollback_time conn = S2C(session); __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session), - "rollback to stable connection logging enabled: %s and btree logging enabled: %s", + WT_RTS_VERB_TAG_TREE_LOGGING + "rollback to stable connection_logging_enabled=%s and btree_logging_enabled=%s", FLD_ISSET(conn->log_flags, WT_CONN_LOG_ENABLED) ? "true" : "false", F_ISSET(btree, WT_BTREE_LOGGED) ? "true" : "false"); diff --git a/src/third_party/wiredtiger/src/rollback_to_stable/rts_history.c b/src/third_party/wiredtiger/src/rollback_to_stable/rts_history.c index d96d608fad0..5406b1f98dc 100644 --- a/src/third_party/wiredtiger/src/rollback_to_stable/rts_history.c +++ b/src/third_party/wiredtiger/src/rollback_to_stable/rts_history.c @@ -213,12 +213,13 @@ __wt_rts_history_final_pass(WT_SESSION_IMPL *session, wt_timestamp_t rollback_ti */ if (max_durable_ts > rollback_timestamp && rollback_timestamp != WT_TS_NONE) { __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session), - "tree rolled back with durable timestamp: %s", + WT_RTS_VERB_TAG_HS_TREE_ROLLBACK "tree rolled back with durable_timestamp=%s", __wt_timestamp_to_string(max_durable_ts, ts_string[0])); WT_TRET(__wt_rts_btree_walk_btree(session, rollback_timestamp)); } else __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session), - "tree skipped with durable timestamp: %s and stable timestamp: %s", + WT_RTS_VERB_TAG_HS_TREE_SKIP + "tree skipped with durable_timestamp=%s and stable_timestamp=%s", __wt_timestamp_to_string(max_durable_ts, ts_string[0]), __wt_timestamp_to_string(rollback_timestamp, ts_string[1])); diff --git a/src/third_party/wiredtiger/src/rollback_to_stable/rts_visibility.c b/src/third_party/wiredtiger/src/rollback_to_stable/rts_visibility.c index 11bd6ac7a5e..73fa073425e 100644 --- a/src/third_party/wiredtiger/src/rollback_to_stable/rts_visibility.c +++ b/src/third_party/wiredtiger/src/rollback_to_stable/rts_visibility.c @@ -147,8 +147,9 @@ __wt_rts_visibility_page_needs_abort( } __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session), - "%p: page with %s durable timestamp: %s, newest txn: %" PRIu64 - " and prepared updates: %s needs abort: %s", + WT_RTS_VERB_TAG_PAGE_ABORT_CHECK + "ref=%p: page with %s, durable_timestamp=%s, newest_txn=%" PRIu64 + ", prepared_updates=%s, needs_abort=%s", (void *)ref, tag, __wt_timestamp_to_string(durable_ts, ts_string), newest_txn, prepared ? "true" : "false", result ? "true" : "false"); diff --git a/src/third_party/wiredtiger/src/txn/txn.c b/src/third_party/wiredtiger/src/txn/txn.c index 9384e2dac50..fa79e58f288 100644 --- a/src/third_party/wiredtiger/src/txn/txn.c +++ b/src/third_party/wiredtiger/src/txn/txn.c @@ -2425,7 +2425,7 @@ __wt_txn_global_shutdown(WT_SESSION_IMPL *session, const char **cfg) */ if (use_timestamp) { __wt_verbose(session, WT_VERB_RTS, - "performing shutdown rollback to stable with stable timestamp: %s", + "[SHUTDOWN_INIT] performing shutdown rollback to stable, stable_timestamp=%s", __wt_timestamp_to_string(conn->txn_global.stable_timestamp, ts_string)); WT_TRET(conn->rts->rollback_to_stable(session, cfg, true)); } diff --git a/src/third_party/wiredtiger/src/txn/txn_recover.c b/src/third_party/wiredtiger/src/txn/txn_recover.c index 3e95d24e600..9ac6a18be08 100644 --- a/src/third_party/wiredtiger/src/txn/txn_recover.c +++ b/src/third_party/wiredtiger/src/txn/txn_recover.c @@ -1009,8 +1009,8 @@ done: __wt_verbose_multi(session, WT_DECL_VERBOSE_MULTI_CATEGORY(((WT_VERBOSE_CATEGORY[]){WT_VERB_RECOVERY, WT_VERB_RTS})), - "performing recovery rollback_to_stable with stable timestamp: %s and oldest timestamp: " - "%s", + "[RECOVERY_RTS] performing recovery rollback_to_stable with stable_timestamp=%s and " + "oldest_timestamp=%s", __wt_timestamp_to_string(conn->txn_global.stable_timestamp, ts_string[0]), __wt_timestamp_to_string(conn->txn_global.oldest_timestamp, ts_string[1])); rts_executed = true; diff --git a/src/third_party/wiredtiger/test/suite/rollback_to_stable_util.py b/src/third_party/wiredtiger/test/suite/rollback_to_stable_util.py new file mode 100644 index 00000000000..45399753785 --- /dev/null +++ b/src/third_party/wiredtiger/test/suite/rollback_to_stable_util.py @@ -0,0 +1,218 @@ +#!/usr/bin/env python +# +# Public Domain 2014-present MongoDB, Inc. +# Public Domain 2008-2014 WiredTiger, Inc. +# +# This is free and unencumbered software released into the public domain. +# +# Anyone is free to copy, modify, publish, use, compile, sell, or +# distribute this software, either in source code form or as a compiled +# binary, for any purpose, commercial or non-commercial, and by any +# means. +# +# In jurisdictions that recognize copyright laws, the author or authors +# of this software dedicate any and all copyright interest in the +# software to the public domain. We make this dedication for the benefit +# of the public at large and to the detriment of our heirs and +# successors. We intend this dedication to be an overt act of +# relinquishment in perpetuity of all present and future rights to this +# software under copyright law. +# +# THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, +# EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF +# MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. +# IN NO EVENT SHALL THE AUTHORS BE LIABLE FOR ANY CLAIM, DAMAGES OR +# OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, +# ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR +# OTHER DEALINGS IN THE SOFTWARE. + +import os, pathlib, subprocess, wiredtiger, wttest +from time import sleep +from wiredtiger import wiredtiger_strerror, WiredTigerError, WT_ROLLBACK +from wtscenario import make_scenarios + +def get_git_root(): + output = subprocess.run(["git", "rev-parse", "--show-toplevel"], check=True, capture_output=True) + return output.stdout.strip().decode("utf-8") + +def get_rts_verify_path(): + rel_path = os.path.join('tools', 'rts_verifier', 'rts_verify.py') + try: + root = get_git_root() + return os.path.join(root, rel_path) + except: + pass + + this_dir = pathlib.Path(__file__).parent.resolve() + return os.path.join(this_dir, '..', '..', rel_path) + +def verify_rts_logs(): + binary_path = get_rts_verify_path() + stdout_path = os.path.join(os.getcwd(), 'stdout.txt') + + if os.name == 'nt': + output = subprocess.run(['python.exe', binary_path, stdout_path]) + else: + output = subprocess.run([binary_path, stdout_path]) + + stderr = b'' if output.stderr is None else output.stderr + return (output.returncode, stderr.strip().decode('utf-8')) + +# test_rollback_to_stable_base.py +# Shared base class used by rollback to stable tests. +# +# Note: this class now expects self.value_format to have been set for some of the +# operations (those that need to specialize themselves for FLCS). +class test_rollback_to_stable_base(wttest.WiredTigerTestCase): + # Don't raise errors for these, the expectation is that the RTS verifier will + # run on the test output. + def __init__(self, *args, **kwargs): + super().__init__(*args, **kwargs) + self.ignoreStdoutPattern('WT_VERB_RTS') + self.addTearDownAction(verify_rts_logs) + + def retry_rollback(self, name, txn_session, code): + retry_limit = 100 + retries = 0 + completed = False + saved_exception = None + while not completed and retries < retry_limit: + if retries != 0: + self.pr("Retrying operation for " + name) + if txn_session: + txn_session.rollback_transaction() + sleep(0.1) + if txn_session: + txn_session.begin_transaction() + self.pr("Began new transaction for " + name) + try: + code() + completed = True + except WiredTigerError as e: + rollback_str = wiredtiger_strerror(WT_ROLLBACK) + if rollback_str not in str(e): + raise(e) + retries += 1 + saved_exception = e + if not completed and saved_exception: + raise(saved_exception) + + def large_updates(self, uri, value, ds, nrows, prepare, commit_ts): + # Update a large number of records. + session = self.session + try: + cursor = session.open_cursor(uri) + for i in range(1, nrows + 1): + if commit_ts == 0: + session.begin_transaction('no_timestamp=true') + else: + session.begin_transaction() + cursor[ds.key(i)] = value + if commit_ts == 0: + session.commit_transaction() + elif prepare: + session.prepare_transaction('prepare_timestamp=' + self.timestamp_str(commit_ts-1)) + session.timestamp_transaction('commit_timestamp=' + self.timestamp_str(commit_ts)) + session.timestamp_transaction('durable_timestamp=' + self.timestamp_str(commit_ts+1)) + session.commit_transaction() + else: + session.commit_transaction('commit_timestamp=' + self.timestamp_str(commit_ts)) + cursor.close() + except WiredTigerError as e: + rollback_str = wiredtiger_strerror(WT_ROLLBACK) + if rollback_str in str(e): + session.rollback_transaction() + raise(e) + + def large_modifies(self, uri, value, ds, location, nbytes, nrows, prepare, commit_ts): + # Load a slight modification. + session = self.session + try: + cursor = session.open_cursor(uri) + session.begin_transaction() + for i in range(1, nrows + 1): + cursor.set_key(i) + # FLCS doesn't support modify (for obvious reasons) so just update. + # Use the first character of the passed-in value. + if self.value_format == '8t': + cursor.set_value(bytes(value, encoding='utf-8')[0]) + self.assertEqual(cursor.update(), 0) + else: + mods = [wiredtiger.Modify(value, location, nbytes)] + self.assertEqual(cursor.modify(mods), 0) + + if commit_ts == 0: + session.commit_transaction() + elif prepare: + session.prepare_transaction('prepare_timestamp=' + self.timestamp_str(commit_ts-1)) + session.timestamp_transaction('commit_timestamp=' + self.timestamp_str(commit_ts)) + session.timestamp_transaction('durable_timestamp=' + self.timestamp_str(commit_ts+1)) + session.commit_transaction() + else: + session.commit_transaction('commit_timestamp=' + self.timestamp_str(commit_ts)) + cursor.close() + except WiredTigerError as e: + rollback_str = wiredtiger_strerror(WT_ROLLBACK) + if rollback_str in str(e): + session.rollback_transaction() + raise(e) + + def large_removes(self, uri, ds, nrows, prepare, commit_ts): + # Remove a large number of records. + session = self.session + try: + cursor = session.open_cursor(uri) + for i in range(1, nrows + 1): + session.begin_transaction() + cursor.set_key(i) + cursor.remove() + if commit_ts == 0: + session.commit_transaction() + elif prepare: + session.prepare_transaction('prepare_timestamp=' + self.timestamp_str(commit_ts-1)) + session.timestamp_transaction('commit_timestamp=' + self.timestamp_str(commit_ts)) + session.timestamp_transaction('durable_timestamp=' + self.timestamp_str(commit_ts+1)) + session.commit_transaction() + else: + session.commit_transaction('commit_timestamp=' + self.timestamp_str(commit_ts)) + cursor.close() + except WiredTigerError as e: + rollback_str = wiredtiger_strerror(WT_ROLLBACK) + if rollback_str in str(e): + session.rollback_transaction() + raise(e) + + def check(self, check_value, uri, nrows, flcs_extrarows, read_ts): + # In FLCS, deleted values read back as 0, and (at least for now) uncommitted appends + # cause zeros to appear under them. If flcs_extrarows isn't None, expect that many + # rows of zeros following the regular data. + flcs_tolerance = self.value_format == '8t' and flcs_extrarows is not None + + session = self.session + if read_ts == 0: + session.begin_transaction() + else: + session.begin_transaction('read_timestamp=' + self.timestamp_str(read_ts)) + cursor = session.open_cursor(uri) + count = 0 + for k, v in cursor: + if flcs_tolerance and count >= nrows: + self.assertEqual(v, 0) + else: + self.assertEqual(v, check_value) + count += 1 + session.commit_transaction() + self.assertEqual(count, nrows + flcs_extrarows if flcs_tolerance else nrows) + cursor.close() + + def evict_cursor(self, uri, nrows, check_value): + # Configure debug behavior on a cursor to evict the page positioned on when the reset API is used. + evict_cursor = self.session.open_cursor(uri, None, "debug=(release_evict)") + self.session.begin_transaction("ignore_prepare=true") + for i in range (1, nrows + 1): + evict_cursor.set_key(i) + self.assertEqual(evict_cursor[i], check_value) + if i % 10 == 0: + evict_cursor.reset() + evict_cursor.close() + self.session.rollback_transaction() diff --git a/src/third_party/wiredtiger/test/suite/test_prepare21.py b/src/third_party/wiredtiger/test/suite/test_prepare21.py index 5e4845d494d..83e4aff571a 100644 --- a/src/third_party/wiredtiger/test/suite/test_prepare21.py +++ b/src/third_party/wiredtiger/test/suite/test_prepare21.py @@ -27,7 +27,7 @@ # OTHER DEALINGS IN THE SOFTWARE. import threading -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base from wiredtiger import stat from wtdataset import SimpleDataSet from wtscenario import make_scenarios diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable01.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable01.py index 08b8623ce8e..9b7ec2cf8ae 100755 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable01.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable01.py @@ -27,166 +27,14 @@ # OTHER DEALINGS IN THE SOFTWARE. import wiredtiger, wttest +from rollback_to_stable_util import test_rollback_to_stable_base from wtdataset import SimpleDataSet -from wiredtiger import stat, wiredtiger_strerror, WiredTigerError, WT_ROLLBACK +from wiredtiger import stat from wtscenario import make_scenarios -from time import sleep # test_rollback_to_stable01.py -# Shared base class used by rollback to stable tests. -# -# Note: this class now expects self.value_format to have been set for some of the -# operations (those that need to specialize themselves for FLCS). -class test_rollback_to_stable_base(wttest.WiredTigerTestCase): - def retry_rollback(self, name, txn_session, code): - retry_limit = 100 - retries = 0 - completed = False - saved_exception = None - while not completed and retries < retry_limit: - if retries != 0: - self.pr("Retrying operation for " + name) - if txn_session: - txn_session.rollback_transaction() - sleep(0.1) - if txn_session: - txn_session.begin_transaction() - self.pr("Began new transaction for " + name) - try: - code() - completed = True - except WiredTigerError as e: - rollback_str = wiredtiger_strerror(WT_ROLLBACK) - if rollback_str not in str(e): - raise(e) - retries += 1 - saved_exception = e - if not completed and saved_exception: - raise(saved_exception) - - def large_updates(self, uri, value, ds, nrows, prepare, commit_ts): - # Update a large number of records. - session = self.session - try: - cursor = session.open_cursor(uri) - for i in range(1, nrows + 1): - if commit_ts == 0: - session.begin_transaction('no_timestamp=true') - else: - session.begin_transaction() - cursor[ds.key(i)] = value - if commit_ts == 0: - session.commit_transaction() - elif prepare: - session.prepare_transaction('prepare_timestamp=' + self.timestamp_str(commit_ts-1)) - session.timestamp_transaction('commit_timestamp=' + self.timestamp_str(commit_ts)) - session.timestamp_transaction('durable_timestamp=' + self.timestamp_str(commit_ts+1)) - session.commit_transaction() - else: - session.commit_transaction('commit_timestamp=' + self.timestamp_str(commit_ts)) - cursor.close() - except WiredTigerError as e: - rollback_str = wiredtiger_strerror(WT_ROLLBACK) - if rollback_str in str(e): - session.rollback_transaction() - raise(e) - - def large_modifies(self, uri, value, ds, location, nbytes, nrows, prepare, commit_ts): - # Load a slight modification. - session = self.session - try: - cursor = session.open_cursor(uri) - session.begin_transaction() - for i in range(1, nrows + 1): - cursor.set_key(i) - # FLCS doesn't support modify (for obvious reasons) so just update. - # Use the first character of the passed-in value. - if self.value_format == '8t': - cursor.set_value(bytes(value, encoding='utf-8')[0]) - self.assertEqual(cursor.update(), 0) - else: - mods = [wiredtiger.Modify(value, location, nbytes)] - self.assertEqual(cursor.modify(mods), 0) - - if commit_ts == 0: - session.commit_transaction() - elif prepare: - session.prepare_transaction('prepare_timestamp=' + self.timestamp_str(commit_ts-1)) - session.timestamp_transaction('commit_timestamp=' + self.timestamp_str(commit_ts)) - session.timestamp_transaction('durable_timestamp=' + self.timestamp_str(commit_ts+1)) - session.commit_transaction() - else: - session.commit_transaction('commit_timestamp=' + self.timestamp_str(commit_ts)) - cursor.close() - except WiredTigerError as e: - rollback_str = wiredtiger_strerror(WT_ROLLBACK) - if rollback_str in str(e): - session.rollback_transaction() - raise(e) - - def large_removes(self, uri, ds, nrows, prepare, commit_ts): - # Remove a large number of records. - session = self.session - try: - cursor = session.open_cursor(uri) - for i in range(1, nrows + 1): - session.begin_transaction() - cursor.set_key(i) - cursor.remove() - if commit_ts == 0: - session.commit_transaction() - elif prepare: - session.prepare_transaction('prepare_timestamp=' + self.timestamp_str(commit_ts-1)) - session.timestamp_transaction('commit_timestamp=' + self.timestamp_str(commit_ts)) - session.timestamp_transaction('durable_timestamp=' + self.timestamp_str(commit_ts+1)) - session.commit_transaction() - else: - session.commit_transaction('commit_timestamp=' + self.timestamp_str(commit_ts)) - cursor.close() - except WiredTigerError as e: - rollback_str = wiredtiger_strerror(WT_ROLLBACK) - if rollback_str in str(e): - session.rollback_transaction() - raise(e) - - def check(self, check_value, uri, nrows, flcs_extrarows, read_ts): - # In FLCS, deleted values read back as 0, and (at least for now) uncommitted appends - # cause zeros to appear under them. If flcs_extrarows isn't None, expect that many - # rows of zeros following the regular data. - flcs_tolerance = self.value_format == '8t' and flcs_extrarows is not None - - session = self.session - if read_ts == 0: - session.begin_transaction() - else: - session.begin_transaction('read_timestamp=' + self.timestamp_str(read_ts)) - cursor = session.open_cursor(uri) - count = 0 - for k, v in cursor: - if flcs_tolerance and count >= nrows: - self.assertEqual(v, 0) - else: - self.assertEqual(v, check_value) - count += 1 - session.commit_transaction() - self.assertEqual(count, nrows + flcs_extrarows if flcs_tolerance else nrows) - cursor.close() - - def evict_cursor(self, uri, nrows, check_value): - # Configure debug behavior on a cursor to evict the page positioned on when the reset API is used. - evict_cursor = self.session.open_cursor(uri, None, "debug=(release_evict)") - self.session.begin_transaction("ignore_prepare=true") - for i in range (1, nrows + 1): - evict_cursor.set_key(i) - self.assertEqual(evict_cursor[i], check_value) - if i % 10 == 0: - evict_cursor.reset() - evict_cursor.close() - self.session.rollback_transaction() - # Test that rollback to stable clears the remove operation. class test_rollback_to_stable01(test_rollback_to_stable_base): - format_values = [ ('column', dict(key_format='r', value_format='S')), ('column_fix', dict(key_format='r', value_format='8t')), @@ -211,7 +59,7 @@ class test_rollback_to_stable01(test_rollback_to_stable_base): scenarios = make_scenarios(format_values, in_memory_values, prepare_values, dryrun_values) def conn_config(self): - config = 'cache_size=50MB,statistics=(all)' + config = 'cache_size=50MB,statistics=(all),verbose=(rts:5)' if self.in_memory: config += ',in_memory=true' return config diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable02.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable02.py index 1cd327e5373..23f9b28e9e9 100755 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable02.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable02.py @@ -30,7 +30,7 @@ import wttest from wtdataset import SimpleDataSet from wiredtiger import stat from wtscenario import make_scenarios -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base # test_rollback_to_stable02.py # Test that rollback to stable brings back the history value to replace on-disk value. @@ -70,7 +70,7 @@ class test_rollback_to_stable02(test_rollback_to_stable_base): scenarios = make_scenarios(format_values, in_memory_values, prepare_values, dryrun_values) def conn_config(self): - config = 'cache_size=100MB,statistics=(all)' + config = 'cache_size=100MB,statistics=(all),verbose=(rts:5)' if self.in_memory: config += ',in_memory=true' return config diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable03.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable03.py index f0792af8b22..2e3a2242b93 100755 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable03.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable03.py @@ -30,11 +30,11 @@ import wttest from wtdataset import SimpleDataSet from wiredtiger import stat from wtscenario import make_scenarios -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base # test_rollback_to_stable03.py # Test that rollback to stable clears the history store updates from reconciled pages. -class test_rollback_to_stable01(test_rollback_to_stable_base): +class test_rollback_to_stable03(test_rollback_to_stable_base): format_values = [ ('column', dict(key_format='r', value_format='S')), @@ -55,7 +55,7 @@ class test_rollback_to_stable01(test_rollback_to_stable_base): scenarios = make_scenarios(format_values, in_memory_values, prepare_values) def conn_config(self): - config = 'cache_size=4GB,statistics=(all)' + config = 'cache_size=4GB,statistics=(all),verbose=(rts:5)' if self.in_memory: config += ',in_memory=true' return config diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable04.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable04.py index be75d500684..658df6361aa 100755 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable04.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable04.py @@ -29,7 +29,7 @@ from wiredtiger import stat from wtdataset import SimpleDataSet from wtscenario import make_scenarios -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base def mod_val(value, char, location, nbytes=1): return value[0:location] + char + value[location+nbytes:] @@ -63,7 +63,7 @@ class test_rollback_to_stable04(test_rollback_to_stable_base): scenarios = make_scenarios(format_values, in_memory_values, prepare_values, dryrun_values) def conn_config(self): - config = 'cache_size=500MB,statistics=(all)' + config = 'cache_size=500MB,statistics=(all),verbose=(rts:5)' if self.in_memory: config += ',in_memory=true' return config diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable05.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable05.py index f1e3c74b448..c6301f36ad5 100755 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable05.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable05.py @@ -30,7 +30,7 @@ import wttest from wtdataset import SimpleDataSet from wiredtiger import stat from wtscenario import make_scenarios -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base # test_rollback_to_stable05.py # Test that rollback to stable cleans history store for non-timestamp tables. @@ -55,7 +55,7 @@ class test_rollback_to_stable05(test_rollback_to_stable_base): scenarios = make_scenarios(format_values, in_memory_values, prepare_values) def conn_config(self): - config = 'cache_size=50MB,statistics=(all)' + config = 'cache_size=50MB,statistics=(all),verbose=(rts:5)' if self.in_memory: config += ',in_memory=true' return config diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable06.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable06.py index 38f1661166f..8d0a6962f61 100755 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable06.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable06.py @@ -29,7 +29,7 @@ from wiredtiger import stat from wtdataset import SimpleDataSet from wtscenario import make_scenarios -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base # test_rollback_to_stable06.py # Test that rollback to stable removes all keys when the stable timestamp is earlier than @@ -55,7 +55,7 @@ class test_rollback_to_stable06(test_rollback_to_stable_base): scenarios = make_scenarios(format_values, in_memory_values, prepare_values) def conn_config(self): - config = 'cache_size=50MB,statistics=(all)' + config = 'cache_size=50MB,statistics=(all),verbose=(rts:5)' if self.in_memory: config += ',in_memory=true' return config diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable07.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable07.py index f54f01b8858..de8a90aaf6e 100755 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable07.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable07.py @@ -27,7 +27,7 @@ # OTHER DEALINGS IN THE SOFTWARE. from helper import simulate_crash_restart -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base from wiredtiger import stat from wtdataset import SimpleDataSet from wtscenario import make_scenarios @@ -53,7 +53,7 @@ class test_rollback_to_stable07(test_rollback_to_stable_base): scenarios = make_scenarios(format_values, prepare_values) def conn_config(self): - config = 'cache_size=5MB,statistics=(all)' + config = 'cache_size=5MB,statistics=(all),verbose=(rts:5)' return config def test_rollback_to_stable(self): diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable08.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable08.py index 736670e12cf..a0f9adee447 100755 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable08.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable08.py @@ -29,7 +29,7 @@ from wiredtiger import stat from wtdataset import SimpleDataSet from wtscenario import make_scenarios -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base # test_rollback_to_stable08.py # Test that rollback to stable does not abort updates when the stable timestamp is @@ -55,7 +55,7 @@ class test_rollback_to_stable08(test_rollback_to_stable_base): scenarios = make_scenarios(format_values, in_memory_values, prepare_values) def conn_config(self): - config = 'cache_size=50MB,statistics=(all)' + config = 'cache_size=50MB,statistics=(all),verbose=(rts:5)' if self.in_memory: config += ',in_memory=true' return config diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable09.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable09.py index 69dc6e23f46..1533b9ea26b 100755 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable09.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable09.py @@ -29,7 +29,7 @@ import os import wiredtiger from wtscenario import make_scenarios -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base # test_rollback_to_stable09.py # Test that rollback to stable does not abort schema operations that are done @@ -60,7 +60,7 @@ class test_rollback_to_stable09(test_rollback_to_stable_base): scenarios = make_scenarios(colstore_values, in_memory_values, prepare_values) def conn_config(self): - config = 'cache_size=250MB' + config = 'cache_size=250MB,verbose=(rts:5)' if self.in_memory: config += ',in_memory=true' return config diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable10.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable10.py index dab9b579a1e..f8f9a91ddae 100755 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable10.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable10.py @@ -28,7 +28,7 @@ import threading, time from helper import copy_wiredtiger_home, simulate_crash_restart -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base from wiredtiger import stat from wtdataset import SimpleDataSet from wtscenario import make_scenarios @@ -53,7 +53,7 @@ class test_rollback_to_stable10(test_rollback_to_stable_base): scenarios = make_scenarios(format_values, prepare_values) def conn_config(self): - config = 'cache_size=25MB,statistics=(all),statistics_log=(json,on_close,wait=1),timing_stress_for_test=[history_store_checkpoint_delay]' + config = 'cache_size=25MB,statistics=(all),statistics_log=(json,on_close,wait=1),timing_stress_for_test=[history_store_checkpoint_delay],verbose=(rts:5)' return config def test_rollback_to_stable(self): diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable11.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable11.py index 9667820c282..ebff70e9b7f 100755 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable11.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable11.py @@ -27,7 +27,7 @@ # OTHER DEALINGS IN THE SOFTWARE. from helper import simulate_crash_restart -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base from wiredtiger import stat from wtdataset import SimpleDataSet from wtscenario import make_scenarios @@ -50,7 +50,7 @@ class test_rollback_to_stable11(test_rollback_to_stable_base): scenarios = make_scenarios(format_values, prepare_values) def conn_config(self): - config = 'cache_size=1MB,statistics=(all)' + config = 'cache_size=1MB,statistics=(all),verbose=(rts:5)' return config def test_rollback_to_stable(self): diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable12.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable12.py index 31b27b9e22e..9e226281807 100755 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable12.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable12.py @@ -27,7 +27,7 @@ # OTHER DEALINGS IN THE SOFTWARE. from helper import simulate_crash_restart -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base from wiredtiger import stat from wtdataset import SimpleDataSet from wtscenario import make_scenarios @@ -56,7 +56,7 @@ class test_rollback_to_stable12(test_rollback_to_stable_base): scenarios = make_scenarios(format_values, prepare_values) def conn_config(self): - config = 'cache_size=500MB,statistics=(all)' + config = 'cache_size=500MB,statistics=(all),verbose=(rts:5)' return config def test_rollback_to_stable(self): diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable13.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable13.py index be295341f56..aeecb132841 100755 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable13.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable13.py @@ -27,7 +27,7 @@ # OTHER DEALINGS IN THE SOFTWARE. import wttest from helper import simulate_crash_restart -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base from wiredtiger import stat from wtdataset import SimpleDataSet from wtscenario import make_scenarios @@ -56,7 +56,7 @@ class test_rollback_to_stable13(test_rollback_to_stable_base): scenarios = make_scenarios(format_values, prepare_values, dryrun_values) def conn_config(self): - config = 'cache_size=50MB,statistics=(all)' + config = 'cache_size=50MB,statistics=(all),verbose=(rts:5)' return config @wttest.prevent(["timestamp"]) # prevent the use of hooks that manage timestamps diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable14.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable14.py index 289f9ffc5fe..07bb56e851e 100755 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable14.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable14.py @@ -28,7 +28,7 @@ import threading, time from helper import simulate_crash_restart -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base from wiredtiger import stat from wtdataset import SimpleDataSet from wtscenario import make_scenarios @@ -60,7 +60,7 @@ class test_rollback_to_stable14(test_rollback_to_stable_base): scenarios = make_scenarios(key_format_values, prepare_values) def conn_config(self): - config = 'cache_size=25MB,statistics=(all),statistics_log=(json,on_close,wait=1),timing_stress_for_test=[history_store_checkpoint_delay]' + config = 'cache_size=25MB,statistics=(all),statistics_log=(json,on_close,wait=1),timing_stress_for_test=[history_store_checkpoint_delay],verbose=(rts:5)' return config def test_rollback_to_stable(self): diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable15.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable15.py index 89afb56895e..183f98ae49e 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable15.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable15.py @@ -27,6 +27,7 @@ # OTHER DEALINGS IN THE SOFTWARE. import wttest +from rollback_to_stable_util import verify_rts_logs from wiredtiger import stat from wtscenario import make_scenarios @@ -51,8 +52,15 @@ class test_rollback_to_stable15(wttest.WiredTigerTestCase): ] scenarios = make_scenarios(key_format_values, value_format_values, in_memory_values) + # Don't raise errors for these, the expectation is that the RTS verifier will + # run on the test output. + def __init__(self, *args, **kwargs): + super().__init__(*args, **kwargs) + self.ignoreStdoutPattern('WT_VERB_RTS') + self.addTearDownAction(verify_rts_logs) + def conn_config(self): - config = 'cache_size=200MB,statistics=(all),debug_mode=(eviction=false)' + config = 'cache_size=200MB,statistics=(all),debug_mode=(eviction=false),verbose=(rts:5)' if self.in_memory: config += ',in_memory=true' return config diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable16.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable16.py index 8b47b221d6e..4ba1b609bb0 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable16.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable16.py @@ -31,6 +31,7 @@ # [END_TAGS] from helper import simulate_crash_restart +from rollback_to_stable_util import verify_rts_logs import wiredtiger, wttest from wiredtiger import stat from wtscenario import make_scenarios @@ -66,8 +67,15 @@ class test_rollback_to_stable16(wttest.WiredTigerTestCase): scenarios = make_scenarios(key_format_values, value_format_values, in_memory_values, include=keep) + # Don't raise errors for these, the expectation is that the RTS verifier will + # run on the test output. + def __init__(self, *args, **kwargs): + super().__init__(*args, **kwargs) + self.ignoreStdoutPattern('WT_VERB_RTS') + self.addTearDownAction(verify_rts_logs) + def conn_config(self): - config = 'cache_size=200MB,statistics=(all)' + config = 'cache_size=200MB,statistics=(all),verbose=(rts:5)' if self.in_memory: config += ',in_memory=true' else: diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable17.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable17.py index 6d024785ab3..f3d819bc1b1 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable17.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable17.py @@ -27,6 +27,7 @@ # OTHER DEALINGS IN THE SOFTWARE. from helper import simulate_crash_restart +from rollback_to_stable_util import verify_rts_logs import wttest from wiredtiger import stat from wtscenario import make_scenarios @@ -48,8 +49,13 @@ class test_rollback_to_stable17(wttest.WiredTigerTestCase): scenarios = make_scenarios(format_values, in_memory_values) + def __init__(self, *args, **kwargs): + super().__init__(*args, **kwargs) + self.ignoreStdoutPattern('WT_VERB_RTS') + self.addTearDownAction(verify_rts_logs) + def conn_config(self): - config = 'cache_size=200MB,statistics=(all)' + config = 'cache_size=200MB,statistics=(all),verbose=(rts:5)' if self.in_memory: config += ',in_memory=true' return config diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable18.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable18.py index 8c53e989091..2b993156fcf 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable18.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable18.py @@ -31,7 +31,7 @@ # aggregated_time_windows # [END_TAGS] -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base from wiredtiger import stat from wtdataset import SimpleDataSet from wtscenario import make_scenarios @@ -55,7 +55,7 @@ class test_rollback_to_stable18(test_rollback_to_stable_base): def conn_config(self): config = 'cache_size=50MB,in_memory=true,statistics=(all),' \ - 'eviction_dirty_trigger=10,eviction_updates_trigger=10' + 'eviction_dirty_trigger=10,eviction_updates_trigger=10,verbose=(rts:5)' return config def test_rollback_to_stable(self): diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable19.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable19.py index 0861b6020f4..d29702d7823 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable19.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable19.py @@ -27,7 +27,7 @@ # OTHER DEALINGS IN THE SOFTWARE. from helper import simulate_crash_restart -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base from wiredtiger import stat, WT_NOTFOUND from wtdataset import SimpleDataSet from wtscenario import make_scenarios @@ -56,7 +56,7 @@ class test_rollback_to_stable19(test_rollback_to_stable_base): def conn_config(self): config = 'cache_size=50MB,statistics=(all),eviction_dirty_trigger=10,' \ - 'eviction_updates_trigger=10' + 'eviction_updates_trigger=10,verbose=(rts:5)' if self.in_memory: config += ',in_memory=true' return config diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable20.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable20.py index ee15849cc5c..e20f00ffe55 100755 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable20.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable20.py @@ -31,7 +31,7 @@ from wtdataset import SimpleDataSet from wtscenario import make_scenarios from wiredtiger import stat from helper import simulate_crash_restart -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base # Test that rollback to stable does not open any dhandles that don't have unstable updates. class test_rollback_to_stable20(test_rollback_to_stable_base): @@ -45,7 +45,7 @@ class test_rollback_to_stable20(test_rollback_to_stable_base): scenarios = make_scenarios(format_values) def conn_config(self): - config = 'cache_size=50MB,statistics=(all)' + config = 'cache_size=50MB,statistics=(all),verbose=(rts:5)' return config def test_rollback_to_stable(self): diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable22.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable22.py index 02fc9cca4e7..b2c382534c0 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable22.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable22.py @@ -26,7 +26,7 @@ # ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR # OTHER DEALINGS IN THE SOFTWARE. -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base from wtdataset import SimpleDataSet # test_rollback_to_stable22 @@ -39,7 +39,7 @@ from wtdataset import SimpleDataSet # history store itself is always row-store) so it doesn't seem necessary or worthwhile to run # this explicitly on VLCS or FLCS. class test_rollback_to_stable22(test_rollback_to_stable_base): - conn_config = 'cache_size=100MB' + conn_config = 'cache_size=100MB,verbose=(rts:5)' prepare = False def test_rollback_to_stable(self): diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable23.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable23.py index d787e2daeaf..bd680aa51e2 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable23.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable23.py @@ -27,7 +27,7 @@ # OTHER DEALINGS IN THE SOFTWARE. from helper import simulate_crash_restart -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base from wiredtiger import stat from wtdataset import SimpleDataSet from wtscenario import make_scenarios @@ -56,7 +56,7 @@ class test_rollback_to_stable23(test_rollback_to_stable_base): scenarios = make_scenarios(key_format_values, prepare_values) def conn_config(self): - config = 'cache_size=50MB,statistics=(all),statistics_log=(json,on_close,wait=1)' + config = 'cache_size=50MB,statistics=(all),statistics_log=(json,on_close,wait=1),verbose=(rts:5)' return config def check_with_set_key(self, ds, check_value, uri, nrows, read_ts): diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable24.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable24.py index d6be8a24e76..aca60b20d02 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable24.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable24.py @@ -26,6 +26,7 @@ # ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR # OTHER DEALINGS IN THE SOFTWARE. +from rollback_to_stable_util import verify_rts_logs import wttest from wtscenario import make_scenarios @@ -69,6 +70,14 @@ class test_rollback_to_stable24(wttest.WiredTigerTestCase): scenarios = make_scenarios(key_format_values) + def __init__(self, *args, **kwargs): + super().__init__(*args, **kwargs) + self.ignoreStdoutPattern('WT_VERB_RTS') + self.addTearDownAction(verify_rts_logs) + + def conn_config(self): + return 'verbose=(rts:5)' + def test_rollback_to_stable24(self): # Create a table without logging. uri = "table:rollback_to_stable24" diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable25.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable25.py index 5e25d2b8cb4..64842b789d7 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable25.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable25.py @@ -26,6 +26,7 @@ # ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR # OTHER DEALINGS IN THE SOFTWARE. +from rollback_to_stable_util import verify_rts_logs import wiredtiger, wttest from wtscenario import make_scenarios, filter_scenarios @@ -64,7 +65,13 @@ def keys_of_write(write): return [2 + my_rle_size - 1] class test_rollback_to_stable25(wttest.WiredTigerTestCase): - conn_config = 'in_memory=false' + def __init__(self, *args, **kwargs): + super().__init__(*args, **kwargs) + self.ignoreStdoutPattern('WT_VERB_RTS') + self.addTearDownAction(verify_rts_logs) + + def conn_config(self): + return 'in_memory=false,verbose=(rts:5)' write_10_values = [ ('10u', dict(write_10='u')), diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable26.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable26.py index 12da956d2b0..13ebf9ffe2e 100755 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable26.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable26.py @@ -28,7 +28,7 @@ import threading, time from helper import simulate_crash_restart -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base from wiredtiger import stat from wtdataset import SimpleDataSet from wtscenario import make_scenarios @@ -63,7 +63,7 @@ class test_rollback_to_stable26(test_rollback_to_stable_base): scenarios = make_scenarios(format_values, hs_remove_values, prepare_values, prepare_remove_values) def conn_config(self): - config = 'cache_size=10MB,statistics=(all),timing_stress_for_test=[history_store_checkpoint_delay]' + config = 'cache_size=10MB,statistics=(all),timing_stress_for_test=[history_store_checkpoint_delay],verbose=(rts:5)' return config def evict_cursor(self, uri, nrows): diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable27.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable27.py index 1ae240919de..7a135706abe 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable27.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable27.py @@ -26,7 +26,7 @@ # ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR # OTHER DEALINGS IN THE SOFTWARE. -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base from wtdataset import SimpleDataSet from wtscenario import make_scenarios @@ -50,9 +50,10 @@ class test_rollback_to_stable27(test_rollback_to_stable_base): scenarios = make_scenarios(key_format_values, in_memory_values) def conn_config(self): + config = 'verbose=(rts:5)' if self.in_memory: - return 'in_memory=true' - return '' + config += ',in_memory=true' + return config # Evict the page to force reconciliation. def evict(self, uri, key, check_value): diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable28.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable28.py index faeb49a4714..215bc62a71f 100755 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable28.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable28.py @@ -31,7 +31,7 @@ from wiredtiger import stat from wtdataset import SimpleDataSet from wtscenario import make_scenarios from helper import simulate_crash_restart -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base # test_rollback_to_stable28.py # Test the debug mode setting for update_restore_evict during recovery. @@ -40,7 +40,7 @@ from test_rollback_to_stable01 import test_rollback_to_stable_base # the proper write generation number and we don't end up reading stale # transaction ID's stored on the page. class test_rollback_to_stable28(test_rollback_to_stable_base): - conn_config = 'statistics=(all)' + conn_config = 'statistics=(all),verbose=(rts:5)' # Recovery connection config: The debug mode is only effective on high cache pressure as WiredTiger can potentially decide # to do an update restore evict on a page when the cache pressure requirements are not met. # This means setting eviction target low and cache size low. diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable29.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable29.py index e776ef9ddc6..e1c5a0544d1 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable29.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable29.py @@ -30,13 +30,13 @@ from wiredtiger import stat from wtdataset import SimpleDataSet from wtscenario import make_scenarios from helper import simulate_crash_restart -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base # test_rollback_to_stable29.py # Test that the rollback to stable to verify the history store order when an update without a # timestamp inserted to a tombstone. class test_rollback_to_stable29(test_rollback_to_stable_base): - conn_config = 'cache_size=5MB,statistics=(all),statistics_log=(json,on_close,wait=1),log=(enabled=true)' + conn_config = 'cache_size=5MB,statistics=(all),statistics_log=(json,on_close,wait=1),log=(enabled=true),verbose=(rts:5)' format_values = [ ('column', dict(key_format='r', value_format='S')), diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable30.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable30.py index 87202e46dfb..803a408ab96 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable30.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable30.py @@ -26,6 +26,7 @@ # ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR # OTHER DEALINGS IN THE SOFTWARE. +from rollback_to_stable_util import verify_rts_logs import wiredtiger, wttest from wtdataset import SimpleDataSet, ComplexDataSet from wtscenario import make_scenarios @@ -41,6 +42,16 @@ class test_rollback_to_stable30(wttest.WiredTigerTestCase): ('table-S-complex', dict(keyfmt='S', valfmt=None, dataset=ComplexDataSet)), ]) + # Don't raise errors for these, the expectation is that the RTS verifier will + # run on the test output. + def __init__(self, *args, **kwargs): + super().__init__(*args, **kwargs) + self.ignoreStdoutPattern('WT_VERB_RTS') + self.addTearDownAction(verify_rts_logs) + + def conn_config(self): + return 'verbose=(rts:5)' + def prepare_resolve(self, resolve): ds = self.dataset(self, "table:rts30", 10, key_format=self.keyfmt, value_format=self.valfmt) ds.populate() diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable31.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable31.py index 6c7b3570aca..27312822567 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable31.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable31.py @@ -26,7 +26,7 @@ # ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR # OTHER DEALINGS IN THE SOFTWARE. -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base from helper import simulate_crash_restart from wtdataset import SimpleDataSet from wtscenario import make_scenarios @@ -52,6 +52,9 @@ class test_rollback_to_stable31(test_rollback_to_stable_base): scenarios = make_scenarios(format_values, checkpoint_modes, rollback_modes) + def conn_config(self): + return 'verbose=(rts:5)' + def test_rollback_to_stable(self): nrows = 10 diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable32.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable32.py index 90371f1aefb..358fbb625f5 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable32.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable32.py @@ -25,7 +25,7 @@ # OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, # ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR # OTHER DEALINGS IN THE SOFTWARE. -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base from wtdataset import SimpleDataSet from wtscenario import make_scenarios @@ -48,7 +48,7 @@ class test_rollback_to_stable32(test_rollback_to_stable_base): scenarios = make_scenarios(format_values, prepare_values) def conn_config(self): - config = 'cache_size=100MB,statistics=(all)' + config = 'cache_size=100MB,statistics=(all),verbose=(rts:5)' return config def test_rollback_to_stable_with_update_restore_evict(self): diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable33.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable33.py index e037e333f07..30f21be38a2 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable33.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable33.py @@ -26,6 +26,7 @@ # ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR # OTHER DEALINGS IN THE SOFTWARE. +from rollback_to_stable_util import verify_rts_logs import wttest from wtdataset import SimpleDataSet from wtscenario import make_scenarios @@ -44,7 +45,14 @@ class test_rollback_to_stable33(wttest.WiredTigerTestCase): scenarios = make_scenarios(format_values, logged) # Configure an in-memory database. - conn_config = 'in_memory=true' + conn_config = 'in_memory=true,verbose=(rts:5)' + + # Don't raise errors for these, the expectation is that the RTS verifier will + # run on the test output. + def __init__(self, *args, **kwargs): + super().__init__(*args, **kwargs) + self.ignoreStdoutPattern('WT_VERB_RTS') + self.addTearDownAction(verify_rts_logs) # Smoke test RTS on in-memory databases. def test_rollback_to_stable33(self): diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable34.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable34.py index cd564dff6ea..4fe6391d0ec 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable34.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable34.py @@ -27,7 +27,7 @@ # OTHER DEALINGS IN THE SOFTWARE. from helper import simulate_crash_restart -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base from wiredtiger import stat from wtdataset import SimpleDataSet from wtscenario import make_scenarios @@ -36,7 +36,7 @@ from wtscenario import make_scenarios # Test interaction between fast-delete and RTS. class test_rollback_to_stable34(test_rollback_to_stable_base): session_config = 'isolation=snapshot' - conn_config = 'cache_size=50MB,statistics=(all),log=(enabled=false)' + conn_config = 'cache_size=50MB,statistics=(all),log=(enabled=false),verbose=(rts:5)' format_values = [ ('column', dict(key_format='r', value_format='S', extraconfig='')), diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable35.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable35.py index eb07370513b..434f7f73844 100755 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable35.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable35.py @@ -32,7 +32,7 @@ from wtthread import checkpoint_thread from wiredtiger import stat from helper import copy_wiredtiger_home from wtscenario import make_scenarios -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base # test_rollback_to_stable35.py # Test that log is flushed for all writes that occurred in the checkpoint. @@ -79,7 +79,7 @@ class test_rollback_to_stable35(test_rollback_to_stable_base): cursor_2.close() def conn_config(self): - config = 'cache_size=50MB,statistics=(all),log=(enabled,force_write_wait=60),timing_stress_for_test=[checkpoint_slow, checkpoint_stop]' + config = 'cache_size=50MB,statistics=(all),log=(enabled,force_write_wait=60),timing_stress_for_test=[checkpoint_slow, checkpoint_stop],verbose=(rts:5)' return config def test_rollback_to_stable(self): diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable36.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable36.py index 5cdfc85ced1..eb1e5df0c62 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable36.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable36.py @@ -28,6 +28,7 @@ import wttest from helper import simulate_crash_restart +from rollback_to_stable_util import verify_rts_logs from wiredtiger import stat, WiredTigerError, wiredtiger_strerror, WT_ROLLBACK from wtdataset import SimpleDataSet from wtscenario import make_scenarios @@ -38,7 +39,7 @@ from wtscenario import make_scenarios # everything else on the page is. class test_rollback_to_stable36(wttest.WiredTigerTestCase): - conn_config = 'statistics=(all)' + conn_config = 'statistics=(all),verbose=(rts:5)' session_config = 'isolation=snapshot' # Hook to run using remove instead of truncate for reference. This should not alter the @@ -61,6 +62,13 @@ class test_rollback_to_stable36(wttest.WiredTigerTestCase): ] scenarios = make_scenarios(trunc_values, format_values, rollback_modes) + # Don't raise errors for these, the expectation is that the RTS verifier will + # run on the test output. + def __init__(self, *args, **kwargs): + super().__init__(*args, **kwargs) + self.ignoreStdoutPattern('WT_VERB_RTS') + self.addTearDownAction(verify_rts_logs) + def truncate(self, uri, make_key, keynum1, keynum2): if self.trunc_with_remove: cursor = self.session.open_cursor(uri) diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable37.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable37.py index fa4a8796290..526ea0c342d 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable37.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable37.py @@ -29,13 +29,13 @@ from wiredtiger import stat from wtdataset import SimpleDataSet from wtscenario import make_scenarios -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base # test_rollback_to_stable37.py # Test that the rollback to stable to restore proper stable update from history store when a no timestamp # update has rewritten the history store data. class test_rollback_to_stable37(test_rollback_to_stable_base): - conn_config = 'cache_size=1GB,statistics=(all),statistics_log=(json,on_close,wait=1),log=(enabled=false)' + conn_config = 'cache_size=1GB,statistics=(all),statistics_log=(json,on_close,wait=1),log=(enabled=false),verbose=(rts:5)' format_values = [ ('column', dict(key_format='r', value_format='S')), diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable38.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable38.py index 404a01e075e..c369f139137 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable38.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable38.py @@ -28,6 +28,7 @@ import wttest from helper import simulate_crash_restart +from rollback_to_stable_util import verify_rts_logs from wiredtiger import stat from wtdataset import SimpleDataSet from wtscenario import make_scenarios @@ -37,7 +38,7 @@ from wtscenario import make_scenarios # Test using fast truncate to delete the whole tree of records from the history store class test_rollback_to_stable38(wttest.WiredTigerTestCase): - conn_config = 'statistics=(all),cache_size=50MB' + conn_config = 'statistics=(all),cache_size=50MB,verbose=(rts:5)' session_config = 'isolation=snapshot' format_values = [ @@ -48,6 +49,13 @@ class test_rollback_to_stable38(wttest.WiredTigerTestCase): ] scenarios = make_scenarios(format_values) + # Don't raise errors for these, the expectation is that the RTS verifier will + # run on the test output. + def __init__(self, *args, **kwargs): + super().__init__(*args, **kwargs) + self.ignoreStdoutPattern('WT_VERB_RTS') + self.addTearDownAction(verify_rts_logs) + def check(self, ds, value, nrows, ts): cursor = self.session.open_cursor(ds.uri) self.session.begin_transaction('read_timestamp=' + self.timestamp_str(ts)) diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable39.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable39.py index 90bf63935da..34cdf197c8d 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable39.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable39.py @@ -27,7 +27,7 @@ # OTHER DEALINGS IN THE SOFTWARE. import threading, time from helper import simulate_crash_restart -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base from wiredtiger import stat from wtdataset import SimpleDataSet from wtscenario import make_scenarios @@ -55,7 +55,7 @@ class test_rollback_to_stable39(test_rollback_to_stable_base): scenarios = make_scenarios(format_values, prepare_values) def conn_config(self): - config = 'cache_size=25MB,statistics=(all),statistics_log=(json,on_close,wait=1)' + config = 'cache_size=25MB,statistics=(all),statistics_log=(json,on_close,wait=1),verbose=(rts:5)' if self.restart_config: config += ',timing_stress_for_test=[checkpoint_slow]' else: diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable40.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable40.py index 52a7c18d8bf..ccb495b28fc 100755 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable40.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable40.py @@ -27,7 +27,7 @@ # OTHER DEALINGS IN THE SOFTWARE. from helper import simulate_crash_restart -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base from wiredtiger import stat from wtdataset import SimpleDataSet from wtscenario import make_scenarios @@ -47,7 +47,7 @@ class test_rollback_to_stable40(test_rollback_to_stable_base): scenarios = make_scenarios(key_format_values) def conn_config(self): - config = 'cache_size=1MB,statistics=(all),log=(enabled=true)' + config = 'cache_size=1MB,statistics=(all),log=(enabled=true),verbose=(rts:5)' return config def test_rollback_to_stable(self): diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable41.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable41.py index 6c6abdf861a..2866025332b 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable41.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable41.py @@ -28,7 +28,7 @@ from wtdataset import SimpleDataSet from wtscenario import make_scenarios -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base # test_rollback_to_stable41.py # Test that the dry-run config for RTS only applies to a single call. @@ -41,6 +41,9 @@ class test_rollback_to_stable41(test_rollback_to_stable_base): scenarios = make_scenarios(format_values) + def conn_config(self): + return 'verbose=(rts:5)' + def test_rollback_to_stable(self): uri = 'table:test_rollback_to_stable41' nrows = 1000 diff --git a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable42.py b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable42.py index eb3b6ebf772..88d4a3842ea 100644 --- a/src/third_party/wiredtiger/test/suite/test_rollback_to_stable42.py +++ b/src/third_party/wiredtiger/test/suite/test_rollback_to_stable42.py @@ -38,7 +38,7 @@ from test_rollback_to_stable01 import test_rollback_to_stable_base # unacceptable or we don't see the needle at all. def custom_validator(data): acceptable = [ - "connection logging enabled", + "connection_logging_enabled", "deleted page walk skipped", "page with reconciled", "performing recovery rollback", diff --git a/src/third_party/wiredtiger/test/suite/test_truncate13.py b/src/third_party/wiredtiger/test/suite/test_truncate13.py index dcc284c36d2..0e74f17ebb9 100644 --- a/src/third_party/wiredtiger/test/suite/test_truncate13.py +++ b/src/third_party/wiredtiger/test/suite/test_truncate13.py @@ -27,7 +27,7 @@ # OTHER DEALINGS IN THE SOFTWARE. import wttest -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base from wiredtiger import stat from wtdataset import SimpleDataSet from wtscenario import make_scenarios diff --git a/src/third_party/wiredtiger/test/suite/test_truncate14.py b/src/third_party/wiredtiger/test/suite/test_truncate14.py index 90d3a9b1bd0..ec882aa6606 100644 --- a/src/third_party/wiredtiger/test/suite/test_truncate14.py +++ b/src/third_party/wiredtiger/test/suite/test_truncate14.py @@ -28,7 +28,7 @@ import wttest from helper import simulate_crash_restart -from test_rollback_to_stable01 import test_rollback_to_stable_base +from rollback_to_stable_util import test_rollback_to_stable_base from wiredtiger import stat, WT_NOTFOUND from wtdataset import SimpleDataSet from wtscenario import make_scenarios diff --git a/src/third_party/wiredtiger/test/suite/wttest.py b/src/third_party/wiredtiger/test/suite/wttest.py index f76a8048113..d26697e2261 100755 --- a/src/third_party/wiredtiger/test/suite/wttest.py +++ b/src/third_party/wiredtiger/test/suite/wttest.py @@ -92,6 +92,10 @@ class CapturedFd(object): self.desc = desc self.expectpos = 0 self.file = None + self.ignore_regex = None + + def setIgnorePattern(self, regex): + self.ignore_regex = regex def readFileFrom(self, filename, pos, maxchars): """ @@ -128,7 +132,15 @@ class CapturedFd(object): return if self.file != None: self.file.flush() - return self.expectpos < os.path.getsize(self.filename) + new_size = os.path.getsize(self.filename) + if self.ignore_regex is None: + return self.expectpos < new_size + + gotstr = self.readFileFrom(self.filename, self.expectpos, new_size - self.expectpos) + for line in list(filter(None, gotstr.split('\n'))): + if self.ignore_regex.search(line) is None: + return True + return False def check(self, testcase): """ @@ -360,6 +372,8 @@ class WiredTigerTestCase(unittest.TestCase): self.captureerr = CapturedFd('stderr.txt', 'error output') sys.stdout = self.captureout.capture() sys.stderr = self.captureerr.capture() + if self.ignore_regex is not None: + self.captureout.setIgnorePattern(self.ignore_regex) def fdTearDown(self): # restore stderr/stdout @@ -373,6 +387,8 @@ class WiredTigerTestCase(unittest.TestCase): assert(len(self.scenarios) == len(dict(self.scenarios))) unittest.TestCase.__init__(self, *args, **kwargs) self.skipped = False + self.ignore_regex = None + self.teardown_actions = [] if not self._globalSetup: WiredTigerTestCase.globalSetup() self.platform_api = WiredTigerTestCase._hookmgr.get_platform_api() @@ -685,6 +701,9 @@ class WiredTigerTestCase(unittest.TestCase): def checkStdout(self): self.captureout.check(self) + def ignoreStdoutPattern(self, pattern, re_flags = 0): + self.ignore_regex = re.compile(pattern, re_flags) + def readyDirectoryForRemoval(self, directory): # Make sure any read-only files or directories left behind # are made writeable in preparation for removal. @@ -695,7 +714,20 @@ class WiredTigerTestCase(unittest.TestCase): for f in files: os.chmod(os.path.join(root, f), 0o666) + # Return value of each action should be a tuple with the first value an integer (non-zero to indicate + # failure), and the second value a string suitable for printing when the test fails. + def addTearDownAction(self, action): + self.teardown_actions.append(action) + def tearDown(self, dueToRetry=False): + teardown_failed = False + if not dueToRetry: + for action in self.teardown_actions: + tmp = action() + if tmp[0] != 0: + self.pr('ERROR: teardown action failed, message=' + tmp[1]) + teardown_failed = True + # This approach works for all our support Python versions and # is suggested by one of the answers in: # https://stackoverflow.com/questions/4414234/getting-pythons-unittest-results-in-a-teardown-method @@ -711,7 +743,7 @@ class WiredTigerTestCase(unittest.TestCase): exc_failure = (sys.exc_info() != (None, None, None)) self._failed = error or failure or exc_failure - passed = not self._failed + passed = not (self._failed or teardown_failed) self.platform_api.tearDown() diff --git a/src/third_party/wiredtiger/tools/rts_verifier/.gitignore b/src/third_party/wiredtiger/tools/rts_verifier/.gitignore new file mode 100644 index 00000000000..bee8a64b79a --- /dev/null +++ b/src/third_party/wiredtiger/tools/rts_verifier/.gitignore @@ -0,0 +1 @@ +__pycache__ diff --git a/src/third_party/wiredtiger/tools/rts_verifier/basic_types.py b/src/third_party/wiredtiger/tools/rts_verifier/basic_types.py new file mode 100644 index 00000000000..b06e7dbafd0 --- /dev/null +++ b/src/third_party/wiredtiger/tools/rts_verifier/basic_types.py @@ -0,0 +1,58 @@ +from enum import Enum + +class PrepareState(Enum): + WT_PREPARE_INIT = 0 + WT_PREPARE_INPROGRESS = 1 + WT_PREPARE_LOCKED = 2 + WT_PREPARE_RESOLVED = 3 + +class UpdateType(Enum): + WT_UPDATE_MODIFY = 0 + WT_UPDATE_RESERVE = 1 + WT_UPDATE_STANDARD = 2 + WT_UPDATE_TOMBSTONE = 3 + +class Timestamp(): + def __init__(self, start, stop): + self.start = start + self.stop = stop + + def __eq__(self, other): + return self.start == other.start and self.stop == other.stop + + def __lt__(self, rhs): + return ((self.start, self.stop) < (rhs.start, rhs.stop)) + + def __le__(self, rhs): + return self.__lt__(rhs) or self.__eq__(rhs) + + def __gt__(self, rhs): + return ((self.start, self.stop) > (rhs.start, rhs.stop)) + + def __ge__(self, rhs): + return self.__gt__(rhs) or self.__eq__(rhs) + + def __repr__(self): + return f"({self.start}, {self.stop})" + +class Tree(): + def __init__(self, filename): + self.logged = None + self.file = filename + + def __eq__(self, other): + return self.file == other.file + + def __hash__(self): + return hash(self.file) + +class Page(): + def __init__(self, addr): + self.addr = addr + self.modified = None + + def __eq__(self, other): + return self.addr == other.addr + + def __hash__(self): + return hash(self.addr) diff --git a/src/third_party/wiredtiger/tools/rts_verifier/checker.py b/src/third_party/wiredtiger/tools/rts_verifier/checker.py new file mode 100644 index 00000000000..3c49c1f2570 --- /dev/null +++ b/src/third_party/wiredtiger/tools/rts_verifier/checker.py @@ -0,0 +1,213 @@ +#!/usr/bin/env python3 + +from basic_types import Page, PrepareState, Timestamp, Tree +from operation import OpType + +class Checker: + def __init__(self): + self.stable = None + self.visited_trees = set() + self.visited_pages = set() + + def apply(self, operation): + # The type's name will be something like 'PAGE_ROLLBACK'. + opname = operation.type.name.lower() + + # Construct the name of the function call from the opname, e.g. __apply_check_page_rollback. + # The '_Checker' bit is the class name. + ptr = getattr(self, '_Checker__apply_check_' + opname) + if ptr is None: + raise Exception("Checker got an operation type it didn't understand!") + + # Call the function we found. + ptr(operation) + + def __apply_check_init(self, operation): + # reset a bunch of internal state + self.stable = operation.stable + self.visited_trees = set() + self.visited_pages = set() + self.current_tree = None + + def __apply_check_tree(self, operation): + tree = Tree(operation.file) + if tree in self.visited_trees: + raise Exception(f"visited file {operation.file} again, {operation=}") + self.visited_trees.add(tree) + self.current_tree = tree + + if not(operation.modified or + operation.durable_gt_stable or + operation.has_prepared_updates or + operation.durable_ts_not_found or + operation.txnid_gt_recov_ckpt_snap_min): + raise Exception(f"unnecessary visit to {operation.file}") + + if operation.durable_gt_stable and not operation.durable > operation.stable: + raise Exception(f"incorrect timestamp comparison: thought {operation.durable} > {operation.stable}, but it isn't") + if not operation.durable_gt_stable and not operation.stable >= operation.durable: + raise Exception(f"incorrect timestamp comparison: thought {operation.durable} <= {operation.stable}, but it isn't") + + if operation.durable_ts_not_found and operation.durable != Timestamp(0, 0): + raise Exception("we thought we didn't have a durable timestamp, but we do") + + if operation.stable != self.stable: + raise Exception(f"stable timestamp spuriously changed from {self.stable} to {operation.stable} while rolling back {operation.file}") + + def __apply_check_tree_logging(self, operation): + # TODO expand this out + # if operation.file != self.current_tree.file: + # raise Exception(f"spurious visit to {operation.file}") + + if self.current_tree is not None and self.current_tree.logged is not None and self.current_tree.logged != operation.btree_logging_enabled: + raise Exception(f"{operation.file} spuriously changed btree logging state") + + if self.current_tree is not None: + self.current_tree.logged = operation.btree_logging_enabled + + def __apply_check_page_rollback(self, operation): + # TODO expand this out - not always spurious for the history store. + # if operation.file != self.current_tree.file: + # raise Exception(f"spurious visit to {operation.file}") + + page = Page(operation.addr) + page.modified = operation.modified + # if page in self.visited_pages: + # raise Exception(f"visited page {operation.addr} again") + self.visited_pages.add(page) + + def __apply_check_update_abort(self, operation): + if operation.file != self.current_tree.file: + raise Exception(f"spurious visit to {operation.file}") + + if not(operation.txnid_not_visible or + operation.stable_lt_durable or + operation.prepare_state == PrepareState.PREPARE_INPROGRESS): + raise Exception(f"aborted update with txnid={operation.txnid} for no reason") + + if operation.stable_lt_durable and not operation.stable < operation.durable: + raise Exception(f"incorrect timestamp comparison: thought {operation.stable} < {operation.durable}, but it isn't") + if not operation.stable_lt_durable and not operation.stable >= operation.durable: + raise Exception(f"incorrect timestamp comparison: thought {operation.stable} >= {operation.durable}, but it isn't") + + def __apply_check_page_abort_check(self, operation): + # TODO expand this out + # if operation.file != self.current_tree.file: + # raise Exception(f"spurious visit to {operation.file}, {operation=}") + + # TODO print session recovery flags to check the other way this can be wrong + should_rollback = (operation.durable <= self.stable) or operation.has_prepared + # if should_rollback and not operation.needs_abort: + # raise Exception(f"incorrectly skipped rolling back page with ref={operation.ref}") + + # TODO be a little smarter about storing page state. the decision we make about rolling back + # can be stored, and checked against future log lines to e.g. make sure we don't change our + # mind at some point. + + # TODO can probably use the txn ID somehow. + + def __apply_check_key_clear_remove(self, operation): + if operation.file != self.current_tree.file: + raise Exception(f"spurious visit to {operation.file}, {operation=}") + + # TODO print session recovery flags to check the other way this can be wrong + should_abort = (operation.removed_durable <= self.stable) or operation.removed_prepared + if should_abort and not operation.needs_abort: + raise Exception(f"incorrectly skipped rolling back page with ref={operation.ref}") + + # TODO can likely expand on these + if operation.restored_stable != self.stable: + raise Exception("stable timestamp spuriously moved forward") + + if operation.removed_commit < self.stable: + raise Exception("aborted an update from before the stable timestamp?!") + + def __apply_check_ondisk_kv_remove(self, operation): + # TODO expand this out + # if operation.file != self.current_tree.file: + # raise Exception(f"spurious visit to {operation.file}, {operation=}") + pass + + def __apply_check_shutdown_init(self, operation): + # TODO expand this out + pass + + def __apply_check_tree_skip(self, operation): + # TODO expand this out + pass + + def __apply_check_skip_del_null(self, operation): + # TODO expand this out + pass + + def __apply_check_ondisk_abort_tw(self, operation): + # TODO expand this out + pass + + def __apply_check_ondisk_key_rollback(self, operation): + # TODO expand this out + pass + + def __apply_check_hs_update_abort(self, operation): + # TODO expand this out + pass + + def __apply_check_hs_update_valid(self, operation): + # TODO expand this out + pass + + def __apply_check_hs_update_restored(self, operation): + # TODO expand this out + pass + + def __apply_check_key_removed(self, operation): + # TODO expand this out + pass + + def __apply_check_stable_pg_walk_skip(self, operation): + # TODO expand this out + pass + + def __apply_check_skip_unmodified(self, operation): + # TODO expand this out + pass + + def __apply_check_hs_gt_ondisk(self, operation): + # TODO expand this out + pass + + def __apply_check_recovery_rts(self, operation): + # TODO expand this out + pass + + def __apply_check_hs_stop_obsolete(self, operation): + # TODO expand this out + pass + + def __apply_check_recover_ckpt(self, operation): + # TODO expand this out + pass + + def __apply_check_hs_tree_rollback(self, operation): + # TODO expand this out + pass + + def __apply_check_hs_tree_skip(self, operation): + # TODO expand this out + pass + + def __apply_check_hs_abort_stop(self, operation): + # TODO expand this out + pass + + def __apply_check_hs_restore_tombstone(self, operation): + # TODO expand this out + pass + + def __apply_check_file_skip(self, operation): + # TODO expand this out + pass + + def __apply_check_skip_damage(self, operation): + # TODO expand this out + pass diff --git a/src/third_party/wiredtiger/tools/rts_verifier/operation.py b/src/third_party/wiredtiger/tools/rts_verifier/operation.py new file mode 100644 index 00000000000..2bc5d93a2b1 --- /dev/null +++ b/src/third_party/wiredtiger/tools/rts_verifier/operation.py @@ -0,0 +1,459 @@ +#!/usr/bin/env python3 + +import os, re + +from basic_types import PrepareState, Timestamp, UpdateType +from enum import Enum + +class OpType(Enum): + INIT = 0 + TREE = 1 + TREE_LOGGING = 2 + PAGE_ROLLBACK = 3 + UPDATE_ABORT = 4 + PAGE_ABORT_CHECK = 5 + KEY_CLEAR_REMOVE = 6 + ONDISK_KV_REMOVE = 7 + SHUTDOWN_INIT = 8 + TREE_SKIP = 9 + SKIP_DEL_NULL = 10 + ONDISK_ABORT_TW = 11 + ONDISK_KEY_ROLLBACK = 12 + HS_UPDATE_ABORT = 13 + HS_UPDATE_VALID = 14 + HS_UPDATE_RESTORED = 15 + KEY_REMOVED = 16 + STABLE_PG_WALK_SKIP = 17 + SKIP_UNMODIFIED = 18 + HS_GT_ONDISK = 19 + RECOVERY_RTS = 20 + HS_STOP_OBSOLETE = 21 + RECOVER_CKPT = 22 + HS_TREE_ROLLBACK = 23 + HS_TREE_SKIP = 24 + HS_ABORT_STOP = 25 + HS_RESTORE_TOMBSTONE = 26 + FILE_SKIP = 27 + SKIP_DAMAGE = 28 + +class Operation: + def __init__(self, line): + self.line = line + + # Extract the RTS message type, e.g. 'PAGE_ROLLBACK'. + matches = re.search('\[WT_VERB_RTS\]\[DEBUG_\d+\]: \[(\w+)\]', line) + if matches is None or matches.group(1) is None: + raise Exception("Checker got a verbose RTS message in a format it didn't understand: {}" + .format(line)) + + # 'PAGE_ROLLBACK' -> 'page_rollback' since we're using it to search for a function + # and our names are all lowercase. + name = matches.group(1).lower() + + # Search for a function in the class with the name we found. Our functions all start + # with `__init_` so add that. The '_Operation' is our class name. + ptr = getattr(self, '_Operation__init_' + name) + if ptr is None: + raise Exception("Checker got a verbose RTS message with a type it didn't understand!") + + # Call the function we found. + ptr(line) + + def __repr__(self): + return f"{self.__dict__}" + + def __extract_file(self, line): + matches = re.search('file:([\w_\.]+)', line) + if matches is None: + raise Exception(f"failed to extract a filename from {line}") + return matches.group(1) + + def __extract_simple_timestamp(self, prefix, line): + matches = re.search("{}=\((\d+), (\d+)\)".format(prefix), line) + start = int(matches.group(1)) + stop = int(matches.group(2)) + return Timestamp(start, stop) + + def __extract_pointer(self, prefix, line): + if os.name == 'nt': + matches = re.search(f'{prefix}=([A-Za-z0-9]+)', line) + else: + matches = re.search(f'{prefix}=(0x[A-Za-z0-9]+)', line) + + if matches is None: + raise Exception("failed to parse address string") + + return int(matches.group(1), 16) + + def __init_init(self, line): + self.type = OpType.INIT + + matches = re.search('stable_timestamp=\((\d+), (\d+)\)', line) + if matches is None: + raise Exception("failed to parse init string") + + stable_start = int(matches.group(1)) + stable_stop = int(matches.group(2)) + self.stable = Timestamp(stable_start, stable_stop) + + def __init_tree(self, line): + self.type = OpType.TREE + self.file = self.__extract_file(line) + + matches = re.search('modified=(\w+)', line) + self.modified = matches.group(1).lower() == "true" + + matches = re.search('durable_timestamp=\((\d+), (\d+)\).*>.*stable_timestamp=\((\d+), (\d+)\): (\w+)', line) + durable_start = int(matches.group(1)) + durable_stop = int(matches.group(2)) + self.durable = Timestamp(durable_start, durable_stop) + stable_start = int(matches.group(3)) + stable_stop = int(matches.group(4)) + self.stable = Timestamp(stable_start, stable_stop) + self.durable_gt_stable = matches.group(5).lower() == "true" + + matches = re.search('has_prepared_updates=(\w+)', line) + self.has_prepared_updates = matches.group(1).lower() == "true" + + matches = re.search('durable_timestamp_not_found=(\w+)', line) + self.durable_ts_not_found = matches.group(1).lower() == "true" + + matches = re.search('txnid=(\d+).*>.*recovery_checkpoint_snap_min=(\d+): (\w+)', line) + self.txnid = int(matches.group(1)) + self.recovery_ckpt_snap_min = int(matches.group(2)) + self.txnid_gt_recov_ckpt_snap_min = matches.group(3).lower() == "true" + + def __init_tree_logging(self, line): + self.type = OpType.TREE_LOGGING + self.file = self.__extract_file(line) + + matches = re.search('connection_logging_enabled=(\w+)', line) + self.conn_logging_enabled = matches.group(1).lower() == "true" + + matches = re.search('btree_logging_enabled=(\w+)', line) + self.btree_logging_enabled = matches.group(1).lower() == "true" + + def __init_page_rollback(self, line): + self.type = OpType.PAGE_ROLLBACK + self.file = self.__extract_file(line) + self.addr = self.__extract_pointer('addr', line) + + matches = re.search('modified=(\w+)', line) + self.modified = matches.group(1).lower() == "true" + + def __init_update_abort(self, line): + self.type = OpType.UPDATE_ABORT + self.file = self.__extract_file(line) + + matches = re.search('txnid=(\d+)', line) + self.txnid = int(matches.group(1)) + matches = re.search('txnid_not_visible=(\w+)', line) + self.txnid_not_visible = matches.group(1).lower() == "true" + + matches = re.search('stable_timestamp=\((\d+), (\d+)\).*<.*durable_timestamp=\((\d+), (\d+)\): (\w+)', line) + stable_start = int(matches.group(1)) + stable_stop = int(matches.group(2)) + self.stable = Timestamp(stable_start, stable_stop) + + durable_start = int(matches.group(3)) + durable_stop = int(matches.group(4)) + self.durable = Timestamp(durable_start, durable_stop) + + self.stable_lt_durable = matches.group(5).lower() == "true" + + matches = re.search('prepare_state=(\w+)', line) + self.prepare_state = PrepareState[matches.group(1)] + + def __init_page_abort_check(self, line): + self.type = OpType.PAGE_ABORT_CHECK + self.file = self.__extract_file(line) + + self.ref = self.__extract_pointer('ref', line) + + self.durable = self.__extract_simple_timestamp('durable_timestamp', line) + + matches = re.search('newest_txn=(\d+)', line) + self.newest_txn = int(matches.group(1)) + + matches = re.search('prepared_updates=(\w+)', line) + self.has_prepared = matches.group(1).lower() == "true" + + matches = re.search('needs_abort=(\w+)', line) + self.needs_abort = matches.group(1).lower() == "true" + + def __init_key_clear_remove(self, line): + self.type = OpType.KEY_CLEAR_REMOVE + self.file = self.__extract_file(line) + + self.restored_commit = self.__extract_simple_timestamp('commit_timestamp', line) + self.restored_durable = self.__extract_simple_timestamp('durable_timestamp', line) + self.restored_stable = self.__extract_simple_timestamp('stable_timestamp', line) + + matches = re.search('txnid=(\d+)', line) + self.restored_txnid = int(matches.group(1)) + + self.removed_commit = self.__extract_simple_timestamp('removed.*commit_timestamp', line) + self.removed_durable = self.__extract_simple_timestamp('removed.*durable_timestamp', line) + + matches = re.search('removed.*txnid=(\d+)', line) + self.removed_txnid = int(matches.group(1)) + + matches = re.search('removed.*prepared=(\w+)', line) + self.removed_prepared = matches.group(1).lower() == "true" + + def __init_ondisk_kv_remove(self, line): + self.type = OpType.ONDISK_KV_REMOVE + self.file = self.__extract_file(line) + + matches = re.search('tombstone=(\w+)', line) + self.tombstone = matches.group(1).lower() == "true" + + matches = re.search('key=(\d+)', line) + self.key = int(matches.group(1)) + + def __init_shutdown_init(self, line): + self.type = OpType.SHUTDOWN_INIT + + self.stable = self.__extract_simple_timestamp('stable_timestamp', line) + + def __init_tree_skip(self, line): + self.type = OpType.TREE_SKIP + self.file = self.__extract_file(line) + + self.durable = self.__extract_simple_timestamp('durable_timestamp', line) + self.stable = self.__extract_simple_timestamp('stable_timestamp', line) + + matches = re.search('txnid=(\d+)', line) + self.txnid = int(matches.group(1)) + + def __init_skip_del_null(self, line): + self.type = OpType.SKIP_DEL_NULL + self.file = self.__extract_file(line) + self.ref = self.__extract_pointer('ref', line) + + def __init_ondisk_abort_tw(self, line): + self.type = OpType.ONDISK_ABORT_TW + self.file = self.__extract_file(line) + + matches = re.search('time_window=\((\d+), (\d+)\)/\((\d+), (\d+)\)/(\d+)', line) + start_start = int(matches.group(1)) + start_end = int(matches.group(2)) + self.start = Timestamp(start_start, start_end) + durable_start_start = int(matches.group(3)) + durable_start_end = int(matches.group(4)) + self.durable_start = Timestamp(durable_start_start, durable_start_end) + self.start_txn = int(matches.group(5)) + + matches = re.search('durable_timestamp > stable_timestamp: (\w+)', line) + self.durable_gt_stable = matches.group(1).lower() == "true" + + matches = re.search('txnid_not_visible=(\w+)', line) + self.txnid_not_visible = matches.group(1).lower == "true" + + matches = re.search('tw_has_no_stop_and_is_prepared=(\w+)', line) + self.tw_has_no_stop_and_is_prepared = matches.group(1).lower == "true" + + def __init_ondisk_key_rollback(self, line): + self.type = OpType.ONDISK_KEY_ROLLBACK + self.file = self.__extract_file(line) + + matches = re.search('key=(\d+)', line) + self.key = int(matches.group(1)) + + def __init_hs_update_abort(self, line): + self.type = OpType.HS_UPDATE_ABORT + self.file = self.__extract_file(line) + + matches = re.search('time_window=start: \((\d+), (\d+)\)/\((\d+), (\d+)\)/(\d+) stop: \((\d+), (\d+)\)/\((\d+), (\d+)\)/(\d+)', line) + + durable_start_start = int(matches.group(1)) + durable_start_end = int(matches.group(2)) + self.durable_start = Timestamp(durable_start_start, durable_start_end) + start_start = int(matches.group(3)) + start_end = int(matches.group(4)) + self.start = Timestamp(start_start, start_end) + self.start_txn = int(matches.group(5)) + + durable_stop_start = int(matches.group(6)) + durable_stop_end = int(matches.group(7)) + self.durable_stop = Timestamp(durable_start_start, durable_start_end) + stop_start = int(matches.group(8)) + stop_end = int(matches.group(9)) + self.stop = Timestamp(start_start, start_end) + self.stop_txn = int(matches.group(10)) + + matches = re.search('type=(\w+)', line) + self.update_type = UpdateType[matches.group(1)] + + self.stable = self.__extract_simple_timestamp('stable_timestamp', line) + + def __init_hs_update_valid(self, line): + self.type = OpType.HS_UPDATE_VALID + self.file = self.__extract_file(line) + + matches = re.search('time_window=start: \((\d+), (\d+)\)/\((\d+), (\d+)\)/(\d+) stop: \((\d+), (\d+)\)/\((\d+), (\d+)\)/(\d+)', line) + + durable_start_start = int(matches.group(1)) + durable_start_end = int(matches.group(2)) + self.durable_start = Timestamp(durable_start_start, durable_start_end) + start_start = int(matches.group(3)) + start_end = int(matches.group(4)) + self.start = Timestamp(start_start, start_end) + self.start_txn = int(matches.group(5)) + + durable_stop_start = int(matches.group(6)) + durable_stop_end = int(matches.group(7)) + self.durable_stop = Timestamp(durable_start_start, durable_start_end) + stop_start = int(matches.group(8)) + stop_end = int(matches.group(9)) + self.stop = Timestamp(start_start, start_end) + self.stop_txn = int(matches.group(10)) + + matches = re.search('type=(\w+)', line) + self.update_type = UpdateType[matches.group(1)] + + self.stable = self.__extract_simple_timestamp('stable_timestamp', line) + + def __init_hs_update_restored(self, line): + self.type = OpType.HS_UPDATE_VALID + self.file = self.__extract_file(line) + + matches = re.search('txnid=(\d+)', line) + self.txnid = int(matches.group(1)) + + self.start = self.__extract_simple_timestamp('start_ts', line) + self.durable = self.__extract_simple_timestamp('durable_ts', line) + + def __init_key_removed(self, line): + self.type = OpType.KEY_REMOVED + self.file = self.__extract_file(line) + + def __init_stable_pg_walk_skip(self, line): + self.type = OpType.KEY_REMOVED + self.file = self.__extract_file(line) + self.addr = self.__extract_pointer('ref', line) + + def __init_skip_unmodified(self, line): + self.type = OpType.SKIP_UNMODIFIED + self.file = self.__extract_file(line) + self.addr = self.__extract_pointer('ref', line) + + def __init_hs_gt_ondisk(self, line): + self.type = OpType.HS_GT_ONDISK + self.file = self.__extract_file(line) + + matches = re.search('time_window=start: \((\d+), (\d+)\)/\((\d+), (\d+)\)/(\d+) stop: \((\d+), (\d+)\)/\((\d+), (\d+)\)/(\d+)', line) + + durable_start_start = int(matches.group(1)) + durable_start_end = int(matches.group(2)) + self.durable_start = Timestamp(durable_start_start, durable_start_end) + start_start = int(matches.group(3)) + start_end = int(matches.group(4)) + self.start = Timestamp(start_start, start_end) + self.start_txn = int(matches.group(5)) + + durable_stop_start = int(matches.group(6)) + durable_stop_end = int(matches.group(7)) + self.durable_stop = Timestamp(durable_start_start, durable_start_end) + stop_start = int(matches.group(8)) + stop_end = int(matches.group(9)) + self.stop = Timestamp(start_start, start_end) + self.stop_txn = int(matches.group(10)) + + matches = re.search('type=(\w+)', line) + self.update_type = UpdateType[matches.group(1)] + + def __init_recovery_rts(self, line): + self.type = OpType.RECOVERY_RTS + + self.stable = self.__extract_simple_timestamp('stable_timestamp', line) + self.oldest = self.__extract_simple_timestamp('oldest_timestamp', line) + + def __init_hs_stop_obsolete(self, line): + self.type = OpType.HS_STOP_OBSOLETE + self.file = self.__extract_file(line) + + matches = re.search('time_window=start: \((\d+), (\d+)\)/\((\d+), (\d+)\)/(\d+) stop: \((\d+), (\d+)\)/\((\d+), (\d+)\)/(\d+)', line) + durable_start_start = int(matches.group(1)) + durable_start_end = int(matches.group(2)) + self.durable_start = Timestamp(durable_start_start, durable_start_end) + start_start = int(matches.group(3)) + start_end = int(matches.group(4)) + self.start = Timestamp(start_start, start_end) + self.start_txn = int(matches.group(5)) + + durable_stop_start = int(matches.group(6)) + durable_stop_end = int(matches.group(7)) + self.durable_stop = Timestamp(durable_start_start, durable_start_end) + stop_start = int(matches.group(8)) + stop_end = int(matches.group(9)) + self.stop = Timestamp(start_start, start_end) + self.stop_txn = int(matches.group(10)) + + self.pinned = self.__extract_simple_timestamp('pinned_timestamp', line) + + def __init_recover_ckpt(self, line): + self.type = OpType.RECOVER_CKPT + + matches = re.search('snapshot_min=(\d+)', line) + self.snapshot_min = int(matches.group(1)) + + matches = re.search('snapshot_max=(\d+)', line) + self.snapshot_max = int(matches.group(1)) + + matches = re.search('snapshot_count=(\d+)', line) + self.snapshot_count = int(matches.group(1)) + + def __init_hs_tree_rollback(self, line): + self.type = OpType.HS_TREE_ROLLBACK + self.file = self.__extract_file(line) + + self.durable = self.__extract_simple_timestamp('durable_timestamp', line) + + def __init_hs_tree_skip(self, line): + self.type = OpType.HS_TREE_SKIP + self.file = self.__extract_file(line) + + self.durable = self.__extract_simple_timestamp('durable_timestamp', line) + self.stable = self.__extract_simple_timestamp('stable_timestamp', line) + + def __init_hs_abort_stop(self, line): + self.type = OpType.HS_ABORT_STOP + self.file = self.__extract_file(line) + + matches = re.search('start_durable/commit_timestamp=\((\d+), (\d+)\), \((\d+), (\d+)\)', line) + durable_start_start = int(matches.group(1)) + durable_start_stop = int(matches.group(2)) + self.durable_start = Timestamp(durable_start_start, durable_start_stop) + commit_start_start = int(matches.group(3)) + commit_start_stop = int(matches.group(4)) + self.commit_start = Timestamp(commit_start_start, commit_start_stop) + + matches = re.search('stop_durable/commit_timestamp=\((\d+), (\d+)\), \((\d+), (\d+)\)', line) + durable_stop_start = int(matches.group(1)) + durable_stop_stop = int(matches.group(2)) + self.durable_stop = Timestamp(durable_start_start, durable_stop_start) + commit_stop_start = int(matches.group(3)) + commit_stop_stop = int(matches.group(4)) + self.commit_stop = Timestamp(commit_stop_start, commit_stop_stop) + + self.stable = self.__extract_simple_timestamp('stable_timestamp', line) + + def __init_hs_restore_tombstone(self, line): + self.type = OpType.HS_RESTORE_TOMBSTONE + self.file = self.__extract_file(line) + + matches = re.search('txnid=(\d+)', line) + self.txnid = int(matches.group(1)) + + self.start = self.__extract_simple_timestamp('start_ts', line) + self.durable = self.__extract_simple_timestamp('durable_ts', line) + + def __init_file_skip(self, line): + self.type = OpType.TREE_SKIP + self.file = self.__extract_file(line) + + def __init_skip_damage(self, line): + self.type = OpType.SKIP_DAMAGE + self.file = self.__extract_file(line) + self.corrupted = "corrupt" in line diff --git a/src/third_party/wiredtiger/tools/rts_verifier/rts_verify.py b/src/third_party/wiredtiger/tools/rts_verifier/rts_verify.py new file mode 100755 index 00000000000..cf85565bbd5 --- /dev/null +++ b/src/third_party/wiredtiger/tools/rts_verifier/rts_verify.py @@ -0,0 +1,18 @@ +#!/usr/bin/env python3 + +import argparse + +from checker import Checker +from operation import Operation + +if __name__ == '__main__': + parser = argparse.ArgumentParser(description='Verify actions taken by rollback to stable from verbose messages.') + parser.add_argument('file', type=str, help='the log file to parse verbose messages from') + args = parser.parse_args() + + checker = Checker() + with open(args.file) as f: + for line in f: + if 'WT_VERB_RTS' in line: + op = Operation(line) + checker.apply(op) |