On 10/15/2015 06:21 AM, Dmitry Vyukov wrote: > Hello, > > I've run a set of sanitizers on > git://git.kernel.org/pub/scm/linux/kernel/git/will/kvmtool.git commit > 3695adeb227813d96d9c41850703fb53a23845eb. I've just booted a VM and > shut it down. > > AddressSanitizer detected a heap-use-after-free: > > AddressSanitizer: heap-use-after-free on address 0x60400000df90 at pc > 0x0000004f46d0 bp 0x7ffc79def2d0 sp 0x7ffc79def2c8 > READ of size 8 at 0x60400000df90 thread T0 > #0 0x4f46cf in kvm__pause kvm.c:436:7 > #1 0x4f0d5d in ioport__unregister ioport.c:129:2 > #2 0x4efb2f in serial8250__exit hw/serial.c:446:7 > #3 0x516204 in init_list__exit util/init.c:59:8 > #4 0x4ea956 in kvm_cmd_run_exit builtin-run.c:645:2 > #5 0x4ea956 in kvm_cmd_run builtin-run.c:661 > #6 0x51596f in handle_command kvm-cmd.c:84:8 > #7 0x7fa398101ec4 in __libc_start_main > /build/buildd/eglibc-2.19/csu/libc-start.c:287 > #8 0x41a505 in _start (lkvm+0x41a505) > > 0x60400000df90 is located 0 bytes inside of 40-byte region > [0x60400000df90,0x60400000dfb8) > freed by thread T0 here: > #0 0x4b75a0 in free > /usr/local/google/home/dvyukov/src/llvm/build/../projects/compiler-rt/lib/asan/asan_malloc_linux.cc:30 > #1 0x4f29e6 in kvm_cpu__exit kvm-cpu.c:263:2 > #2 0x5160c4 in init_list__exit util/init.c:59:8 > > previously allocated by thread T0 here: > #0 0x4b7a2c in calloc > /usr/local/google/home/dvyukov/src/llvm/build/../projects/compiler-rt/lib/asan/asan_malloc_linux.cc:56 > #1 0x4f2491 in kvm_cpu__init kvm-cpu.c:221:14 I'm sending a patch to fix this + another issue it uncovered. This was caused by the kvm cpu exit function to be marked as late call rather than core call, so it would free the vcpus before anything else had a chance to exit. > > ThreadSanitizer detected a whole bunch of data races, for example: > > WARNING: ThreadSanitizer: data race (pid=109228) > Write of size 1 at 0x7d6c0001f384 by thread T55: > #0 memcpy /usr/local/google/home/dvyukov/src/llvm/build/../projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:608 > (lkvm+0x00000044b28b) > #1 virtio_pci__msix_mmio_callback virtio/pci.c:269:3 (lkvm+0x0000004b3ee0) > #2 kvm__emulate_mmio mmio.c:131:3 (lkvm+0x0000004ac332) > #3 kvm_cpu__emulate_mmio x86/include/kvm/kvm-cpu-arch.h:46:9 > (lkvm+0x0000004aa8c6) > #4 kvm_cpu__start kvm-cpu.c:147 (lkvm+0x0000004aa8c6) > #5 kvm_cpu_thread builtin-run.c:174:6 (lkvm+0x0000004a6e3e) > > Previous read of size 4 at 0x7d6c0001f384 by thread T58: > #0 virtio_pci__signal_vq virtio/pci.c:290:29 (lkvm+0x0000004b36b6) > #1 virtio_net_tx_thread virtio/net.c:210:4 (lkvm+0x0000004b1fb5) > > Location is heap block of size 1648 at 0x7d6c0001f100 allocated by > main thread: > #0 calloc /usr/local/google/home/dvyukov/src/llvm/build/../projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:544 > (lkvm+0x00000043e812) > #1 virtio_init virtio/core.c:191:12 (lkvm+0x0000004afa48) > #2 virtio_net__init_one virtio/net.c:846:2 (lkvm+0x0000004b095d) > #3 virtio_net__init virtio/net.c:868:3 (lkvm+0x0000004b0296) > #4 init_list__init util/init.c:40:8 (lkvm+0x0000004bc7ee) > #5 kvm_cmd_run_init builtin-run.c:621:6 (lkvm+0x0000004a6799) > #6 kvm_cmd_run builtin-run.c:656 (lkvm+0x0000004a6799) > #7 handle_command kvm-cmd.c:84:8 (lkvm+0x0000004bc40c) > #8 handle_kvm_command main.c:11:9 (lkvm+0x0000004ac0b4) > #9 main main.c:18 (lkvm+0x0000004ac0b4) > > Thread T55 'kvm-vcpu-2' (tid=109285, running) created by main thread at: > #0 pthread_create > /usr/local/google/home/dvyukov/src/llvm/build/../projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:848 > (lkvm+0x0000004478a3) > #1 kvm_cmd_run_work builtin-run.c:633:7 (lkvm+0x0000004a683f) > #2 kvm_cmd_run builtin-run.c:660 (lkvm+0x0000004a683f) > #3 handle_command kvm-cmd.c:84:8 (lkvm+0x0000004bc40c) > #4 handle_kvm_command main.c:11:9 (lkvm+0x0000004ac0b4) > #5 main main.c:18 (lkvm+0x0000004ac0b4) > > Thread T58 'virtio-net-tx' (tid=109334, running) created by thread T53 at: > #0 pthread_create > /usr/local/google/home/dvyukov/src/llvm/build/../projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:848 > (lkvm+0x0000004478a3) > #1 init_vq virtio/net.c:526:4 (lkvm+0x0000004b1523) > #2 virtio_pci__io_out virtio/pci.c:219:3 (lkvm+0x0000004b484c) > #3 kvm__emulate_io ioport.c:196:11 (lkvm+0x0000004aa0f8) > #4 virtio_pci__io_mmio_callback virtio/pci.c:340:2 (lkvm+0x0000004b3e55) > #5 kvm__emulate_mmio mmio.c:131:3 (lkvm+0x0000004ac332) > #6 kvm_cpu__emulate_mmio x86/include/kvm/kvm-cpu-arch.h:46:9 > (lkvm+0x0000004aa8c6) > #7 kvm_cpu__start kvm-cpu.c:147 (lkvm+0x0000004aa8c6) > #8 kvm_cpu_thread builtin-run.c:174:6 (lkvm+0x0000004a6e3e) So in this case (and most of the other data race cases described in the full log) it seems like ThreadSanitizer is mixing with different accesses by the guest to one underlying block of memory on the host. Here, for example, T55 accesses the msix block of the virtio-net PCI device, and T58 is accessing the virtqueue exposed by that device. While they both get to the same block of memory inside > and mutex unlock in a wrong thread (not supported by pthread): > > WARNING: ThreadSanitizer: unlock of an unlocked mutex (or by a wrong > thread) (pid=109228) > #0 pthread_mutex_unlock > /usr/local/google/home/dvyukov/src/llvm/build/../projects/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:3303 > (lkvm+0x00000042d183) > #1 mutex_unlock include/kvm/mutex.h:35:6 (lkvm+0x0000004abfc8) > #2 kvm__continue kvm.c:463 (lkvm+0x0000004abfc8) > #3 kvm_cpu_signal_handler kvm-cpu.c:50:4 (lkvm+0x0000004aab59) > #4 __tsan::CallUserSignalHandler(__tsan::ThreadState*, bool, bool, > bool, int, my_siginfo_t*, void*) > /usr/local/google/home/dvyukov/src/llvm/build/../projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:1827 > (lkvm+0x00000041f808) > #5 kvm_cpu__reboot kvm-cpu.c:80:4 (lkvm+0x0000004aa449) > #6 kbd_write_command hw/i8042.c:166:3 (lkvm+0x0000004cad7c) > #7 kbd_out hw/i8042.c:327 (lkvm+0x0000004cad7c) > #8 kvm__emulate_io ioport.c:196:11 (lkvm+0x0000004aa0f8) > #9 kvm_cpu__emulate_io x86/include/kvm/kvm-cpu-arch.h:41:9 > (lkvm+0x0000004aa718) > #10 kvm_cpu__start kvm-cpu.c:126 (lkvm+0x0000004aa718) > #11 kvm_cpu_thread builtin-run.c:174:6 (lkvm+0x0000004a6e3e) Still didn't look into this. > Full list is attached. > > > What do you think about incorporating the tools into Makefile and > running them continuously? > As far as I understand lkvm itself does not consume significant > portion of CPU time, so I would expect that it is possible to run the > tools always during development. > > > I've hacked Makefile as follows (makefile is not my favorite language): > > $(PROGRAM)-static: $(STATIC_OBJS) $(OTHEROBJS) $(GUEST_INIT) > $(E) " LINK " $@ > - $(Q) $(CC) -static $(CFLAGS) $(STATIC_OBJS) $(OTHEROBJS) > $(GUEST_OBJS) $(LIBS) $(LIBS_STATOPT) -o $@ > + $(Q) clang -fsanitize=address -static $(CFLAGS) $(STATIC_OBJS) > $(OTHEROBJS) $(GUEST_OBJS) $(LIBS) $(LIBS_STATOPT) -o $@ > > $(PROGRAM): $(OBJS) $(OBJS_DYNOPT) $(OTHEROBJS) $(GUEST_INIT) > $(E) " LINK " $@ > - $(Q) $(CC) $(CFLAGS) $(OBJS) $(OBJS_DYNOPT) $(OTHEROBJS) > $(GUEST_OBJS) $(LIBS) $(LIBS_DYNOPT) -o $@ > + $(Q) clang -fsanitize=address $(CFLAGS) $(OBJS) $(OBJS_DYNOPT) > $(OTHEROBJS) $(GUEST_OBJS) $(LIBS) $(LIBS_DYNOPT) -o $@ > > %.s: %.c > $(Q) $(CC) -o $@ -S $(CFLAGS) -fverbose-asm $< > @@ -407,7 +409,7 @@ ifeq ($(C),1) > $(Q) $(CHECK) -c $(CFLAGS) $(CFLAGS_DYNOPT) $< -o $@ > endif > $(E) " CC " $@ > - $(Q) $(CC) -c $(c_flags) $(CFLAGS_DYNOPT) $< -o $@ > + $(Q) clang -fsanitize=address -c $(c_flags) $(CFLAGS_DYNOPT) $< -o $@ > > > > > The set of flags you need is: > -fsanitize=address > -fsanitize=thread > -fsanitize=memory -fsanitize-memory-track-origins > > I've used tip clang, gcc also supports asan/tsan but not msan (and it > has somewhat outdated runtime). That'll be fine after we fix anything it finds right now :) Thanks, Sasha -- To unsubscribe from this list: send the line "unsubscribe kvm" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
