(disagg.mode=leader) Test/format key OOO (internal page delta)

XMLWordPrintableJSON

      There is an key OOO that only happens with internal page delta on and leaf page delta turned off. The issue reproduces consistently with the CONFIG. Here is the error:

      [2025/09/30 14:17:15.687] 0x731a7fc8a8b0:[1759205835:687490][31934:0xffff2b3fdbc0], t, file:T00002.wt_stable, eviction-server: [WT_VERB_EVICTION][WARNING]: Eviction took more than 1 minute (68886900us). Building disk image took 68858332us. History store wrapup took 8us.
      [2025/09/30 14:18:13.714] 0x731a7fc8af78:[1759205893:714042][31934:0xffff2a9edbc0], t, file:T00002.wt_stable, eviction-server: [WT_VERB_EVICTION][WARNING]: Eviction took more than 1 minute (127332352us). Building disk image took 127302781us. History store wrapup took 9us.
      [2025/09/30 14:24:57.878] table.1 skipped verify because verify does not support disagg delta pages. table.2 skipped verify because verify does not support disagg delta pages. table.3 skipped verify because verify does not support disagg delta pages. 0x731a7fc8a8b0:[1759206297:878925][31934:0xffff2b3fdbc0], t, file:T00003.wt_stable, eviction-server: [WT_VERB_EVICTION][WARNING]: Eviction took more than 1 minute (79015322us). Building disk image took 55972988us. History store wrapup took 114us.
      [2025/09/30 14:25:01.085] 0x731a7fc8b640:[1759206301:085414][31934:0xffff29fddbc0], t, file:T00003.wt_stable, eviction-server: [WT_VERB_EVICTION][WARNING]: Eviction took more than 1 minute (81088877us). Building disk image took 77910102us. History store wrapup took 0us.
      [2025/09/30 14:26:13.583] 0x731a7fc8a8b0:[1759206373:583315][31934:0xffff2b3fdbc0], t, file:T00002.wt_stable, eviction-server: [WT_VERB_EVICTION][WARNING]: Eviction took more than 1 minute (75582398us). Building disk image took 65504122us. History store wrapup took 81us.
      [2025/09/30 14:43:07.500] 0x731a7fc8af78:[1759207387:500618][31934:0xffff2a9edbc0], t, file:T00003.wt_stable, eviction-server: [WT_VERB_EVICTION][WARNING]: Eviction took more than 1 minute (108747207us). Building disk image took 100716922us. History store wrapup took 54us.
      [2025/09/30 14:43:11.200] 0x731a7fc8b640:[1759207391:200718][31934:0xffff29fddbc0], t, file:T00003.wt_stable, eviction-server: [WT_VERB_EVICTION][WARNING]: Eviction took more than 1 minute (112348257us). Building disk image took 102176763us. History store wrapup took 57us.
      [2025/09/30 14:44:58.878] 0x731a7fc8b640:[1759207498:878182][31934:0xffff29fddbc0], t, file:T00003.wt_stable, eviction-server: [WT_VERB_EVICTION][WARNING]: Eviction took more than 1 minute (107677407us). Building disk image took 101738648us. History store wrapup took 41us.
      [2025/09/30 14:45:04.483] 0x731a7fc8af78:[1759207504:483152][31934:0xffff2a9edbc0], t, file:T00003.wt_stable, eviction-server: [WT_VERB_EVICTION][WARNING]: Eviction took more than 1 minute (116982479us). Building disk image took 100454538us. History store wrapup took 50us.
      [2025/09/30 14:46:54.353] 0x731a7fc8af78:[1759207614:353338][31934:0xffff2a9edbc0], t, file:T00003.wt_stable, eviction-server: [WT_VERB_EVICTION][WARNING]: Eviction took more than 1 minute (109870240us). Building disk image took 104169772us. History store wrapup took 66us.
      [2025/09/30 14:46:59.540] 0x731a7fc8b640:[1759207619:540465][31934:0xffff29fddbc0], t, file:T00003.wt_stable, eviction-server: [WT_VERB_EVICTION][WARNING]: Eviction took more than 1 minute (120662339us). Building disk image took 103367389us. History store wrapup took 79us.
      [2025/09/30 14:47:46.310] 0x731a7fc8a8b0:[1759207666:310393][31934:0xffff2b3fdbc0], t, file:T00003.wt_stable, eviction-server: [WT_VERB_EVICTION][WARNING]: Eviction took more than 1 minute (396134307us). Building disk image took 379494610us. History store wrapup took 65us.
      [2025/09/30 15:03:13.845] 0x731a7fc8af78:[1759208593:845574][31934:0xffff2a9edbc0], t, file:T00003.wt_stable, eviction-server: [WT_VERB_EVICTION][WARNING]: Eviction took more than 1 minute (128052498us). Building disk image took 121115547us. History store wrapup took 234us.
      [2025/09/30 15:03:14.567] 0x731a7fc8a8b0:[1759208594:567123][31934:0xffff2b3fdbc0], t, file:T00003.wt_stable, eviction-server: [WT_VERB_EVICTION][WARNING]: Eviction took more than 1 minute (128733974us). Building disk image took 121740388us. History store wrapup took 206us.
      [2025/09/30 15:29:11.250] table.1 skipped verify because verify does not support disagg delta pages. table.2 skipped verify because verify does not support disagg delta pages. table.3 skipped verify because verify does not support disagg delta pages. t: successful run completed (5081 seconds)
      [2025/09/30 15:29:11.308]  t: process 34885 running
      [2025/09/30 15:29:13.750]   ./t -R $format_args  || fail
      [2025/09/30 15:29:13.750] done
      [2025/09/30 15:29:13.750] [1759210153:750803][34885:0xffff213fdbc0], t, file:T00003.wt_stable, WT_CURSOR.prev: [WT_VERB_OUT_OF_ORDER][ERROR]: WT_CURSOR.prev out-of-order returns: returned key 0000498447.00/opqrstuvw then key 0000498479.00/opqrstuvwxyz
      

      CONFIG:

      ############################################
      #  RUN PARAMETERS: V3
      ############################################
      assert.read_timestamp=0
      background_compact=0
      background_compact.free_space_target=80
      backup=0
      backup.incremental=off
      backup.incr_granularity=5811
      backup.live_restore=0
      backup.live_restore_read_size=64
      backup.live_restore_threads=0
      block_cache=1
      block_cache.cache_on_checkpoint=0
      block_cache.cache_on_writes=1
      block_cache.size=1296
      cache=6480
      cache.evict_max=2
      cache.eviction_dirty_target=0
      cache.eviction_dirty_trigger=0
      cache.eviction_updates_target=0
      cache.eviction_updates_trigger=0
      cache.minimum=0
      cache.maximum=0
      checkpoint=on
      checkpoint.log_size=44
      checkpoint.wait=28
      chunk_cache=0
      chunk_cache.capacity=4236
      chunk_cache.chunk_size=3
      chunk_cache.storage_path=off
      chunk_cache.type=off
      compact.free_space_target=28
      debug.background_compact=0
      debug.checkpoint_retention=3
      debug.cursor_reposition=0
      debug.eviction=0
      debug.log_retention=1
      debug.realloc_exact=0
      debug.realloc_malloc=0
      debug.slow_checkpoint=0
      debug.table_logging=0
      debug.update_restore_evict=0
      disagg.page_log=palm
      disagg.mode=leader
      disagg.enabled=1
      disagg.layered=1
      disk.data_extend=0
      disk.encryption=none
      disk.mmap=1
      disk.mmap_all=0
      eviction.evict_use_softptr=0
      file_manager.close_handle_minimum=6
      file_manager.close_idle_time=37
      file_manager.close_scan_interval=0
      format.abort=0
      format.independent_thread_rng=1
      format.major_timeout=0
      import=0
      logging=0
      logging.compression=none
      logging.file_max=251364
      logging.prealloc=0
      logging.remove=0
      obsolete_cleanup.method=off
      obsolete_cleanup.wait=2789
      ops.alter=0
      ops.compaction=0
      ops.hs_cursor=0
      ops.pct.modify=0
      ops.bound_cursor=1
      ops.prepare=0
      ops.random_cursor=1
      ops.salvage=0
      ops.throttle=0
      ops.throttle.sleep_us=163780
      ops.truncate=0
      ops.verify=1
      prefetch=0
      precise_checkpoint=1
      preserve_prepared=0
      quiet=1
      random.data_seed=2331135
      random.extra_seed=2154478
      runs.in_memory=0
      runs.mirror=1
      runs.ops=300000
      runs.predictable_replay=0
      runs.rows=100000
      runs.source=layered
      runs.tables=2
      runs.threads=26
      runs.timer=3
      runs.type=row-store
      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=0
      stress.split_3=0
      stress.split_4=0
      stress.split_5=0
      stress.split_6=1
      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=0
      wiredtiger.leak_memory=0
      ############################################
      #  TABLE PARAMETERS: table 1
      ############################################
      table1.btree.compression=none
      table1.btree.dictionary=0
      table1.btree.internal_key_truncation=1
      table1.btree.internal_page_max=13
      table1.btree.key_max=41
      table1.btree.key_min=31
      table1.btree.leaf_page_max=11
      table1.btree.memory_page_max=6
      table1.btree.prefix_len=0
      table1.btree.prefix_compression=1
      table1.btree.prefix_compression_min=7
      table1.btree.reverse=0
      table1.btree.split_pct=79
      table1.btree.value_max=2974
      table1.btree.value_min=13
      table1.disagg.enabled=0
      table1.disk.checksum=uncompressed
      table1.disk.firstfit=1
      table1.ops.pareto=0
      table1.ops.pareto.skew=19
      table1.ops.pct.delete=46
      table1.ops.pct.insert=38
      table1.ops.pct.read=4
      table1.ops.pct.write=12
      table1.runs.rows=352397
      table1.runs.source=table
      ############################################
      #  TABLE PARAMETERS: table 2
      ############################################
      table2.btree.compression=none
      table2.btree.dictionary=1
      table2.btree.internal_key_truncation=1
      table2.btree.internal_page_max=14
      table2.btree.key_max=42
      table2.btree.key_min=24
      table2.btree.leaf_page_max=16
      table2.btree.memory_page_max=9
      table2.btree.prefix_len=0
      table2.btree.prefix_compression=1
      table2.btree.prefix_compression_min=4
      table2.btree.reverse=0
      table2.btree.split_pct=89
      table2.btree.value_max=588
      table2.btree.value_min=12
      table2.disk.checksum=on
      table2.disk.firstfit=0
      table2.ops.pareto=0
      table2.ops.pareto.skew=96
      table2.ops.pct.delete=71
      table2.ops.pct.insert=9
      table2.ops.pct.read=19
      table2.ops.pct.write=1
      table2.runs.rows=352397
      ############################################
      #  TABLE PARAMETERS: table 3
      ############################################
      table3.btree.compression=none
      table3.btree.dictionary=1
      table3.btree.internal_key_truncation=1
      table3.btree.internal_page_max=12
      table3.btree.key_max=102
      table3.btree.key_min=15
      table3.btree.leaf_page_max=14
      table3.btree.memory_page_max=1
      table3.btree.prefix_len=0
      table3.btree.prefix_compression=1
      table3.btree.prefix_compression_min=4
      table3.btree.reverse=0
      table3.btree.split_pct=68
      table3.btree.value_max=2094
      table3.btree.value_min=18
      table3.disk.checksum=uncompressed
      table3.disk.firstfit=1
      table3.ops.pareto=0
      table3.ops.pareto.skew=19
      table3.ops.pct.delete=8
      table3.ops.pct.insert=4
      table3.ops.pct.read=47
      table3.ops.pct.write=41
      table3.runs.mirror=0
      table3.runs.rows=352397
      

            Assignee:
            [DO NOT USE] Backlog - Storage Engines Team
            Reporter:
            Jie Chen
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Created:
              Updated: