-
Type:
Bug
-
Resolution: Fixed
-
Priority:
Major - P3
-
Affects Version/s: None
-
Component/s: None
-
Labels:
-
Storage Engines
-
2
-
Storage Engines 2018-09-24, Storage Engines 2018-10-08
We have seen test/format failures with:
- Timestamps enabled
- Many threads configured
- A small cache size
- Random isolation level
That are failing due to the cache becoming stuck full of clean internal pages. We should reproduce and understand why those pages aren't being evicted. If possible evict them, if not figure out how to prevent the cache becoming stuck full in format for these configurations.
This failure happened post WT-3799. Timestamps were enabled, and cache was pinned full.
Test failure:
http://build.wiredtiger.com:8080/job/wiredtiger-test-race-condition-stress-sanitizer/26141/
++ nice ./t -1 -c CONFIG [1530663935:672438][10701:0x7fe256bf7700], t, eviction-server: Cache stuck for too long, giving up: Connection timed out t: process 10701 0x7fe25c20f3c0:=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-= 0x7fe25c20f3c0:transaction state dump 0x7fe25c20f3c0:current ID: 116945 0x7fe25c20f3c0:last running ID: 116682 0x7fe25c20f3c0:oldest ID: 116674 0x7fe25c20f3c0:commit timestamp: 45b9f 0x7fe25c20f3c0:oldest timestamp: 45b9f 0x7fe25c20f3c0:pinned timestamp: 45891 0x7fe25c20f3c0:stable timestamp: 0 0x7fe25c20f3c0:has_commit_timestamp: yes 0x7fe25c20f3c0:has_oldest_timestamp: yes 0x7fe25c20f3c0:has_pinned_timestamp: yes 0x7fe25c20f3c0:has_stable_timestamp: no 0x7fe25c20f3c0:oldest_is_pinned: no 0x7fe25c20f3c0:stable_is_pinned: no 0x7fe25c20f3c0:checkpoint running: yes 0x7fe25c20f3c0:checkpoint generation: 3 0x7fe25c20f3c0:checkpoint pinned ID: 105986 0x7fe25c20f3c0:checkpoint txn ID: 106028 0x7fe25c20f3c0:oldest named snapshot ID: 0 0x7fe25c20f3c0:session count: 46 0x7fe25c20f3c0:Transaction state of active sessions: 0x7fe25c20f3c0:ID: 116682, pinned ID: 116674, metadata pinned ID: 106028, name: WT_CURSOR.prev 0x7fe25c211f80:mod count: 1, snap min: 106028, snap max: 116681, commit_timestamp: 4588f, first_commit_timestamp: 4588f, read_timestamp: 45891, flags: 0x0000142c, isolation: WT_ISO_SNAPSHOT 0x7fe25c20f3c0:ID: 116738, pinned ID: 116682, metadata pinned ID: 116682, name: WT_CURSOR.next 0x7fe25c215860:mod count: 3, snap min: 106028, snap max: 116663, commit_timestamp: 4591b, first_commit_timestamp: 4591b, read_timestamp: 4584c, flags: 0x00001004, isolation: WT_ISO_READ_UNCOMMITTED 0x7fe25c20f3c0:ID: 116699, pinned ID: 116682, metadata pinned ID: 116682, name: WT_CURSOR.next 0x7fe25c215cc0:mod count: 2, snap min: 106028, snap max: 116691, commit_timestamp: 458ad, first_commit_timestamp: 458ad, read_timestamp: 458a4, flags: 0x00001004, isolation: WT_ISO_READ_UNCOMMITTED 0x7fe25c20f3c0:=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-= 0x7fe25c20f3c0:cache dump 0x7fe25c20f3c0:cache full: no 0x7fe25c20f3c0:cache clean check: no (79.551%) 0x7fe25c20f3c0:cache dirty check: yes (20.001%)
The configuration:
############################################ # RUN PARAMETERS ############################################ abort=0 alter=1 auto_throttle=1 backups=0 bitcnt=2 bloom=1 bloom_bit_count=6 bloom_hash_count=21 bloom_oldest=0 cache=30 cache_minimum=20 checkpoints=wiredtiger checkpoint_log_size=121 checkpoint_wait=91 checksum=uncompressed chunk_size=4 compaction=0 compression=lz4 data_extend=0 data_source=table delete_pct=29 dictionary=1 direct_io=0 encryption=rotn-7 evict_max=4 file_type=row-store firstfit=0 huffman_key=0 huffman_value=0 independent_thread_rng=0 in_memory=0 insert_pct=6 internal_key_truncation=1 internal_page_max=10 isolation=random key_gap=12 key_max=69 key_min=21 leaf_page_max=11 leak_memory=0 logging=0 logging_archive=0 logging_compression=none logging_file_max=381521 logging_prealloc=1 long_running_txn=0 lsm_worker_threads=3 merge_max=20 mmap=1 modify_pct=8 ops=0 prefix_compression=1 prefix_compression_min=2 prepare=0 quiet=1 read_pct=52 rebalance=1 repeat_data_pct=18 reverse=0 rows=1000000 runs=1 salvage=1 split_pct=94 statistics=0 statistics_server=0 threads=30 timer=4 timing_stress_checkpoint=0 timing_stress_lookaside_sweep=0 timing_stress_split_1=0 timing_stress_split_2=0 timing_stress_split_3=1 timing_stress_split_4=0 timing_stress_split_5=0 timing_stress_split_6=0 timing_stress_split_7=0 timing_stress_split_8=0 timing_stress_split_9=0 transaction_timestamps=1 transaction-frequency=9 truncate=1 value_max=4032 value_min=2 verify=1 wiredtiger_config= write_pct=5 ############################################
- links to
(13 links to)