Vader BTL segfaults, sm okay

[sjackman]

What version of Open MPI are you using? (e.g., v1.10.3, v2.1.0, git branch name and hash, etc.)

Open MPI 3.1.0
Also tested Open MPI 2.1.3

Describe how Open MPI was installed (e.g., from a source/distribution tarball, from a git clone, from an operating system distribution package, etc.)

Using Linuxbrew with brew install open-mpi
See https://github.com/Linuxbrew/homebrew-core/blob/master/Formula/open-mpi.rb

Please describe the system on which you are running

• Operating system/version: CentOS Linux release 7.1.1503 (Core)
• Computer hardware: Intel(R) Xeon(R) CPU E7-8867 v3 @ 2.50GHz
• Network type: Shared memory

---

Details of the problem

I'm using OpenMPI to assemble a human genome with ABySS 2.1.0.
It crashes with a segfault in libc.so.6 called by mca_btl_vader.so when using OpenMPI 3.1.0 with the vader BTL.
It crashes with a segfault when using OpenMPI 2.1.3 with the vader BTL.
It succeeds when using OpenMPI 2.1.3 with the sm BTL.
The segfault does not occur at a consistent time but occurs within a couple of hours and a day of running. It did not completed successfully after ten attempts.

The backtrace with Open MPI 3.1.0 is…

[hpce705:162958] *** Process received signal ***
[hpce705:162958] Signal: Segmentation fault (11)
[hpce705:162958] Signal code:  (128)
[hpce705:162958] Failing at address: (nil)
[hpce705:162958] [ 0] /gsc/btl/linuxbrew/lib/libc.so.6(+0x33070)[0x7f7b4c627070]
[hpce705:162958] [ 1] /gsc/btl/linuxbrew/Cellar/open-mpi/3.1.0/lib/openmpi/mca_btl_vader.so(+0x4bde)[0x7f7b40b8fbde]
[hpce705:162958] [ 2] /gsc/btl/linuxbrew/lib/libopen-pal.so.40(opal_progress+0x2c)[0x7f7b4be5f60c]
[hpce705:162958] [ 3] /gsc/btl/linuxbrew/lib/libmpi.so.40(PMPI_Request_get_status+0x74)[0x7f7b4d2abb54]
[hpce705:162958] [ 4] ABYSS-P[0x40dcec]
[hpce705:162958] [ 5] ABYSS-P[0x40df24]
[hpce705:162958] [ 6] ABYSS-P[0x40f384]
[hpce705:162958] [ 7] ABYSS-P[0x4148a7]
[hpce705:162958] [ 8] ABYSS-P[0x416c12]
[hpce705:162958] [ 9] ABYSS-P[0x4066aa]
[hpce705:162958] [10] /gsc/btl/linuxbrew/lib/libc.so.6(__libc_start_main+0xf5)[0x7f7b4c614825]
[hpce705:162958] [11] ABYSS-P[0x407d39]
[hpce705:162958] *** End of error message ***

The failed mpirun command is…

mpirun -np 48 ABYSS-P …

The successful mpirun command is…

mpirun -np 48 --mca btl self,sm ABYSS-P …

Please let me know what further information I can provide to help troubleshoot. If it would help you to reproduce the issue locally, I can provide you with data and a command line to reproduce the issue.

This issue was originally reported by @jdmontenegro and reproduced by myself at a different site.
The downstream ABySS issue is at bcgsc/abyss#236
cc @benvvalk

[jsquyres]

@hjelmn Can you have a look?

[hjelmn]

Can you try master. Also, how big and what type of filesystem is /tmp?

[jsquyres]

@sjackman You can download a bootstrapped nightly master tarball from here: https://www.open-mpi.org/nightly/master/

We made some changes on master to how shared memory is allocated -- our assumption is that you are running out of space in /tmp and things go downhill from there. On master, we do shared memory differently (/dev/shm/ on Linux), and that can get all of memory without impacting filesystem space availability.

[sjackman]

@hjelmn Hi, Nathan.

$ df -h /dev/shm /tmp /var/tmp
Filesystem      Size  Used Avail Use% Mounted on
tmpfs           1.3T  472K  1.3T   1% /dev/shm
/dev/sda5       8.0G   64M  8.0G   1% /tmp
/dev/sda6       1.1T   46G  1.1T   5% /var
$ mount | egrep '/dev/(sda5|sda6|shm)'
/dev/sda5 on /tmp type xfs (rw,relatime,attr2,inode64,noquota)
/dev/sda6 on /var type xfs (rw,relatime,attr2,inode64,noquota)
tmpfs on /dev/shm type tmpfs (rw,nosuid,nodev)

I believe both sda5 and sda6 are on the same spinning hard disk.

Is it possible to configure OpenMPI 3.1.0 to use /dev/shm/?

I'll try the nightly build.

[hjelmn]

We will port the /dev/shm change back to v3.0.x and v3.1.x.

[sjackman]

Excellent. You read my mind. That was going to be my next question.

This test will run for a couple of days. I'll let you know how it turns out. So far so good.

[t-niemi]

Hi

I don't know if this is related, but it looks very similar so I report this here.

I'm using OpenFOAM (CFD-code using OpenMPI) and recently switched from OpenMPI 2.1.1 to 2.1.3. The 2.1.1 (and earlier) have been working fine, but with 2.1.3 random crashes started to happen in btl_vader. I then tested 2.1.5 and 3.1.2, but the same thing happens, below is a cleaned trace:

#0  Foam::error::printStack(Foam::Ostream&) at ~/OpenFOAM/OpenFOAM-6/src/OSspecific/POSIX/printStack.C:218
#1  Foam::sigSegv::sigHandler(int) at ~/OpenFOAM/OpenFOAM-6/src/OSspecific/POSIX/signals/sigSegv.C:54
#2  ? in "/lib64/libc.so.6"
#3  ? at btl_vader_component.c:?
#4  opal_progress in "/openmpi-3.1.2/lib64/libopen-pal.so.40"
#5  ompi_request_default_wait in "/openmpi-3.1.2/lib64/libmpi.so.40"
#6  ompi_coll_base_sendrecv_actual in "/openmpi-3.1.2/lib64/libmpi.so.40"
#7  ompi_coll_base_allreduce_intra_recursivedoubling in "/openmpi-3.1.2/lib64/libmpi.so.40"
#8  PMPI_Allreduce in "/openmpi-3.1.2/lib64/libmpi.so.40"

The crashes typically happen within 30 min to couple of hours of running. The code was obtained from a source tarball, compiled with gcc 4.9.2 and run in Ubuntu 16.04 and 18.04 in various Xeon v4 and Gold cpus using up to 28 cores of shared memory.

Unfortunately, I can't provide a simple test case to reproduce these crashes for you. I currently have a debug-build of OpenMPI running to get a better trace, but that case has not yet crashed.

[benvvalk]

@t-niemi Thanks very much for taking the time to report this. I agree, it does sound related to this GitHub issue.

As per @sjackman's problem description above, have you tried explicitly choosing sm instead of vader by doing:

abyss-pe mpirun='mpirun --mca btl self,sm' ...

?

[sjackman]

I had success with OpenMPI 2.1.3 with the sm transport.
Success with OpenMPI 3.1.1.201807110306 (nightly build) with the vader transport.
I believe that fix would be included in 3.1.2, but you'll want to confirm.
I haven't yet tested 3.1.2.

[t-niemi]

No, I haven't yet tested sm, I can try it. In the meantime, my debug run now crashed and here is the trace (note this was with 2.1.5):

#0  Foam::error::printStack(Foam::Ostream&) at ??:?
#1  Foam::sigSegv::sigHandler(int) at ??:?
#2  ? in "/lib64/libc.so.6"
#3  ? at /openmpi-2.1.5/opal/mca/btl/vader/btl_vader_fbox.h:208
#4  ? at /openmpi-2.1.5/opal/mca/btl/vader/btl_vader_component.c:689
#5  opal_progress in "/openmpi-2.1.5/lib64/libopen-pal.so.20"
#6  ? in "/openmpi-2.1.5/lib64/libmpi.so.20"
#7  ompi_request_default_wait_all in "/openmpi-2.1.5/lib64/libmpi.so.20"
#8  PMPI_Waitall in "/openmpi-2.1.5/lib64/libmpi.so.20"
#9  Foam::UPstream::waitRequests(int) at ??:?

This time the crash seems to happen with PMPI_Waitall instead of PMPI_Allreduce.

[t-niemi]

Just to update, I have a case running with sm and so far it is ok. However, it will need to run for a longer time to be sure. I also tested todays daily build (openmpi-master-201808280417) and got a similar crash as with the 2.1.5 (crash in PMPI_Waitall).

[hjelmn]

@t-niemi How big is /dev/shm on your system? How many MPI processes are you running on each node?

[t-niemi]

@hjelmn /dev/shm size differs a bit from system to system, but typical size is 94 G with 28 processes. (50 % of the total ram in the system). The simulations I'm currently running are relatively lightweight in terms of memory and they only consume about 17 G mem in total.

It might be that this is not related to the original bug after all, except that the crashes happen roughly in the same place.

