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

Fix history store using incorrect key for lookups

    • 5
    • Storage Engines 2020-03-23, Storage Engines 2020-04-06

      Summary:
      In some cases the history store lookup could be done using the wrong key, resulting in the wrong value being returned or (in this particular case), an attempt to read from an evicted page.


       ==22544==ERROR: AddressSanitizer: heap-use-after-free on address 0x631005233d69 at pc 0x0000004c2606 bp 0x7f8d98e41330 sp 0x7f8d98e40ae0
          READ of size 23 at 0x631005233d69 thread T17
              #0 0x4c2605 in __asan_memcpy /data/mci/bb51bb2e9ea058cc981d517c2029628d/toolchain-builder/tmp/build-llvm.sh-ieZ/llvm/projects/compiler-rt/lib/asan/asan_interceptors_memintrinsics.cc:23:3
              #1 0x67cfe4 in __pack_write /home/chenhaoqu/work/wiredtiger/build_posix/../src/include/packing.i:421:13
              #2 0x66463c in __wt_struct_packv /home/chenhaoqu/work/wiredtiger/build_posix/../src/include/packing.i:641:9
              #3 0x658c55 in __wt_cursor_set_keyv /home/chenhaoqu/work/wiredtiger/build_posix/../src/cursor/cur_std.c:467:13
              #4 0x6562a2 in __wt_cursor_set_key /home/chenhaoqu/work/wiredtiger/build_posix/../src/cursor/cur_std.c:288:5
              #5 0x6c4de7 in __wt_hs_cursor_position /home/chenhaoqu/work/wiredtiger/build_posix/../src/history/hs.c:819:5
              #6 0x6c62bb in __wt_find_hs_upd /home/chenhaoqu/work/wiredtiger/build_posix/../src/history/hs.c:939:11
              #7 0xa25ea2 in __wt_txn_read /home/chenhaoqu/work/wiredtiger/build_posix/../src/include/txn.i:851:15
              #8 0xa24140 in __wt_cursor_valid /home/chenhaoqu/work/wiredtiger/build_posix/../src/btree/bt_cursor.c:334:9
              #9 0xaa02c1 in __random_slot_valid /home/chenhaoqu/work/wiredtiger/build_posix/../src/btree/bt_random.c:45:13
              #10 0xa9ed2d in __random_leaf_disk /home/chenhaoqu/work/wiredtiger/build_posix/../src/btree/bt_random.c:252:9
              #11 0xa97aad in __random_leaf /home/chenhaoqu/work/wiredtiger/build_posix/../src/btree/bt_random.c:305:9
              #12 0xa97062 in __wt_btcur_next_random /home/chenhaoqu/work/wiredtiger/build_posix/../src/btree/bt_random.c:594:5
              #13 0x619abf in __wt_curfile_next_random /home/chenhaoqu/work/wiredtiger/build_posix/../src/cursor/cur_file.c:120:5
              #14 0x51926d in random_kv /home/chenhaoqu/work/wiredtiger/build_posix/test/format/../../../test/format/random.c:73:27
              #15 0x7f8da78cd6da in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x76da)
              #16 0x7f8da6c1b88e in clone /build/glibc-OTsEL5/glibc-2.27/misc/../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      
          0x631005233d69 is located 13673 bytes inside of 66503-byte region [0x631005230800,0x631005240bc7)
          freed by thread T17 here:
              #0 0x4c31d2 in free /data/mci/bb51bb2e9ea058cc981d517c2029628d/toolchain-builder/tmp/build-llvm.sh-ieZ/llvm/projects/compiler-rt/lib/asan/asan_malloc_linux.cc:124:3
              #1 0x76386a in __wt_free_int /home/chenhaoqu/work/wiredtiger/build_posix/../src/os_common/os_alloc.c:301:5
              #2 0xa59b74 in __wt_page_out /home/chenhaoqu/work/wiredtiger/build_posix/../src/btree/bt_discard.c:126:9
              #3 0xa58a3f in __wt_ref_out /home/chenhaoqu/work/wiredtiger/build_posix/../src/btree/bt_discard.c:41:5
              #4 0x6b2915 in __evict_page_clean_update /home/chenhaoqu/work/wiredtiger/build_posix/../src/evict/evict_page.c:337:5
              #5 0x6aec58 in __wt_evict /home/chenhaoqu/work/wiredtiger/build_posix/../src/evict/evict_page.c:217:9
              #6 0x6accda in __wt_page_release_evict /home/chenhaoqu/work/wiredtiger/build_posix/../src/evict/evict_page.c:81:11
              #7 0xb6be27 in __wt_page_release /home/chenhaoqu/work/wiredtiger/build_posix/../src/include/btree.i:1480:13
              #8 0xb6af3f in __tree_walk_internal /home/chenhaoqu/work/wiredtiger/build_posix/../src/btree/bt_walk.c:518:5
              #9 0xb6b163 in __wt_tree_walk_skip /home/chenhaoqu/work/wiredtiger/build_posix/../src/btree/bt_walk.c:599:9
              #10 0xa96ef2 in __wt_btcur_next_random /home/chenhaoqu/work/wiredtiger/build_posix/../src/btree/bt_random.c:578:9
              #11 0x619abf in __wt_curfile_next_random /home/chenhaoqu/work/wiredtiger/build_posix/../src/cursor/cur_file.c:120:5
              #12 0x51926d in random_kv /home/chenhaoqu/work/wiredtiger/build_posix/test/format/../../../test/format/random.c:73:27
              #13 0x7f8da78cd6da in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x76da)
      

      Looks like the data page is evicted when we trying to search the history store with the key.

      (gdb) bt
      #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
      #1  0x00007f8da6b3a801 in __GI_abort () at abort.c:79
      #2  0x00000000004e1107 in __sanitizer::Abort() ()
          at /data/mci/bb51bb2e9ea058cc981d517c2029628d/toolchain-builder/tmp/build-llvm.sh-ieZ/llvm/projects/compiler-rt/lib/sanitizer_common/sanitizer_posix_libcdep.cc:157
      #3  0x00000000004dfb51 in __sanitizer::Die() ()
          at /data/mci/bb51bb2e9ea058cc981d517c2029628d/toolchain-builder/tmp/build-llvm.sh-ieZ/llvm/projects/compiler-rt/lib/sanitizer_common/sanitizer_termination.cc:59
      #4  0x00000000004c7b39 in ~ScopedInErrorReport () at /data/mci/bb51bb2e9ea058cc981d517c2029628d/toolchain-builder/tmp/build-llvm.sh-ieZ/llvm/projects/compiler-rt/lib/asan/asan_report.cc:187
      #5  0x00000000004c9323 in ReportGenericError () at /data/mci/bb51bb2e9ea058cc981d517c2029628d/toolchain-builder/tmp/build-llvm.sh-ieZ/llvm/projects/compiler-rt/lib/asan/asan_report.cc:464
      #6  0x00000000004c2625 in __asan_memcpy ()
          at /data/mci/bb51bb2e9ea058cc981d517c2029628d/toolchain-builder/tmp/build-llvm.sh-ieZ/llvm/projects/compiler-rt/lib/asan/asan_interceptors_memintrinsics.cc:23
      #7  0x000000000067cfe5 in __pack_write (session=0x7f8da7f66f30, pv=0x7f8d98e417c0, pp=0x7f8d98e41890, maxlen=41) at ../src/include/packing.i:421
      #8  0x000000000066463d in __wt_struct_packv (session=0x7f8da7f66f30, buffer=0x6040000a65d0, size=43, fmt=0x6020000039d0 "IuQQ", ap=0x7f8d98e42960) at ../src/include/packing.i:641
      #9  0x0000000000658c56 in __wt_cursor_set_keyv (cursor=0x6180000c0880, flags=12292, ap=0x7f8d98e42960) at ../src/cursor/cur_std.c:467
      #10 0x00000000006562a3 in __wt_cursor_set_key (cursor=0x6180000c0880) at ../src/cursor/cur_std.c:288
      #11 0x00000000006c4de8 in __wt_hs_cursor_position (session=0x7f8da7f66f30, cursor=0x6180000c0880, btree_id=2, key=0x61800007e980, timestamp=0) at ../src/history/hs.c:819
      #12 0x00000000006c62bc in __wt_find_hs_upd (session=0x7f8da7f66f30, cbt=0x61800007e880, updp=0x7f8d98e43c60, allow_prepare=false, on_disk_buf=0x7f8d98e437c0) at ../src/history/hs.c:939
      #13 0x0000000000a25ea3 in __wt_txn_read (session=0x7f8da7f66f30, cbt=0x61800007e880, upd=0x0, vpack=0x0, updp=0x7f8d98e43c60) at ../src/include/txn.i:851
      #14 0x0000000000a24141 in __wt_cursor_valid (cbt=0x61800007e880, updp=0x7f8d98e44200, valid=0x7f8d98e44220) at ../src/btree/bt_cursor.c:334
      #15 0x0000000000aa02c2 in __random_slot_valid (cbt=0x61800007e880, slot=94, updp=0x7f8d98e44200, validp=0x7f8d98e44220) at ../src/btree/bt_random.c:45
      #16 0x0000000000a9ed2e in __random_leaf_disk (cbt=0x61800007e880, updp=0x7f8d98e44200, validp=0x7f8d98e44220) at ../src/btree/bt_random.c:252
      #17 0x0000000000a97aae in __random_leaf (cbt=0x61800007e880) at ../src/btree/bt_random.c:305
      #18 0x0000000000a97063 in __wt_btcur_next_random (cbt=0x61800007e880) at ../src/btree/bt_random.c:594
      #19 0x0000000000619ac0 in __wt_curfile_next_random (cursor=0x61800007e880) at ../src/cursor/cur_file.c:120
      #20 0x000000000051926e in random_kv (arg=0x0) at ../../../test/format/random.c:73
      #21 0x00007f8da78cd6db in start_thread (arg=0x7f8d98e45700) at pthread_create.c:463
      #22 0x00007f8da6c1b88f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      (gdb) f 7
      #7  0x000000000067cfe5 in __pack_write (session=0x7f8da7f66f30, pv=0x7f8d98e417c0, pp=0x7f8d98e41890, maxlen=41) at ../src/include/packing.i:421
      421	            memcpy(*pp, pv->u.item.data, s);
      (gdb) p f 3
      No symbol "f" in current context.
      (gdb) f 3
      #3  0x00000000004dfb51 in __sanitizer::Die() () at /data/mci/bb51bb2e9ea058cc981d517c2029628d/toolchain-builder/tmp/build-llvm.sh-ieZ/llvm/projects/compiler-rt/lib/sanitizer_common/sanitizer_termination.cc:59
      59	/data/mci/bb51bb2e9ea058cc981d517c2029628d/toolchain-builder/tmp/build-llvm.sh-ieZ/llvm/projects/compiler-rt/lib/sanitizer_common/sanitizer_termination.cc: No such file or directory.
      (gdb) f 9
      #9  0x0000000000658c56 in __wt_cursor_set_keyv (cursor=0x6180000c0880, flags=12292, ap=0x7f8d98e42960) at ../src/cursor/cur_std.c:467
      467	            WT_ERR(__wt_struct_packv(session, buf->mem, sz, cursor->key_format, ap));
      (gdb) ls
      Undefined command: "ls".  Try "help".
      (gdb) p buf
      $1 = (WT_ITEM *) 0x6180000c0980
      (gdb) f 11
      #11 0x00000000006c4de8 in __wt_hs_cursor_position (session=0x7f8da7f66f30, cursor=0x6180000c0880, btree_id=2, key=0x61800007e980, timestamp=0) at ../src/history/hs.c:819
      819	    cursor->set_key(
      (gdb) f 10
      #10 0x00000000006562a3 in __wt_cursor_set_key (cursor=0x6180000c0880) at ../src/cursor/cur_std.c:288
      288	    WT_IGNORE_RET(__wt_cursor_set_keyv(cursor, cursor->flags, ap));
      (gdb) p ap
      $2 = {{gp_offset = 24, fp_offset = 48, overflow_arg_area = 0x7f8d98e42ba0, reg_save_area = 0x7f8d98e42ab0}}
      (gdb) f 7
      #7  0x000000000067cfe5 in __pack_write (session=0x7f8da7f66f30, pv=0x7f8d98e417c0, pp=0x7f8d98e41890, maxlen=41) at ../src/include/packing.i:421
      421	            memcpy(*pp, pv->u.item.data, s);
      (gdb) f 8
      #8  0x000000000066463d in __wt_struct_packv (session=0x7f8da7f66f30, buffer=0x6040000a65d0, size=43, fmt=0x6020000039d0 "IuQQ", ap=0x7f8d98e42960) at ../src/include/packing.i:641
      641	        WT_RET(__pack_write(session, &pv, &p, (size_t)(end - p)));
      (gdb) p buf->mem
      Attempt to extract a component of a value that is not a structure pointer.
      (gdb) f 7
      #7  0x000000000067cfe5 in __pack_write (session=0x7f8da7f66f30, pv=0x7f8d98e417c0, pp=0x7f8d98e41890, maxlen=41) at ../src/include/packing.i:421
      421	            memcpy(*pp, pv->u.item.data, s);
      (gdb) p pp
      $3 = (uint8_t **) 0x7f8d98e41890
      (gdb) p pv->u.item.data
      $4 = (const void *) 0x631005233d69
      (gdb) f 8
      #8  0x000000000066463d in __wt_struct_packv (session=0x7f8da7f66f30, buffer=0x6040000a65d0, size=43, fmt=0x6020000039d0 "IuQQ", ap=0x7f8d98e42960) at ../src/include/packing.i:641
      641	        WT_RET(__pack_write(session, &pv, &p, (size_t)(end - p)));
      (gdb) f 10
      #10 0x00000000006562a3 in __wt_cursor_set_key (cursor=0x6180000c0880) at ../src/cursor/cur_std.c:288
      288	    WT_IGNORE_RET(__wt_cursor_set_keyv(cursor, cursor->flags, ap));
      (gdb) f 11
      #11 0x00000000006c4de8 in __wt_hs_cursor_position (session=0x7f8da7f66f30, cursor=0x6180000c0880, btree_id=2, key=0x61800007e980, timestamp=0) at ../src/history/hs.c:819
      819	    cursor->set_key(
      (gdb) p key
      $5 = (WT_ITEM *) 0x61800007e980
      (gdb) p key->data
      $6 = (const void *) 0x631005233d69
      

            Assignee:
            keith.bostic@mongodb.com Keith Bostic (Inactive)
            Reporter:
            chenhao.qu@mongodb.com Chenhao Qu
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

              Created:
              Updated:
              Resolved: