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

Ensure we are doing eviction when threads are waiting for it

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Critical - P2 Critical - P2
    • WT2.9.0, 3.2.10, 3.3.15
    • Affects Version/s: None
    • Component/s: None
    • None

      Reproduced on a vanilla linux box after 44/100 runs.

      Config

      ############################################
      #  RUN PARAMETERS
      ############################################
      abort=0
      auto_throttle=1
      backups=0
      bitcnt=6
      bloom=1
      bloom_bit_count=31
      bloom_hash_count=13
      bloom_oldest=0
      cache=53
      checkpoints=1
      checksum=uncompressed
      chunk_size=9
      compaction=0
      compression=snappy
      data_extend=0
      data_source=table
      delete_pct=38
      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=19
      internal_key_truncation=1
      internal_page_max=16
      isolation=read-uncommitted
      key_gap=13
      key_max=73
      key_min=27
      leaf_page_max=11
      leak_memory=0
      logging=1
      logging_archive=1
      logging_compression=lz4
      logging_prealloc=0
      long_running_txn=0
      lsm_worker_threads=3
      merge_max=5
      mmap=1
      ops=100000
      prefix_compression=1
      prefix_compression_min=3
      quiet=1
      repeat_data_pct=6
      reverse=0
      rows=100000
      runs=100
      rebalance=1
      salvage=1
      split_pct=49
      statistics=1
      statistics_server=0
      threads=13
      timer=20
      transaction-frequency=65
      value_max=4029
      value_min=4
      verify=1
      wiredtiger_config=
      write_pct=48
      ############################################
      

      Backtrace

      Thread 18 (Thread 0x7fa606d8c700 (LWP 5503)):
      #0  0x00007fa6089b0a82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
      #1  0x000000000044e6bf in __wt_cond_wait_signal (session=0x2b885f0, cond=0xb211d0, usecs=100000, signalled=0x7fa606d8be9f) at ../src/os_posix/os_mtx_cond.c:71
      #2  0x00000000004192ec in __wt_cond_wait (session=0x2b885f0, cond=0xb211d0, usecs=100000) at ../src/include/misc.i:18
      #3  0x000000000041a82e in __log_file_server (arg=0x2b885f0) at ../src/conn/conn_log.c:520
      #4  0x00007fa6089acdc5 in start_thread () from /lib64/libpthread.so.0
      #5  0x00007fa6080a7ced in clone () from /lib64/libc.so.6
      
      Thread 17 (Thread 0x7fa5fbfff700 (LWP 5504)):
      #0  0x00007fa6089b0a82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
      #1  0x000000000044e6bf in __wt_cond_wait_signal (session=0x2b88930, cond=0xb212f0, usecs=1000000, signalled=0x7fa5fbffeeaf) at ../src/os_posix/os_mtx_cond.c:71
      #2  0x00000000004838ff in __wt_cond_auto_wait_signal (session=0x2b88930, cond=0xb212f0, progress=false, signalled=0x7fa5fbffeeaf) at ../src/support/cond_auto.c:97
      #3  0x00000000004839e5 in __wt_cond_auto_wait (session=0x2b88930, cond=0xb212f0, progress=false) at ../src/support/cond_auto.c:120
      #4  0x000000000041b0b1 in __log_wrlsn_server (arg=0x2b88930) at ../src/conn/conn_log.c:736
      #5  0x00007fa6089acdc5 in start_thread () from /lib64/libpthread.so.0
      #6  0x00007fa6080a7ced in clone () from /lib64/libc.so.6
      
      Thread 16 (Thread 0x7fa60658b700 (LWP 5505)):
      #0  0x00007fa6089b0a82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
      #1  0x000000000044e6bf in __wt_cond_wait_signal (session=0x2b88c70, cond=0x2c01590, usecs=1000000, signalled=0x7fa60658aebe) at ../src/os_posix/os_mtx_cond.c:71
      #2  0x00000000004838ff in __wt_cond_auto_wait_signal (session=0x2b88c70, cond=0x2c01590, progress=false, signalled=0x7fa60658aebe) at ../src/support/cond_auto.c:97
      #3  0x000000000041b2e1 in __log_server (arg=0x2b88c70) at ../src/conn/conn_log.c:843
      #4  0x00007fa6089acdc5 in start_thread () from /lib64/libpthread.so.0
      #5  0x00007fa6080a7ced in clone () from /lib64/libc.so.6
      
      Thread 15 (Thread 0x7fa605d8a700 (LWP 5506)):
      #0  0x00007fa6089b0a82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
      #1  0x000000000044e6bf in __wt_cond_wait_signal (session=0x2b892f0, cond=0x2b86ec0, usecs=1000000, signalled=0x7fa605d89e8f) at ../src/os_posix/os_mtx_cond.c:71
      #2  0x00000000004838ff in __wt_cond_auto_wait_signal (session=0x2b892f0, cond=0x2b86ec0, progress=false, signalled=0x7fa605d89e8f) at ../src/support/cond_auto.c:97
      #3  0x00000000004839e5 in __wt_cond_auto_wait (session=0x2b892f0, cond=0x2b86ec0, progress=false) at ../src/support/cond_auto.c:120
      #4  0x000000000042a551 in __wt_evict_thread_run (session=0x2b892f0, thread=0xba2a10) at ../src/evict/evict_lru.c:249
      #5  0x000000000048f169 in __wt_thread_run (arg=0xba2a10) at ../src/support/thread_group.c:25
      #6  0x00007fa6089acdc5 in start_thread () from /lib64/libpthread.so.0
      #7  0x00007fa6080a7ced in clone () from /lib64/libc.so.6
      
      Thread 14 (Thread 0x7fa60758d700 (LWP 5507)):
      #0  0x00007fa6089b0a82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
      #1  0x000000000044e6bf in __wt_cond_wait_signal (session=0x2b89970, cond=0x2b42640, usecs=10000000, signalled=0x7fa60758ceaf) at ../src/os_posix/os_mtx_cond.c:71
      #2  0x000000000041ef70 in __wt_cond_wait (session=0x2b89970, cond=0x2b42640, usecs=10000000) at ../src/include/misc.i:18
      #3  0x000000000041f8f8 in __sweep_server (arg=0x2b89970) at ../src/conn/conn_sweep.c:272
      #4  0x00007fa6089acdc5 in start_thread () from /lib64/libpthread.so.0
      #5  0x00007fa6080a7ced in clone () from /lib64/libc.so.6
      
      Thread 13 (Thread 0x7fa605589700 (LWP 5508)):
      #0  0x00007fa6089b0a82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
      #1  0x000000000044e6bf in __wt_cond_wait_signal (session=0x2b8c3b0, cond=0xba2960, usecs=10000, signalled=0x7fa605587abf) at ../src/os_posix/os_mtx_cond.c:71
      #2  0x0000000000429e41 in __wt_cond_wait (session=0x2b8c3b0, cond=0xba2960, usecs=10000) at ../src/include/misc.i:18
      #3  0x000000000042e41c in __wt_cache_eviction_worker (session=0x2b8c3b0, busy=false, pct_full=84) at ../src/evict/evict_lru.c:1829
      #4  0x000000000052e362 in __wt_cache_eviction_check (session=0x2b8c3b0, busy=false, didworkp=0x0) at ../src/include/cache.i:355
      #5  0x000000000052e6d8 in __wt_txn_idle_cache_check (session=0x2b8c3b0) at ../src/include/txn.i:313
      ---Type <return> to continue, or q <return> to quit---
      #6  0x000000000052f5f5 in __cursor_func_init (cbt=0x7fa5a003dcb0, reenter=true) at ../src/include/cursor.i:260
      #7  0x000000000053189e in __wt_btcur_update (cbt=0x7fa5a003dcb0) at ../src/btree/bt_cursor.c:774
      #8  0x00000000004edfde in __curfile_update (cursor=0x7fa5a003dcb0) at ../src/cursor/cur_file.c:284
      #9  0x000000000040842c in col_update (cursor=0x7fa5a003dcb0, key=0x7fa605587e10, value=0x7fa605587de0, keyno=2708) at ../../../test/format/ops.c:1104
      #10 0x00000000004076a0 in ops (arg=0x2d515d0) at ../../../test/format/ops.c:671
      #11 0x00007fa6089acdc5 in start_thread () from /lib64/libpthread.so.0
      #12 0x00007fa6080a7ced in clone () from /lib64/libc.so.6
      
      Thread 12 (Thread 0x7fa604d88700 (LWP 5509)):
      #0  0x00007fa6089b0a82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
      #1  0x000000000044e6bf in __wt_cond_wait_signal (session=0x2b8bd30, cond=0xba2960, usecs=10000, signalled=0x7fa604d86a9f) at ../src/os_posix/os_mtx_cond.c:71
      #2  0x0000000000429e41 in __wt_cond_wait (session=0x2b8bd30, cond=0xba2960, usecs=10000) at ../src/include/misc.i:18
      #3  0x000000000042e41c in __wt_cache_eviction_worker (session=0x2b8bd30, busy=false, pct_full=84) at ../src/evict/evict_lru.c:1829
      #4  0x000000000052e362 in __wt_cache_eviction_check (session=0x2b8bd30, busy=false, didworkp=0x0) at ../src/include/cache.i:355
      #5  0x000000000052f396 in __cursor_enter (session=0x2b8bd30) at ../src/include/cursor.i:56
      #6  0x000000000052f473 in __curfile_enter (cbt=0x7fa59403d640) at ../src/include/cursor.i:90
      #7  0x000000000052f624 in __cursor_func_init (cbt=0x7fa59403d640, reenter=true) at ../src/include/cursor.i:263
      #8  0x000000000053189e in __wt_btcur_update (cbt=0x7fa59403d640) at ../src/btree/bt_cursor.c:774
      #9  0x00000000004edfde in __curfile_update (cursor=0x7fa59403d640) at ../src/cursor/cur_file.c:284
      #10 0x000000000040842c in col_update (cursor=0x7fa59403d640, key=0x7fa604d86e10, value=0x7fa604d86de0, keyno=45310) at ../../../test/format/ops.c:1104
      #11 0x00000000004076a0 in ops (arg=0x2d51650) at ../../../test/format/ops.c:671
      #12 0x00007fa6089acdc5 in start_thread () from /lib64/libpthread.so.0
      #13 0x00007fa6080a7ced in clone () from /lib64/libc.so.6
      
      Thread 11 (Thread 0x7fa604587700 (LWP 5510)):
      #0  0x00007fa6089b0a82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
      #1  0x000000000044e6bf in __wt_cond_wait_signal (session=0x2b8b370, cond=0xba2960, usecs=10000, signalled=0x7fa604585a9f) at ../src/os_posix/os_mtx_cond.c:71
      #2  0x0000000000429e41 in __wt_cond_wait (session=0x2b8b370, cond=0xba2960, usecs=10000) at ../src/include/misc.i:18
      #3  0x000000000042e41c in __wt_cache_eviction_worker (session=0x2b8b370, busy=false, pct_full=84) at ../src/evict/evict_lru.c:1829
      #4  0x000000000052e362 in __wt_cache_eviction_check (session=0x2b8b370, busy=false, didworkp=0x0) at ../src/include/cache.i:355
      #5  0x000000000052f396 in __cursor_enter (session=0x2b8b370) at ../src/include/cursor.i:56
      #6  0x000000000052f473 in __curfile_enter (cbt=0x7fa59c03dcb0) at ../src/include/cursor.i:90
      #7  0x000000000052f624 in __cursor_func_init (cbt=0x7fa59c03dcb0, reenter=true) at ../src/include/cursor.i:263
      #8  0x000000000053189e in __wt_btcur_update (cbt=0x7fa59c03dcb0) at ../src/btree/bt_cursor.c:774
      #9  0x00000000004edfde in __curfile_update (cursor=0x7fa59c03dcb0) at ../src/cursor/cur_file.c:284
      #10 0x000000000040842c in col_update (cursor=0x7fa59c03dcb0, key=0x7fa604585e10, value=0x7fa604585de0, keyno=3726) at ../../../test/format/ops.c:1104
      #11 0x00000000004076a0 in ops (arg=0x2d516d0) at ../../../test/format/ops.c:671
      #12 0x00007fa6089acdc5 in start_thread () from /lib64/libpthread.so.0
      #13 0x00007fa6080a7ced in clone () from /lib64/libc.so.6
      
      Thread 10 (Thread 0x7fa603585700 (LWP 5512)):
      #0  0x00007fa6089b0a82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
      #1  0x000000000044e6bf in __wt_cond_wait_signal (session=0x2b8b030, cond=0xba2960, usecs=10000, signalled=0x7fa603583abf) at ../src/os_posix/os_mtx_cond.c:71
      #2  0x0000000000429e41 in __wt_cond_wait (session=0x2b8b030, cond=0xba2960, usecs=10000) at ../src/include/misc.i:18
      #3  0x000000000042e41c in __wt_cache_eviction_worker (session=0x2b8b030, busy=false, pct_full=84) at ../src/evict/evict_lru.c:1829
      #4  0x000000000052e362 in __wt_cache_eviction_check (session=0x2b8b030, busy=false, didworkp=0x0) at ../src/include/cache.i:355
      #5  0x000000000052f396 in __cursor_enter (session=0x2b8b030) at ../src/include/cursor.i:56
      #6  0x000000000052f473 in __curfile_enter (cbt=0x7fa5fc03d640) at ../src/include/cursor.i:90
      #7  0x000000000052f624 in __cursor_func_init (cbt=0x7fa5fc03d640, reenter=true) at ../src/include/cursor.i:263
      #8  0x00000000005312d2 in __wt_btcur_remove (cbt=0x7fa5fc03d640) at ../src/btree/bt_cursor.c:677
      #9  0x00000000004eebf0 in __curfile_remove (cursor=0x7fa5fc03d640) at ../src/cursor/cur_file.c:331
      ---Type <return> to continue, or q <return> to quit---
      #10 0x0000000000408af4 in col_remove (cursor=0x7fa5fc03d640, key=0x7fa603583e10, keyno=33169) at ../../../test/format/ops.c:1392
      #11 0x0000000000407372 in ops (arg=0x2d517d0) at ../../../test/format/ops.c:611
      #12 0x00007fa6089acdc5 in start_thread () from /lib64/libpthread.so.0
      #13 0x00007fa6080a7ced in clone () from /lib64/libc.so.6
      
      Thread 9 (Thread 0x7fa602d84700 (LWP 5513)):
      #0  0x00007fa6089b0a82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
      #1  0x000000000044e6bf in __wt_cond_wait_signal (session=0x2b8a330, cond=0xba2960, usecs=10000, signalled=0x7fa602d82acf) at ../src/os_posix/os_mtx_cond.c:71
      #2  0x0000000000429e41 in __wt_cond_wait (session=0x2b8a330, cond=0xba2960, usecs=10000) at ../src/include/misc.i:18
      #3  0x000000000042e41c in __wt_cache_eviction_worker (session=0x2b8a330, busy=false, pct_full=84) at ../src/evict/evict_lru.c:1829
      #4  0x000000000052e362 in __wt_cache_eviction_check (session=0x2b8a330, busy=false, didworkp=0x0) at ../src/include/cache.i:355
      #5  0x000000000052f396 in __cursor_enter (session=0x2b8a330) at ../src/include/cursor.i:56
      #6  0x000000000052f473 in __curfile_enter (cbt=0x7fa5a80759c0) at ../src/include/cursor.i:90
      #7  0x000000000052f624 in __cursor_func_init (cbt=0x7fa5a80759c0, reenter=true) at ../src/include/cursor.i:263
      #8  0x000000000053009a in __wt_btcur_search (cbt=0x7fa5a80759c0) at ../src/btree/bt_cursor.c:337
      #9  0x00000000004ecd9b in __curfile_search (cursor=0x7fa5a80759c0) at ../src/cursor/cur_file.c:200
      #10 0x0000000000408ad7 in col_remove (cursor=0x7fa5a80759c0, key=0x7fa602d82e10, keyno=76685) at ../../../test/format/ops.c:1391
      #11 0x0000000000407372 in ops (arg=0x2d51850) at ../../../test/format/ops.c:611
      #12 0x00007fa6089acdc5 in start_thread () from /lib64/libpthread.so.0
      #13 0x00007fa6080a7ced in clone () from /lib64/libc.so.6
      
      Thread 8 (Thread 0x7fa602583700 (LWP 5514)):
      #0  0x00007fa6089b0a82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
      #1  0x000000000044e6bf in __wt_cond_wait_signal (session=0x2b89ff0, cond=0xba2960, usecs=10000, signalled=0x7fa602581aef) at ../src/os_posix/os_mtx_cond.c:71
      #2  0x0000000000429e41 in __wt_cond_wait (session=0x2b89ff0, cond=0xba2960, usecs=10000) at ../src/include/misc.i:18
      #3  0x000000000042e41c in __wt_cache_eviction_worker (session=0x2b89ff0, busy=false, pct_full=84) at ../src/evict/evict_lru.c:1829
      #4  0x000000000052e362 in __wt_cache_eviction_check (session=0x2b89ff0, busy=false, didworkp=0x0) at ../src/include/cache.i:355
      #5  0x000000000052e6d8 in __wt_txn_idle_cache_check (session=0x2b89ff0) at ../src/include/txn.i:313
      #6  0x000000000052f5f5 in __cursor_func_init (cbt=0x7fa5cc04e400, reenter=true) at ../src/include/cursor.i:260
      #7  0x000000000053009a in __wt_btcur_search (cbt=0x7fa5cc04e400) at ../src/btree/bt_cursor.c:337
      #8  0x00000000004ecd9b in __curfile_search (cursor=0x7fa5cc04e400) at ../src/cursor/cur_file.c:200
      #9  0x0000000000408ad7 in col_remove (cursor=0x7fa5cc04e400, key=0x7fa602581e10, keyno=43904) at ../../../test/format/ops.c:1391
      #10 0x0000000000407372 in ops (arg=0x2d518d0) at ../../../test/format/ops.c:611
      #11 0x00007fa6089acdc5 in start_thread () from /lib64/libpthread.so.0
      #12 0x00007fa6080a7ced in clone () from /lib64/libc.so.6
      
      Thread 7 (Thread 0x7fa601d82700 (LWP 5515)):
      #0  0x00007fa6089b0a82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
      #1  0x000000000044e6bf in __wt_cond_wait_signal (session=0x2b89cb0, cond=0xba2960, usecs=10000, signalled=0x7fa601d8069f) at ../src/os_posix/os_mtx_cond.c:71
      #2  0x0000000000429e41 in __wt_cond_wait (session=0x2b89cb0, cond=0xba2960, usecs=10000) at ../src/include/misc.i:18
      #3  0x000000000042e41c in __wt_cache_eviction_worker (session=0x2b89cb0, busy=false, pct_full=84) at ../src/evict/evict_lru.c:1829
      #4  0x000000000052e362 in __wt_cache_eviction_check (session=0x2b89cb0, busy=false, didworkp=0x0) at ../src/include/cache.i:355
      #5  0x000000000052f396 in __cursor_enter (session=0x2b89cb0) at ../src/include/cursor.i:56
      #6  0x000000000052f473 in __curfile_enter (cbt=0x7fa5ac033e10) at ../src/include/cursor.i:90
      #7  0x000000000052f624 in __cursor_func_init (cbt=0x7fa5ac033e10, reenter=true) at ../src/include/cursor.i:263
      #8  0x000000000053009a in __wt_btcur_search (cbt=0x7fa5ac033e10) at ../src/btree/bt_cursor.c:337
      #9  0x00000000004ecd9b in __curfile_search (cursor=0x7fa5ac033e10) at ../src/cursor/cur_file.c:200
      #10 0x000000000046dce3 in __schema_open_table (session=0x2b89cb0, name=0xb14506 "wt", namelen=2, ok_incomplete=false, tablep=0x7fa601d80b00) at ../src/schema/schema_open.c:444
      #11 0x000000000046e850 in __wt_schema_open_table (session=0x2b89cb0, name=0xb14506 "wt", namelen=2, ok_incomplete=false, tablep=0x7fa601d80b00) at ../src/schema/schema_open.c:630
      #12 0x000000000046b497 in __schema_add_table (session=0x2b89cb0, name=0xb14506 "wt", namelen=2, ok_incomplete=false, tablep=0x7fa601d80b60) at ../src/schema/schema_list.c:28
      #13 0x000000000046b879 in __wt_schema_get_table (session=0x2b89cb0, name=0xb14506 "wt", namelen=2, ok_incomplete=false, tablep=0x7fa601d80bb8) at ../src/schema/schema_list.c:100
      ---Type <return> to continue, or q <return> to quit---
      #14 0x0000000000505d81 in __wt_curtable_open (session=0x2b89cb0, uri=0xb14500 "table:wt", owner=0x0, cfg=0x7fa601d80d10, cursorp=0x7fa601d80d30) at ../src/cursor/cur_table.c:888
      #15 0x0000000000473f9f in __session_open_cursor_int (session=0x2b89cb0, uri=0xb14500 "table:wt", owner=0x0, other=0x0, cfg=0x7fa601d80d10, cursorp=0x7fa601d80d30) at ../src/session/session_api.c:295
      #16 0x000000000047487f in __session_open_cursor (wt_session=0x2b89cb0, uri=0xb14500 "table:wt", to_dup=0x0, config=0x543dcf "overwrite", cursorp=0x7fa601d80e48) at ../src/session/session_api.c:430
      #17 0x0000000000406d9e in ops (arg=0x2d51950) at ../../../test/format/ops.c:489
      #18 0x00007fa6089acdc5 in start_thread () from /lib64/libpthread.so.0
      #19 0x00007fa6080a7ced in clone () from /lib64/libc.so.6
      
      Thread 6 (Thread 0x7fa601581700 (LWP 5516)):
      #0  0x00007fa6089b0a82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
      #1  0x000000000044e6bf in __wt_cond_wait_signal (session=0x2b8a9b0, cond=0xba2960, usecs=10000, signalled=0x7fa60157fabf) at ../src/os_posix/os_mtx_cond.c:71
      #2  0x0000000000429e41 in __wt_cond_wait (session=0x2b8a9b0, cond=0xba2960, usecs=10000) at ../src/include/misc.i:18
      #3  0x000000000042e41c in __wt_cache_eviction_worker (session=0x2b8a9b0, busy=false, pct_full=84) at ../src/evict/evict_lru.c:1829
      #4  0x000000000052e362 in __wt_cache_eviction_check (session=0x2b8a9b0, busy=false, didworkp=0x0) at ../src/include/cache.i:355
      #5  0x000000000052f396 in __cursor_enter (session=0x2b8a9b0) at ../src/include/cursor.i:56
      #6  0x000000000052f473 in __curfile_enter (cbt=0x7fa55403d100) at ../src/include/cursor.i:90
      #7  0x000000000052f624 in __cursor_func_init (cbt=0x7fa55403d100, reenter=true) at ../src/include/cursor.i:263
      #8  0x00000000005312d2 in __wt_btcur_remove (cbt=0x7fa55403d100) at ../src/btree/bt_cursor.c:677
      #9  0x00000000004eebf0 in __curfile_remove (cursor=0x7fa55403d100) at ../src/cursor/cur_file.c:331
      #10 0x0000000000408af4 in col_remove (cursor=0x7fa55403d100, key=0x7fa60157fe10, keyno=63951) at ../../../test/format/ops.c:1392
      #11 0x0000000000407372 in ops (arg=0x2d519d0) at ../../../test/format/ops.c:611
      #12 0x00007fa6089acdc5 in start_thread () from /lib64/libpthread.so.0
      #13 0x00007fa6080a7ced in clone () from /lib64/libc.so.6
      
      Thread 5 (Thread 0x7fa600d80700 (LWP 5517)):
      #0  0x00007fa6089b0a82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
      #1  0x000000000044e6bf in __wt_cond_wait_signal (session=0x2b8a670, cond=0xba2960, usecs=10000, signalled=0x7fa600d7ea8f) at ../src/os_posix/os_mtx_cond.c:71
      #2  0x0000000000429e41 in __wt_cond_wait (session=0x2b8a670, cond=0xba2960, usecs=10000) at ../src/include/misc.i:18
      #3  0x000000000042e41c in __wt_cache_eviction_worker (session=0x2b8a670, busy=false, pct_full=84) at ../src/evict/evict_lru.c:1829
      #4  0x000000000052e362 in __wt_cache_eviction_check (session=0x2b8a670, busy=false, didworkp=0x0) at ../src/include/cache.i:355
      #5  0x000000000052f396 in __cursor_enter (session=0x2b8a670) at ../src/include/cursor.i:56
      #6  0x000000000052f473 in __curfile_enter (cbt=0x7fa5740b9e10) at ../src/include/cursor.i:90
      #7  0x000000000052f624 in __cursor_func_init (cbt=0x7fa5740b9e10, reenter=true) at ../src/include/cursor.i:263
      #8  0x00000000005309c9 in __wt_btcur_insert (cbt=0x7fa5740b9e10) at ../src/btree/bt_cursor.c:520
      #9  0x00000000004ed83c in __curfile_insert (cursor=0x7fa5740b9e10) at ../src/cursor/cur_file.c:245
      #10 0x00000000004087fd in col_insert (cursor=0x7fa5740b9e10, key=0x7fa600d7ee10, value=0x7fa600d7ede0, keynop=0x7fa600d7edd0) at ../../../test/format/ops.c:1283
      #11 0x00000000004074ea in ops (arg=0x2d51a50) at ../../../test/format/ops.c:644
      #12 0x00007fa6089acdc5 in start_thread () from /lib64/libpthread.so.0
      #13 0x00007fa6080a7ced in clone () from /lib64/libc.so.6
      
      Thread 4 (Thread 0x7fa5fb7fe700 (LWP 5518)):
      #0  0x00007fa6089b0a82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
      #1  0x000000000044e6bf in __wt_cond_wait_signal (session=0x2b8acf0, cond=0xba2960, usecs=10000, signalled=0x7fa5fb7fcaef) at ../src/os_posix/os_mtx_cond.c:71
      #2  0x0000000000429e41 in __wt_cond_wait (session=0x2b8acf0, cond=0xba2960, usecs=10000) at ../src/include/misc.i:18
      #3  0x000000000042e41c in __wt_cache_eviction_worker (session=0x2b8acf0, busy=false, pct_full=84) at ../src/evict/evict_lru.c:1829
      #4  0x000000000052e362 in __wt_cache_eviction_check (session=0x2b8acf0, busy=false, didworkp=0x0) at ../src/include/cache.i:355
      #5  0x000000000052e6d8 in __wt_txn_idle_cache_check (session=0x2b8acf0) at ../src/include/txn.i:313
      #6  0x000000000052f5f5 in __cursor_func_init (cbt=0x7fa5b8046a30, reenter=true) at ../src/include/cursor.i:260
      #7  0x000000000053009a in __wt_btcur_search (cbt=0x7fa5b8046a30) at ../src/btree/bt_cursor.c:337
      #8  0x00000000004ecd9b in __curfile_search (cursor=0x7fa5b8046a30) at ../src/cursor/cur_file.c:200
      #9  0x0000000000408ad7 in col_remove (cursor=0x7fa5b8046a30, key=0x7fa5fb7fce10, keyno=16778) at ../../../test/format/ops.c:1391
      #10 0x0000000000407372 in ops (arg=0x2d51ad0) at ../../../test/format/ops.c:611
      ---Type <return> to continue, or q <return> to quit---
      #11 0x00007fa6089acdc5 in start_thread () from /lib64/libpthread.so.0
      #12 0x00007fa6080a7ced in clone () from /lib64/libc.so.6
      
      Thread 3 (Thread 0x7fa5fa7fc700 (LWP 5520)):
      #0  0x00007fa6089b2f4d in __lll_lock_wait () from /lib64/libpthread.so.0
      #1  0x00007fa6089aed02 in _L_lock_791 () from /lib64/libpthread.so.0
      #2  0x00007fa6089aec08 in pthread_mutex_lock () from /lib64/libpthread.so.0
      #3  0x0000000000491fe6 in __wt_spin_lock (session=0x2b8c070, t=0x2b73460) at ../src/include/mutex.i:159
      #4  0x0000000000494ded in __txn_checkpoint (session=0x2b8c070, cfg=0x7fa5fa7fad10) at ../src/txn/txn_ckpt.c:648
      #5  0x0000000000495e44 in __wt_txn_checkpoint (session=0x2b8c070, cfg=0x7fa5fa7fad10) at ../src/txn/txn_ckpt.c:908
      #6  0x000000000047fcaf in __session_checkpoint (wt_session=0x2b8c070, config=0x0) at ../src/session/session_api.c:1578
      #7  0x0000000000406faf in ops (arg=0x2d51bd0) at ../../../test/format/ops.c:533
      #8  0x00007fa6089acdc5 in start_thread () from /lib64/libpthread.so.0
      #9  0x00007fa6080a7ced in clone () from /lib64/libc.so.6
      
      Thread 2 (Thread 0x7fa5f9ffb700 (LWP 5521)):
      #0  0x00007fa6089b0a82 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
      #1  0x000000000044e6bf in __wt_cond_wait_signal (session=0x2b89630, cond=0x2b86ec0, usecs=1000000, signalled=0x7fa5f9ffae8f) at ../src/os_posix/os_mtx_cond.c:71
      #2  0x00000000004838ff in __wt_cond_auto_wait_signal (session=0x2b89630, cond=0x2b86ec0, progress=false, signalled=0x7fa5f9ffae8f) at ../src/support/cond_auto.c:97
      #3  0x00000000004839e5 in __wt_cond_auto_wait (session=0x2b89630, cond=0x2b86ec0, progress=false) at ../src/support/cond_auto.c:120
      #4  0x000000000042a551 in __wt_evict_thread_run (session=0x2b89630, thread=0xbacf00) at ../src/evict/evict_lru.c:249
      #5  0x000000000048f169 in __wt_thread_run (arg=0xbacf00) at ../src/support/thread_group.c:25
      #6  0x00007fa6089acdc5 in start_thread () from /lib64/libpthread.so.0
      #7  0x00007fa6080a7ced in clone () from /lib64/libc.so.6
      
      Thread 1 (Thread 0x7fa6093e2740 (LWP 29959)):
      #0  0x00007fa60806eefd in nanosleep () from /lib64/libc.so.6
      #1  0x00007fa60809fb34 in usleep () from /lib64/libc.so.6
      #2  0x00000000004062cd in wts_ops (lastrun=0) at ../../../test/format/ops.c:172
      #3  0x0000000000409878 in main (argc=0, argv=0x7fff9c8fc1a0) at ../../../test/format/t.c:216
      (gdb)
      

      Dumps of cache var and size

      (gdb) p conn->cache_size
      $3 = 55574528
      
      (gdb) p *cache
      $2 = {bytes_dirty_intl = 112904, pages_dirty_intl = 1, bytes_dirty_leaf = 2340800, pages_dirty_leaf = 859, bytes_evict = 19209509, pages_evict = 4930, pages_evicted = 0, bytes_image = 1572943,
        bytes_inmem = 3503503, pages_inmem = 6553, bytes_internal = 113226, bytes_read = 2297728, bytes_written = 18561645, app_waits = 41770371, app_evicts = 652, server_evicts = 0, worker_evicts = 2667,
        evict_max_page_size = 901335, stuck_ts = {tv_sec = 1474386839, tv_nsec = 309386116}, read_gen = 86482, read_gen_oldest = 43934, evict_cond = 0x2b86ec0, evict_walk_lock = {lock = {__data = {__lock = 0,
              __count = 0, __owner = 0, __nusers = 0, __kind = 0, __spins = 0, __list = {__prev = 0x0, __next = 0x0}}, __size = '\000' <repeats 39 times>, __align = 0}, name = 0x54736e "cache walk",
          initialized = 1 '\001'}, eviction_dirty_target = 5, eviction_dirty_trigger = 20, eviction_trigger = 95, eviction_target = 80, eviction_checkpoint_target = 5, eviction_scrub_limit = 4.5471168374115569,
        overhead_pct = 8, pass_intr = 0, evict_pass_lock = {lock = {__data = {__lock = 0, __count = 0, __owner = 0, __nusers = 0, __kind = 0, __spins = 0, __list = {__prev = 0x0, __next = 0x0}},
            __size = '\000' <repeats 39 times>, __align = 0}, name = 0x54734e "evict pass", initialized = 1 '\001'}, walk_session = 0x2b882b0, evict_file_next = 0x0, evict_queue_lock = {lock = {__data = {__lock = 0,
              __count = 0, __owner = 0, __nusers = 0, __kind = 0, __spins = 0, __list = {__prev = 0x0, __next = 0x0}}, __size = '\000' <repeats 39 times>, __align = 0}, name = 0x547359 "cache eviction queue",
          initialized = 1 '\001'}, evict_queues = {{evict_lock = {lock = {__data = {__lock = 0, __count = 0, __owner = 0, __nusers = 0, __kind = 0, __spins = 0, __list = {__prev = 0x0, __next = 0x0}},
                __size = '\000' <repeats 39 times>, __align = 0}, name = 0x5473ac "cache eviction", initialized = 1 '\001'}, evict_queue = 0x2bb0040, evict_current = 0x0, evict_candidates = 100, evict_entries = 300,
            evict_max = 400}, {evict_lock = {lock = {__data = {__lock = 0, __count = 0, __owner = 0, __nusers = 0, __kind = 0, __spins = 0, __list = {__prev = 0x0, __next = 0x0}}, __size = '\000' <repeats 39 times>,
                __align = 0}, name = 0x5473ac "cache eviction", initialized = 1 '\001'}, evict_queue = 0x2bb25d0, evict_current = 0x0, evict_candidates = 100, evict_entries = 300, evict_max = 400}, {evict_lock = {
              lock = {__data = {__lock = 0, __count = 0, __owner = 0, __nusers = 0, __kind = 0, __spins = 0, __list = {__prev = 0x0, __next = 0x0}}, __size = '\000' <repeats 39 times>, __align = 0},
              name = 0x5473ac "cache eviction", initialized = 1 '\001'}, evict_queue = 0xb146d0, evict_current = 0x0, evict_candidates = 0, evict_entries = 0, evict_max = 0}}, evict_current_queue = 0x2b86d30,
        evict_fill_queue = 0x2b86cb0, evict_other_queue = 0x2b86cb0, evict_urgent_queue = 0x2b86db0, evict_slots = 400, evict_aggressive_score = 0, evict_empty_score = 0, cp_pass_pressure = 0, cp_quota = 0,
        cp_reserved = 0, cp_session = 0x0, cp_skip_count = 0, cp_tid = 0, cp_saved_app_evicts = 0, cp_saved_app_waits = 0, cp_saved_read = 0, flags = 24}
      

            Assignee:
            michael.cahill@mongodb.com Michael Cahill (Inactive)
            Reporter:
            david.hows David Hows
            Votes:
            0 Vote for this issue
            Watchers:
            8 Start watching this issue

              Created:
              Updated:
              Resolved: