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

test/format assert gets hit verifying imported table

      As a follow on ticket from WT-7253, a test/format assert is being hit with

      [2021/04/19 08:43:13.676]     ############################################
       [2021/04/19 08:43:13.676]     t: FAILED: verify_import/163: iteration == IMPORT_ENTRIES
       [2021/04/19 08:43:13.676]     t: process aborting
       [2021/04/19 08:43:13.676] format.sh: /data/mci/5916fe752a24e3d6180af23032f421a7/wiredtiger/test/format/RUNDIR.5/CONFIG:
       [2021/04/19 08:43:13.676]     ############################################
      

      with config:

       [2021/04/19 08:43:13.672]     t: run FAILED
       [2021/04/19 08:43:13.672]     ############################################
       [2021/04/19 08:43:13.672]     #  RUN PARAMETERS: V2
       [2021/04/19 08:43:13.672]     ############################################
       [2021/04/19 08:43:13.672]     assert.commit_timestamp=0
       [2021/04/19 08:43:13.672]     assert.read_timestamp=0
       [2021/04/19 08:43:13.672]     backup=0
       [2021/04/19 08:43:13.672]     backup.incremental=off
       [2021/04/19 08:43:13.672]     backup.incr_granularity=11434
       [2021/04/19 08:43:13.672]     btree.bitcnt=4
       [2021/04/19 08:43:13.672]     btree.compression=none
       [2021/04/19 08:43:13.672]     btree.dictionary=0
       [2021/04/19 08:43:13.672]     btree.huffman_value=0
       [2021/04/19 08:43:13.672]     btree.internal_key_truncation=1
       [2021/04/19 08:43:13.672]     btree.internal_page_max=9
       [2021/04/19 08:43:13.672]     btree.key_gap=10
       [2021/04/19 08:43:13.672]     btree.key_max=256
       [2021/04/19 08:43:13.672]     btree.key_min=256
       [2021/04/19 08:43:13.672]     btree.leaf_page_max=9
       [2021/04/19 08:43:13.672]     btree.memory_page_max=5
       [2021/04/19 08:43:13.672]     btree.prefix_compression=1
       [2021/04/19 08:43:13.672]     btree.prefix_compression_min=2
       [2021/04/19 08:43:13.672]     btree.repeat_data_pct=69
       [2021/04/19 08:43:13.672]     btree.reverse=0
       [2021/04/19 08:43:13.672]     btree.split_pct=90
       [2021/04/19 08:43:13.672]     btree.value_max=790
       [2021/04/19 08:43:13.672]     btree.value_min=256
       [2021/04/19 08:43:13.672]     cache=60
       [2021/04/19 08:43:13.672]     cache.evict_max=1
       [2021/04/19 08:43:13.672]     cache.minimum=20
       [2021/04/19 08:43:13.672]     checkpoint=on
       [2021/04/19 08:43:13.672]     checkpoint.log_size=119
       [2021/04/19 08:43:13.672]     checkpoint.wait=84
       [2021/04/19 08:43:13.672]     disk.checksum=uncompressed
       [2021/04/19 08:43:13.672]     disk.data_extend=1
       [2021/04/19 08:43:13.672]     disk.direct_io=0
       [2021/04/19 08:43:13.672]     disk.encryption=rotn-7
       [2021/04/19 08:43:13.672]     disk.firstfit=0
       [2021/04/19 08:43:13.672]     disk.mmap=1
       [2021/04/19 08:43:13.672]     disk.mmap_all=0
       [2021/04/19 08:43:13.672]     format.abort=0
       [2021/04/19 08:43:13.672]     format.independent_thread_rng=1
       [2021/04/19 08:43:13.672]     format.major_timeout=0
       [2021/04/19 08:43:13.672]     import=1
       [2021/04/19 08:43:13.672]     logging=1
       [2021/04/19 08:43:13.672]     logging.archive=0
       [2021/04/19 08:43:13.672]     logging.compression=none
       [2021/04/19 08:43:13.672]     logging.file_max=273467
       [2021/04/19 08:43:13.672]     logging.prealloc=0
       [2021/04/19 08:43:13.672]     lsm.auto_throttle=0
       [2021/04/19 08:43:13.672]     lsm.bloom=1
       [2021/04/19 08:43:13.672]     lsm.bloom_bit_count=11
       [2021/04/19 08:43:13.672]     lsm.bloom_hash_count=13
       [2021/04/19 08:43:13.672]     lsm.bloom_oldest=0
       [2021/04/19 08:43:13.672]     lsm.chunk_size=7
       [2021/04/19 08:43:13.672]     lsm.merge_max=13
       [2021/04/19 08:43:13.672]     lsm.worker_threads=3
       [2021/04/19 08:43:13.672]     ops.alter=1
       [2021/04/19 08:43:13.672]     ops.compaction=0
       [2021/04/19 08:43:13.672]     ops.hs_cursor=0
       [2021/04/19 08:43:13.673]     ops.pct.delete=94
       [2021/04/19 08:43:13.673]     ops.pct.insert=2
       [2021/04/19 08:43:13.673]     ops.pct.modify=0
       [2021/04/19 08:43:13.673]     ops.pct.read=0
       [2021/04/19 08:43:13.673]     ops.pct.write=4
       [2021/04/19 08:43:13.673]     ops.prepare=0
       [2021/04/19 08:43:13.673]     ops.random_cursor=0
       [2021/04/19 08:43:13.673]     ops.salvage=0
       [2021/04/19 08:43:13.673]     ops.truncate=1
       [2021/04/19 08:43:13.673]     ops.verify=1
       [2021/04/19 08:43:13.673]     quiet=1
       [2021/04/19 08:43:13.673]     runs=1
       [2021/04/19 08:43:13.673]     runs.in_memory=0
       [2021/04/19 08:43:13.673]     runs.ops=0
       [2021/04/19 08:43:13.673]     runs.rows=100000
       [2021/04/19 08:43:13.673]     runs.source=table
       [2021/04/19 08:43:13.673]     runs.threads=6
       [2021/04/19 08:43:13.673]     runs.timer=4
       [2021/04/19 08:43:13.675]     runs.type=row-store
       [2021/04/19 08:43:13.675]     runs.verify_failure_dump=0
       [2021/04/19 08:43:13.675]     statistics=0
       [2021/04/19 08:43:13.675]     statistics.server=1
       [2021/04/19 08:43:13.675]     stress.aggressive_sweep=0
       [2021/04/19 08:43:13.675]     stress.checkpoint=0
       [2021/04/19 08:43:13.675]     stress.checkpoint_prepare=0
       [2021/04/19 08:43:13.675]     stress.hs_checkpoint_delay=0
       [2021/04/19 08:43:13.675]     stress.hs_search=0
       [2021/04/19 08:43:13.676]     stress.hs_sweep=0
       [2021/04/19 08:43:13.676]     stress.split_1=0
       [2021/04/19 08:43:13.676]     stress.split_2=0
       [2021/04/19 08:43:13.676]     stress.split_3=0
       [2021/04/19 08:43:13.676]     stress.split_4=0
       [2021/04/19 08:43:13.676]     stress.split_5=0
       [2021/04/19 08:43:13.676]     stress.split_6=0
       [2021/04/19 08:43:13.676]     stress.split_7=0
       [2021/04/19 08:43:13.676]     stress.split_8=0
       [2021/04/19 08:43:13.676]     transaction.frequency=100
       [2021/04/19 08:43:13.676]     transaction.isolation=snapshot
       [2021/04/19 08:43:13.676]     transaction.rollback_to_stable=0
       [2021/04/19 08:43:13.676]     transaction.timestamps=1
       [2021/04/19 08:43:13.676]     wiredtiger.config=
       [2021/04/19 08:43:13.676]     wiredtiger.rwlock=1
       [2021/04/19 08:43:13.676]     wiredtiger.leak_memory=0
       [2021/04/19 08:43:13.676]     ############################################
      

      The test/format is importing a new table with 1000 entries. After successful import, we should expect 1000 entries when iterating through a cursor. However when analysing the stacktrace:

      (gdb) info locals
      cursor = 0x619000fc2180
      key = 15451232
      value = 0
      ret = -31800
      iteration = 0
      

      it shows that WT_ROLLBACK as the return.

            Assignee:
            backlog-server-storage-engines [DO NOT USE] Backlog - Storage Engines Team
            Reporter:
            jie.chen@mongodb.com Jie Chen
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

              Created:
              Updated: