[WT-6423] Salvage testing fails after setting stable timestamp in test format - MongoDB Jira

XML

Word

Printable

JSON

Details

Type: Bug
Status: Closed
Priority: Major - P3
Resolution: Duplicate
Affects Version/s: None
Fix Version/s: None
Component/s: None
Labels:
- RTS-test-format

Description

~~WT-6263~~ sets the stable timestamp in test format, however, salvage test starts to fail:

[2020/06/15 03:57:58.685]     t: process 6817 running

 [2020/06/15 03:57:58.685]     [1592193477:859129][6817:0x7f87ce8ef7c0], file:wt.wt, txn rollback_to_stable: __desc_read, 380: wt.wt does not appear to be a WiredTiger file: WT_ERROR: non-specific WiredTiger error

 [2020/06/15 03:57:58.685]     [1592193477:859228][6817:0x7f87ce8ef7c0], txn-recover: __wt_txn_recover, 852: Recovery failed: WT_ERROR: non-specific WiredTiger error

 [2020/06/15 03:57:58.685]     [1592193477:861411][6817:0x7f87ce8ef7c0], connection: __wt_cache_destroy, 350: cache server: exiting with 3 pages in memory and 0 pages evicted

 [2020/06/15 03:57:58.685]     [1592193477:861437][6817:0x7f87ce8ef7c0], connection: __wt_cache_destroy, 355: cache server: exiting with 2573 image bytes in memory

 [2020/06/15 03:57:58.685]     [1592193477:861449][6817:0x7f87ce8ef7c0], connection: __wt_cache_destroy, 358: cache server: exiting with 3214 bytes in memory

 [2020/06/15 03:57:58.685]     t: run FAILED

 [2020/06/15 03:57:58.685]     ############################################

 [2020/06/15 03:57:58.685]     #  RUN PARAMETERS: V2

 [2020/06/15 03:57:58.685]     ############################################

 [2020/06/15 03:57:58.685]     assert.commit_timestamp=0

 [2020/06/15 03:57:58.685]     assert.read_timestamp=0

 [2020/06/15 03:57:58.685]     backup=0

 [2020/06/15 03:57:58.685]     backup.incremental=off

 [2020/06/15 03:57:58.685]     backup.incr_granularity=4210

 [2020/06/15 03:57:58.685]     btree.bitcnt=4

 [2020/06/15 03:57:58.685]     btree.compression=none

 [2020/06/15 03:57:58.685]     btree.dictionary=0

 [2020/06/15 03:57:58.686]     btree.huffman_key=0

 [2020/06/15 03:57:58.686]     btree.huffman_value=0

 [2020/06/15 03:57:58.686]     btree.internal_key_truncation=1

 [2020/06/15 03:57:58.686]     btree.internal_page_max=9

 [2020/06/15 03:57:58.686]     btree.key_gap=3

 [2020/06/15 03:57:58.686]     btree.key_max=256

 [2020/06/15 03:57:58.686]     btree.key_min=256

 [2020/06/15 03:57:58.686]     btree.leaf_page_max=9

 [2020/06/15 03:57:58.686]     btree.memory_page_max=6

 [2020/06/15 03:57:58.686]     btree.prefix_compression=1

 [2020/06/15 03:57:58.686]     btree.prefix_compression_min=1

 [2020/06/15 03:57:58.686]     btree.repeat_data_pct=67

 [2020/06/15 03:57:58.686]     btree.reverse=0

 [2020/06/15 03:57:58.686]     btree.split_pct=80

 [2020/06/15 03:57:58.686]     btree.value_max=2048

 [2020/06/15 03:57:58.686]     btree.value_min=7

 [2020/06/15 03:57:58.686]     cache=72

 [2020/06/15 03:57:58.686]     cache.evict_max=4

 [2020/06/15 03:57:58.686]     cache.minimum=20

 [2020/06/15 03:57:58.686]     checkpoint=on

 [2020/06/15 03:57:58.686]     checkpoint.log_size=88

 [2020/06/15 03:57:58.686]     checkpoint.wait=68

 [2020/06/15 03:57:58.686]     disk.checksum=uncompressed

 [2020/06/15 03:57:58.686]     disk.data_extend=1

 [2020/06/15 03:57:58.686]     disk.direct_io=0

 [2020/06/15 03:57:58.686]     disk.encryption=rotn-7

 [2020/06/15 03:57:58.686]     disk.firstfit=0

 [2020/06/15 03:57:58.686]     disk.mmap=0

 [2020/06/15 03:57:58.686]     disk.mmap_all=0

 [2020/06/15 03:57:58.686]     format.abort=0

 [2020/06/15 03:57:58.686]     format.independent_thread_rng=1

 [2020/06/15 03:57:58.686]     format.major_timeout=0

 [2020/06/15 03:57:58.686]     logging=0

 [2020/06/15 03:57:58.686]     logging.archive=0

 [2020/06/15 03:57:58.686]     logging.compression=none

 [2020/06/15 03:57:58.686]     logging.file_max=323484

 [2020/06/15 03:57:58.686]     logging.prealloc=0

 [2020/06/15 03:57:58.686]     lsm.auto_throttle=1

 [2020/06/15 03:57:58.686]     lsm.bloom=1

 [2020/06/15 03:57:58.686]     lsm.bloom_bit_count=38

 [2020/06/15 03:57:58.686]     lsm.bloom_hash_count=18

 [2020/06/15 03:57:58.686]     lsm.bloom_oldest=0

 [2020/06/15 03:57:58.686]     lsm.chunk_size=7

 [2020/06/15 03:57:58.686]     lsm.merge_max=15

 [2020/06/15 03:57:58.686]     lsm.worker_threads=3

 [2020/06/15 03:57:58.686]     ops.alter=1

 [2020/06/15 03:57:58.686]     ops.compaction=0

 [2020/06/15 03:57:58.686]     ops.hs_cursor=0

 [2020/06/15 03:57:58.686]     ops.pct.delete=95

 [2020/06/15 03:57:58.686]     ops.pct.insert=0

 [2020/06/15 03:57:58.686]     ops.pct.modify=3

 [2020/06/15 03:57:58.686]     ops.pct.read=2

 [2020/06/15 03:57:58.686]     ops.pct.write=0

 [2020/06/15 03:57:58.686]     ops.prepare=0

 [2020/06/15 03:57:58.686]     ops.random_cursor=0

 [2020/06/15 03:57:58.686]     ops.rebalance=0

 [2020/06/15 03:57:58.686]     ops.salvage=1

 [2020/06/15 03:57:58.686]     ops.truncate=1

 [2020/06/15 03:57:58.686]     ops.verify=1

 [2020/06/15 03:57:58.686]     quiet=1

 [2020/06/15 03:57:58.686]     runs=1

 [2020/06/15 03:57:58.686]     runs.in_memory=0

 [2020/06/15 03:57:58.686]     runs.ops=0

 [2020/06/15 03:57:58.686]     runs.rows=100000

 [2020/06/15 03:57:58.686]     runs.source=table

 [2020/06/15 03:57:58.686]     runs.threads=6

 [2020/06/15 03:57:58.686]     runs.timer=4

 [2020/06/15 03:57:58.686]     runs.type=row-store

 [2020/06/15 03:57:58.686]     runs.verify_failure_dump=0

 [2020/06/15 03:57:58.686]     statistics=0

 [2020/06/15 03:57:58.686]     statistics.server=0

 [2020/06/15 03:57:58.686]     stress.aggressive_sweep=0

 [2020/06/15 03:57:58.686]     stress.checkpoint=0

 [2020/06/15 03:57:58.686]     stress.hs_checkpoint_delay=0

 [2020/06/15 03:57:58.686]     stress.hs_sweep=0

 [2020/06/15 03:57:58.686]     stress.split_1=0

 [2020/06/15 03:57:58.686]     stress.split_2=0

 [2020/06/15 03:57:58.686]     stress.split_3=0

 [2020/06/15 03:57:58.686]     stress.split_4=0

 [2020/06/15 03:57:58.686]     stress.split_5=0

 [2020/06/15 03:57:58.686]     stress.split_6=0

 [2020/06/15 03:57:58.686]     stress.split_7=1

 [2020/06/15 03:57:58.686]     stress.split_8=0

 [2020/06/15 03:57:58.686]     transaction.frequency=100

 [2020/06/15 03:57:58.686]     transaction.isolation=snapshot

 [2020/06/15 03:57:58.686]     transaction.timestamps=1

 [2020/06/15 03:57:58.686]     wiredtiger.config=

 [2020/06/15 03:57:58.686]     wiredtiger.rwlock=1

 [2020/06/15 03:57:58.686]     wiredtiger.leak_memory=0

 [2020/06/15 03:57:58.686]     ############################################

 [2020/06/15 03:57:58.686]     t: FAILED: wts_open/457: wiredtiger_open(home, &event_handler, config, &conn): /data/mci/1eefb1ed0e64db55824b944c7b10a081/wiredtiger/test/format/RUNDIR.4: WT_PANIC: WiredTiger library panic

 [2020/06/15 03:57:58.686]     process aborting

 [2020/06/15 03:57:58.686] format.sh: /data/mci/1eefb1ed0e64db55824b944c7b10a081/wiredtiger/test/format/RUNDIR.4/CONFIG:

 [2020/06/15 03:57:58.686]     ############################################

 [2020/06/15 03:57:58.686]     #  RUN PARAMETERS: V2

 [2020/06/15 03:57:58.686]     ############################################

 [2020/06/15 03:57:58.686]     assert.commit_timestamp=0

 [2020/06/15 03:57:58.686]     assert.read_timestamp=0

 [2020/06/15 03:57:58.686]     backup=0

 [2020/06/15 03:57:58.687]     backup.incremental=off

 [2020/06/15 03:57:58.687]     backup.incr_granularity=4210

 [2020/06/15 03:57:58.687]     btree.bitcnt=4

 [2020/06/15 03:57:58.687]     btree.compression=none

 [2020/06/15 03:57:58.687]     btree.dictionary=0

 [2020/06/15 03:57:58.687]     btree.huffman_key=0

 [2020/06/15 03:57:58.687]     btree.huffman_value=0

 [2020/06/15 03:57:58.687]     btree.internal_key_truncation=1

 [2020/06/15 03:57:58.687]     btree.internal_page_max=9

 [2020/06/15 03:57:58.687]     btree.key_gap=3

 [2020/06/15 03:57:58.687]     btree.key_max=256

 [2020/06/15 03:57:58.687]     btree.key_min=256

 [2020/06/15 03:57:58.687]     btree.leaf_page_max=9

 [2020/06/15 03:57:58.687]     btree.memory_page_max=6

 [2020/06/15 03:57:58.687]     btree.prefix_compression=1

 [2020/06/15 03:57:58.687]     btree.prefix_compression_min=1

 [2020/06/15 03:57:58.687]     btree.repeat_data_pct=67

 [2020/06/15 03:57:58.687]     btree.reverse=0

 [2020/06/15 03:57:58.687]     btree.split_pct=80

 [2020/06/15 03:57:58.687]     btree.value_max=2048

 [2020/06/15 03:57:58.687]     btree.value_min=7

 [2020/06/15 03:57:58.687]     cache=72

 [2020/06/15 03:57:58.687]     cache.evict_max=4

 [2020/06/15 03:57:58.687]     cache.minimum=20

 [2020/06/15 03:57:58.687]     checkpoint=on

 [2020/06/15 03:57:58.687]     checkpoint.log_size=88

 [2020/06/15 03:57:58.687]     checkpoint.wait=68

 [2020/06/15 03:57:58.687]     disk.checksum=uncompressed

 [2020/06/15 03:57:58.687]     disk.data_extend=1

 [2020/06/15 03:57:58.687]     disk.direct_io=0

 [2020/06/15 03:57:58.687]     disk.encryption=rotn-7

 [2020/06/15 03:57:58.687]     disk.firstfit=0

 [2020/06/15 03:57:58.687]     disk.mmap=0

 [2020/06/15 03:57:58.687]     disk.mmap_all=0

 [2020/06/15 03:57:58.687]     format.abort=0

 [2020/06/15 03:57:58.687]     format.independent_thread_rng=1

 [2020/06/15 03:57:58.687]     format.major_timeout=0

 [2020/06/15 03:57:58.687]     logging=0

 [2020/06/15 03:57:58.687]     logging.archive=0

 [2020/06/15 03:57:58.687]     logging.compression=none

 [2020/06/15 03:57:58.687]     logging.file_max=323484

 [2020/06/15 03:57:58.687]     logging.prealloc=0

 [2020/06/15 03:57:58.687]     lsm.auto_throttle=1

 [2020/06/15 03:57:58.687]     lsm.bloom=1

 [2020/06/15 03:57:58.687]     lsm.bloom_bit_count=38

 [2020/06/15 03:57:58.687]     lsm.bloom_hash_count=18

 [2020/06/15 03:57:58.687]     lsm.bloom_oldest=0

 [2020/06/15 03:57:58.687]     lsm.chunk_size=7

 [2020/06/15 03:57:58.687]     lsm.merge_max=15

 [2020/06/15 03:57:58.687]     lsm.worker_threads=3

 [2020/06/15 03:57:58.687]     ops.alter=1

 [2020/06/15 03:57:58.687]     ops.compaction=0

 [2020/06/15 03:57:58.687]     ops.hs_cursor=0

 [2020/06/15 03:57:58.687]     ops.pct.delete=95

 [2020/06/15 03:57:58.687]     ops.pct.insert=0

 [2020/06/15 03:57:58.687]     ops.pct.modify=3

 [2020/06/15 03:57:58.687]     ops.pct.read=2

 [2020/06/15 03:57:58.687]     ops.pct.write=0

 [2020/06/15 03:57:58.687]     ops.prepare=0

 [2020/06/15 03:57:58.687]     ops.random_cursor=0

 [2020/06/15 03:57:58.687]     ops.rebalance=0

 [2020/06/15 03:57:58.687]     ops.salvage=1

 [2020/06/15 03:57:58.687]     ops.truncate=1

 [2020/06/15 03:57:58.687]     ops.verify=1

 [2020/06/15 03:57:58.687]     quiet=1

 [2020/06/15 03:57:58.687]     runs=1

 [2020/06/15 03:57:58.687]     runs.in_memory=0

 [2020/06/15 03:57:58.687]     runs.ops=0

 [2020/06/15 03:57:58.687]     runs.rows=100000

 [2020/06/15 03:57:58.687]     runs.source=table

 [2020/06/15 03:57:58.687]     runs.threads=6

 [2020/06/15 03:57:58.687]     runs.timer=4

 [2020/06/15 03:57:58.687]     runs.type=row-store

 [2020/06/15 03:57:58.687]     runs.verify_failure_dump=0

 [2020/06/15 03:57:58.687]     statistics=0

 [2020/06/15 03:57:58.687]     statistics.server=0

 [2020/06/15 03:57:58.687]     stress.aggressive_sweep=0

 [2020/06/15 03:57:58.687]     stress.checkpoint=0

 [2020/06/15 03:57:58.687]     stress.hs_checkpoint_delay=0

 [2020/06/15 03:57:58.687]     stress.hs_sweep=0

 [2020/06/15 03:57:58.687]     stress.split_1=0

 [2020/06/15 03:57:58.687]     stress.split_2=0

 [2020/06/15 03:57:58.687]     stress.split_3=0

 [2020/06/15 03:57:58.687]     stress.split_4=0

 [2020/06/15 03:57:58.687]     stress.split_5=0

 [2020/06/15 03:57:58.687]     stress.split_6=0

 [2020/06/15 03:57:58.687]     stress.split_7=1

 [2020/06/15 03:57:58.687]     stress.split_8=0

 [2020/06/15 03:57:58.687]     transaction.frequency=100

 [2020/06/15 03:57:58.687]     transaction.isolation=snapshot

 [2020/06/15 03:57:58.687]     transaction.timestamps=1

 [2020/06/15 03:57:58.687]     wiredtiger.config=

 [2020/06/15 03:57:58.687]     wiredtiger.rwlock=1

 [2020/06/15 03:57:58.687]     wiredtiger.leak_memory=0

 [2020/06/15 03:57:58.687]     ############################################

 [2020/06/15 04:01:25.493] format.sh: 2 successful jobs, 1 failed jobs

 [2020/06/15 04:01:25.493] format.sh: 3 successful jobs, 1 failed jobs

 [2020/06/15 04:01:25.495] format.sh: 3 successful jobs, 1 failed jobs

There is a known problem in rebalance (~~WT-6410~~) that it fails because we can't do a single file checkpoint with timestamp. This may be related to that as well. In the case of salvage, I find what we do in the test is that we intentionally corrupt some data, do a salvage, and reopen it. However, with ~~WT-6263~~, we fail to reopen.

Attachments

Issue Links

duplicates

WT-6427 Always set stable timestamp when setting oldest timestamp

Closed

is depended on by

WT-6263 Reenable history store verification

Closed

is duplicated by

WT-6384 rollback to stable test leads to corruption

Closed

Activity

People

Assignee:: Keith Bostic (Inactive)

Reporter:: Chenhao Qu

Votes:: 0 Vote for this issue

Watchers:: 5 Start watching this issue

Dates

Created:: Jun 16 2020 12:37:09 AM UTC

Updated:: Sep 21 2020 03:11:55 AM UTC

Resolved:: Jun 21 2020 10:53:44 PM UTC