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

Deadlock during first access to lookaside table

    • Type: Icon: Bug Bug
    • Resolution: Fixed
    • Priority: Icon: Major - P3 Major - P3
    • WT2.9.3, 3.4.11, 3.5.9
    • Affects Version/s: None
    • Component/s: None
    • None
    • Storage 2017-05-08, Storage 2017-05-29
    • v3.4

      Reporting this one as it is novel, 75mB cache and only 4mB used. The threads all seem to be stuck trying to page data into memory. Has only showed up on zSeries.

      http://build.wiredtiger.com:8080/job/wiredtiger-test-format-stress-zseries/24576/

      Config

      ############################################
      #  RUN PARAMETERS
      ############################################
      abort=0
      alter=0
      auto_throttle=1
      backups=0
      bitcnt=2
      bloom=1
      bloom_bit_count=57
      bloom_hash_count=12
      bloom_oldest=0
      cache=75
      checkpoints=1
      checksum=uncompressed
      chunk_size=4
      compaction=1
      compression=zlib
      data_extend=0
      data_source=table
      delete_pct=0
      dictionary=0
      direct_io=0
      encryption=rotn-7
      evict_max=2
      file_type=variable-length column-store
      firstfit=0
      huffman_key=0
      huffman_value=0
      in_memory=0
      insert_pct=4
      internal_key_truncation=1
      internal_page_max=15
      isolation=read-committed
      key_gap=5
      key_max=55
      key_min=13
      leaf_page_max=17
      leak_memory=0
      logging=0
      logging_archive=0
      logging_compression=none
      logging_prealloc=0
      long_running_txn=0
      lsm_worker_threads=4
      merge_max=16
      mmap=0
      ops=100000
      prefix_compression=1
      prefix_compression_min=5
      quiet=1
      read_pct=81
      rebalance=1
      repeat_data_pct=22
      reverse=0
      rows=100000
      runs=100
      salvage=1
      split_pct=90
      statistics=0
      statistics_server=0
      threads=24
      timer=20
      transaction-frequency=57
      value_max=159
      value_min=10
      verify=1
      wiredtiger_config=
      write_pct=15
      ############################################
      

      Cache/TXN Dump

      0x885915b8:=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
      0x885915b8:transaction state dump
      0x885915b8:current ID: 32762
      0x885915b8:last running ID: 32750
      0x885915b8:oldest ID: 32671
      0x885915b8:oldest named snapshot ID: 0
      0x885915b8:checkpoint running? yes
      0x885915b8:checkpoint generation: 4
      0x885915b8:checkpoint pinned ID: 32750
      0x885915b8:checkpoint txn ID: 32761
      0x885915b8:session count: 32
      0x885915b8:Transaction state of active sessions:
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32749, snap min: 32749, snap max: 32756, metadata pinned ID: 0, flags: 0x00000048, name: WT_CURSOR.search_near, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32671, snap min: 32671, snap max: 32749, metadata pinned ID: 0, flags: 0x00000008, name: WT_CURSOR.search_near, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:  32750, mod count: 1, pinned ID: 32671, snap min: 32671, snap max: 32751, metadata pinned ID: 0, flags: 0x0000004c, name: WT_CURSOR.search, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32738, snap min: 32738, snap max: 32755, metadata pinned ID: 0, flags: 0x00000048, name: WT_CURSOR.search, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32750, snap min: 32750, snap max: 32761, metadata pinned ID: 0, flags: 0x00000048, name: WT_CURSOR.search_near, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32750, snap min: 32750, snap max: 32758, metadata pinned ID: 0, flags: 0x00000008, name: WT_CURSOR.search, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32749, snap min: 32749, snap max: 32755, metadata pinned ID: 0, flags: 0x00000048, name: WT_CURSOR.search_near, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32744, snap min: 32744, snap max: 32755, metadata pinned ID: 0, flags: 0x00000048, name: WT_CURSOR.search_near, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:  32754, mod count: 3, pinned ID: 32738, snap min: 32738, snap max: 32755, metadata pinned ID: 0, flags: 0x0000004c, name: WT_CURSOR.search, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32750, snap min: 32750, snap max: 32756, metadata pinned ID: 0, flags: 0x00000008, name: WT_CURSOR.search_near, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32750, snap min: 32750, snap max: 32759, metadata pinned ID: 0, flags: 0x00000008, name: WT_CURSOR.search_near, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32671, snap min: 32671, snap max: 32750, metadata pinned ID: 0, flags: 0x00000048, name: WT_CURSOR.search, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32671, snap min: 32671, snap max: 32752, metadata pinned ID: 0, flags: 0x00000048, name: WT_CURSOR.search, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32671, snap min: 32671, snap max: 32750, metadata pinned ID: 0, flags: 0x00000008, name: WT_CURSOR.search, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32671, snap min: 32671, snap max: 32752, metadata pinned ID: 0, flags: 0x00000048, name: WT_CURSOR.search, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32671, snap min: 32671, snap max: 32750, metadata pinned ID: 0, flags: 0x00000048, name: WT_CURSOR.search_near, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32671, snap min: 32671, snap max: 32750, metadata pinned ID: 0, flags: 0x00000008, name: WT_CURSOR.search, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32708, snap min: 32708, snap max: 32755, metadata pinned ID: 0, flags: 0x00000009, name: WT_CURSOR.update, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32671, snap min: 32671, snap max: 32750, metadata pinned ID: 0, flags: 0x00000008, name: WT_CURSOR.search, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32671, snap min: 32671, snap max: 32754, metadata pinned ID: 0, flags: 0x00000048, name: WT_CURSOR.search, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32750, snap min: 32750, snap max: 32756, metadata pinned ID: 0, flags: 0x00000048, name: WT_CURSOR.search_near, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32750, snap min: 32750, snap max: 32757, metadata pinned ID: 0, flags: 0x00000008, name: WT_CURSOR.search, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32750, snap min: 32750, snap max: 32761, metadata pinned ID: 0, flags: 0x00000008, name: WT_CURSOR.search_near, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:ID:      0, mod count: 0, pinned ID: 32750, snap min: 32750, snap max: 32761, metadata pinned ID: 0, flags: 0x00000008, name: WT_CURSOR.search, isolation: WT_ISO_READ_COMMITTED
      0x885915b8:=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
      0x885915b8:=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
      0x885915b8:cache dump
      0x885915b8:file:wt.wt(<live>):
      0x885915b8:internal: 1 pages, 0MB, 0/1 clean/dirty pages, 0/0 clean/dirty MB, 0MB max page, 0MB max dirty page
      0x885915b8:leaf: 16 pages, 2MB, 13/3 clean/dirty pages, 0/2 clean/dirty MB, 1MB max page, 1MB max dirty page
      0x885915b8:file:WiredTigerLAS.wt(<live>):
      0x885915b8:internal: 1 pages, 0MB, 1/0 clean/dirty pages, 0/0 clean/dirty MB, 0MB max page, 0MB max dirty page
      0x885915b8:leaf: 1 pages, 0MB, 1/0 clean/dirty pages, 0/0 clean/dirty MB, 0MB max page, 0MB max dirty page
      0x885915b8:file:WiredTiger.wt(<live>):
      0x885915b8:internal: 1 pages, 0MB, 1/0 clean/dirty pages, 0/0 clean/dirty MB, 0MB max page, 0MB max dirty page
      0x885915b8:leaf: 1 pages, 0MB, 1/0 clean/dirty pages, 0/0 clean/dirty MB, 0MB max page, 0MB max dirty page
      0x885915b8:cache dump: total found: 3MB vs tracked inuse 4MB
      0x885915b8:total dirty bytes: 2MB
      0x885915b8:=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
      

        1. stack.txt
          43 kB
          David Hows

            Assignee:
            keith.bostic@mongodb.com Keith Bostic (Inactive)
            Reporter:
            david.hows David Hows
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

              Created:
              Updated:
              Resolved: