[test/format] Cache stuck: dirty eviction pressure (26%) causes timeout (stress.split_2 + compact)

XMLWordPrintableJSON

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

      format-stress-test-2 on ubuntu2004-stress-tests-arm64

      Host: i-0604703e4d9cad7b6
      Project: wiredtiger
      Commit: 88eb57ca
      Please refer to BF(G) Playbook for instructions on handling BF and BFG tickets as well as Auto-Resolution Rules

      Task Logs:

      format-stress-test-2 task_log

      Logs:

          [1778063780:247676][49365:0xffff9f051c80], t, WT_SESSION.compact: [WT_VERB_DEFAULT][ERROR]: __compact_worker, 344: Compaction halted at data handle file:T00002.wt by eviction pressure. Returning EBUSY.: Device or resource busy
      
      

      logs

      format-stress-test-2 task_log

      Logs:

          format run more than 15 minutes past the maximum time
      

      logs

      format-stress-test-2 task_log

      Logs:

          format run dumping cache and transaction state, then aborting the process
      
      

      logs

      format-stress-test-2 task_log

      Logs:

          0x135a3feb0000:transaction state dump
          0x135a3feb0000:current ID: 16806
          0x135a3feb0000:last running ID: 16806
          0x135a3feb0000:metadata_pinned ID: 16806
          0x135a3feb0000:oldest ID: 16806
          0x135a3feb0000:durable timestamp: (0, 50416997)
          0x135a3feb0000:oldest timestamp: (0, 50414795)
          0x135a3feb0000:pinned timestamp: (0, 50414795)
          0x135a3feb0000:stable timestamp: (0, 50414795)
          0x135a3feb0000:stable disaggregated schema epoch: (0, 0)
          0x135a3feb0000:has_durable_timestamp: yes
          0x135a3feb0000:has_oldest_timestamp: yes
          0x135a3feb0000:has_pinned_timestamp: yes
          0x135a3feb0000:has_stable_timestamp: yes
          0x135a3feb0000:has_stable_disaggregated_schema_epoch: no
          0x135a3feb0000:oldest_is_pinned: yes
          0x135a3feb0000:stable_is_pinned: yes
          0x135a3feb0000:checkpoint running: no
          0x135a3feb0000:checkpoint generation: 24
          0x135a3feb0000:checkpoint pinned ID: 0
          0x135a3feb0000:checkpoint txn ID: 0
          0x135a3feb0000:session count: 39
          0x135a3feb0000:Transaction state of active sessions:
          0x135a3feb0000:=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
          0x135a3feb0000:cache dump
          0x135a3feb0000:cache full: no
          0x135a3feb0000:cache clean check: no (69.723%)
          0x135a3feb0000:cache dirty check: yes (26.198%)
          0x135a3feb0000:cache updates check: no (3.339%)
          0x135a3feb0000:file:T00007.wt(checkpoint=WiredTigerCheckpoint.22):
          0x135a3feb0000:internal: 86 pages, 36964.43 KB, 86/0 clean/dirty pages, 36964.43/0.00 clean / dirty KB, 745.49 KB max page, 0.00 KB max dirty page
          0x135a3feb0000:leaf: 159171 pages, 266088.17 KB, 159171/0 clean/dirty pages, 266088.17 /0.00 /0.00 clean/dirty/updates KB, 4.90 KB max page, 0.00 KB max dirty page
          0x135a3feb0000:file:T00001.wt(checkpoint=WiredTigerCheckpoint.22):
          0x135a3feb0000:internal: 27 pages, 767.72 KB, 27/0 clean/dirty pages, 767.72/0.00 clean / dirty KB, 30.93 KB max page, 0.00 KB max dirty page
          0x135a3feb0000:leaf: 3730 pages, 216041.54 KB, 3730/0 clean/dirty pages, 216041.54 /0.00 /0.00 clean/dirty/updates KB, 61.62 KB max page, 0.00 KB max dirty page
          0x135a3feb0000:file:WiredTigerHS.wt(checkpoint=WiredTigerCheckpoint.13):
          0x135a3feb0000:internal: 1 pages, 0.41 KB, 1/0 clean/dirty pages, 0.41/0.00 clean / dirty KB, 0.41 KB max page, 0.00 KB max dirty page
          0x135a3feb0000:leaf: 0 pages
          0x135a3feb0000:file:T00007.wt(<live>):
          Segmentation fault (core dumped)
          *** Segmentation fault
          Backtrace:
          /data/mci/b1c55ceea9c2485f2a7fa3c6f75186aa/wiredtiger/cmake_build/test/format/../../libwiredtiger.so.12.0.0(+0x107f64)[0xffffae777f64]
          /data/mci/b1c55ceea9c2485f2a7fa3c6f75186aa/wiredtiger/cmake_build/test/format/../../libwiredtiger.so.12.0.0(+0x108508)[0xffffae778508]
          /data/mci/b1c55ceea9c2485f2a7fa3c6f75186aa/wiredtiger/cmake_build/test/format/../../libwiredtiger.so.12.0.0(__wt_tree_walk+0x1c)[0xffffae778e78]
          /data/mci/b1c55ceea9c2485f2a7fa3c6f75186aa/wiredtiger/cmake_build/test/format/../../libwiredtiger.so.12.0.0(+0x1f6d94)[0xffffae866d94]
          /data/mci/b1c55ceea9c2485f2a7fa3c6f75186aa/wiredtiger/cmake_build/test/format/../../libwiredtiger.so.12.0.0(+0x1f718c)[0xffffae86718c]
          /data/mci/b1c55ceea9c2485f2a7fa3c6f75186aa/wiredtiger/cmake_build/test/format/../../libwiredtiger.so.12.0.0(__wt_verbose_dump_cache+0x318)[0xffffae86b280]
          /data/mci/b1c55ceea9c2485f2a7fa3c6f75186aa/wiredtiger/cmake_build/test/format/../../libwiredtiger.so.12.0.0(+0x150dd8)[0xffffae7c0dd8]
          /data/mci/b1c55ceea9c2485f2a7fa3c6f75186aa/wiredtiger/test/format/ops.c:463(operations)[0x417da4]
          /data/mci/b1c55ceea9c2485f2a7fa3c6f75186aa/wiredtiger/test/format/t.c:395 (discriminator 3)(main)[0x41bbc0]
          /lib/aarch64-linux-gnu/libc.so.6(__libc_start_main+0xe8)[0xffffae3dee10]
          ??:?(_start)[0x402eb4]
          Memory map:
          00400000-00441000 r-xp 00000000 103:00 201326879 /data/mci/b1c55ceea9c2485f2a7fa3c6f75186aa/wiredtiger/cmake_build/test/format/t
          0045f000-00460000 r--p 0004f000 103:00 201326879 /data/mci/b1c55ceea9c2485f2a7fa3c6f75186aa/wiredtiger/cmake_build/test/format/t
          00460000-00462000 rw-p 00050000 103:00 201326879 /data/mci/b1c55ceea9c2485f2a7fa3c6f75186aa/wiredtiger/cmake_build/test/format/t
          00462000-00470000 rw-p 00000000 00:00 0
          fa400000000-fa43e600000 ---p 00000000 00:00 0
          fa43e600000-fa440000000 rw-p 00000000 00:00 0
          135a00000000-135a40200000 rw-p 00000000 00:00 0
          135a40200000-135a80200000 rw-p 00000000 00:00 0
          135a80200000-135ac0200000 rw-p 00000000 00:00 0
          135ac0200000-135b00200000 rw-p 00000000 00:00 0
          135b00200000-135b40000000 rw-p 00000000 00:00 0
          135b40000000-135b54200000 ---p 00000000 00:00 0
          135b54200000-135b80000000 rw-p 00000000 00:00 0
          210321000000-210321202000 ---p 00000000 00:00 0
          62b980000000-62b9b6800000 ---p 00000000 00:00 0
          62b9b6800000-62b9c0000000 rw-p 00000000 00:00 0
          fffee6323000-ffff76c84000 rw-s 00000000 103:00 741379354 /data/mci/b1c55ceea9c2485f2a7fa3c6f75186aa/wiredtiger/cmake_build/test/format/RUNDIR.103/T00007.wt
          ffff76c84000-ffff76c85000 ---p 00000000 00:00 0
          ffff76c85000-ffff77485000 rw-p 00000000 00:00 0
          ffff77485000-ffff77486000 ---p 00000000 00:00 0
          ffff77486000-ffff77c86000 rw-p 00000000 00:00 0
          ffff77c86000-ffff77c87000 ---p 00000000 00:00 0
      /data/mci/b1c55ceea9c2485f2a7fa3c6f75186aa/wiredtiger/cmake_build/test/format/RUNDIR.103/CONFIG:
          ############################################
          #  RUN PARAMETERS: V3
          ############################################
          assert.read_timestamp=0
          background_compact=1
          background_compact.free_space_target=57
          backup=1
          backup.incremental=off
          backup.incr_granularity=11281
          backup.live_restore=0
          backup.live_restore_read_size=512
          backup.live_restore_threads=9
          block_cache=0
          block_cache.cache_on_checkpoint=0
          block_cache.cache_on_writes=1
          block_cache.size=28
          cache=3072
          cache.evict_max=3
          cache.eviction_dirty_target=0
          cache.eviction_dirty_trigger=0
          cache.eviction_updates_target=0
          cache.eviction_updates_trigger=0
          cache.minimum=20
          cache.maximum=3145
          checkpoint=on
          checkpoint.log_size=59
          checkpoint.wait=60
          checkpoint_threads=2
          compact.free_space_target=93
          debug.background_compact=0
          debug.checkpoint_retention=6
          debug.cursor_reposition=0
          debug.eviction=0
          debug.log_retention=9
          debug.realloc_exact=0
          debug.realloc_malloc=0
          debug.slow_checkpoint=0
          debug.table_logging=0
          debug.update_restore_evict=0
          disagg.internal_page_delta=1
          disagg.leaf_page_delta=1
          disagg.multi=0
          disagg.multi_validation=0
          disagg.layered=1
          disagg.mode=off
          disagg.page_log=off
          disagg.key_provider=0
          disagg.page_log.verbose=0
          disagg.drain_threads=6
          disagg.preserve=0
          disk.data_extend=0
          disk.encryption=rotn-7
          disk.mmap=1
          disk.mmap_all=0
          eviction.evict_use_softptr=0
          file_manager.close_handle_minimum=24
          file_manager.close_idle_time=12
          file_manager.close_scan_interval=14
          format.abort=0
          format.independent_thread_rng=1
          format.major_timeout=0
          import=0
          logging=0
          logging.compression=none
          logging.file_max=402820
          logging.prealloc=0
          logging.remove=1
          obsolete_cleanup.method=off
          obsolete_cleanup.wait=1810
          ops.alter=0
          ops.compaction=1
          ops.hs_cursor=1
          ops.bound_cursor=0
          ops.prepare=0
          ops.reserve=11
          ops.random_cursor=0
          ops.salvage=0
          ops.throttle=0
          ops.throttle.sleep_us=792180
          ops.verify=1
          prefetch=1
          prefetch.default=0
          precise_checkpoint=1
          preserve_prepared=1
          quiet=1
          random.data_seed=10328451
          random.extra_seed=14963159
          rollback_to_stable_threads=0
          runs.in_memory=0
          runs.ops=0
          runs.predictable_replay=0
          runs.rows=4200000
          runs.tables=7
          runs.threads=10
          runs.timer=11
          runs.verify_failure_dump=0
          statistics.mode=fast
          statistics_log.sources=off
          stress.aggressive_stash_free=0
          stress.aggressive_sweep=0
          stress.checkpoint=0
          stress.checkpoint_evict_page=0
          stress.checkpoint_prepare=0
          stress.compact_slow=0
          stress.evict_reposition=0
          stress.failpoint_eviction_split=0
          stress.failpoint_hs_delete_key_from_ts=0
          stress.failpoint_rec_before_wrapup=0
          stress.hs_checkpoint_delay=0
          stress.hs_search=0
          stress.hs_sweep=0
          stress.prefetch_delay=0
          stress.prepare_resolution_1=0
          stress.sleep_before_read_overflow_onpage=0
          stress.split_1=0
          stress.split_2=1
          stress.split_3=0
          stress.split_4=0
          stress.split_5=0
          stress.split_6=0
          stress.split_7=0
          stress.split_8=0
          tiered_storage.flush_frequency=0
          tiered_storage.storage_source=off
          transaction.implicit=0
          transaction.operation_timeout_ms=2000
          transaction.timestamps=1
          wiredtiger.config=off
          wiredtiger.rwlock=1
          wiredtiger.leak_memory=0
          ############################################
          #  TABLE PARAMETERS: table 1
          ############################################
          table1.btree.compression=zlib
          table1.btree.dictionary=0
          table1.btree.internal_key_truncation=1
          table1.btree.internal_page_max=12
          table1.btree.key_max=122
          table1.btree.key_min=14
          table1.btree.leaf_page_max=14
          table1.btree.memory_page_max=9
          table1.btree.prefix_len=0
          table1.btree.prefix_compression=1
          table1.btree.prefix_compression_min=2
          table1.btree.reverse=0
          table1.btree.split_pct=87
          table1.btree.value_max=3812
          table1.btree.value_min=13
          table1.disagg.enabled=0
          table1.disk.checksum=on
          table1.disk.firstfit=1
          table1.ops.pareto=0
          table1.ops.pareto.skew=67
          table1.ops.pct.delete=27
          table1.ops.pct.insert=33
          table1.ops.pct.modify=26
          table1.ops.pct.read=2
          table1.ops.pct.write=12
          table1.ops.truncate=1
          table1.runs.mirror=1
          table1.runs.source=table
          table1.runs.type=row-store
          ############################################
          #
      

      logs

      Repro Artifacts:

            Assignee:
            [DO NOT USE] Backlog - Storage Engines Team
            Reporter:
            xgen-buildbaron-user
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Created:
              Updated: