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

Cache stuck /cache full clean (non-prepare)

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Open
    • Priority: Major - P3
    • Resolution: Unresolved
    • Affects Version/s: None
    • Fix Version/s: Backlog
    • Component/s: None
    • Labels:
      None
    • Story Points:
      13
    • Sprint:
      Storage - Ra 2021-10-18

      Description

      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
      

       

        Attachments

          Activity

            People

            Assignee:
            backlog-server-storage-engines Backlog - Storage Engines Team
            Reporter:
            siddhartha.mahajan Sid Mahajan
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Dates

              Created:
              Updated: