-
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