[starpu-devel] [wrong binding, measuring execution/sleep time, incorrect timing results]

[Maxim Abalenkov <maxim.abalenkov@gmail.com>]

Dear all,

How are you? I hope all is well with you. I need help please.

I wrote a simple program to test StarPU. The program takes a matrix and raises each matrix element to the power of two. The matrix of size (m x n) is processed in blocks of size (p x n). You may find the full source code of my example attached. I’m running my code on a MacBook Air M2 with 16 GB of RAM. I compile my code with

clang -I /opt/local/include/starpu/1.4 -I /opt/local/include mtrx-blk-xpu.c -o mtrx-blk-xpu -L /opt/local/lib -lstarpu-1.4

It is Apple clang version 15.0.0 (clang-1500.1.0.2.5).

Please find below a snippet that I adopted from one of StarPU examples to display profiling information:

// display profiling information

for (int worker = 0; worker < starpu_worker_get_count(); worker++) {

        struct starpu_profiling_worker_info worker_info;

        status = starpu_profiling_worker_get_info(worker, &worker_info);

        STARPU_ASSERT(!status);

        // times

        double t_total          = starpu_timing_timespec_to_us(&worker_info.total_time);

        double t_execution = starpu_timing_timespec_to_us(&worker_info.executing_time);

        double t_sleep         = starpu_timing_timespec_to_us(&worker_info.sleeping_time);

        double t_overhead  = t_total - t_execution - t_sleep;

        // ratios

        float r_execution = 100.0*t_execution/t_total;

        float r_sleep          = 100.0*t_sleep/t_total;

        float r_overhead  = 100.0 - r_execution - r_sleep;

        char workername[128];

        starpu_worker_get_name(worker, workername, 128);

        printf("Worker %s:\n", workername);

        printf("\t%d task(s)\n", worker_info.executed_tasks);

        printf("\ttotal time: %.2lf s\n", t_total*1e-6);

        printf("\texecution time: %.2lf s (%.2lf %%)\n", t_execution*1e-6, r_execution);

        printf("\tsleep time: %.2lf s (%.2lf %%)\n", t_sleep*1e-6, r_sleep);

        printf("\toverhead time: %.2lf s (%.2lf %%)\n", t_overhead*1e-6, r_overhead);

}

My questions are

1) I see a series of warnings when I run my code:

[starpu][lobachevsky][_starpu_init_topology] Warning: there are several kinds of CPU on this system. For now StarPU assumes all CPU are equal

[starpu][lobachevsky][_starpu_init_topology] Warning: could not get current CPU binding: Function not implemented

[starpu][lobachevsky][initialize_lws_policy] Warning: you are running the default lws scheduler, which is not a very smart scheduler, while the system has GPUs or several memory nodes. Make sure to read the StarPU documentation about adding performance models in order to be able to use the dmda or dmdas scheduler instead.

[starpu][lobachevsky][_starpu_bind_thread_on_cpu] [lobachevsky] Warning: worker 0 was already bound to PU 0

[starpu][lobachevsky][_starpu_bind_thread_on_cpu] and we were told to also bind worker 8 to it.

[starpu][lobachevsky][_starpu_bind_thread_on_cpu] This will strongly degrade performance.

[starpu][lobachevsky][_starpu_bind_thread_on_cpu] [lobachevsky] Maybe check starpu_machine_display's output to determine what wrong binding happened. Hwloc reported a total of 8 cores and 8 threads, and to use 8 threads from logical 0, perhaps there is misdetection between hwloc, the kernel and the BIOS, or an administrative allocation issue from e.g. the job scheduler? You may want to try to use export STARPU_WORKERS_GETBIND=0 to ignore the job scheduler binding

How do I avoid wrong binding? For now, I would like to omit the OpenCL 0 worker from doing any calculation.

Please find below my timing results:

Worker OpenCL 0 (Apple M2 9.6 GiB):

0 task(s)

total time: 6.39 s

execution time: 0.00 s (0.00 %)

sleep time: 0.00 s (0.00 %)

overhead time: 6.39 s (100.00 %)

Worker CPU 0:

119 task(s)

total time: 6.39 s

execution time: 0.00 s (0.00 %)

sleep time: 0.00 s (0.00 %)

overhead time: 6.39 s (100.00 %)

Worker CPU 1:

139 task(s)

total time: 6.39 s

execution time: 0.00 s (0.00 %)

sleep time: 0.00 s (0.00 %)

overhead time: 6.39 s (100.00 %)

Worker CPU 2:

109 task(s)

total time: 6.39 s

execution time: 0.00 s (0.00 %)

sleep time: 0.00 s (0.00 %)

overhead time: 6.39 s (100.00 %)

Worker CPU 3:

124 task(s)

total time: 6.39 s

execution time: 0.00 s (0.00 %)

sleep time: 0.00 s (0.00 %)

overhead time: 6.39 s (100.00 %)

Worker CPU 4:

132 task(s)

total time: 6.39 s

execution time: 0.00 s (0.00 %)

sleep time: 0.00 s (0.00 %)

overhead time: 6.39 s (100.00 %)

Worker CPU 5:

120 task(s)

total time: 6.48 s

execution time: 0.00 s (0.00 %)

sleep time: 0.00 s (0.00 %)

overhead time: 6.48 s (100.00 %)

Worker CPU 6:

120 task(s)

total time: 6.48 s

execution time: 0.00 s (0.00 %)

sleep time: 0.00 s (0.00 %)

overhead time: 6.48 s (100.00 %)

Worker CPU 7:

75 task(s)

total time: 6.48 s

execution time: 0.00 s (0.00 %)

sleep time: 0.00 s (0.00 %)

overhead time: 6.48 s (100.00 %)

2) My execution time and sleep time on all workers are 0.00 s. How do I measure these times correctly?

Please find below an output of ‘starpu_machine_display’:

[starpu][lobachevsky][_starpu_init_topology] Warning: there are several kinds of CPU on this system. For now StarPU assumes all CPU are equal

[starpu][lobachevsky][_starpu_init_topology] Warning: could not get current CPU binding: Function not implemented

[starpu][lobachevsky][initialize_lws_policy] Warning: you are running the default lws scheduler, which is not a very smart scheduler, while the system has GPUs or several memory nodes. Make sure to read the StarPU documentation about adding performance models in order to be able to use the dmda or dmdas scheduler instead.

[starpu][lobachevsky][_starpu_bind_thread_on_cpu] [lobachevsky] Warning: worker 0 was already bound to PU 0

[starpu][lobachevsky][_starpu_bind_thread_on_cpu] and we were told to also bind worker 8 to it.

[starpu][lobachevsky][_starpu_bind_thread_on_cpu] This will strongly degrade performance.

[starpu][lobachevsky][_starpu_bind_thread_on_cpu] [lobachevsky] Maybe check starpu_machine_display's output to determine what wrong binding happened. Hwloc reported a total of 8 cores and 8 threads, and to use 8 threads from logical 0, perhaps there is misdetection between hwloc, the kernel and the BIOS, or an administrative allocation issue from e.g. the job scheduler? You may want to try to use export STARPU_WORKERS_GETBIND=0 to ignore the job scheduler binding

Real hostname: lobachevsky (StarPU hostname: lobachevsky)

Environment variables

STARPU_NCPU=8

StarPU has found :

8 CPU workers:

CPU 0

CPU 1

CPU 2

CPU 3

CPU 4

CPU 5

CPU 6

CPU 7

No CUDA worker

1 OpenCL worker:

OpenCL 0 (Apple M2 9.6 GiB)

No FPGA worker

No MPI_MS worker

No TCPIP_MS worker

No HIP worker

topology ... (hwloc logical indexes)

numa  0 pack  0 core 0 PU 0 OpenCL 0 (Apple M2 9.6 GiB) CPU 7

core 1 PU 1 CPU 0

core 2 PU 2 CPU 1

core 3 PU 3 CPU 2

core 4 PU 4 CPU 3

core 5 PU 5 CPU 4

core 6 PU 6 CPU 5

core 7 PU 7 CPU 6

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

from/to NUMA 0 OpenCL 0

NUMA 0 0 21905

OpenCL 0 22473 0

NUMA 0 0 255

OpenCL 0 160 0

GPU NUMA in preference order (logical index), host-to-device, device-to-host

OpenCL0 0

3) I have two blocks in my ‘main’ program where I initialise StarPU, execute tasks and finalise StarPU. Before I finalise StarPU I print out profiling information onto the screen. However, the second StarPU block returns very high timing values. Please find them below. What do I need to do to have correct time measurements in a second StarPU block?

Worker OpenCL 0 (Apple M2 9.6 GiB):

0 task(s)

total time: 418806.03 s

execution time: 0.00 s (0.00 %)

sleep time: 0.00 s (0.00 %)

overhead time: 418806.03 s (100.00 %)

Worker CPU 0:

121 task(s)

total time: 418806.03 s

execution time: 0.00 s (0.00 %)

sleep time: 0.00 s (0.00 %)

overhead time: 418806.03 s (100.00 %)

Worker CPU 1:

124 task(s)

total time: 418806.03 s

execution time: 0.00 s (0.00 %)

sleep time: 0.00 s (0.00 %)

overhead time: 418806.03 s (100.00 %)

Worker CPU 2:

127 task(s)

total time: 418806.06 s

execution time: 0.00 s (0.00 %)

sleep time: 0.00 s (0.00 %)

overhead time: 418806.06 s (100.00 %)

Worker CPU 3:

137 task(s)

total time: 418806.06 s

execution time: 0.00 s (0.00 %)

sleep time: 0.00 s (0.00 %)

overhead time: 418806.06 s (100.00 %)

Worker CPU 4:

107 task(s)

total time: 418806.06 s

execution time: 0.00 s (0.00 %)

sleep time: 0.00 s (0.00 %)

overhead time: 418806.06 s (100.00 %)

Worker CPU 5:

142 task(s)

total time: 418806.06 s

execution time: 0.00 s (0.00 %)

sleep time: 0.00 s (0.00 %)

overhead time: 418806.06 s (100.00 %)

Worker CPU 6:

104 task(s)

total time: 418806.06 s

execution time: 0.00 s (0.00 %)

sleep time: 0.00 s (0.00 %)

overhead time: 418806.06 s (100.00 %)

Worker CPU 7:

76 task(s)

total time: 418806.06 s

execution time: 0.00 s (0.00 %)

sleep time: 0.00 s (0.00 %)

overhead time: 418806.06 s (100.00 %)

Thank you for your help and have a great day ahead!

—

Best wishes,

Maxim

Attachment: Makefile
Description: Binary data

Attachment: mtrx-blk-xpu.c
Description: Binary data

Maxim Abalenkov \\ maxim.abalenkov@gmail.com
+44 7 486 486 505 \\ www.maxim.abalenkov.uk