Drastical performance degradation when switching from StarPU-1.3.11 to StarPU-1.4.4 on a GPU node

[Muxas]

The Issue

On a GPU node when switching from StarPU version 1.3.11 to 1.4 versions we experience strange performance drop. For our new software NNTile it results in a 10x performance drop. Yes, it goes from 100% to only 10% percent.

Attempt to switch to a master branch (commit 50cf74508 at Inria gitlab repository) leads to different errors, related to data transfers between CPU and GPU. We tried some other commits from master branch and realized, that they only work with CPU and something strange with memory manager happens when it goes to GPU nodes. DARTS scheduler always fails, while DM and DMDA schedulers fail for some commits (e.g., 50cf74508) and work correctly for other commits (e.g., 2b8a91fe). I cannot present the output of master branch experiments right now, as this current issue is about performance degradation of 1.4 series of StarPU releases.

Although 10x performance drop happens on our new software, I prepared a simple example that shows performance for versions 1.2.10, 1.3.11 and 1.4.4. Most performance drop for the simple example happened when switching from 1.2.10 version to 1.3.11.

Steps to reproduce

I have implemented a simple test https://github.com/Muxas/starpu_gemm_redux to reproduce the issue. The repo simply implements several chains of matrix multiplications:

C[i] = A[i][0]*B[i][0] + A[i][1]*B[i][1] + ... +A[i][NB-1]*B[i][NB-1]

for i in range from 0 to D-1.

which can be simply described with the following C code (the first order of task submissions):

for(int r = 0; r < R; ++r) // Number of repeats
{
    for(int i = 0; i < NB; ++i) // Number of A and B matrices in each chain of matrix multiplications
    {
        for(int j = 0; j < D; ++j) // Number of output C matrices
        {
            starpu_task_insert(&gemm_cl, STARPU_R, A[i*D+j], STARPU_R, B[i*D+j],
                    C_mode, C[j], 0);
        }
    }
}

or with the following C code (the other order of task submissions):

for(int r = 0; r < R; ++r) // Number of repeats
{
    for(int j = 0; j < D; ++j) // Number of output C matrices
    {
        for(int i = 0; i < NB; ++i) // Number of A and B matrices in each chain of matrix multiplications
        {
            starpu_task_insert(&gemm_cl, STARPU_R, A[i*D+j], STARPU_R, B[i*D+j],
                    C_mode, C[j], 0);
        }
    }
}

Matrices A are of size M-by-K, matrices B are of size K-by-N and matrices C are of size M-by-N. No transpositions in matrix multiplications.

Our results are produced on a HGX node with 8 (eight) Nvidia A100 80GB SXM GPUs. We compiled the code and run two experimental setups:

1. M=N=K=1024, D=32, NB=100, R=50. with and without STARPU_REDUX access mode for the matrices C.
2. M=256, N=K=1532, D=32, NB=100, R=50. with and without STARPU_REDUX access mode for the matrices C.

StarPU-1.4.4 behavior

This section presents plots for the StarPU-1.4.4 version. The first plot shows warmup time (done by the first order of task submission), time for the first order of task submission and time for the other way of task submission with STARPU_RW|STARPU_COMMUTE access mode for the matrices C and M=N=K=1024:

The second plot shows the same timings but for the STARPU_REDUX access mode for the matrices C:

The third plot shows timings for M=256 and N=K=1532 with STARPU_RW|STARPU_COMMUTE access mode:

And the last plot in this section (for the STARPU_REDUX access mode):

We see, that most dumb scheduling algorithm, namely eager, outperforms smarter ones.

StarPU-1.3.11 behavior

This section presents plots for StarPU of version 1.3.11 in the same order as above.

We see, that most dumb scheduling algorithm, namely eager, outperforms smarter ones.

StarPU-1.2.10 behavior

This section presents plots for StarPU of version 1.2.10 in the same order as above.

Here we see, that in case of STARPU_RW|STARPU_COMMUTE access mode smart schedulers DMDA and DMDAR perform nearly perfectly, just as EAGER. The problem with DMDA and DMDAR appears when switching to 1.3.11 or 1.4.4 StarPU version.

Configuration

The configure line we used is within config.log files in the section below.

Configuration result

This is a config file for StarPU-1.2.10:
config-1.2.10.log

This is a config file for StarPU-1.3.11:
config-1.3.11.log

This is a config file for StarPU-1.4.4:
config-1.4.4.log

Distribution

Inria Gitlab repository

Version of StarPU

We used starpu-1.3.11 and starpu-1.4.4 tags of Inria GitLab repository

Version of GPU drivers

We use CUDA 12.3, hwloc 2.9.3

[Muxas]

Dear StarPU team,

I think I figured out what is the reason for 10x performance drop of my application. I disabled kernels and printed bus stats for 1.3.11 and 1.4.4 versions of StarPU.

StarPU-1.3.11:

Total transfers: 29525.0176 GB
Real time including initialization: 4:58.20
Training performance: 1039.465649305438 Tflops/s

StarPU-1.4.4:

Total transfers: 44654.4844 GB
Real time: 17:05.05
Training performance: 58.44558141509535 Tflops/s

For some reason DMDAR and other DM** schedulers in StarPU-1.4.4 send nearly twice more data. And if I specifically take a look at the slowest part, namely PCI-express connection between CPU and GPUs, the new 1.4.4 version sends 65 times more data compared to old version 1.3.11.

Could you please advice if there is a way in StarPU-1.4.4 to put this data transmission overload of 1.4.4 StarPU back to where it was with 1.3.11 version?

I believe there is something wrong with the Memory Manager.

P.S. Enabling CUDA memory map leads to the following error:
../../src/datawizard/copy_driver.c:312: _starpu_driver_copy_data_1_to_1: Assertion `0 && "src_replicate->memory_node == dst_replicate->mapped"' failed.

P.P.S Using STARPU_REDUX leads to another but similar error. Seems like memory manager is bugged in 1.4.4 StarPU.

[sthibaul]

This is unexpected of course :)

Particularly since the 1.3 series introduces heuristics which are precisely meant to improve the overall flow of data.

AIUI, the involved matrices can completely fit in even just one GPU?

Could you also post results with starpu 1.3.0? To make sure whether it's the 1.2->1.3 development that introduced the first regression, or possibly some backports from the 1.4.x series to the 1.3.x series.

Could you also post the output of starpu_machine_display obtained with the different versions, to make sure dmda gets the correct understanding of available PCI bandwidths, gpu placement etc.

Ideally, if you could provide your testcase with an LGPL-2.1+ licence, we could integrate it in our testsuite, and with simulation support we could add non-regression check-up.

Using STARPU_REDUX leads to another but similar error

That's not precise enough for us to be able to act :)

[Muxas]

Output for the StarPU-1.3.0.

M=N=K=1024, mode=STARPU_RW|STARPU_COMMUTE

M=N=K=1024, mode=STARPU_REDUX

M=256, N=K=1532, mode=STARPU_RW|STARPU_COMMUTE

M=256, N=K=1532, mode=STARPU_REDUX

It seems, that 1.3.0 performs similar to 1.2.10.

[Muxas]

Using STARPU_REDUX leads to another but similar error

That's not precise enough for us to be able to act :)
As soon as we find out the source of increased timing with 1.3.11 version, I will prepare some minimal example where CUDA map and STARPU_REDUX lead to internal StarPU assertion failures.

[Muxas]

Comparison of 1.2.10 vs 1.3.0

I believe I misjudged the plots of StarPU-1.3.0. Take a look at the most right graphs.

StarPU-1.2.10:

StarPU-1.3.0:

There is a gap between Eager and other smart schedulers. And then, for the StarPU-1.3.5 (below) the gap becomes larger.

Another portion of plots. This time for the StarPU-1.3.5.

M=N=K=1024, mode=STARPU_RW|STARPU_COMMUTE

M=N=K=1024, mode=STARPU_REDUX

M=256, N=K=1532, mode=STARPU_RW|STARPU_COMMUTE

M=256, N=K=1532, mode=STARPU_REDUX

[Muxas]

And another update

This time I tried other application NNTile

I took a look at data transfers and total execution time (reported by /usr/bin/time utility) for different versions. Total amount of transferred data sorted in descending order:

1. StarPU-1.2.10: transmitted 64987 GB, execution time 55:32.68 minutes
2. StarPU-1.4.4: transmitted 56783 GB, execution time 27:25.60 minutes
3. StarPU-1.3.0: transmitted 29539 GB, execution time 5:36.09 minutes
4. StarPU-1.3.11: transmitted 29313 GB, execution time 5:54.13 minutes

As one can see, 1.3.x indeed saves a lot of data transmissions. However, 1.4.4 version brings all those transmissions back. Seems like some old code was brought back by 1.4.x release chain. The main problem comes from CPU<->GPU transfers, as 1.4.4 version transfers through a slow PCI-e bus around 65 times more than 1.3.11 version.

Files

Here are the more detailed transmission reports provided by STARPU_BUS_STATS=1 env variable.

transfers_starpu_1.2.10_dmdar.txt

transfers_starpu_1.3.0_dmdar.txt

transfers_starpu_1.3.11_dmdar.txt

transfers_starpu_1.4.4_dmdar.txt

[sthibaul]

Using STARPU_REDUX leads to another but similar error

That's not precise enough for us to be able to act :)
As soon as we find out the source of increased timing with 1.3.11 version, I will prepare some minimal example where CUDA map and STARPU_REDUX lead to internal StarPU assertion failures.

I mean: please provide the error message. "similar error" doesn't allow us to have any idea what this is about.

Also, again:
Could you also post the output of starpu_machine_display obtained with the different versions, to make sure dmda gets the correct understanding of available PCI bandwidths, gpu placement etc.

Otherwise it's really not surprising that dm* etc. get everything wrong.

I don't have easy access to an 8-gpu machine, so I tried with simulation, and got results that actually see 1.4.4 get better result than 1.3.11 and 1.2.10... So I really need details on how things are going on the machine where you can reproduce the issue.

Also, providing us with the .starpu/sampling/bus/ and codelet/45/ files corresponding to the machine would allow me to simulate the exact same architecture, rather than simulating some 8-gpu machine I happened to have access to at some point.

[Muxas]

Also, again:
Could you also post the output of starpu_machine_display obtained with the different versions, to make sure dmda gets the correct understanding of available PCI bandwidths, gpu placement etc.

Here are the files:
starpu_machine_display_1.2.10.txt
starpu_machine_display_1.3.0.txt
starpu_machine_display_1.3.11.txt
starpu_machine_display_1.4.4.txt

P.S. How can I help you simulate my runs? I compiled StarPU without SimGrid support. Traces by FXT weight more than 1 GB. Do not know if giving you contents of codelets/45/ or codelets/44 will help. However, here are the contents of /bus samplings.

bus_stats.tar.gz

[sthibaul]

Here are the files:

Ok, so you have an nvswitch, which wasn't the case of the machine I was simulated, that can explain why I wasn't seeing the problem.

How can I help you simulate my runs?

By providing the information I'm asking :)

I compiled StarPU without SimGrid support.

Simgrid is only needed for the replay part, not for the calibration part.

Traces by FXT weight more than 1 GB

We don't need traces :)

Do not know if giving you contents of codelets/45/ or codelets/44 will help

Yes, please, to be sure to have the same timings as on your machine.

[sthibaul]

starpu_machine_display_1.4.4.txt

there's one odd thing here compared to the others: CUDA 0 has very low bandwidth, whatever the peer. Is this reproducible when you force bus re-calibration with STARPU_BUS_CALIBRATE=1 ?

[Muxas]

starpu_machine_display_1.4.4.txt

I double checked. It remains the same. CUDA 0 has 11 GB/s connection to CPU, other have 13-15 GB/s. With StarPU-1.3.11 the speeds are around 25 GB/s.

StarPU-1.4.4 bandwidth

bandwidth (MB/s) and latency (us)...

from/to	NUMA 0	CUDA 0	CUDA 1	CUDA 2	CUDA 3	CUDA 4	CUDA 5	CUDA 6	CUDA 7	
NUMA 0	0	11625	14683	14671	14659	14661	14598	14587	14588	
CUDA 0	11744	0	14721	14612	14629	14620	14727	14711	14707	
CUDA 1	14661	13621	0	236193	241212	241259	241637	241287	241874	
CUDA 2	14661	13722	243595	0	241024	243733	244475	244209	243717	
CUDA 3	14684	13867	244122	243544	0	241130	243455	244064	244585	
CUDA 4	14607	13908	240379	241467	246133	0	243570	243885	243641	
CUDA 5	13484	15234	241671	241864	243550	247702	0	244909	244375	
CUDA 6	13229	15071	241887	242582	244249	245052	247115	0	244958	
CUDA 7	13528	15133	241470	241637	244368	244738	244376	247771	0

StarPU-1.3.11 bandwidth

bandwidth (MB/s) and latency (us)...

from/to	NUMA 0	CUDA 0	CUDA 1	CUDA 2	CUDA 3	CUDA 4	CUDA 5	CUDA 6	CUDA 7	
NUMA 0	0	25081	25169	25150	25160	25094	25097	25086	25091	
CUDA 0	23837	0	237628	245022	244849	243492	244425	244068	244064	
CUDA 1	23837	244489	0	244506	244464	244747	244650	244639	244372	
CUDA 2	23837	242112	248106	0	244695	243829	244250	245212	244295	
CUDA 3	23836	241816	243238	247892	0	244343	244691	244443	244240	
CUDA 4	23829	241359	243141	243036	247535	0	244676	244164	244173	
CUDA 5	23908	241918	241900	243932	244365	247550	0	243878	244382	
CUDA 6	23829	241531	241140	244337	244161	244080	246877	0	244022	
CUDA 7	23830	242094	241616	244295	244201	243430	243710	244042	0

[Muxas]

starpu_machine_display_1.4.4.txt

Looking at latencies of StarPU-1.4.4:

NUMA 0	0	0	10	9	9	10	9	9	9	
CUDA 0	0	0	10	9	9	10	9	9	9	
CUDA 1	12	12	0	14	14	14	14	14	14	
CUDA 2	12	12	14	0	14	13	13	13	13	
CUDA 3	11	12	14	13	0	13	13	13	13	
CUDA 4	12	12	14	14	13	0	14	13	13	
CUDA 5	12	12	13	13	12	12	0	12	12	
CUDA 6	12	11	13	13	13	13	12	0	12	
CUDA 7	12	11	13	13	13	13	12	12	0

StarPU thinks that CUDA 0 uses the same memory, as NUMA 0... Surprise!

[sthibaul]

CUDA 0 has 11 GB/s connection to CPU, other have 13-15 GB/s

Not only that, but also the gpu-gpu connexions are not getting the nvswitch speed, that's really odd.

[sthibaul]

StarPU thinks that CUDA 0 uses the same memory, as NUMA 0... Surprise!

The duplicates in the rows and columns and the 0 values in numa0/cuda0 are suspicious indeed.

[sthibaul]

It might be useful to see the config.log output in the 1.4.4 case.