Patcher issues reported on mailing list

[jsquyres]

As reported by @PHHargrove http://www.open-mpi.org/community/lists/devel/2016/05/18928.php and http://www.open-mpi.org/community/lists/devel/2016/05/18930.php, and by @bosilca http://www.open-mpi.org/community/lists/devel/2016/05/18929.php, there appear to be new segv's in master -- potentially caused by patcher...?

Here's one stack trace posted by @PHHargrove on LITTLE-ENDIAN Power8:

Program terminated with signal SIGSEGV, Segmentation fault.

(gdb) where
#0  0x0000000000000000 in ?? ()
#1  0x00003fff897adb38 in intercept_munmap (start=0x3fff89670000, length=65536)
    at /home/phargrov/OMPI/openmpi-v2.x-dev-1410-g81e0924-linux-ppc64el-xlc/openmpi-gitclone/opal/mca/memory/patcher/memory_patcher_component.c:155
#2  0x00003fff8933bc80 in __GI__IO_setb () from /lib64/libc.so.6
#3  0x00003fff89339528 in __GI__IO_file_close_it () from /lib64/libc.so.6
#4  0x00003fff89327f74 in fclose@@GLIBC_2.17 () from /lib64/libc.so.6
#5  0x0000000010000f7c in do_test ()
    at /home/phargrov/OMPI/openmpi-v2.x-dev-1410-g81e0924-linux-ppc64el-xlc/openmpi-gitclone/ompi/debuggers/dlopen_test.c:97
#6  0x00000000100010e0 in main (argc=1, argv=0x3fffff332888)
    at /home/phargrov/OMPI/openmpi-v2.x-dev-1410-g81e0924-linux-ppc64el-xlc/openmpi-gitclone/ompi/debuggers/dlopen_test.c:135

"start" is valid:
(gdb) print *(char*)0x3fff89670000
$1 = 35 '#'

Frame 1:
155         opal_mem_hooks_release_hook (start, length, true);

Here's another:

BIG-endian PPC64 w/ xlc V13.1 experiences a nearly identical failure.
However, this time gdb appears to have been able to resolve frame #0 to a PLT slot (instead of "??").

#0  0x00000fff8904ef88 in 00000010.plt_call.opal_mem_hooks_release_hook+0 ()
   from /gpfs-biou/phh1/OMPI/openmpi-v2.x-dev-1410-g81e0924-linux-ppc64-xlc-13.1/INST/lib/libopen-pal.so.20
#1  0x00000fff8910b630 in intercept_munmap (start=0xfff88d20000, length=2097152)
    at /gpfs-biou/phh1/OMPI/openmpi-v2.x-dev-1410-g81e0924-linux-ppc64-xlc-13.1/openmpi-gitclone/opal/mca/memory/patcher/memory_patcher_component.c:155
#2  0x000000800cc5ca80 in ._IO_setb () from /lib64/libc.so.6
#3  0x000000800cc5b16c in ._IO_file_close_it () from /lib64/libc.so.6
#4  0x000000800cc4a758 in .fclose () from /lib64/libc.so.6
#5  0x0000000010000f88 in do_test ()
    at /gpfs-biou/phh1/OMPI/openmpi-v2.x-dev-1410-g81e0924-linux-ppc64-xlc-13.1/openmpi-gitclone/ompi/debuggers/dlopen_test.c:97
#6  0x00000000100010d8 in main (argc=1, argv=0xffff462f398)
    at /gpfs-biou/phh1/OMPI/openmpi-v2.x-dev-1410-g81e0924-linux-ppc64-xlc-13.1/openmpi-gitclone/ompi/debuggers/dlopen_test.c:135

@hjelmn Please investigate.

[jsquyres]

@hjelmn Where are we with this?

[jsquyres]

@hjelmn We're told by @bosilca that C++ new is busted with this. Any ideas?

[bosilca]

Let me try to detail my findings. I am working on master, compiled with the default options, but I call MPI_Init_thread with THREAD_MULTIPLE. However, I am not sure how the MPI library has been initialized is important in this context, simply because the issue (t least as far as I understand it) is not related to MPI functions. In fact I notices it happening when the application threads are allocating/releasing memory in same time. Anyway, I have a test case I can replicate pretty consistently, so I will use it to explain what I understand from the issue. I will dump below the stack of the 2 threads that deadlock.

The first thread (let's call it th1) is basically trying to register some memory. While parsing the list of allocations, it realizes that it has to free a VMA item. At this point it will try to acquire the libc memory allocator lock. Keep in mind that here we are deep inside the registration, so we already own the rcache_grdma->cache->vma_module->vma_lock (it was taken right above do_unregistration_gc).

#0  0x00007f705a10309e in __lll_lock_wait_private () from /lib64/libc.so.6
#1  0x00007f705a087f4e in _L_lock_5793 () from /lib64/libc.so.6
#2  0x00007f705a083adb in _int_free () from /lib64/libc.so.6
#3  0x00007f7059ab924a in mca_rcache_base_vma_tree_delete (vma_module=0x336ba70, reg=0x15fad300)
    at ../../../../ompi/opal/mca/rcache/base/rcache_base_vma_tree.c:494
#4  0x00007f7059ab74d7 in mca_rcache_base_vma_delete (vma_module=0x336ba70, reg=0x15fad300)
    at ../../../../ompi/opal/mca/rcache/base/rcache_base_vma.c:144
#5  0x00007f705420b4d4 in dereg_mem (reg=0x15fad300)
    at ../../../../../ompi/opal/mca/rcache/grdma/rcache_grdma_module.c:131
#6  0x00007f705420b549 in do_unregistration_gc (rcache=0x3373ee0)
    at ../../../../../ompi/opal/mca/rcache/grdma/rcache_grdma_module.c:153
#7  0x00007f705420b6e4 in mca_rcache_grdma_register (rcache=0x3373ee0, addr=0xd4d13c0, size=33132,
    flags=0, access_flags=5, reg=0x7f704cc2b750)
    at ../../../../../ompi/opal/mca/rcache/grdma/rcache_grdma_module.c:206
