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

Fix cache stuck in race-condition-stress-sanitizer-test-2

    • Type: Icon: Build Failure Build Failure
    • Resolution: Duplicate
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: None
    • Component/s: None
    • None

      Error signature:

      [1618979734:551643][26287:0x7f1f4def8700], eviction-server: __evict_server, 452: Cache stuck for too long, giving up: Connection timed out
      ...
      
      [2021/04/21 04:35:49.916]     [1618979735:295160][26287:0x7f1f4def8700], eviction-server: __wt_evict_thread_run, 324: cache eviction thread error: Connection timed out
      [2021/04/21 04:35:49.916]     [1618979735:295189][26287:0x7f1f4def8700], eviction-server: __wt_evict_thread_run, 324: the process must exit and restart: WT_PANIC: WiredTiger library panic
      [2021/04/21 04:35:49.916]     [1618979735:295203][26287:0x7f1f4def8700], eviction-server: __wt_abort, 28: aborting WiredTiger library 
      [2021/04/21 04:35:49.916]     0x6340000213d0:Transaction state of active sessions:
       [2021/04/21 04:35:49.916]     0x6340000213d0:ID: 0, pinned ID: 70567, metadata pinned ID: 70567, name: WT_CURSOR.next
       [2021/04/21 04:35:49.916]     0x6340000213d0:transaction id: 50382, mod count: 0, snap min: 50368, snap max: 50382, snapshot count: 13, 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: 0x0000040c, isolation: WT_ISO_READ_UNCOMMITTED
       [2021/04/21 04:35:49.916]     0x6340000213d0:=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
       [2021/04/21 04:35:49.916]     0x6340000213d0:cache dump
       [2021/04/21 04:35:49.916]     0x6340000213d0:cache full: no
       [2021/04/21 04:35:49.916]     0x6340000213d0:cache clean check: no (57.692%)
       [2021/04/21 04:35:49.916]     0x6340000213d0:cache dirty check: no (18.343%)
       [2021/04/21 04:35:49.916]     0x6340000213d0:cache updates check: yes (10.119%)
       [2021/04/21 04:35:49.916]     0x6340000213d0:file:wt(<live>):
       [2021/04/21 04:35:49.916]     0x6340000213d0:internal: 6271 pages, 31MB, 5878/393 clean/dirty pages, 29/1 clean/dirty MB, 0MB max page, 0MB max dirty page
       [2021/04/21 04:35:49.916]     0x6340000213d0:leaf: 94870 pages, 201MB, 63053/31817 clean/dirty pages, 127/73/41 clean/dirty/updates MB, 0MB max page, 0MB max dirty page
       [2021/04/21 04:35:49.916]     0x6340000213d0:file:WiredTigerHS.wt(<live>):
       [2021/04/21 04:35:49.916]     0x6340000213d0:internal: 1 pages, 0MB, 0/1 clean/dirty pages, 0/0 clean/dirty MB, 0MB max page, 0MB max dirty page
       [2021/04/21 04:35:49.916]     0x6340000213d0:leaf: 16 pages, 1MB, 6/10 clean/dirty pages, 0/1/0 clean/dirty/updates MB, 0MB max page, 0MB max dirty page
       [2021/04/21 04:35:49.916]     0x6340000213d0:file:WiredTiger.wt(<live>):
       [2021/04/21 04:35:49.916]     0x6340000213d0:internal: 1 pages, 0MB, 1/0 clean/dirty pages, 0/0 clean/dirty MB, 0MB max page, 0MB max dirty page
       [2021/04/21 04:35:49.916]     0x6340000213d0:leaf: 0 pages
       [2021/04/21 04:35:49.916]     0x6340000213d0:cache dump: total found: 253MB vs tracked inuse 235MB
       [2021/04/21 04:35:49.916]     0x6340000213d0:total dirty bytes: 76MB vs tracked dirty 76MB
       [2021/04/21 04:35:49.916]     0x6340000213d0:total updates bytes: 41MB vs tracked updates 44MB
       [2021/04/21 04:35:49.916]     [1618979735:295160][26287:0x7f1f4def8700], eviction-server: __wt_evict_thread_run, 324: cache eviction thread error: Connection timed out
       [2021/04/21 04:35:49.916]     [1618979735:295189][26287:0x7f1f4def8700], eviction-server: __wt_evict_thread_run, 324: the process must exit and restart: WT_PANIC: WiredTiger library panic
       [2021/04/21 04:35:49.916]     [1618979735:295203][26287:0x7f1f4def8700], eviction-server: __wt_abort, 28: aborting WiredTiger library 

      Config:

      [2021/04/21 04:35:49.924]     ############################################
      [2021/04/21 04:35:49.924]     #  RUN PARAMETERS: V2
      [2021/04/21 04:35:49.924]     ############################################
      [2021/04/21 04:35:49.924]     assert.commit_timestamp=0
      [2021/04/21 04:35:49.924]     assert.read_timestamp=0
      [2021/04/21 04:35:49.924]     backup=1
      [2021/04/21 04:35:49.924]     backup.incremental=block
      [2021/04/21 04:35:49.924]     backup.incr_granularity=16384
      [2021/04/21 04:35:49.924]     btree.bitcnt=6
      [2021/04/21 04:35:49.924]     btree.compression=snappy
      [2021/04/21 04:35:49.924]     btree.dictionary=1
      [2021/04/21 04:35:49.924]     btree.huffman_value=0
      [2021/04/21 04:35:49.924]     btree.internal_key_truncation=0
      [2021/04/21 04:35:49.924]     btree.internal_page_max=10
      [2021/04/21 04:35:49.924]     btree.key_gap=15
      [2021/04/21 04:35:49.924]     btree.key_max=128
      [2021/04/21 04:35:49.924]     btree.key_min=17
      [2021/04/21 04:35:49.924]     btree.leaf_page_max=11
      [2021/04/21 04:35:49.924]     btree.memory_page_max=10
      [2021/04/21 04:35:49.924]     btree.prefix_compression=1
      [2021/04/21 04:35:49.924]     btree.prefix_compression_min=0
      [2021/04/21 04:35:49.924]     btree.repeat_data_pct=85
      [2021/04/21 04:35:49.924]     btree.reverse=0
      [2021/04/21 04:35:49.924]     btree.split_pct=52
      [2021/04/21 04:35:49.924]     btree.value_max=3658
      [2021/04/21 04:35:49.924]     btree.value_min=17
      [2021/04/21 04:35:49.924]     cache=440
      [2021/04/21 04:35:49.924]     cache.evict_max=1
      [2021/04/21 04:35:49.924]     cache.minimum=20
      [2021/04/21 04:35:49.924]     checkpoint=on
      [2021/04/21 04:35:49.924]     checkpoint.log_size=92
      [2021/04/21 04:35:49.924]     checkpoint.wait=93
      [2021/04/21 04:35:49.924]     disk.checksum=uncompressed
      [2021/04/21 04:35:49.924]     disk.data_extend=0
      [2021/04/21 04:35:49.924]     disk.direct_io=0
      [2021/04/21 04:35:49.924]     disk.encryption=none
      [2021/04/21 04:35:49.924]     disk.firstfit=0
      [2021/04/21 04:35:49.924]     disk.mmap=1
      [2021/04/21 04:35:49.924]     disk.mmap_all=0
      [2021/04/21 04:35:49.924]     format.abort=0
      [2021/04/21 04:35:49.924]     format.independent_thread_rng=1
      [2021/04/21 04:35:49.924]     format.major_timeout=0
      [2021/04/21 04:35:49.924]     import=0
      [2021/04/21 04:35:49.924]     logging=0
      [2021/04/21 04:35:49.924]     logging.archive=1
      [2021/04/21 04:35:49.924]     logging.compression=none
      [2021/04/21 04:35:49.924]     logging.file_max=257586
      [2021/04/21 04:35:49.924]     logging.prealloc=1
      [2021/04/21 04:35:49.924]     lsm.auto_throttle=1
      [2021/04/21 04:35:49.924]     lsm.bloom=1
      [2021/04/21 04:35:49.924]     lsm.bloom_bit_count=13
      [2021/04/21 04:35:49.924]     lsm.bloom_hash_count=5
      [2021/04/21 04:35:49.924]     lsm.bloom_oldest=1
      [2021/04/21 04:35:49.924]     lsm.chunk_size=7
      [2021/04/21 04:35:49.924]     lsm.merge_max=11
      [2021/04/21 04:35:49.924]     lsm.worker_threads=4
      [2021/04/21 04:35:49.924]     ops.alter=0
      [2021/04/21 04:35:49.924]     ops.compaction=0
      [2021/04/21 04:35:49.924]     ops.hs_cursor=0
      [2021/04/21 04:35:49.924]     ops.pct.delete=0
      [2021/04/21 04:35:49.924]     ops.pct.insert=4
      [2021/04/21 04:35:49.924]     ops.pct.modify=91
      [2021/04/21 04:35:49.924]     ops.pct.read=0
      [2021/04/21 04:35:49.924]     ops.pct.write=5
      [2021/04/21 04:35:49.924]     ops.prepare=0
      [2021/04/21 04:35:49.924]     ops.random_cursor=0
      [2021/04/21 04:35:49.924]     ops.salvage=0
      [2021/04/21 04:35:49.924]     ops.truncate=1
      [2021/04/21 04:35:49.924]     ops.verify=1
      [2021/04/21 04:35:49.924]     quiet=1
      [2021/04/21 04:35:49.924]     runs=1
      [2021/04/21 04:35:49.924]     runs.in_memory=0
      [2021/04/21 04:35:49.924]     runs.ops=0
      [2021/04/21 04:35:49.924]     runs.rows=1000000
      [2021/04/21 04:35:49.924]     runs.source=file
      [2021/04/21 04:35:49.924]     runs.threads=22
      [2021/04/21 04:35:49.924]     runs.timer=16
      [2021/04/21 04:35:49.924]     runs.type=row-store
      [2021/04/21 04:35:49.924]     runs.verify_failure_dump=0
      [2021/04/21 04:35:49.925]     statistics=0
      [2021/04/21 04:35:49.925]     statistics.server=0
      [2021/04/21 04:35:49.925]     stress.aggressive_sweep=0
      [2021/04/21 04:35:49.925]     stress.checkpoint=0
      [2021/04/21 04:35:49.925]     stress.checkpoint_prepare=0
      [2021/04/21 04:35:49.925]     stress.hs_checkpoint_delay=0
      [2021/04/21 04:35:49.925]     stress.hs_search=0
      [2021/04/21 04:35:49.925]     stress.hs_sweep=0
      [2021/04/21 04:35:49.925]     stress.split_1=0
      [2021/04/21 04:35:49.925]     stress.split_2=1
      [2021/04/21 04:35:49.925]     stress.split_3=1
      [2021/04/21 04:35:49.925]     stress.split_4=1
      [2021/04/21 04:35:49.925]     stress.split_5=0
      [2021/04/21 04:35:49.925]     stress.split_6=1
      [2021/04/21 04:35:49.925]     stress.split_7=0
      [2021/04/21 04:35:49.925]     stress.split_8=0
      [2021/04/21 04:35:49.925]     transaction.frequency=100
      [2021/04/21 04:35:49.925]     transaction.isolation=snapshot
      [2021/04/21 04:35:49.925]     transaction.rollback_to_stable=0
      [2021/04/21 04:35:49.925]     transaction.timestamps=1
      [2021/04/21 04:35:49.925]     wiredtiger.config=
      [2021/04/21 04:35:49.925]     wiredtiger.rwlock=1
      [2021/04/21 04:35:49.925]     wiredtiger.leak_memory=0
      [2021/04/21 04:35:49.925]     ############################################ 

            Assignee:
            backlog-server-storage-engines [DO NOT USE] Backlog - Storage Engines Team
            Reporter:
            etienne.petrel@mongodb.com Etienne Petrel
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Created:
              Updated:
              Resolved: