pmix dstore esh bus error in orted on cray in dvm mode

[marksantcroos]

With the latest master, in dvm mode, after running around a couple of thousand tasks I repeatedly run into the following:

Core was generated by `orted -mca orte_debug "1" -mca orte_debug_daemons "1" --hnp-topo-sig 0N:1S:1L3:'.
Program terminated with signal 7, Bus error.
(gdb) bt
#0  0x00002aaaadcaa85b in __memset_sse2 () from /lib64/libc.so.6
#1  0x00002aaaac2b2718 in _create_new_segment (type=NS_META_SEGMENT, ns_map=0x2aaaae3a76d0, id=0)
    at /ccs/home/marksant1/openmpi/src/ompi/opal/mca/pmix/pmix2x/pmix/src/dstore/pmix_esh.c:1456
#2  0x00002aaaac2b2bcb in _update_ns_elem (ns_elem=0x2aaab3b3bde0, info=0x2aaaae3a76d0)
    at /ccs/home/marksant1/openmpi/src/ompi/opal/mca/pmix/pmix2x/pmix/src/dstore/pmix_esh.c:1550
#3  0x00002aaaac2afce1 in _esh_store (nspace=0xe2fb2c8 "528289639", rank=4294967294, kv=0xdf52210)
    at /ccs/home/marksant1/openmpi/src/ompi/opal/mca/pmix/pmix2x/pmix/src/dstore/pmix_esh.c:918
#4  0x00002aaaac2ad2cb in pmix_dstore_store (nspace=0xe2fb2c8 "528289639", rank=4294967294, kv=0xdf52210)
    at /ccs/home/marksant1/openmpi/src/ompi/opal/mca/pmix/pmix2x/pmix/src/dstore/pmix_dstore.c:66
#5  0x00002aaaac28fa9d in _rank_key_dstore_store (cbdata=0xe01e8c0) at /ccs/home/marksant1/openmpi/src/ompi/opal/mca/pmix/pmix2x/pmix/src/common/pmix_jobdata.c:96
#6  0x00002aaaac2917a7 in _job_data_store (nspace=0xd1aca68 "528289639", cbdata=0xe01e8c0)
    at /ccs/home/marksant1/openmpi/src/ompi/opal/mca/pmix/pmix2x/pmix/src/common/pmix_jobdata.c:386
#7  0x00002aaaac28fc2c in pmix_job_data_dstore_store (nspace=0xd1aca68 "528289639", bptr=0xe01cf80)
    at /ccs/home/marksant1/openmpi/src/ompi/opal/mca/pmix/pmix2x/pmix/src/common/pmix_jobdata.c:118
#8  0x00002aaaac2658ff in _register_nspace (sd=-1, args=4, cbdata=0xd1ac9b0) at /ccs/home/marksant1/openmpi/src/ompi/opal/mca/pmix/pmix2x/pmix/src/server/pmix_server.c:459
#9  0x00002aaaab1e4151 in event_process_active_single_queue (activeq=0x7079c0, base=0x707730)
    at /ccs/home/marksant1/openmpi/src/ompi/opal/mca/event/libevent2022/libevent/event.c:1370
#10 event_process_active (base=<optimized out>) at /ccs/home/marksant1/openmpi/src/ompi/opal/mca/event/libevent2022/libevent/event.c:1440
#11 opal_libevent2022_event_base_loop (base=0x707730, flags=1) at /ccs/home/marksant1/openmpi/src/ompi/opal/mca/event/libevent2022/libevent/event.c:1644
#12 0x00002aaaac2b7efa in progress_engine (obj=0x7072d8) at /ccs/home/marksant1/openmpi/src/ompi/opal/mca/pmix/pmix2x/pmix/src/runtime/pmix_progress_threads.c:149
#13 0x00002aaaada0e806 in start_thread () from /lib64/libpthread.so.0
#14 0x00002aaaadd029bd in clone () from /lib64/libc.so.6
#15 0x0000000000000000 in ?? ()

Will dig further, but increasing the set of eyes looking at it.

[rhc54]

@marksantcroos Try configuring with --disable-pmix-dstore. My best guess is that the pmix shared memory system isn't cleaning up properly after each job and so you are eventually running out of shared memory space.

[marksantcroos]

Thanks, will try. That actually sounds promising, as I get the same error immediately if I restart the DVM!

[rhc54]

Check your /tmp area - you may have to rm -rf some session dir(s) to clean up. Look for anything that starts with ompi or pmix.

[marksantcroos]

Yes, I noticed that also indeed. But I run out of them per run already.

[marksantcroos]

With --disable-pmix-dstore the issue is indeed gone. It is also much much faster! What do I loose by not using the pmix dstore?

[rhc54]

you gain a little memory footprint, but that's all - however, it should have been faster, not slower. we'll have to investigate.

[rhc54]

@marksantcroos Can you tell if it slows down as the number of jobs grows? I'm wondering if it is faster at first, but then slows down - this could potentially be a consequence of the cleanup problem.

[ggouaillardet]

@marksantcroos @rhc54 i previously noted such an odd thing.

the root cause was /dev/shm was full, and for some reason, both ftruncate() and mmap() success (at least on Linux) but a crash occurs when accessing the mmap'ed memory

the attached program can be used to evidence this behavior

#include <stdio.h>
#include <sys/mman.h>
#include <sys/types.h>
#include <fcntl.h>
#include <unistd.h>
#include <stdlib.h>
#include <string.h>

#ifndef ROOT
#define ROOT "/mnt"
#endif

#define SZE 4096
char buffer[SZE];

int main (int argc, char *argv) {
    char * filename = ROOT "/test";
    int fd = open(filename, O_RDWR|O_CREAT|O_TRUNC, 0600);
    void *p;
    if (0 > fd) {
        perror("open ");
        exit(1);
    }
    if (0 > ftruncate(fd, SZE)) {
        perror("ftruncate ");
        exit(1);
    }
#if 0
    if (0 > write(fd, buffer, SZE)) {
        perror("write ");
        exit(1);
    }
#endif
    if (MAP_FAILED == (p = mmap(NULL, SZE,
                                PROT_READ | PROT_WRITE, MAP_SHARED,
                                fd, 0))) {
        perror("mmap ");
        exit(1);
     }
     printf("mmap'ed %d bytes at %p\n", SZE, p);
     memset(p, 0, SZE);
     printf("memset'ed %d mmap'ed bytes at %p\n", SZE, p);
     munmap(p, SZE);
     close(fd);
     unlink(filename);
     return 0;
}

then

# mount -t tmpfs -o size=1M none /mnt
# dd if=/dev/zero of=/mnt/big
# ./mmap

this causes a crash in memset()

a way (workaround ?) to detect this is to try to write() the full file after ftruncate() and before mmap()

[rhc54]

@artpol84 @karasevb Can you guys take a look at this problem?

[marksantcroos]

@marksantcroos Can you tell if it slows down as the number of jobs grows? I'm wondering if it is faster at first, but then slows down - this could potentially be a consequence of the cleanup problem.

Now that it works again I will go back to data gathering :-) Will report back.

[artpol84]

Ok, we will check this out
I think I was observing this on my virtual cluster build on linux-containers. But @karasevb was unable to reproduce. We will take a closer look now.
@ggouaillardet thanks for the analysis!

[artpol84]

@marksantcroos, am I understanding you correctly and the reason of repeated failures was in the bunch of dstore-related leftover in the /tmp directory?

[marksantcroos]

@artpol84 Not exactly, let me explain my use case. I make use of a persistent DVM (that I start with orte-dvm) and then launch many (often small and short) tasks to that. So they were not "leftovers" from previous runs, but files from the same DVM instance, but from completed tasks. Does that make sense?

[artpol84]

@marksantcroos, thank you - it does makes sense. We haven't checked this usecase, but we will do that now.
@rhc54 @marksantcroos can you provide short guidance on how to use the dvm mode to speedup the debugging process? Maybe anonymized script snippet?

[ggouaillardet]

@marksantcroos when you are running your test, can you monitor /dev/shm and see how the empty space evolves ?

with plain mpirun, i run into this issue with a tiny /dev/shm when invoking MPI_Comm_spawn multiple times with the same mpirun command.
the use of a persistent DVM involves creating multiple PMIx jobs, and i am afraid the shared dstore grows forever and is only cleaned when the mpirun or persistent DVM completes.

fwiw, i already plugged numerous memory leaks in https://github.com/ggouaillardet/ompi/tree/topic/finalize_leaks
i still need to clean this up, issue a separate PR for pmix2x specific leaks and merge into master.