#8  0x00007f704fbaf917 in mca_btl_openib_register_mem (btl=0x33742e0, endpoint=0x359c680,
    base=0xd4d13c0, size=33132, flags=5)
    at ../../../../../ompi/opal/mca/btl/openib/btl_openib.c:1940
#9  0x00007f704f15aa8a in mca_bml_base_register_mem (bml_btl=0x50c0cf0, base=0xd4d13c0, size=33132,
    flags=5, handle=0xaf4f3c8) at ../../../../../ompi/ompi/mca/bml/bml.h:354
#10 0x00007f704f15d259 in mca_pml_ob1_recv_request_progress_rget (recvreq=0xaf4f100, btl=0x33742e0,
    segments=0x3525408, num_segments=1)
    at ../../../../../ompi/ompi/mca/pml/ob1/pml_ob1_recvreq.c:708
#11 0x00007f704f159297 in mca_pml_ob1_recv_frag_match (btl=0x33742e0, hdr=0x3529144,
    segments=0x3525408, num_segments=1, type=67)
    at ../../../../../ompi/ompi/mca/pml/ob1/pml_ob1_recvfrag.c:718

The second thread (let's call it th2) is oblivious to any MPI operation. In its execution path, it tries to deallocate some memory. So it acquires the memory allocator lock (in _int_free), and then ends up in the grdma trying to acquire the rcache_grdma->cache->vma_module->vma_lock lock. Bad luck, this lock is held by the other thread (th1), who is trying to lock the locks in the opposite direction.

#0  0x00007f705d69b334 in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007f705d6965f3 in _L_lock_892 () from /lib64/libpthread.so.0
#2  0x00007f705d6964d7 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x00007f705420a4e6 in opal_mutex_lock (m=0x336bd60)
    at ../../../../../ompi/opal/threads/mutex_unix.h:139
#4  0x00007f705420bf1b in mca_rcache_grdma_invalidate_range (rcache=0x3373ee0, base=0x7f703f163000,
    size=65536) at ../../../../../ompi/opal/mca/rcache/grdma/rcache_grdma_module.c:389
#5  0x00007f7059ab96b1 in mca_rcache_base_mem_cb (base=0x7f703f163000, size=65536, cbdata=0x0,
    from_alloc=false) at ../../../../ompi/opal/mca/rcache/base/rcache_base_mem_cb.c:63
#6  0x00007f7059a00eec in opal_mem_hooks_release_hook (buf=0x7f703f163000, length=65536,
    from_alloc=false) at ../../ompi/opal/memoryhooks/memory.c:126
#7  0x00007f7059aae518 in intercept_madvise (start=0x7f703f163000, length=65536, advice=4)
    at ../../../../../ompi/opal/mca/memory/patcher/memory_patcher_component.c:234
#8  0x00007f705a083b6b in _int_free () from /lib64/libc.so.6
#9  0x00000000016b22f8 in std::_Sp_counted_deleter<double*, void (*)(void*), std::allocator<void>, (__gnu_cxx::_Lock_policy)2>::_M_dispose (this=0x7f703c62c2e0)
    at /opt/gcc-5.1/include/c++/5.1.0/bits/shared_ptr_base.h:466
#10 0x000000000168de9c in std::_Sp_counted_base<(__gnu_cxx::_Lock_policy)2>::_M_release (
    this=0x7f703c62c2e0) at /opt/gcc-5.1/include/c++/5.1.0/bits/shared_ptr_base.h:150
#11 0x0000000001687dc9 in std::__shared_count<(__gnu_cxx::_Lock_policy)2>::~__shared_count (
    this=0x7f703c627b60, __in_chrg=<optimized out>)
    at /opt/gcc-5.1/include/c++/5.1.0/bits/shared_ptr_base.h:659

Thus, this seems to be a classical issue of interlocking resources from multiple threads. Unfortunately, one of the lock is outside our control. The only solution I can see is to defer the release of the VMA items until we can do it safely without holding the rcache_grdma->cache->vma_module->vma_lock lock (this is totally ugly).

Feel free to chime in.

[hjelmn]

Ugh, that is really ugly. I have an idea that might work. Let me try coding it up and see where it goes. Should have this done sometime today.

[hjelmn]

George, there is no way around it. We absolutely have to delay freeing anything until the vma lock is dropped to protect against this. I think I have a working solution that should do the job without being too horrendous. Testing now and will post a PR soon if it works.

[bosilca]

Once you fill the PR I will gladly give it a try, I have the perfect reproducer.