Uploaded image for project: 'WiredTiger'
  1. WiredTiger
  2. WT-8054

Cache stuck /cache full clean (non-prepare)

    Link: https://evergreen.mongodb.com/task/wiredtiger_ubuntu1804_stress_tests_race_condition_stress_sanitizer_test_3_f08adbc5b4ced8ea39decd4da4efd40cdce768ec_20_11_26_01_35_54

    Config:

     [2020/11/26 04:26:00.465]     ############################################
     [2020/11/26 04:26:00.465]     #  RUN PARAMETERS: V2
     [2020/11/26 04:26:00.465]     ############################################
     [2020/11/26 04:26:00.465]     assert.commit_timestamp=0
     [2020/11/26 04:26:00.465]     assert.read_timestamp=0
     [2020/11/26 04:26:00.465]     backup=0
     [2020/11/26 04:26:00.465]     backup.incremental=off
     [2020/11/26 04:26:00.465]     backup.incr_granularity=6855
     [2020/11/26 04:26:00.465]     btree.bitcnt=2
     [2020/11/26 04:26:00.465]     btree.compression=none
     [2020/11/26 04:26:00.465]     btree.dictionary=0
     [2020/11/26 04:26:00.465]     btree.huffman_value=0
     [2020/11/26 04:26:00.465]     btree.internal_key_truncation=0
     [2020/11/26 04:26:00.465]     btree.internal_page_max=13
     [2020/11/26 04:26:00.465]     btree.key_gap=0
     [2020/11/26 04:26:00.465]     btree.key_max=115
     [2020/11/26 04:26:00.465]     btree.key_min=15
     [2020/11/26 04:26:00.465]     btree.leaf_page_max=10
     [2020/11/26 04:26:00.465]     btree.memory_page_max=2
     [2020/11/26 04:26:00.465]     btree.prefix_compression=1
     [2020/11/26 04:26:00.465]     btree.prefix_compression_min=5
     [2020/11/26 04:26:00.465]     btree.repeat_data_pct=11
     [2020/11/26 04:26:00.465]     btree.reverse=0
     [2020/11/26 04:26:00.465]     btree.split_pct=63
     [2020/11/26 04:26:00.465]     btree.value_max=2573
     [2020/11/26 04:26:00.465]     btree.value_min=2
     [2020/11/26 04:26:00.465]     cache=24
     [2020/11/26 04:26:00.465]     cache.evict_max=2
     [2020/11/26 04:26:00.465]     cache.minimum=20
     [2020/11/26 04:26:00.465]     checkpoint=wiredtiger
     [2020/11/26 04:26:00.465]     checkpoint.log_size=178
     [2020/11/26 04:26:00.465]     checkpoint.wait=93
     [2020/11/26 04:26:00.465]     disk.checksum=off
     [2020/11/26 04:26:00.465]     disk.data_extend=0
     [2020/11/26 04:26:00.465]     disk.direct_io=0
     [2020/11/26 04:26:00.465]     disk.encryption=rotn-7
     [2020/11/26 04:26:00.465]     disk.firstfit=0
     [2020/11/26 04:26:00.465]     disk.mmap=1
     [2020/11/26 04:26:00.465]     disk.mmap_all=0
     [2020/11/26 04:26:00.465]     format.abort=0
     [2020/11/26 04:26:00.465]     format.independent_thread_rng=1
     [2020/11/26 04:26:00.465]     format.major_timeout=0
     [2020/11/26 04:26:00.465]     logging=0
     [2020/11/26 04:26:00.465]     logging.archive=0
     [2020/11/26 04:26:00.465]     logging.compression=none
     [2020/11/26 04:26:00.465]     logging.file_max=336657
     [2020/11/26 04:26:00.465]     logging.prealloc=0
     [2020/11/26 04:26:00.465]     lsm.auto_throttle=1
     [2020/11/26 04:26:00.465]     lsm.bloom=1
     [2020/11/26 04:26:00.465]     lsm.bloom_bit_count=42
     [2020/11/26 04:26:00.465]     lsm.bloom_hash_count=30
     [2020/11/26 04:26:00.465]     lsm.bloom_oldest=0
     [2020/11/26 04:26:00.465]     lsm.chunk_size=5
     [2020/11/26 04:26:00.465]     lsm.merge_max=5
     [2020/11/26 04:26:00.465]     lsm.worker_threads=4
     [2020/11/26 04:26:00.465]     ops.alter=0
     [2020/11/26 04:26:00.465]     ops.compaction=0
     [2020/11/26 04:26:00.465]     ops.hs_cursor=1
     [2020/11/26 04:26:00.465]     ops.pct.delete=6
     [2020/11/26 04:26:00.465]     ops.pct.insert=57
     [2020/11/26 04:26:00.465]     ops.pct.modify=3
     [2020/11/26 04:26:00.465]     ops.pct.read=20
     [2020/11/26 04:26:00.465]     ops.pct.write=14
     [2020/11/26 04:26:00.465]     ops.prepare=0
     [2020/11/26 04:26:00.465]     ops.random_cursor=1
     [2020/11/26 04:26:00.465]     ops.salvage=0
     [2020/11/26 04:26:00.465]     ops.truncate=1
     [2020/11/26 04:26:00.465]     ops.verify=1
     [2020/11/26 04:26:00.465]     quiet=1
     [2020/11/26 04:26:00.465]     runs=1
     [2020/11/26 04:26:00.465]     runs.in_memory=0
     [2020/11/26 04:26:00.465]     runs.ops=0
     [2020/11/26 04:26:00.465]     runs.rows=5000000
     [2020/11/26 04:26:00.465]     runs.source=file
     [2020/11/26 04:26:00.465]     runs.threads=4
     [2020/11/26 04:26:00.465]     runs.timer=6
     [2020/11/26 04:26:00.465]     runs.type=row-store
     [2020/11/26 04:26:00.465]     runs.verify_failure_dump=0
     [2020/11/26 04:26:00.465]     statistics=0
     [2020/11/26 04:26:00.465]     statistics.server=0
     [2020/11/26 04:26:00.465]     stress.aggressive_sweep=0
     [2020/11/26 04:26:00.465]     stress.checkpoint=0
     [2020/11/26 04:26:00.465]     stress.checkpoint_prepare=0
     [2020/11/26 04:26:00.465]     stress.hs_checkpoint_delay=0
     [2020/11/26 04:26:00.465]     stress.hs_sweep=0
     [2020/11/26 04:26:00.465]     stress.split_1=0
     [2020/11/26 04:26:00.465]     stress.split_2=0
     [2020/11/26 04:26:00.465]     stress.split_3=0
     [2020/11/26 04:26:00.465]     stress.split_4=1
     [2020/11/26 04:26:00.465]     stress.split_5=0
     [2020/11/26 04:26:00.465]     stress.split_6=1
     [2020/11/26 04:26:00.465]     stress.split_7=1
     [2020/11/26 04:26:00.465]     stress.split_8=0
     [2020/11/26 04:26:00.465]     transaction.frequency=100
     [2020/11/26 04:26:00.465]     transaction.isolation=snapshot
     [2020/11/26 04:26:00.465]     transaction.rollback_to_stable=0
     [2020/11/26 04:26:00.465]     transaction.timestamps=1
     [2020/11/26 04:26:00.465]     wiredtiger.config=
     [2020/11/26 04:26:00.465]     wiredtiger.rwlock=1
     [2020/11/26 04:26:00.466]     wiredtiger.leak_memory=0
     [2020/11/26 04:26:00.466]     ############################################
    

    Cache signature:

     [2020/11/26 04:26:00.463]     [1606364757:891645][10225:0x7fc7d32f8700], eviction-server: __evict_server, 446: Cache stuck for too long, giving up: Connection timed out
     [2020/11/26 04:26:00.463]     0x6340000213a0:=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
     [2020/11/26 04:26:00.463]     0x6340000213a0:transaction state dump
     [2020/11/26 04:26:00.463]     0x6340000213a0:current ID: 113
     [2020/11/26 04:26:00.463]     0x6340000213a0:last running ID: 113
     [2020/11/26 04:26:00.463]     0x6340000213a0:metadata_pinned ID: 2
     [2020/11/26 04:26:00.463]     0x6340000213a0:oldest ID: 2
     [2020/11/26 04:26:00.463]     0x6340000213a0:durable timestamp: (0, 3159)
     [2020/11/26 04:26:00.463]     0x6340000213a0:oldest timestamp: (0, 3158)
     [2020/11/26 04:26:00.463]     0x6340000213a0:pinned timestamp: (0, 3158)
     [2020/11/26 04:26:00.463]     0x6340000213a0:stable timestamp: (0, 3159)
     [2020/11/26 04:26:00.463]     0x6340000213a0:has_durable_timestamp: yes
     [2020/11/26 04:26:00.463]     0x6340000213a0:has_oldest_timestamp: yes
     [2020/11/26 04:26:00.463]     0x6340000213a0:has_pinned_timestamp: yes
     [2020/11/26 04:26:00.463]     0x6340000213a0:has_stable_timestamp: yes
     [2020/11/26 04:26:00.463]     0x6340000213a0:oldest_is_pinned: yes
     [2020/11/26 04:26:00.463]     0x6340000213a0:stable_is_pinned: no
     [2020/11/26 04:26:00.463]     0x6340000213a0:checkpoint running: no
     [2020/11/26 04:26:00.463]     0x6340000213a0:checkpoint generation: 6
     [2020/11/26 04:26:00.463]     0x6340000213a0:checkpoint pinned ID: 0
     [2020/11/26 04:26:00.463]     0x6340000213a0:checkpoint txn ID: 0
     [2020/11/26 04:26:00.463]     0x6340000213a0:session count: 16
     [2020/11/26 04:26:00.463]     0x6340000213a0:Transaction state of active sessions:
     [2020/11/26 04:26:00.463]     0x6340000213a0:ID: 0, pinned ID: 2, metadata pinned ID: 0, name: WT_CURSOR.next
     [2020/11/26 04:26:00.463]     0x6340000213a0:transaction id: 0, mod count: 0, snap min: 2, snap max: 4, snapshot count: 1, commit_timestamp: (0, 0), durable_timestamp: (0, 0), first_commit_timestamp: (0, 0), prepare_timestamp: (0, 0), pinned_durable_timestamp: (0, 0), read_timestamp: (0, 0), checkpoint LSN: [0][0], full checkpoint: false, rollback reason: , flags: 0x00000008, isolation: WT_ISO_SNAPSHOT
     [2020/11/26 04:26:00.463]     0x6340000213a0:=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
     [2020/11/26 04:26:00.463]     0x6340000213a0:cache dump
     [2020/11/26 04:26:00.463]     0x6340000213a0:cache full: yes
     [2020/11/26 04:26:00.463]     0x6340000213a0:cache clean check: yes (115.579%)
     [2020/11/26 04:26:00.463]     0x6340000213a0:cache dirty check: no (0.000%)
     [2020/11/26 04:26:00.463]     0x6340000213a0:cache updates check: no (0.016%)
     [2020/11/26 04:26:00.463]     0x6340000213a0:file:wt(<live>):
     [2020/11/26 04:26:00.463]     0x6340000213a0:internal: 96 pages, 25MB, 96/0 clean/dirty pages, 25/0 clean/dirty MB, 2MB max page, 0MB max dirty page
     [2020/11/26 04:26:00.463]     0x6340000213a0:leaf: 1 pages, 0MB, 1/0 clean/dirty pages, 0/0/0 clean/dirty/updates MB, 0MB max page, 0MB max dirty page
     [2020/11/26 04:26:00.463]     0x6340000213a0:file:WiredTigerHS.wt(<live>):
     [2020/11/26 04:26:00.463]     0x6340000213a0:internal: 1 pages, 0MB, 1/0 clean/dirty pages, 0/0 clean/dirty MB, 0MB max page, 0MB max dirty page
     [2020/11/26 04:26:00.463]     0x6340000213a0:leaf: 0 pages
     [2020/11/26 04:26:00.463]     0x6340000213a0:file:WiredTiger.wt(<live>):
     [2020/11/26 04:26:00.463]     0x6340000213a0:internal: 1 pages, 0MB, 1/0 clean/dirty pages, 0/0 clean/dirty MB, 0MB max page, 0MB max dirty page
     [2020/11/26 04:26:00.463]     0x6340000213a0:leaf: 1 pages, 0MB, 1/0 clean/dirty pages, 0/0/0 clean/dirty/updates MB, 0MB max page, 0MB max dirty page
     [2020/11/26 04:26:00.463]     0x6340000213a0:cache dump: total found: 27MB vs tracked inuse 25MB
     [2020/11/26 04:26:00.463]     0x6340000213a0:total dirty bytes: 0MB vs tracked dirty 0MB
     [2020/11/26 04:26:00.463]     0x6340000213a0:total updates bytes: 0MB vs tracked updates 0MB
     [2020/11/26 04:26:00.463]     [1606364757:892542][10225:0x7fc7d32f8700], eviction-server: __wt_evict_thread_run, 321: cache eviction thread error: Connection timed out
     [2020/11/26 04:26:00.463]     [1606364757:892561][10225:0x7fc7d32f8700], eviction-server: __wt_evict_thread_run, 321: the process must exit and restart: WT_PANIC: WiredTiger library panic
     [2020/11/26 04:26:00.463]     [1606364757:892575][10225:0x7fc7d32f8700], eviction-server: __wt_abort, 28: aborting WiredTiger library
    

     

          Assignee:
          sue.loverso@mongodb.com Susan LoVerso
          Reporter:
          siddhartha.mahajan@mongodb.com Sid Mahajan
          Votes:
          0 Vote for this issue
          Watchers:
          13 Start watching this issue

            Created:
            Updated:
            Resolved: