Mentions légales du service

Skip to content
Snippets Groups Projects

Weird behavior when using StarPU

    • Closed Issue created by Mathieu Faverge @faverge

    @fpruvost and @ltaief reported that the actual running time of chameleon timings were much slower that what was printed by the output when using StarPU. the problem does not appear when using Quark. (@agullo, @thibault)

    With StarPU and 15 threads on a 32 cores architecture from KAUST:

    $ time numactl --interleave=all ./time_dpotrf_tile --n_range=10000:10000:10000 --k=10000 --nb=320 --threads=15 --nowarmup
Profiling throught FxT has not been enabled in StarPU runtime (configure StarPU with --with-fxt)
#
# CHAMELEON 0.9.1, ./time_dpotrf_tile
# Nb threads: 15
# Nb GPUs:    0
# NB:         320
# IB:         32
# eps:        1.110223e-16
#
#     M       N  K/NRHS   seconds   Gflop/s Deviation
  10000   10000   10000     0.778    428.57 +-   0.00  

real	0m0.937s
user	0m12.296s
sys	0m0.426s

    And with 31 threads:

    $ time numactl --interleave=all ./time_dpotrf_tile --n_range=10000:10000:10000 --k=10000 --nb=320 --threads=31 --nowarmup
Profiling throught FxT has not been enabled in StarPU runtime (configure StarPU with --with-fxt)
#
# CHAMELEON 0.9.1, ./time_dpotrf_tile
# Nb threads: 31
# Nb GPUs:    0
# NB:         320
# IB:         32
# eps:        1.110223e-16
#
#     M       N  K/NRHS   seconds   Gflop/s Deviation
  10000   10000   10000     0.462    721.70 +-   0.00  

real	0m5.742s
user	2m53.004s
sys	0m3.008s

    While when using Quark (and Plasma, not within chameleon but the behavior is similar)

    time numactl --interleave=all ./time_dgemm_tile --n_range=10000:10000:10000 --k=10000 --nb=320 --threads=31 --nowarmup
#
# PLASMA 2.8.0, ./time_dgemm_tile
# Nb threads: 31
# NB:         320
# IB:         32
# eps:        1.110223e-16
#
#     M       N  K/NRHS   seconds   Gflop/s Deviation
  10000   10000   10000     2.282    876.24      0.00

