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

test_timestamp_abort cache stuck (clean) on wiredtiger-mongo-v6.0

    • Type: Icon: Build Failure Build Failure
    • Resolution: Gone away
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: None
    • Component/s: None
    • NachoCheese - 2023-10-03

      recovery-stress-test-no-barrier on ubuntu2004-stress-tests-arm64

      Host: i-0ac4c90ae0d64acd9
      Project: wiredtiger-mongo-v6.0
      Commit: 62a0b0f2

      Task Logs:

      recovery-stress-test-no-barrier task_log

      Logs:

      [1691026611:399853][865605:0xffffa48e01c0], eviction-server: [WT_VERB_DEFAULT][ERROR]: __evict_server, 493: Cache stuck for too long, giving up: Connection timed out
      
      

      logs

      recovery-stress-test-no-barrier task_log

      Logs:

      transaction state dump
      current ID: 39717
      last running ID: 39704
      metadata_pinned ID: 39642
      oldest ID: 39642
      durable timestamp: (0, 38832)
      oldest timestamp: (0, 32334)
      pinned timestamp: (0, 32334)
      stable timestamp: (0, 32334)
      has_durable_timestamp: yes
      has_oldest_timestamp: yes
      has_pinned_timestamp: yes
      has_stable_timestamp: yes
      oldest_is_pinned: yes
      stable_is_pinned: yes
      checkpoint running: yes
      checkpoint generation: 2
      checkpoint pinned ID: 0
      checkpoint txn ID: 0
      session count: 59
      Transaction state of active sessions:
      ID: 39716, pinned ID: 39664, metadata pinned ID: 0, name: WT_CURSOR.insert
      transaction id: 39716, mod count: 0, snap min: 39664, snap max: 39713, snapshot count: 33, commit_timestamp: (0, 38843), durable_timestamp: (0, 38843), first_commit_timestamp: (0, 38843), prepare_timestamp: (0, 0), pinned_durable_timestamp: (0, 38843), read_timestamp: (0, 0), checkpoint LSN: [0][0], full checkpoint: false, rollback reason: , flags: 0x0002181c, isolation: WT_ISO_SNAPSHOT
      ID: 39711, pinned ID: 39664, metadata pinned ID: 0, name: WT_CURSOR.insert
      transaction id: 39711, mod count: 1, snap min: 39664, snap max: 39710, snapshot count: 34, commit_timestamp: (0, 38836), durable_timestamp: (0, 38836), first_commit_timestamp: (0, 38835), prepare_timestamp: (0, 0), pinned_durable_timestamp: (0, 38835), read_timestamp: (0, 0), checkpoint LSN: [0][0], full checkpoint: false, rollback reason: , flags: 0x0002181c, isolation: WT_ISO_SNAPSHOT
      ID: 39713, pinned ID: 39664, metadata pinned ID: 0, name: WT_CURSOR.insert
      transaction id: 39713, mod count: 0, snap min: 39664, snap max: 39713, snapshot count: 33, commit_timestamp: (0, 38839), durable_timestamp: (0, 38839), first_commit_timestamp: (0, 38839), prepare_timestamp: (0, 0), pinned_durable_timestamp: (0, 38839), read_timestamp: (0, 0), checkpoint LSN: [0][0], full checkpoint: false, rollback reason: , flags: 0x0002181c, isolation: WT_ISO_SNAPSHOT
      ID: 39712, pinned ID: 39664, metadata pinned ID: 0, name: WT_CURSOR.insert
      transaction id: 39712, mod count: 1, snap min: 39664, snap max: 39710, snapshot count: 34, commit_timestamp: (0, 38838), durable_timestamp: (0, 38838), first_commit_timestamp: (0, 38837), prepare_timestamp: (0, 0), pinned_durable_timestamp: (0, 38837), read_timestamp: (0, 0), checkpoint LSN: [0][0], full checkpoint: false, rollback reason: , flags: 0x0002181c, isolation: WT_ISO_SNAPSHOT
      ID: 39705, pinned ID: 39664, metadata pinned ID: 0, name: WT_CURSOR.insert
      transaction id: 39705, mod count: 2, snap min: 39664, snap max: 39700, snapshot count: 27, commit_timestamp: (0, 38830), durable_timestamp: (0, 38830), first_commit_timestamp: (0, 38829), prepare_timestamp: (0, 0), pinned_durable_timestamp: (0, 38829), read_timestamp: (0, 0), checkpoint LSN: [0][0], full checkpoint: false, rollback reason: , flags: 0x0002181c, isolation: WT_ISO_SNAPSHOT
      ID: 39710, pinned ID: 39664, metadata pinned ID: 0, name: WT_CURSOR.insert
      transaction id: 39710, mod count: 2, snap min: 39664, snap max: 39709, snapshot count: 33, commit_timestamp: (0, 38834), durable_timestamp: (0, 38834), first_commit_timestamp: (0, 38833), prepare_timestamp: (0, 0), pinned_durable_timestamp: (0, 38833), read_timestamp: (0, 0), checkpoint LSN: [0][0], full checkpoint: false, rollback reason: , flags: 0x0002181c, isolation: WT_ISO_SNAPSHOT
      ID: 39715, pinned ID: 39664, metadata pinned ID: 0, name: WT_CURSOR.insert
      transaction id: 39715, mod count: 0, snap min: 39664, snap max: 39713, snapshot count: 33, commit_timestamp: (0, 38845), durable_timestamp: (0, 38845), first_commit_timestamp: (0, 38845), prepare_timestamp: (0, 0), pinned_durable_timestamp: (0, 38845), read_timestamp: (0, 0), checkpoint LSN: [0][0], full checkpoint: false, rollback reason: , flags: 0x0002181c, isolation: WT_ISO_SNAPSHOT
      ID: 39704, pinned ID: 39642, metadata pinned ID: 0, name: EMPTY
      transaction id: 39704, mod count: 1, snap min: 39642, snap max: 39695, snapshot count: 29, commit_timestamp: (0, 38824), durable_timestamp: (0, 38824), first_commit_timestamp: (0, 38823), prepare_timestamp: (0, 0), pinned_durable_timestamp: (0, 38823), read_timestamp: (0, 0), checkpoint LSN: [0][0], full checkpoint: false, rollback reason: , flags: 0x0000181c, isolation: WT_ISO_SNAPSHOT
      ID: 39714, pinned ID: 39664, metadata pinned ID: 0, name: WT_CURSOR.insert
      transaction id: 39714, mod count: 0, snap min: 39664, snap max: 39713, snapshot count: 33, commit_timestamp: (0, 38841), durable_timestamp: (0, 38841), first_commit_timestamp: (0, 38841), prepare_timestamp: (0, 0), pinned_durable_timestamp: (0, 38841), read_timestamp: (0, 0), checkpoint LSN: [0][0], full checkpoint: false, rollback reason: , flags: 0x0002181c, isolation: WT_ISO_SNAPSHOT
      =-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
      cache dump
      cache full: no
      cache clean check: yes (95.014%)
      cache dirty check: no (50.893%)
      cache updates check: no (39.276%)
      file:oplog.wt(<live>):
      internal: 1 pages, 47.44 KB, 1/0 clean/dirty pages, 47.44/0.00 clean / dirty KB, 47.44 KB max page, 0.00 KB max dirty page
      leaf: 90 pages, 5940.22 KB, 54/36 clean/dirty pages, 1265.22 /4675.01 /3827.03 clean/dirty/updates KB, 276.53 KB max page, 276.53 KB max dirty page
      file:local.wt(<live>):
      internal: 1 pages, 55.67 KB, 1/0 clean/dirty pages, 55.67/0.00 clean / dirty KB, 55.67 KB max page, 0.00 KB max dirty page
      leaf: 171 pages, 6595.94 KB, 135/36 clean/dirty pages, 3376.65 /3219.29 /2364.90 clean/dirty/updates KB, 122.79 KB max page, 122.79 KB max dirty page
      file:shadow.wt(<live>):
      internal: 1 pages, 55.97 KB, 1/0 clean/dirty pages, 55.97/0.00 clean / dirty KB, 55.97 KB max page, 0.00 KB max dirty page
      leaf: 172 pages, 6485.62 KB, 135/37 clean/dirty pages, 3387.77 /3097.85 /2230.74 clean/dirty/updates KB, 115.43 KB max page, 115.43 KB max dirty page
      file:collection.wt(<live>):
      internal: 1 pages, 50.77 KB, 1/0 clean/dirty pages, 50.77/0.00 clean / dirty KB, 50.77 KB max page, 0.00 KB max dirty page
      leaf: 218 pages, 8676.52 KB, 182/36 clean/dirty pages, 4709.88 /3966.64 /3105.38 clean/dirty/updates KB, 283.89 KB max page, 283.89 KB max dirty page
      file:WiredTigerHS.wt(<live>) eviction disabled at open:
      internal: 1 pages, 0.27 KB, 1/0 clean/dirty pages, 0.27/0.00 clean / dirty KB, 0.27 KB max page, 0.00 KB max dirty page
      leaf: 1 pages, 0.38 KB, 1/0 clean/dirty pages, 0.38 /0.00 /0.28 clean/dirty/updates KB, 0.38 KB max page, 0.00 KB max dirty page
      file:WiredTiger.wt(<live>):
      internal: 1 pages, 0.56 KB, 1/0 clean/dirty pages, 0.56/0.00 clean / dirty KB, 0.56 KB max page, 0.00 KB max dirty page
      leaf: 1 pages, 16.02 KB, 1/0 clean/dirty pages, 16.02 /0.00 /15.93 clean/dirty/updates KB, 16.02 KB max page, 0.00 KB max dirty page
      cache dump: total found: 29.45 MB vs tracked inuse 27.27 MB
      total dirty bytes: 14.61 MB vs tracked dirty 14.61 MB
      

      logs

      recovery-stress-test-no-barrier task_log

      Logs:

      [1691026611:400294][865605:0xffffa48e01c0], eviction-server: [WT_VERB_DEFAULT][ERROR]: __wt_evict_thread_run, 344: cache eviction thread error: Connection timed out
      [1691026611:400298][865605:0xffffa48e01c0], eviction-server: [WT_VERB_DEFAULT][ERROR]: __wt_evict_thread_run, 344: the process must exit and restart: WT_PANIC: WiredTiger library panic
      [1691026611:400302][865605:0xffffa48e01c0], eviction-server: [WT_VERB_DEFAULT][ERROR]: __wt_abort, 28: aborting WiredTiger library
      

      logs

      recovery-stress-test-no-barrier task_log

      Logs:

      test_timestamp_abort: FAILED: Child process 865605 abnormally exited: Invalid argument
      
      

      logs

      recovery-stress-test-no-barrier task_log

      Logs:

      test_timestamp_abort: process aborting
      WiredTiger Error: __wt_abort, 28: aborting WiredTiger library
      #3  0x0000ffffae31ed68 in __wt_panic_func (session=session@entry=0xffffad9b1410, error=error@entry=110, func=func@entry=0xffffae376ba8 <__PRETTY_FUNCTION__.39227> "__wt_evict_thread_run", line=line@entry=344, category=category@entry=WT_VERB_DEFAULT, fmt=fmt@entry=0xffffae3767b0 "cache eviction thread error") at ../src/support/err.c:550
      

      logs

            Assignee:
            mick.graham@mongodb.com Mick Graham
            Reporter:
            Xgen-BuildBaron-User xgen-buildbaron-user
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

              Created:
              Updated:
              Resolved: