Extremely low collective performance on UCX IB but not PSM3 when using HDR HCA / FDR switch combinations

AlexNinaber commented 2 years ago

Describe the bug

During analyses of figuring out low StarCCM application performance, we did some testing with IMB-MPI1 AlltoAll and noticed extremely low performance with UCX communication. Both OpenMPI and IntelMPI, any version of UCX, native RH7 IB and Mellanox OFED.

What's special is that the hosts have either EDR or HDR cards and the switch is FDR. Tried various cables, copper/fibre, other FDR switches, mixed results/impact. All firmwares are up to date. However: on kernel 5.17.5 with IntelMPI and PSM3 communication, it's fine. Bit worse latency but not much, at 8K it's what is expected.

We're a bit confused about what can be causing this.

Steps to Reproduce

Command line

mpirun -np 64 -ppn 32 -host n1,n2 ./IMB-MPI1 AlltoAll Transport communication: MLX Tried various UCX transports, all same problem.

Once the above hits all 64 processes involved, progress is jumpy and in general very slow.

UCX version used (from github branch XX or release YY) + UCX configure flags (can be checked by ucx_info -v)

# UCT version=1.11.0 revision 6031c98
# configured with: --build=x86_64-redhat-linux-gnu --host=x86_64-redhat-linux-gnu --program-prefix= --disable-dependency-tracking --prefix=/usr --exec-prefix=/usr --bindir=/usr/bin --sbindir=/usr/sbin --sysconfdir=/etc --datadir=/usr/share --includedir=/usr/include --libdir=/usr/lib64 --libexecdir=/usr/libexec --localstatedir=/var --sharedstatedir=/var/lib --mandir=/usr/share/man --infodir=/usr/share/info --disable-optimizations --disable-logging --disable-debug --disable-assertions --enable-mt --disable-params-check --without-java --enable-cma --with-cuda --with-gdrcopy --with-verbs --with-knem --with-rdmacm --without-rocm --with-xpmem --without-fuse3 --without-ugni --with-cuda=/usr/local/cuda-11.2

Any UCX environment variables used

Any version

Setup and versions

OS version: CentOS7.9 with 5.x kernels
For RDMA/IB/RoCE related issues:
- Native RH7.9 IB and MLNX OFED
- HW information from ibstat or ibv_devinfo -vv command: AMD Epyc, any EDR or HDR card

Additional information (depending on the issue)

OpenMPI version
Output of ucx_info -d to show transports and devices recognized by UCX
Configure result - config.log

Log file - configure UCX with "--enable-logging" - and run with "UCX_LOG_LEVEL=data"


#----------------------------------------------------------------
# Benchmarking Alltoall 
# #processes = 64 
#----------------------------------------------------------------
   #bytes #repetitions  t_min[usec]  t_max[usec]  t_avg[usec]
        0         1000         0.06         0.50         0.10
[1651843038.962778] [burn1-005:61337:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0x1423130 of 8217 bytes with 128 elements
[1651843038.962927] [burn1-005:61338:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0x1085150 of 8217 bytes with 128 elements
[1651843038.962996] [burn1-005:61340:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xdd0190 of 8217 bytes with 128 elements
[1651843038.962993] [burn1-005:61343:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xe38a90 of 8217 bytes with 128 elements
[1651843038.962993] [burn1-005:61344:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xdf6a90 of 8217 bytes with 128 elements
[1651843038.962999] [burn1-005:61345:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xf18930 of 8217 bytes with 128 elements
[1651843038.962999] [burn1-005:61346:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xe94930 of 8217 bytes with 128 elements
[1651843038.962984] [burn1-005:61347:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0x11078f0 of 8217 bytes with 128 elements
[1651843038.962984] [burn1-005:61348:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xf18930 of 8217 bytes with 128 elements
[1651843038.963005] [burn1-005:61349:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xeb58f0 of 8217 bytes with 128 elements
[1651843038.963005] [burn1-005:61350:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xe10930 of 8217 bytes with 128 elements
[1651843038.962970] [burn1-005:61351:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xf398f0 of 8217 bytes with 128 elements
[1651843038.962970] [burn1-005:61352:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xed6930 of 8217 bytes with 128 elements
[1651843038.962996] [burn1-005:61339:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xcc8190 of 8217 bytes with 128 elements
[1651843038.963002] [burn1-005:61341:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xd72a90 of 8217 bytes with 128 elements
[1651843038.963002] [burn1-005:61342:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xe38a90 of 8217 bytes with 128 elements
[1651843038.962867] [burn1-006:62827:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xbac580 of 8217 bytes with 128 elements
[1651843038.962867] [burn1-006:62828:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xbab0f0 of 8217 bytes with 128 elements
[1651843038.962868] [burn1-006:62829:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xbab0f0 of 8217 bytes with 128 elements
[1651843038.963221] [burn1-006:62830:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xbab0f0 of 8217 bytes with 128 elements
[1651843038.963225] [burn1-006:62831:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xbab0f0 of 8217 bytes with 128 elements
[1651843038.963225] [burn1-006:62832:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xbab0f0 of 8217 bytes with 128 elements
[1651843038.963228] [burn1-006:62833:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xbab0f0 of 8217 bytes with 128 elements
[1651843038.963228] [burn1-006:62834:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xbab0f0 of 8217 bytes with 128 elements
[1651843038.963229] [burn1-006:62835:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xbab0f0 of 8217 bytes with 128 elements
[1651843038.963229] [burn1-006:62836:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xbab0f0 of 8217 bytes with 128 elements
[1651843038.963230] [burn1-006:62837:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xbab0f0 of 8217 bytes with 128 elements
[1651843038.963230] [burn1-006:62838:0]           mpool.c:206  UCX  DEBUG mpool pending-ops: allocated chunk 0xbab0f0 of 8217 bytes with 128 elements

        2         1000        15.10      5728.96       849.21
[1651843135.954937] [burn1-006:62846:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x101c500: attached remote segment id 0xc0000008c000f57f at 0x15533d052000 cookie 0x419000
[1651843135.955044] [burn1-006:62846:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0xf98680: attached remote segment id 0xc0000008c000f580 at 0x15533cc39000 cookie 0x419000
[1651843135.955115] [burn1-006:62832:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x105ee00: attached remote segment id 0xc00000094000f571 at 0x15533f94c000 cookie 0x419000
[1651843135.955093] [burn1-006:62834:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0xbdb610: attached remote segment id 0xc0000009c000f573 at 0x15533ed01000 cookie 0x419000
[1651843135.955087] [burn1-006:62841:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0xe4e280: attached remote segment id 0xc0000008c000f57b at 0x15533e4cf000 cookie 0x419000
[1651843135.955087] [burn1-006:62842:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x11b0e60: attached remote segment id 0xc0000008c000f57b at 0x15533e4cf000 cookie 0x419000
[1651843135.955067] [burn1-006:62853:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x864820: attached remote segment id 0xc0000008c000f587 at 0x15533bbd5000 cookie 0x419000
[1651843135.955067] [burn1-006:62854:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x10ea060: attached remote segment id 0xc0000008c000f587 at 0x15533af8a000 cookie 0x419000
[1651843135.955122] [burn1-006:62854:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x11f24e0: attached remote segment id 0xc0000008c000f588 at 0x15533ab71000 cookie 0x419000
[1651843135.955116] [burn1-006:62828:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0xe90610: attached remote segment id 0xc00000074000f56d at 0x15533f11a000 cookie 0x419000
[1651843135.955122] [burn1-006:62830:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x101caf0: attached remote segment id 0xc00000084000f56f at 0x15533ed01000 cookie 0x419000
[1651843135.955123] [burn1-006:62836:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x10e2be0: attached remote segment id 0xc0000008c000f575 at 0x15533f11a000 cookie 0x419000
[1651843135.955119] [burn1-006:62838:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x10a0de0: attached remote segment id 0xc0000008c000f577 at 0x15533ed01000 cookie 0x419000
[1651843135.955176] [burn1-006:62842:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x11f2dd0: attached remote segment id 0xc0000008c000f57c at 0x15533e0b6000 cookie 0x419000
[1651843135.955145] [burn1-006:62847:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x155348030e50: attached remote segment id 0xc0000008c000f583 at 0x15533b7bc000 cookie 0x419000
[1651843135.955108] [burn1-006:62848:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0xf14180: attached remote segment id 0xc0000008c000f581 at 0x15533a758000 cookie 0x419000
[1651843135.955224] [burn1-006:62829:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x155348008b30: attached remote segment id 0xc00000084000f56f at 0x15533f94c000 cookie 0x419000
[1651843135.955216] [burn1-006:62830:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x105e750: attached remote segment id 0xc0000008c000f570 at 0x15533e8e8000 cookie 0x419000
[1651843135.955239] [burn1-006:62832:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x1553480f6bf0: attached remote segment id 0xc0000008c000f574 at 0x15533f533000 cookie 0x419000
[1651843135.955229] [burn1-006:62834:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x155348003060: attached remote segment id 0xc0000008c000f576 at 0x15533e8e8000 cookie 0x419000
[1651843135.955228] [burn1-006:62838:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x112ced0: attached remote segment id 0xc0000008c000f578 at 0x15533e8e8000 cookie 0x419000
[1651843135.955239] [burn1-006:62841:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x864950: attached remote segment id 0xc0000008c000f57d at 0x15533e0b6000 cookie 0x419000
[1651843135.955251] [burn1-006:62833:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x10ea190: attached remote segment id 0xc0000009c000f573 at 0x15533e4cf000 cookie 0x419000
[1651843135.955241] [burn1-006:62837:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x112c9f0: attached remote segment id 0xc0000008c000f577 at 0x15533e4cf000 cookie 0x419000
[1651843135.955265] [burn1-006:62838:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x155348002c10: attached remote segment id 0xc0000008c000f57e at 0x15533e4cf000 cookie 0x419000
[1651843135.955273] [burn1-006:62842:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x12b8ae0: attached remote segment id 0xc0000008c000f582 at 0x15533dc9d000 cookie 0x419000
[1651843135.955296] [burn1-006:62833:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x15534800fae0: attached remote segment id 0xc0000008c000f575 at 0x15533e0b6000 cookie 0x419000
[1651843135.955277] [burn1-006:62836:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x155348030bb0: attached remote segment id 0xc0000008c000f57c at 0x15533ed01000 cookie 0x419000
[1651843135.955294] [burn1-006:62841:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x15534804b9d0: attached remote segment id 0xc0000008c000f581 at 0x15533dc9d000 cookie 0x419000
[1651843135.955323] [burn1-006:62837:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x9db810: attached remote segment id 0xc0000008c000f57d at 0x15533e0b6000 cookie 0x419000
[1651843135.955291] [burn1-006:62849:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x155348009490: attached remote segment id 0xc0000008c000f585 at 0x15533b3a3000 cookie 0x419000
[1651843135.955378] [burn1-006:62839:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x15534800fae0: attached remote segment id 0xc0000008c000f57f at 0x15533c407000 cookie 0x419000
[1651843135.955379] [burn1-006:62840:0]           mm_ep.c:68   UCX  DEBUG mm_ep 0x155348051ca0: attached remote segment id 0xc0000008c000f580 at 0x15533b7bc000 cookie 0x419000
****

[1651843038.963228] [burn1-006:62839:0] mpool.c:206 UCX DEBUG mpool pending-ops: allocated chunk 0xbab0f0 of 8217 bytes with 128 elements [1651843038.963228] [burn1-006:62840:0] mpool.c:206 UCX DEBUG mpool pending-ops: allocated chunk 0xbab0f0 of 8217 bytes with 128 elements [1651843038.963227] [burn1-006:62841:0] mpool.c:206 UCX DEBUG mpool pending-ops: allocated chunk 0xbab0f0 of 8217 bytes with 128 elements [1651843038.963227] [burn1-006:62842:0] mpool.c:206 UCX DEBUG mpool pending-ops: allocated chunk 0xbab0f0 of 8217 bytes with 128 elements

yosefe commented 2 years ago

@AlexNinaber can you pls try adding -x UCX_RC_RETRY_COUNT=0 to mpirun? If this causes application to crash, it would mean the problem is with packet drops and retransmissions when having mixed port speeds.

AlexNinaber commented 2 years ago

@yosefe tried with UCX_RC_RETRY_COUNT, no change. The ports have no mixed port speeds by the way, IB just moves to the lowest common speeds which is FDR in this case.

yosefe commented 2 years ago

@AlexNinaber thanks for the feedback. The next step would be to take it with NVIDIA networking support since such a large delay is likely coming from the network level. The issue may still be related to HDR/EDR being downgraded to FDR.

AlexNinaber commented 2 years ago

@yosefe We figured it comes from the network level, however, the (unexpected) weirdness is that with PSM3 we see no such problem. Hence we were wondering if there's anything UCX can be doing weird on an EDR/HDR card if run in FDR mode.

yosefe commented 2 years ago

@AlexNinaber perhaps PSM3 is using a different transport such as UD. Can you try running UCX with "UCX_TLS=ud,self,sm" ?

openucx / ucx