sm transport has been running ok so far, vader runs crash eventually. Typically a release build crashes within an hour and a debug build within a day.

[hjelmn]

@t-niemi Very odd. Can you provide instructions on how to reproduce the issue?

[t-niemi]

@hjelmn I can try, but it will take a while. I have to see if I can get the crash to happen with some of the freely available, small tutorial cases.

[t-niemi]

Ok, I found a small case which crashes reliably. Unfortunately, reproducing will still involve a lot of work, because installation of OpenFOAM is required. Also, the crashes are quite random and the probability of crashing seems to increase with increasing amount of processes. With 36, 28 or 14 cores in use a crash typically occurs within a couple of minutes or even less, with 4 processes it can take a long time (up to 30 min).

The toolchain requirements for OpenFOAM can be found here (cmake, QT, boost are not needed for this, basically gcc > 4.8 and some basic build tools should be enough):
https://openfoam.org/download/source/software-for-compilation/

Step by step

Obtain OpenFOAM:

git clone git://github.com/OpenFOAM/OpenFOAM-6.git
git clone git://github.com/OpenFOAM/ThirdParty-6.git

Get some OpenMPI version and place it in the ThirdParty directory, eg.

cd ThirdParty-6
wget https://download.open-mpi.org/release/open-mpi/v3.1/openmpi-3.1.2.tar.bz2
tar -xf openmpi-3.1.2.tar.bz2

Tell OpenFoam to use the correct OpenMPI (3.1.2 in this case)

cd ..
cd OpenFOAM-6
sed -i -e 's/export WM_MPLIB=SYSTEMOPENMPI/export WM_MPLIB=OPENMPI/' etc/bashrc
sed -i -e 's/export FOAM_MPI=openmpi-2.1.3/export FOAM_MPI=openmpi-3.1.2/' etc/config.sh/mpi

Load OpenFOAM environment variables and compile (takes 30 min or more)

source etc/bashrc
./Allwmake -j

Extract the attached case, decompose and run

tar -xf case.tar.gz
cd case
blockMesh (needs to be done only once)
decomposePar (by default into 28, can be edited in system/decomposeParDict)
foamJob -p buoyantSimpleFoam

Follow the log until crash:

tail -f log

The test case:
case.tar.gz

[t-niemi]

