The error that stopped this test/format run is:
wts_verify/496: ret == 0 || ret == EBUSY: session.verify: table:wt: post-salvage verify
There's lots of evidence that links this to prepare.
[2020/05/18 12:39:12.787] format.sh: starting smoke-test job in /data/mci/e76d248a9fd5d0fa7e32787575b08994/wiredtiger/test/format/RUNDIR.5 (Mon May 18 12:39:12 UTC 2020) [2020/05/18 12:39:12.787] format.sh: catchsegv ./t -c /data/mci/e76d248a9fd5d0fa7e32787575b08994/wiredtiger/test/format/CONFIG.stress -h /data/mci/e76d248a9fd5d0fa7e32787575b08994/wiredtiger/test/format/RUNDIR.5 -1 data_source=table rows=100000 threads=6 timer=4 leaf_page_max=9 internal_page_max=9 file_type=row key_min=256 value_min=256 quiet=1 [2020/05/18 12:39:15.860] ./format.sh: line 316: wait: pid 13040 is not a child of this shell [2020/05/18 12:39:15.860] format.sh: job in /data/mci/e76d248a9fd5d0fa7e32787575b08994/wiredtiger/test/format/RUNDIR.2 failed [2020/05/18 12:39:15.860] format.sh: /data/mci/e76d248a9fd5d0fa7e32787575b08994/wiredtiger/test/format/RUNDIR.2 log: [2020/05/18 12:39:15.865] t: process 13040 running [2020/05/18 12:39:15.865] lt-wt: table:wt: cursor.next: WT_PREPARE_CONFLICT: conflict with a prepared update [2020/05/18 12:39:15.865] lt-wt: table:wt: cursor.next: WT_PREPARE_CONFLICT: conflict with a prepared update [2020/05/18 12:39:15.865] [1589805553:71424][13040:0x7f8cc4d08740], t, file:wt.wt, WT_SESSION.verify: __wt_time_value_validate, 338: aggregate time window is prepared but its parent is not; time aggregate start: (0, 245729)/(0, 245729)/0 stop: (0, 0)/(4294967295, 4294967295)/18446744073709551605, prepared, parent newest durable: (0, 0)/(0, 0) oldest start: (0, 0)/0 newest stop (4294967295, 4294967295)/18446744073709551605: Invalid argument [2020/05/18 12:39:15.865] [1589805553:71470][13040:0x7f8cc4d08740], t, file:wt.wt, WT_SESSION.verify: __verify_page_content_leaf, 980: cell 43 on page at [3641344-3642880, 1536, 4143537416] newest durable: (0, 0)/(0, 0) oldest start: (0, 0)/0 newest stop (4294967295, 4294967295)/18446744073709551605 failed timestamp validation: Invalid argument [2020/05/18 12:39:15.865] [1589805553:97230][13040:0x7f8cc4d08740], t, file:wt.wt, WT_SESSION.verify: __verify_ckptfrag_chk, 526: checkpoint ranges never verified: 2616 [2020/05/18 12:39:15.865] [1589805553:111444][13040:0x7f8cc4d08740], t, file:wt.wt, WT_SESSION.verify: __verify_filefrag_chk, 438: file ranges never verified: 2616 [2020/05/18 12:39:15.865] t: run FAILED [2020/05/18 12:39:15.865] ############################################ [2020/05/18 12:39:15.865] # RUN PARAMETERS: V2 [2020/05/18 12:39:15.865] ############################################ [2020/05/18 12:39:15.865] assert.commit_timestamp=1 [2020/05/18 12:39:15.865] assert.read_timestamp=0 [2020/05/18 12:39:15.865] backup=1 [2020/05/18 12:39:15.865] backup.incremental=off [2020/05/18 12:39:15.865] btree.bitcnt=4 [2020/05/18 12:39:15.865] btree.compression=snappy [2020/05/18 12:39:15.865] btree.dictionary=0 [2020/05/18 12:39:15.865] btree.huffman_key=1 [2020/05/18 12:39:15.865] btree.huffman_value=1 [2020/05/18 12:39:15.865] btree.internal_key_truncation=1 [2020/05/18 12:39:15.865] btree.internal_page_max=10 [2020/05/18 12:39:15.865] btree.key_gap=5 [2020/05/18 12:39:15.865] btree.key_max=41 [2020/05/18 12:39:15.865] btree.key_min=13 [2020/05/18 12:39:15.865] btree.leaf_page_max=12 [2020/05/18 12:39:15.865] btree.memory_page_max=2 [2020/05/18 12:39:15.865] btree.prefix_compression=1 [2020/05/18 12:39:15.865] btree.prefix_compression_min=2 [2020/05/18 12:39:15.865] btree.repeat_data_pct=81 [2020/05/18 12:39:15.865] btree.reverse=0 [2020/05/18 12:39:15.865] btree.split_pct=64 [2020/05/18 12:39:15.865] btree.value_max=2833 [2020/05/18 12:39:15.865] btree.value_min=8 [2020/05/18 12:39:15.865] cache=79 [2020/05/18 12:39:15.865] cache.evict_max=3 [2020/05/18 12:39:15.865] cache.minimum=20 [2020/05/18 12:39:15.865] checkpoint=on [2020/05/18 12:39:15.865] checkpoint.log_size=43 [2020/05/18 12:39:15.865] checkpoint.wait=79 [2020/05/18 12:39:15.865] disk.checksum=uncompressed [2020/05/18 12:39:15.865] disk.data_extend=0 [2020/05/18 12:39:15.865] disk.direct_io=0 [2020/05/18 12:39:15.865] disk.encryption=rotn-7 [2020/05/18 12:39:15.865] disk.firstfit=1 [2020/05/18 12:39:15.865] disk.mmap=1 [2020/05/18 12:39:15.865] disk.mmap_all=0 [2020/05/18 12:39:15.865] format.abort=0 [2020/05/18 12:39:15.865] format.independent_thread_rng=1 [2020/05/18 12:39:15.865] format.major_timeout=0 [2020/05/18 12:39:15.865] logging=0 [2020/05/18 12:39:15.865] logging.archive=1 [2020/05/18 12:39:15.865] logging.compression=none [2020/05/18 12:39:15.865] logging.file_max=230882 [2020/05/18 12:39:15.865] logging.prealloc=1 [2020/05/18 12:39:15.865] lsm.auto_throttle=1 [2020/05/18 12:39:15.865] lsm.bloom=1 [2020/05/18 12:39:15.865] lsm.bloom_bit_count=10 [2020/05/18 12:39:15.865] lsm.bloom_hash_count=27 [2020/05/18 12:39:15.865] lsm.bloom_oldest=0 [2020/05/18 12:39:15.865] lsm.chunk_size=8 [2020/05/18 12:39:15.865] lsm.merge_max=20 [2020/05/18 12:39:15.865] lsm.worker_threads=4 [2020/05/18 12:39:15.865] ops.alter=0 [2020/05/18 12:39:15.866] ops.compaction=0 [2020/05/18 12:39:15.866] ops.pct.delete=25 [2020/05/18 12:39:15.866] ops.pct.insert=19 [2020/05/18 12:39:15.866] ops.pct.modify=24 [2020/05/18 12:39:15.866] ops.pct.read=5 [2020/05/18 12:39:15.866] ops.pct.write=27 [2020/05/18 12:39:15.866] ops.prepare=1 [2020/05/18 12:39:15.866] ops.random_cursor=0 [2020/05/18 12:39:15.866] ops.rebalance=1 [2020/05/18 12:39:15.866] ops.salvage=1 [2020/05/18 12:39:15.866] ops.truncate=1 [2020/05/18 12:39:15.866] ops.verify=1 [2020/05/18 12:39:15.866] quiet=1 [2020/05/18 12:39:15.866] runs=1 [2020/05/18 12:39:15.866] runs.in_memory=0 [2020/05/18 12:39:15.866] runs.ops=0 [2020/05/18 12:39:15.866] runs.rows=100000 [2020/05/18 12:39:15.866] runs.source=table [2020/05/18 12:39:15.866] runs.threads=6 [2020/05/18 12:39:15.866] runs.timer=4 [2020/05/18 12:39:15.866] runs.type=row-store [2020/05/18 12:39:15.866] statistics=1 [2020/05/18 12:39:15.866] statistics.server=0 [2020/05/18 12:39:15.866] stress.aggressive_sweep=0 [2020/05/18 12:39:15.866] stress.checkpoint=0 [2020/05/18 12:39:15.866] stress.hs_sweep=0 [2020/05/18 12:39:15.866] stress.split_1=0 [2020/05/18 12:39:15.866] stress.split_2=0 [2020/05/18 12:39:15.866] stress.split_3=0 [2020/05/18 12:39:15.866] stress.split_4=0 [2020/05/18 12:39:15.866] stress.split_5=0 [2020/05/18 12:39:15.866] stress.split_6=0 [2020/05/18 12:39:15.866] stress.split_7=0 [2020/05/18 12:39:15.866] stress.split_8=0 [2020/05/18 12:39:15.866] transaction.frequency=100 [2020/05/18 12:39:15.866] transaction.isolation=snapshot [2020/05/18 12:39:15.866] transaction.timestamps=1 [2020/05/18 12:39:15.866] wiredtiger.config= [2020/05/18 12:39:15.866] wiredtiger.rwlock=1 [2020/05/18 12:39:15.866] wiredtiger.leak_memory=0 [2020/05/18 12:39:15.866] ############################################ [2020/05/18 12:39:15.866] t: FAILED: wts_verify/496: ret == 0 || ret == EBUSY: session.verify: table:wt: post-salvage verify
- related to
-
WT-6295 Aggregate time windows in salvage
-
- Closed
-