PMIx performance issue

[nkogteva]

We compared execution time of following intervals of mpi_init:

• time from start to completion of rte_init
• time from completion of rte_init to modex
• time to execute modex
• time from modex to first barrier
• time to execute barrier
• time from barrier to complete mpi_init

for 1.8 and trunk versions (configured with --enable-timing) for 0-vpid process using c_hello test.

We noticed that time from modex to first barrier is too much for trunk version. We also compared time of main PMIx procedsures using pmix test (orte/test/mpi/pmix.c) and it seems that PMIx_get is most time-consuming procedure.

Further investigation is needed.

[jladd-mlnx]

@nkogteva Please include the data you collected on the TACC system.

[nkogteva]

mpi_init intervals (c_hello test: release vs. trunk):

time utility output (c_hello test: release vs. trunk):

pmix intervals (pmix test: trunk only):

[hppritcha]

@nkogteva in collecting the data, how many MPI ranks/node were you using?

[jladd-mlnx]

@jsquyres @rhc54 @hppritcha Adding other folks to this issue. This data was collected on the Stampede system at TACC. There are two sets of experimental data here:

1. Launching a simple MPI hello world application.
2. Launching a native PMIx unit test with mpirun and invoking PMIx calls directly. The experiments following "pmix intervals (pmix test: trunk only):" are the second such set of tests.

Nadia told me this morning that all of the runs had 8 processes per node, although looking at the Stampede system overview, I'm thinking she may be mistaken. Each Stampede node has dual 8-core Xeon E5 processors - @nkogteva please confirm the number of cores-per-node that you ran in these experiments, better yet, please provide a representative command line.

[rhc54]

Looking at the numbers, might be good to check that you have coll/ml turned "off" here as it will otherwise bias the data.

[rhc54]

Looking at your unit test, there is clearly something wrong in the measurements. The "modex_send" call cannot be a function of the number of nodes - all it does is cause the provided value to be packed into a local buffer, and then it returns. So there is nothing about modex_send that extends beyond the proc itself, and the time has to be a constant (and pretty darned small, as the scale on your y-axis shows).

I'm working on this area right now, so perhaps it is worth holding off until we get the revised pmix support done. I'm bringing in the pmix-1.0.0 code and instrumenting it with Artem's timing support, so hopefully we'll get some detailed data.

[jladd-mlnx]

We have always set -mca coll ^ml but @nkogteva can you confirm that you did have ml turned off? @rhc54 I'm not sure that we can conclude that the modex sends are really scaling like O(N) as opposed to O(1) or if that's just some noisy data. What's reproducible @nkogteva, how many trials were done per data point?

[nkogteva]

@hppritcha @jladd-mlnx @rhc54

I re-ran test with -mca coll ^ml option (it was missed previously).

My command line for 128 launched nodes:
/usr/bin/time -o <time_utility_output_file_name> -p <path_to_ompi>/mpirun -bind-to core --map-by node -display-map -mca mtl '^mxm' -mca btl tcp,sm,self -mca btl_openib_if_include mlx4_0:1 -mca plm rsh -mca coll '^ml' -np 1024 -mca oob tcp -mca grpcomm_rcd_priority 100 -mca orte_direct_modex_cutoff 100000 -mca dstore hash -mca <ompi_timing true path_to_test>/c_hello

New results for pmix test:

As you can see MODEX_SEND is not exactly function of number of nodes. It is various for different runs. Anyway MODEX_SEND time is small. As for MODEX_RECV it still have too high values of execution time.

Please also note, this data is related to one run. I'm still gathering data to plot average time values for at least 10 runs. Plots for 1 run were attached in order to focus attention on MODEX_RECV problem.

[rhc54]

Thanks Nadia! That cleared things up nicely.

I don't find anything too surprising about the data here. I suspect we are doing a collective behind the scenes (i.e., the fence call returns right away, but a collective is done to exchange the data), and that is why modex_recv looks logarithmic. I wouldn't be too concerned about it for now.

As for it "taking too long" - I would suggest that this isn't necessarily true. It depends on the algorithm and mode we are using. Remember, at this time the BTLs are demanding data for every process in the job, so regardless of direct modex or not, the total time for startup is going to be much longer than we would like.

Frankly, until the BTLs change, the shape of the curves you are seeing are actually about as good as we can do. We can hopefully reduce the time, but the scaling law itself won't change.

One other thing to check: be sure that you build --disable-debug and with some degree of optimization set (e.g., -O2) as that will significantly impact the performance.

[hppritcha]

Isn't the real issue here the delta between the 1.8 and master timings? I think we need to understand the results in Nadia's real graph. I'd be interested in --disable-debug for both 1.8 and master.

[rhc54]

As I've said before, we know the current pmix server implementation in ORTE isn't optimized, and I'm working on it now. So I'm not really concerned at the moment.

[rhc54]

I saw that Elena committed some changes to the grpcomm components that sounded like they directly impact the results here. Thanks Elena!

@nkogteva when you get a chance, could you please update these graphs?