real	0m2.516s
user	1m8.134s
sys	0m1.449s

    Designs

      Child items ...

      2. Activity

      • Mathieu Faverge changed title from Weird behaviour when using StarPU to Weird behavior when using StarPU

        changed title from Weird behaviour when using StarPU to Weird behavior when using StarPU

      • THIBAULT Samuel
        THIBAULT Samuel @thibault ·
        Developer

        Mathieu Faverge, on Thu 09 Feb 2017 17:26:16 +0100, wrote:

        [1]@fpruvost and [2]@ltaief reported that the actual running time of chameleon timings were much slower that what was printed by the output when using StarPU. the problem does not appear when using Quark. ([3]@agullo, [4]@thibault)

        M N K/NRHS seconds Gflop/s Deviation

        10000 10000 10000 0.462 721.70 +- 0.00

        real 0m5.742s

        Ouch, that's quite a difference indeed. I guess there are odd things which are taking a long time to initialize or such, perhaps hwloc for instance. An FxT trace for instance would allow to have a beginning of idea of where that additional time comes from.

      • Mathieu Faverge
        Mathieu Faverge @faverge ·
        Author Owner

        Plasma does the same thing with hwloc so I would not start by there unfortunately.

      • THIBAULT Samuel
        THIBAULT Samuel @thibault ·
        Developer

        Sure, I said to start with FxT, hwloc was just an instance of something that could go wrong. Since I have no information on the system or whatsoever, I have no idea what could be useful to have a look at.

        There is no such issue on the miriel nodes on plafrim for instance (default StarPU and chameleon configurations):

        $ time numactl --interleave=all ./time_dpotrf_tile --n_range=10000:10000:10000 --k=10000 --nb=320 --threads=23 --nowarmup 10000 10000 10000 0.528 630.90 +- 0.00
        real 0m0.697s

        $ time numactl --interleave=all ./time_dpotrf_tile --n_range=20000:20000:20000 --k=10000 --nb=320 --threads=23 --nowarmup 20000 20000 10000 3.951 674.96 +- 0.00
        real 0m4.474s

      • Hatem Ltaief
        Hatem Ltaief @ltaief ·
        Developer

        Dear Samuel and team, Thanks a lot for your continuous support, this has been very beneficial for us at ECRC@KAUST. The issues being reported occurs on two different haswell chips, one with 2 sockets 18 cores (sys1) and one with 2 sockets 16 cores (sys2). I have attached the config.log files for starpu and chameleon on each system. Please let me know if you need anything else.

        config-chameleon-sys1.logconfig-chameleon-sys2.logconfig-starpu-sys1.logconfig-starpu-sys2.log

      • THIBAULT Samuel
        THIBAULT Samuel @thibault ·
        Developer

        Well, as I said above, an FxT trace would allow to know where to look at. Using "strace -f -ttt -o /tmp/strace.log ./time_dpotrf_tile etc." would also be useful to get a trace at a lower level.

        Now, I'm wondering whether it could simply be your NFS which is slow at writing perfmodel files.

        Could you try to explictly

        export STARPU_CALIBRATE=0

        to avoid making StarPU write perfmodels at the end? Chameleon sets it by default to 1, I've always been a bit worried about this since it both hides some warnings, and can have impact on performance. @faverge , what was the rationale for it?

      • Mathieu Faverge
        Mathieu Faverge @faverge ·
        Author Owner

        @thibault I don't remember being responsible for this, or at least in an intentional way :). I think, I 'm indeed the one who rewrote the startup_init call in Chameleon and setup those parameters, but I don't see any reasons to keep too. It was probably done this way before and I kept it.

      • Mathieu Faverge
        Mathieu Faverge @faverge ·
        Author Owner

        @ltaief : have you been able to try with STARPU_CALIBRATE=0 and confirm/infirm the problem ?

      • Hatem Ltaief
        Hatem Ltaief @ltaief ·
        Developer

        @faverge STARPU_CALIBRATE does not really help, but could worsen it:

        ltaiefh@shihab:~/codes/chameleon-intel/build/timing$ export STARPU_CALIBRATE=0; time numactl --interleave=all ./time_dgemm_tile --n_range=10000:10000:10000 --k=10000 --nb=320 --threads=31 --nowarmup Profiling throught FxT has not been enabled in StarPU runtime (configure StarPU with --with-fxt)

        CHAMELEON 0.9.1, ./time_dgemm_tile Nb threads: 31 Nb GPUs: 0 NB: 320 IB: 32 eps: 1.110223e-16

         M       N  K/NRHS   seconds   Gflop/s Deviation

        10000 10000 10000 2.329 858.82 +- 0.00

        real 0m39.859s user 20m26.805s sys 0m12.415s

        ltaiefh@shihab:~/codes/chameleon-intel/build/timing$ export STARPU_CALIBRATE=1; time numactl --interleave=all ./time_dgemm_tile --n_range=10000:10000:10000 --k=10000 --nb=320 --threads=31 --nowarmup Profiling throught FxT has not been enabled in StarPU runtime (configure StarPU with --with-fxt)

        CHAMELEON 0.9.1, ./time_dgemm_tile Nb threads: 31 Nb GPUs: 0 NB: 320 IB: 32 eps: 1.110223e-16

         M       N  K/NRHS   seconds   Gflop/s Deviation

        10000 10000 10000 ^C real 0m59.513s user 30m32.901s sys 0m20.073s

        Edited by Hatem Ltaief
      • Hatem Ltaief
        Hatem Ltaief @ltaief ·
        Developer

        @thibault Please find attached 2 traces, with and w/o calibration, of the respective runs below:

        ltaiefh@shihab:~/codes/chameleon-intel/build/timing$ export STARPU_CALIBRATE=0; time numactl --interleave=all ./time_dgemm_tile --n_range=10000:10000:10000 --k=10000 --nb=320 --threads=31 --nowarmup [starpu][starpu_initialize] Warning: StarPU was configured with --with-fxt, which slows down a bit

        CHAMELEON 0.9.1, ./time_dgemm_tile Nb threads: 31 Nb GPUs: 0 NB: 320 IB: 32 eps: 1.110223e-16 M N K/NRHS seconds Gflop/s Deviation 10000 10000 10000 2.560 781.23 +- 0.00

        real 3m21.531s user 103m43.600s sys 0m46.077s

        ltaiefh@shihab:~/codes/chameleon-intel/build/timing$ export STARPU_CALIBRATE=1; time numactl --interleave=all ./time_dgemm_tile --n_range=10000:10000:10000 --k=10000 --nb=320 --threads=31 --nowarmup [starpu][starpu_initialize] Warning: StarPU was configured with --with-fxt, which slows down a bit

        CHAMELEON 0.9.1, ./time_dgemm_tile Nb threads: 31 Nb GPUs: 0 NB: 320 IB: 32 eps: 1.110223e-16 M N K/NRHS seconds Gflop/s Deviation 10000 10000 10000 2.381 840.02 +- 0.00

        real 3m57.873s user 122m34.772s sys 0m56.212s

        prof_file_ltaiefh_0-calib-0prof_file_ltaiefh_0-calib-1

        Edited by Hatem Ltaief
      • THIBAULT Samuel
        THIBAULT Samuel @thibault ·
        Developer

        Hello, These traces are actually empty, please comment RUNTIME_stop_profiling(); from the timing/timing.c file, so we can get the full trace. Thanks

      • Hatem Ltaief
        Hatem Ltaief @ltaief ·
        Developer

        Each file is now 60MB ;-) How should I send them to you?

      • THIBAULT Samuel
        THIBAULT Samuel @thibault ·
        Developer

        Yes, please :)

      • Mathieu Faverge
        Mathieu Faverge @faverge ·
        Author Owner

        Ok, the problem is found. It is the same behavior as the one observed with Dalal. It is the contention problem that appears when using ws or lws on Haswell.

        I ran Hatem test timing every steps of the algorithm. I extracted only the time spent to generate the matrix because that's were the problem occurs with NT^2 parallel tasks.

        @thibault : Isn't the patch you provided to Dalal integrated into the 1.2.0 ? @ltaief will use another scheduler for now, but we should think about changing that.

        $ for s in eager ws lws dmdas prio; do export STARPU_SCHED=$s; echo "-------- $s -----------"; time numactl --interleave=all ./time_dgemm_tile --n_range=5000:5000:5000 --k=5000 --nb=320 --threads=32; done
-------- eager -----------
...
[Start Initializing A: 0.008834 s
Start Initializing B: 0.008644 s
Start Initializing C: 0.009266 s

...

Start Initializing A: 0.007690 s
Start Initializing B: 0.008098 s
Start Initializing C: 0.007252 s

-------- ws -----------
...
Start Initializing A: 0.887951 s
Start Initializing B: 0.868374 s
Start Initializing C: 0.877149 s

...

Start Initializing A: 26.772077 s
Start Initializing B: 29.454763 s
Start Initializing C: 26.051609 s

-------- lws -----------
...

Start Initializing A: 4.359219 s
Start Initializing B: 5.993681 s
Start Initializing C: 4.836623 s

...

Start Initializing A: 5.034299 s
Start Initializing B: 7.232525 s
Start Initializing C: 5.376520 s

-------- dmdas -----------
...

Start Initializing A: 0.057779 s
Start Initializing B: 0.035715 s
Start Initializing C: 0.057515 s

...

Start Initializing A: 0.013283 s
Start Initializing B: 0.013944 s
Start Initializing C: 0.013350 s

-------- prio -----------
...

Start Initializing A: 0.008727 s
Start Initializing B: 0.008773 s
Start Initializing C: 0.008915 s

...

Start Initializing A: 0.007156 s
Start Initializing B: 0.007552 s
Start Initializing C: 0.008993 s
        Edited by Mathieu Faverge
      • THIBAULT Samuel
        THIBAULT Samuel @thibault ·
        Developer

        Do you mean the 1.2 branch? All my fixes are in the 1.2 branche, yes. 1.2.0, however, was released way before the patch :)

      • Hatem Ltaief
        Hatem Ltaief @ltaief ·
        Developer

        @thibault Ouch! All right, how can we get this 1.2 branch? Do you plan to include these patches to next release? When is the next release? Thanks Sam!

      • THIBAULT Samuel
        THIBAULT Samuel @thibault ·
        Developer

        As explained in earlier mails, the 1.2 branch snapshot is always available from the download page of starpu, which leads to http://starpu.gforge.inria.fr/testing/branches/starpu-1.2/starpu-nightly-latest.tar.gz That's what will be in 1.2.1, we didn't make a schedule for a release, but we can do that soonish if needed.

      • Hatem Ltaief
        Hatem Ltaief @ltaief ·
        Developer

        Oh, thats right! Release will be great, so that we have a single point to maintain on our side.

      • Mathieu Faverge
        Mathieu Faverge @faverge ·
        Author Owner

        @ltaief have you tried if the problem persist with the nightly build or not ? If not, I'll close the issue.

      • Hatem Ltaief
        Hatem Ltaief @ltaief ·
        Developer

        Yes, thanks, problem solved with the nightly build.

      • Mathieu Faverge closed

        closed

      • THIBAULT Samuel mentioned in merge request !33 (merged)

        mentioned in merge request !33 (merged)

      • THIBAULT Samuel mentioned in merge request !238 (merged)

        mentioned in merge request !238 (merged)

      • Mathieu Faverge mentioned in commit e9559ea8

        mentioned in commit e9559ea8

      Please register or sign in to reply