race in forced page eviction

XMLWordPrintableJSON

    • Type: Task
    • Resolution: Done
    • WT1.2
    • Affects Version/s: None
    • Component/s: None
    • None
    • None

      Michael, I saw a free-page race today.

      Here's the gdb run:

         1: read/write ops 12570
Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7ffff7a04700 (LWP 1961)]
0x000000000041a5df in __hazard_exclusive (session=0x85ce20, ref=0x0)
    at ../src/btree/rec_evict.c:500
500             if (WT_ATOMIC_CAS(ref->state, WT_REF_EVICTING, WT_REF_LOCKED))
Missing separate debuginfos, use: debuginfo-install bzip2-libs-1.0.5-7.el6_0.x86
_64 glibc-2.12-1.47.el6_2.5.x86_64
(gdb) p ref
$1 = (WT_REF *) 0x0
(gdb) where
#0  0x000000000041a5df in __hazard_exclusive (session=0x85ce20, ref=0x0)
    at ../src/btree/rec_evict.c:500
WT-1  0x000000000041a3aa in __rec_review (session=0x85ce20, page=0x994940,
    flags=0, top=1) at ../src/btree/rec_evict.c:359
WT-2  0x0000000000419c18 in __wt_rec_evict (session=0x85ce20, page=0x994940,
    flags=0) at ../src/btree/rec_evict.c:47
WT-3  0x0000000000410c72 in __evict_request_walk (session=0x85ce20)
    at ../src/btree/bt_evict.c:367
WT-4  0x0000000000410a08 in __evict_worker (session=0x85ce20)
    at ../src/btree/bt_evict.c:284
WT-5  0x00000000004108cd in __wt_cache_evict_server (arg=0x88f5e0)
    at ../src/btree/bt_evict.c:242
WT-6  0x00000030f38077f1 in start_thread () from /lib64/libpthread.so.0
WT-7  0x00000030f34e592d in clone () from /lib64/libc.so.6
(gdb) info threads
* 4 Thread 0x7ffff7a04700 (LWP 1961)  0x000000000041a5df in __hazard_exclusive
    (session=0x85ce20, ref=0x0) at ../src/btree/rec_evict.c:500
  1 Thread 0x7ffff7fed700 (LWP 1946)  0x00000031048098fb in BZ2_decompress ()
   from /lib64/libbz2.so.1

      It's not real reliable, but I found a run that reproduces it most of the time. 

      evictserver: sleeping
evictserver: waking
file:__wt: evictserver: forcing eviction of page 0xf3d8a0 {0x7fca541173d0}
evictserver: sleeping
evictserver: waking
file:__wt: evictserver: forcing eviction of page 0xf3d8a0 {0x7fca541173d0}
evictserver: sleeping
evictserver: waking
file:__wt: evictserver: forcing eviction of page 0xf3d8a0 {0x7fca541173d0}
evictserver: sleeping
evictserver: waking
file:__wt: evictserver: forcing eviction of page 0xf3d8a0 {0x7fca541173d0}
evictserver: sleeping
evictserver: waking
file:__wt [cursor.insert]: evictserver: ../src/include/cache.i/59: page 0xf3d8a0
 {0x7fca541173d0}
file:__wt: evictserver: forcing eviction of page 0xf3d8a0 {0x7fca541173d0}
file:__wt [cursor.insert]: evictserver: waking, bytes inuse <= max (0MB <= 30MB)
,
file:__wt: evictserver: forcing eviction of page 0xf3d8a0 {(nil)}

      Somehow we're evicting a page, discarding it, and then evicting it again, and we go south because WT_PAGE->ref is NULL.

      I changed __wt_page_out() to overwrite the page on discard with 0xab, and the core shows me something more interesting:

      (gdb) p page
$1 = (WT_PAGE *) 0x9359e0
(gdb) p *page
$2 = {parent = 0x983750, ref = 0xabababababababab, u = {intl = {recno = 12370169
555311111083, t = 0xabababababababab},
    row = {d = 0xabababababababab, ins = 0xabababababababab, upd = 0xabababababa
babab}, col_fix = {
      recno = 12370169555311111083, bitf = 0xabababababababab <Address 0xabababa
babababab out of bounds>}, col_var = {
      recno = 12370169555311111083, d = 0xabababababababab, repeats = 0xabababab
abababab, nrepeats = 2880154539}},
  dsk = 0xabababababababab, modify = 0xabababababababab, read_gen = 123701695553
11111083, entries = 2880154539,
  memory_footprint = 2880154539, type = 171 '\253', flags = 171 '\253'}
(gdb)

      I'll push that change, we might as well keep it.

      I put a check in __wt_evict_page_request:

              WT_EVICT_REQ_FOREACH(er, er_end, cache)
                if (er->session != NULL && er->page == page)
                        fprintf(stderr, "WT-1: %p {%d} %p {%d}\n",
                        er->page, er->page->ref->state,
                        page, page->ref->state); 
        if (!WT_ATOMIC_CAS(page->ref->state, WT_REF_MEM, WT_REF_EVICTING))
                return (0);
        WT_EVICT_REQ_FOREACH(er, er_end, cache)
                if (er->session != NULL && er->page == page)
                        fprintf(stderr, "WT-2 %p {%d} %p {%d}\n",    
                        er->page, er->page->ref->state,
                        page, page->ref->state);

      which gives me:

      ./t -r
... reading CONFIG file
t: process 3060
WT-1: 0x11921e0 {3} 0x11921e0 {3}
WT-2 0x11921e0 {1} 0x11921e0 {1}
Segmentation fault

      which translates to both page and er->page being set to WT_REF_MEM, then both set to WT_REF_EVICTING.

      I haven't gotten any further, but if I don't get back to it today, maybe it will be obvious to you?

      The run file is:

      ############################################
#  RUN PARAMETERS
############################################
# bitcnt not applicable to this run
bzip=1
cache=30
delete_pct=29
file_type=row-store
huffman_key=0
huffman_value=1
insert_pct=9
internal_page_max=11
key_max=121
key_min=17
leaf_page_max=9
ops=20000
# repeat_data_pct not applicable to this run
reverse=1
rows=100
runs=1
value_max=1805
value_min=17
write_pct=70
############################################

            Assignee:
            Michael Cahill (Inactive)
            Reporter:
            Keith Bostic (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Created:
              Updated:
              Resolved: