-
Type: Bug
-
Resolution: Fixed
-
Priority: Major - P3
-
Affects Version/s: None
-
Component/s: None
-
8
-
Storage Engines 2020-03-23, Storage Engines 2020-04-06, Storage - Ra 2020-04-20
-
v4.2
My 10-parallel runs of develop as of yesterday morning, changeset eea1ed346 did eventually hit an assertion failure after over 600 iterations (or 6000+ successful runs). This is the failure:
[1583383769:153219][26627:0x7f7b17fff700], t, WT_SESSION.commit_transaction: __wt_txn_clear_read_timestamp, 1246: txn->read_timestamp >= S2C(session)->txn_global.pinned_timestamp
Here is the stack and timestamp information (I print out the entire txn and then also just the read ts for clarity):
#2 0x0000000000497049 in __wt_abort (session=0x7f7b254471f8) at ../src/os_common/os_abort.c:30 #3 0x000000000051048e in __wt_txn_clear_read_timestamp ( session=0x7f7b254471f8) at ../src/txn/txn_timestamp.c:1246 #4 0x00000000004f3c74 in __wt_txn_release_snapshot (session=0x7f7b254471f8) at ../src/txn/txn.c:140 #5 0x00000000004f5ae5 in __wt_txn_commit (session=0x7f7b254471f8, cfg=0x7f7b17ffed90) at ../src/txn/txn.c:1005 #6 0x00000000004d3b1e in __session_commit_transaction ( wt_session=0x7f7b254471f8, config=0x0) at ../src/session/session_api.c:1669 #7 0x0000000000408138 in commit_transaction (tinfo=0x1ed3da0, prepared=false) at ../../../test/format/ops.c:440 #8 0x00000000004096ab in ops (arg=0x1ed3da0) at ../../../test/format/ops.c:960 #9 0x00007f7b24a3edc5 in start_thread () from /lib64/libpthread.so.0 (gdb) p *txn $1 = {id = 78800, isolation = WT_ISO_SNAPSHOT, forced_iso = 0, snap_min = 78800, snap_max = 78800, snapshot = 0x7f7af851bb60, snapshot_count = 0, txn_logsync = 0, commit_timestamp = 131582, durable_timestamp = 131582, first_commit_timestamp = 131582, prepare_timestamp = 0, read_timestamp = 130282, durable_timestampq = { tqe_next = 0x0, tqe_prev = 0x1dd8aa8}, read_timestampq = {tqe_next = 0x0, tqe_prev = 0x1dd8ae8}, clear_durable_q = false, clear_read_q = false, mod = 0x7f7af84820b0, mod_alloc = 1120, mod_count = 3, logrec = 0x7f7af8043320, notify = 0x0, ckpt_lsn = {l = {offset = 0, file = 0}, file_offset = 0}, ckpt_nsnapshot = 0, ckpt_snapshot = 0x0, full_ckpt = false, operation_timeout_us = 0, rollback_reason = 0x0, flags = 1053844} (gdb) p $2->txn_global.pinned_timestamp $4 = 131387 (gdb) p txn->read_timestamp $5 = 130282