I did some further tests. I tested 2.1.2 and that seemed to work. I checked the commit log and found only one commit between 2.1.2 and 2.1.3 in vader (2467c27#diff-dfa82915b442deeba49157bad6f16830), I'm guessing it might be related to this?

I don't understand the code, but I tried to look what has changed in btl_vader_fbox. I noticed that in 2.1.2

mca_btl_vader_fbox_send(data, tag)

was the last thing that was done in mca_btl_vader_fbox_sendi but in 2.1.3 and later the tag is set earlier. I then tried to change

mca_btl_vader_fbox_set_header (MCA_BTL_VADER_FBOX_HDR(dst), tag, ep->fbox_out.seq++, data_size);

back to (tag -> 0)

mca_btl_vader_fbox_set_header (MCA_BTL_VADER_FBOX_HDR(dst), 0, ep->fbox_out.seq++, data_size);

and added

mca_btl_vader_fbox_send(data, tag);

after

OPAL_THREAD_UNLOCK(&ep->lock);

and it seems to be running stable now. (I also applied 6086b52)

Now this may be purely by change and I may be way off here. But in any case, my suspicion is that something is causing a race condition or some other rare condition that sometimes fails. I tried to reproduce the crashes with my own 4-core desktop but that was stable. However, our server machines constantly crash when many cores are used.

[t-niemi]

I'm starting to get more confident that the issues are indeed caused by setting the tag too early, because I have not had a crash after the fix. Also, I tried to add usleep(10) to the end of mca_btl_vader_fbox_set_header and then I get a crash almost immediately even with just 4 processes. Is there a possibility, that after setting the tag, some other process can interfere before the original process gets to the end of mca_btl_vader_fbox_sendi? (There is some buffer alignment and such)

[jsquyres]

We discussed in 2018-09-11 webex. @hjelmn is going to have a closer look.

[NablaCFD]

Only bug information update.
I encountered the same problem, I have tested the OpenMPI-3.1.1 and 3.1.2 on Ubuntu 18.04 and Ubuntu 16.04 at WSL of Windows 10.

[jsquyres]

This may be related to #5638.

[hjelmn]

@t-niemi Please try this patch

diff --git a/opal/mca/btl/vader/btl_vader_fbox.h b/opal/mca/btl/vader/btl_vader_fbox.h
index 17239ce8ef..b5526050e0 100644
--- a/opal/mca/btl/vader/btl_vader_fbox.h
+++ b/opal/mca/btl/vader/btl_vader_fbox.h
@@ -50,9 +50,10 @@ void mca_btl_vader_poll_handle_frag (mca_btl_vader_hdr_t *hdr, mca_btl_base_endp
 static inline void mca_btl_vader_fbox_set_header (mca_btl_vader_fbox_hdr_t *hdr, uint16_t tag,
                                                   uint16_t seq, uint32_t size)
 {
-    mca_btl_vader_fbox_hdr_t tmp = {.data = {.tag = tag, .seq = seq, .size = size}};
-    opal_atomic_wmb ();
+    mca_btl_vader_fbox_hdr_t tmp = {.data = {.tag = 0, .seq = seq, .size = size}};
     hdr->ival = tmp.ival;
+    opal_atomic_wmb ();
+    hdr->data.tag = tag;
 }
 
 /* attempt to reserve a contiguous segment from the remote ep */

[jsquyres]

@hjelmn figured it out: the fastbox header writing is ok on x86_64, but the ordering of writing is going to matter on other platforms. Nathan is "being clever" by writing several values together as a single 64-bit value -- but the actual write may end up being multiple instructions (i.e., not atomic). ...and he just included a patch above that should fix the issue.

[t-niemi]

Ok, I will test it tomorrow when I get to office.

[t-niemi]

Hmm, I still get a crash with my 4-core desktop when I also have the 10 microsecond wait in mca_btl_vader_fbox_set_header. I can test it tomorrow in the office with a server and more cores and without the wait, but I'm guessing that it might also crash. The wait just makes the crash more likely to happen.

I didn't mention it clearly, but I'm running x86_64 in all cases, so the issue should not be in that.

Everything works, if I delay setting the tag after this

    end += size;
    
    if (OPAL_UNLIKELY(fbox_size == end)) {
        /* toggle the high bit */
        hbs = !hbs;
        /* reset the end pointer to the beginning of the buffer */
        end = MCA_BTL_VADER_FBOX_ALIGNMENT;
    } else if (buffer_free > size) {
        MCA_BTL_VADER_FBOX_HDR(ep->fbox_out.buffer + end)->ival = 0;
    }

    /* align the buffer */
    ep->fbox_out.end = ((uint32_t) hbs << 31) | end;
    opal_atomic_wmb ();

    OPAL_THREAD_UNLOCK(&ep->lock);

This makes me suspect, that something happens between setting the tag and running that code which leads to inconsistency. For example, can some other process access the buffer before the process that set the tag can reset the buffer when it fills up?

[hjelmn]

Hmm, ok. I see the issue you are hitting. Not sure why we aren't triggering it in nightly testing. This should be sufficient for this bug:

diff --git a/opal/mca/btl/vader/btl_vader_fbox.h b/opal/mca/btl/vader/btl_vader_fbox.h
index 17239ce8ef..ee5c913551 100644
--- a/opal/mca/btl/vader/btl_vader_fbox.h
+++ b/opal/mca/btl/vader/btl_vader_fbox.h
@@ -138,9 +138,6 @@ static inline bool mca_btl_vader_fbox_sendi (mca_btl_base_endpoint_t *ep, unsign
         memcpy (data + header_size, payload, payload_size);
     }
 
-    /* write out part of the header now. the tag will be written when the data is available */
-    mca_btl_vader_fbox_set_header (MCA_BTL_VADER_FBOX_HDR(dst), tag, ep->fbox_out.seq++, data_size);
-
     end += size;
 
     if (OPAL_UNLIKELY(fbox_size == end)) {
@@ -152,6 +149,9 @@ static inline bool mca_btl_vader_fbox_sendi (mca_btl_base_endpoint_t *ep, unsign
         MCA_BTL_VADER_FBOX_HDR(ep->fbox_out.buffer + end)->ival = 0;
     }
 
+    /* write out part of the header now. the tag will be written when the data is available */
+    mca_btl_vader_fbox_set_header (MCA_BTL_VADER_FBOX_HDR(dst), tag, ep->fbox_out.seq++, data_size);
+
     /* align the buffer */
     ep->fbox_out.end = ((uint32_t) hbs << 31) | end;
     opal_atomic_wmb ();

[t-niemi]

@hjelmn Yes, that seems to do the trick. I have both patches active and everything seems to be stable now.

It is not surprising that you haven't encountered this because it seems to require some rather unlucky sequence and many simultaneous processes to catch it without artificial sleep. On the other hand, the bug was still probable enough to stop all of my simulations within few hours.

[hjelmn]

Alright, thanks for confirming that. Will get this fix into master and PR'd to releases.

[jsquyres]

Should be fixed by PR #5696.