Investigate why version cursor cannot access the HS entry

    • Type: Task
    • Resolution: Unresolved
    • Priority: Major - P3
    • None
    • Affects Version/s: None
    • Component/s: Cursors
    • None
    • Storage Engines, Storage Engines - Foundations
    • None
    • None

      Reproducer comes from WT-16125 which creates an orphan entry in the HS (in an unusual way). This reproducer also re-opens the db, re-inserts the same key and the idea is to check if we can access it with the version cursor:

      commit 721a6c8cf43db0c264c0c4e1cb1d64fcea2a5e06 (HEAD -> develop, origin/develop, origin/HEAD)
      
      # You will need these changes too to bypass RTS:
      diff --git a/src/rollback_to_stable/rts_btree_walk.c b/src/rollback_to_stable/rts_btree_walk.c
      index 02827863dc..337a731635 100644
      --- a/src/rollback_to_stable/rts_btree_walk.c
      +++ b/src/rollback_to_stable/rts_btree_walk.c
      @@ -381,6 +381,7 @@ __wti_rts_btree_walk_btree_apply(
       
           WT_RET_NOTFOUND_OK(ret);
       
      +    prepared_updates = true;
           if (modified || max_durable_ts > rollback_timestamp || prepared_updates ||
             has_txn_updates_gt_than_ckpt_snap) {
               __wt_verbose_multi(session, WT_VERB_RECOVERY_RTS(session),
      
      class test_hs34(wttest.WiredTigerTestCase):
      
          def open_version_cursor(self, visible_only=False, start_ts=None):
              internal_config = ["enabled=true", "cross_key=false"]
              if visible_only:
                  internal_config.append("visible_only=true")
              if start_ts is not None:
                  internal_config.append("start_timestamp=" + self.timestamp_str(start_ts))
      
              config = "debug=(dump_version=(" + ",".join(internal_config) + "))"
              self.prout(config)
              return self.session.open_cursor("file:tablehs34.wt", None, config)
      
          def test_hs_recovery(self):
      
              # Pin oldest and stable timestamp to 1.
              self.conn.set_timestamp('oldest_timestamp=' + self.timestamp_str(1) +
                  ',stable_timestamp=' + self.timestamp_str(1))
      
              # Create a table.
              uri = 'table:tablehs34'
              self.session.create(uri,"key_format=S,value_format=S")
      
              # Insert
              cursor = self.session.open_cursor(uri)
              self.session.begin_transaction()
              cursor["a"] = "a"
              self.session.commit_transaction("commit_timestamp=" + self.timestamp_str(10))
      
              self.session.begin_transaction()
              cursor["a"] = "b"
              self.session.commit_transaction("commit_timestamp=" + self.timestamp_str(20))
              cursor.close()
      
              self.conn.set_timestamp('stable_timestamp=' + self.timestamp_str(20))
      
              # Force eviction.
              evict_cursor = self.session.open_cursor(uri, None, "debug=(release_evict)")
              self.session.begin_transaction("ignore_prepare=true")
              evict_cursor.set_key("a")
              evict_cursor.search()
              evict_cursor.reset()
              evict_cursor.close()
              self.session.rollback_transaction()
      
              # Move data to HS and everything is clean.
              self.session.checkpoint()
      
              # Do the delete.
              cursor = self.session.open_cursor(uri)
              self.session.begin_transaction()
              cursor.set_key("a")
              cursor.remove()
              self.session.commit_transaction("commit_timestamp=" + self.timestamp_str(30))
              cursor.close()
      
              self.conn.set_timestamp('oldest_timestamp=' + self.timestamp_str(30) +
                  ',stable_timestamp=' + self.timestamp_str(30))
      
              # Force eviction.
              evict_cursor = self.session.open_cursor(uri, None, "debug=(release_evict)")
              self.session.begin_transaction("ignore_prepare=true")
              evict_cursor.set_key("a")
              evict_cursor.search()
              evict_cursor.reset()
              evict_cursor.close()
              self.session.rollback_transaction()
      
              self.session.checkpoint()
      
              self.close_conn('use_timestamp=false')
              self.reopen_conn()
              cursor = self.session.open_cursor(uri)
              self.session.begin_transaction()
              cursor["a"] = "z"
              self.session.commit_transaction("commit_timestamp=" + self.timestamp_str(40))
              self.session.begin_transaction()
              cursor["a"] = "z1"
              self.session.commit_transaction("commit_timestamp=" + self.timestamp_str(41))
              self.conn.set_timestamp('oldest_timestamp=' + self.timestamp_str(1) +
                  ',stable_timestamp=' + self.timestamp_str(41))
      
              # Open a version cursor
              self.session.begin_transaction()
              version_cursor = self.open_version_cursor()
              version_cursor.set_key("a")
              self.assertEqual(version_cursor.search(), 0)
              self.assertEqual(version_cursor.get_key(), "a")
              self.prout("value is " + str(version_cursor.get_value()))
              self.assertEqual(version_cursor.next(), 0)
              self.prout("value is " + str(version_cursor.get_value()))
              self.assertEqual(version_cursor.next(), 0)
              self.prout("value is " + str(version_cursor.get_value()))
      
      

      Output should be:

      [pid:42692]: debug=(dump_version=(enabled=true,cross_key=false))
      [pid:42692]: value is [3, 41, 41, 18446744073709551605, 18446744073709551615, 0, 3, 0, 0, 0, 'z1']
      [pid:42692]: value is [2, 40, 40, 3, 41, 41, 3, 0, 0, 0, 'z']
      [pid:42692]: ERROR in test_hs34.test_hs34.test_hs_recovery
      F
      ======================================================================
      FAIL: test_hs34.test_hs34.test_hs_recovery
      ----------------------------------------------------------------------
      Traceback (most recent call last):
        File "wiredtiger/test/suite/wttest.py", line 290, in _callTestMethod
          method()
        File "wiredtiger/test/suite/test_hs34.py", line 103, in test_hs_recovery
          self.assertEqual(version_cursor.next(), 0)
      AssertionError: -31803 != 0
      

      Instead of the error, I want to know if the version cursor is supposed to see all the HS entries:

      =-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
      file:WiredTigerHS.wt, ckpt_name: WiredTigerCheckpoint.3
      Root:
              > addr: [0: 12288-16384, 4096, 2008333683]
      - 0x100654200: row-store internal
              > ref: 0x100654200 | ref_state: memory | page_type: [internal]
              > disk_img: 0x8f6c33000 | dsk_mem_size: 58 | write_gen: 22 | entries: 1 | state: clean | flags: [disk-alloc] | page_mem_size: 458
              K: {\00}
              ref: 0x8f6c54780 | ref_state: disk | page_type: [leaf] | newest_durable: (0, 40)/(0, 41) | oldest_start: (0, 10)/0 | newest_stop: (0, 41)/0 | addr: [0: 8192-12288, 4096, 3240012203]
      - 0x8f6c54780: row-store leaf
              > ref: 0x8f6c54780 | ref_state: memory | page_type: [leaf] | newest_durable: (0, 40)/(0, 41) | oldest_start: (0, 10)/0 | newest_stop: (0, 41)/0 | addr: [0: 8192-12288, 4096, 3240012203]
              > disk_img: 0x8f6cb4000 | dsk_mem_size: 79 | write_gen: 21 | entries: 2 | state: clean | flags: [keys-built, disk-alloc] | page_mem_size: 319
              K: {16,a\00,10,0}
              cell_type: value | len: 5 | start: (0, 10)/(0, 10)/(0, 0)/0/0 | stop: (0, 20)/(0, 20)/(0, 0)/0/0
              V: {20,10,3,a\00}
              K: {16,a\00,40,0}
              cell_type: value | len: 5 | start: (0, 40)/(0, 40)/(0, 0)/0/0 | stop: (0, 41)/(0, 41)/(0, 0)/0/0
              V: {41,40,3,z\00}
      

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

              Created:
              Updated: