Benchmarking nested do loops, MATMUL and Blas DGEMM

Here is a cleaned-up Fortran Discourse post that presents the SYSTEM_CLOCK benchmark and the 1-, 2-, and 4-thread OpenBLAS results clearly.

Title: MATMUL vs cache-friendly loops vs OpenBLAS DGEMM — SYSTEM_CLOCK and thread scaling

Following the earlier discussion about “MATMUL” versus explicit nested loops, I changed the benchmark to use “SYSTEM_CLOCK” rather than “CPU_TIME”, since I wanted to measure elapsed wall-clock time when testing threaded OpenBLAS.

The benchmark compares:

  1. cache-friendly “j-k-i” nested loops,
  2. the Fortran intrinsic “MATMUL”,
  3. OpenBLAS “DGEMM”.

The matrix size is “1000 x 1000”, using “REAL(real64)”, with five timed runs.

I compiled with:

gfortran benchmark2.f90 -O3 -march=native -o benchmark2 -lopenblas

and tested OpenBLAS with 1, 2, and 4 threads:

export OPENBLAS_NUM_THREADS=1
export OMP_NUM_THREADS=1
./benchmark2

export OPENBLAS_NUM_THREADS=2
export OMP_NUM_THREADS=2
./benchmark2

export OPENBLAS_NUM_THREADS=4
export OMP_NUM_THREADS=4
./benchmark2

“SYSTEM_CLOCK” reports:

SYSTEM_CLOCK rate: 1000000000 counts/second

Average wall-clock results

Threads| Nested loops| MATMUL| DGEMM| MATMUL / loops| DGEMM / loops
1| 0.548147 s| 0.167406 s| 0.140996 s| 3.274x| 3.888x
2| 0.548738 s| 0.164382 s| 0.068577 s| 3.338x| 8.002x
4| 0.545909 s| 0.166466 s| 0.146052 s| 3.279x| 3.738x

The corresponding DGEMM/MATMUL ratios were:

1 thread : 1.187x
2 threads: 2.397x
4 threads: 1.140x

An interesting result is that two OpenBLAS threads are by far the fastest configuration on this system.

DGEMM goes from

0.140996 s 1 thread

to

0.068577 s 2 threads

which is a speedup of about 2.06x.

However, increasing the setting to four threads gives:

0.146052 s 4 threads

which is actually slightly slower than the single-thread result.

By contrast, both the explicit loops and “MATMUL” remain almost unchanged:

             1 thread     2 threads     4 threads

loops 0.548147 0.548738 0.545909
MATMUL 0.167406 0.164382 0.166466
DGEMM 0.140996 0.068577 0.146052

This also suggests that changing “OPENBLAS_NUM_THREADS” is affecting the explicitly called OpenBLAS “DGEMM”, but not the compiler-generated implementation of “MATMUL” in this particular build.

The explicit loop is deliberately ordered:

do j = 1, n
do k = 1, n
do i = 1, n
C(i,j) = C(i,j) + A(i,k)*B(k,j)
end do
end do
end do

so that the first Fortran array index varies fastest. This is considerably better than the original “i-j-k” ordering, but “MATMUL” is still about 3.3 times faster.

The unexpected four-thread OpenBLAS result may be particularly interesting. Possible explanations include the number of physical cores actually available to the UserLAnd process, scheduling overhead, CPU frequency/thermal effects, or the characteristics of OpenBLAS on this Android/Linux environment.

Also, “OMP_NUM_THREADS” should not affect the explicit loops here, since the program contains no OpenMP directives and was not compiled with “-fopenmp”. The important variable for this OpenBLAS test is “OPENBLAS_NUM_THREADS”.

Here is the complete program:

program matmul_dgemm_benchmark

use iso_fortran_env, only : real64, int64
implicit none

integer, parameter :: n = 1000
integer, parameter :: nruns = 5

real(real64), allocatable :: A(:,:), B(:,:), C(:,:)

real(real64) :: t_loop(nruns)
real(real64) :: t_matmul(nruns)
real(real64) :: t_dgemm(nruns)
real(real64) :: checksum

integer(int64) :: count1, count2, count_rate
integer :: i, j, k, r

external :: dgemm

allocate(A(n,n), B(n,n), C(n,n))

call random_number(A)
call random_number(B)

call system_clock(count_rate=count_rate)

print *
print *, "Matrix multiplication benchmark"
print *, "Matrix size:", n, "x", n
print *, "Runs:", nruns
print *
print *, "SYSTEM_CLOCK rate:", count_rate, " counts/second"
print *

! Warm up
C = matmul(A,B)

call dgemm('N','N',n,n,n, &
           1.0_real64,A,n,B,n, &
           0.0_real64,C,n)

! ------------------------------------------------------------
! 1. Cache-friendly explicit loops
! ------------------------------------------------------------

print *, "Nested DO loops"

do r = 1, nruns

    C = 0.0_real64

    call system_clock(count1)

    do j = 1, n
        do k = 1, n
            do i = 1, n
                C(i,j) = C(i,j) + A(i,k)*B(k,j)
            end do
        end do
    end do

    call system_clock(count2)

    t_loop(r) = real(count2-count1,real64) / &
                real(count_rate,real64)

    print '(A,I2,A,F10.6,A)', &
          " Run ",r,": ",t_loop(r)," seconds"

end do

checksum = sum(C)
print '(A,ES20.10)', " Checksum = ",checksum
print *

! ------------------------------------------------------------
! 2. Fortran MATMUL
! ------------------------------------------------------------

print *, "Fortran MATMUL"

do r = 1, nruns

    call system_clock(count1)

    C = matmul(A,B)

    call system_clock(count2)

    t_matmul(r) = real(count2-count1,real64) / &
                  real(count_rate,real64)

    print '(A,I2,A,F10.6,A)', &
          " Run ",r,": ",t_matmul(r)," seconds"

end do

checksum = sum(C)
print '(A,ES20.10)', " Checksum = ",checksum
print *

! ------------------------------------------------------------
! 3. BLAS DGEMM
! C = alpha*A*B + beta*C
! ------------------------------------------------------------

print *, "BLAS DGEMM"

do r = 1, nruns

    call system_clock(count1)

    call dgemm('N','N',n,n,n, &
               1.0_real64,A,n,B,n, &
               0.0_real64,C,n)

    call system_clock(count2)

    t_dgemm(r) = real(count2-count1,real64) / &
                 real(count_rate,real64)

    print '(A,I2,A,F10.6,A)', &
          " Run ",r,": ",t_dgemm(r)," seconds"

end do

checksum = sum(C)
print '(A,ES20.10)', " Checksum = ",checksum
print *

! ------------------------------------------------------------
! Summary
! ------------------------------------------------------------

print *, "==============================================="
print *, "Average wall-clock execution times"
print *, "==============================================="

print '(A,F10.6,A)', &
      "Nested loops : ",sum(t_loop)/nruns," seconds"

print '(A,F10.6,A)', &
      "MATMUL       : ",sum(t_matmul)/nruns," seconds"

print '(A,F10.6,A)', &
      "DGEMM        : ",sum(t_dgemm)/nruns," seconds"

print *

print '(A,F10.3,A)', &
      "MATMUL speedup over loops: ", &
      sum(t_loop)/sum(t_matmul)," x"

print '(A,F10.3,A)', &
      "DGEMM speedup over loops : ", &
      sum(t_loop)/sum(t_dgemm)," x"

print '(A,F10.3,A)', &
      "DGEMM / MATMUL ratio      : ", &
      sum(t_matmul)/sum(t_dgemm)," x"

deallocate(A,B,C)

end program matmul_dgemm_benchmark

The main result for me is that the cache-friendly loop ordering reduces the enormous difference seen with the original loop order, while “MATMUL” remains substantially faster. Direct OpenBLAS “DGEMM” is faster still, but its scaling on this particular system peaks at two threads rather than four.

I would be interested to know whether others see a similar difference between 1, 2 and 4 OpenBLAS threads, particularly on ARM systems or under Android/UserLAnd.One useful addition before posting would be the output of nproc and openblas_get_config() (or the OpenBLAS package/version), because the 2-thread DGEMM = 0.0686 s versus 4-thread = 0.1461 s result is the most interesting part and other Fortran Discourse users will probably ask about the available CPU cores and OpenBLAS build.

Here is the output I see with gfortran on an Apple M2 arm64 machine. With openblas, I get:

$ export OMP_NUM_THREADS=1; export OPENBLAS_NUM_THREADS=1
$ gfortran -O3 -L/opt/homebrew/opt/openblas/lib -lopenblas matmul_dgemm_benchmark.f90
 ===============================================
 Average wall-clock execution times
 ===============================================
Nested loops :   0.154034 seconds
MATMUL       :   0.046450 seconds
DGEMM        :   0.038482 seconds

MATMUL speedup over loops:      3.316 x
DGEMM speedup over loops :      4.003 x
DGEMM / MATMUL ratio      :      1.207 x

$ export OMP_NUM_THREADS=2; export OPENBLAS_NUM_THREADS=2
$ gfortran -O3 -L/opt/homebrew/opt/openblas/lib -lopenblas matmul_dgemm_benchmark.f90
 ===============================================
 Average wall-clock execution times
 ===============================================
Nested loops :   0.153945 seconds
MATMUL       :   0.046511 seconds
DGEMM        :   0.020270 seconds

MATMUL speedup over loops:      3.310 x
DGEMM speedup over loops :      7.595 x
DGEMM / MATMUL ratio      :      2.295 x

$ export OMP_NUM_THREADS=4; export OPENBLAS_NUM_THREADS=4
$ gfortran -O3 -L/opt/homebrew/opt/openblas/lib -lopenblas matmul_dgemm_benchmark.f90
 ===============================================
 Average wall-clock execution times
 ===============================================
Nested loops :   0.154502 seconds
MATMUL       :   0.046563 seconds
DGEMM        :   0.010680 seconds

MATMUL speedup over loops:      3.318 x
DGEMM speedup over loops :     14.466 x
DGEMM / MATMUL ratio      :      4.360 x

$ export OMP_NUM_THREADS=8; export OPENBLAS_NUM_THREADS=8
$ gfortran -O3 -L/opt/homebrew/opt/openblas/lib -lopenblas matmul_dgemm_benchmark.f90
 ===============================================
 Average wall-clock execution times
 ===============================================
Nested loops :   0.154361 seconds
MATMUL       :   0.046677 seconds
DGEMM        :   0.005937 seconds

MATMUL speedup over loops:      3.307 x
DGEMM speedup over loops :     26.001 x
DGEMM / MATMUL ratio      :      7.862 x

Larger values for the OMP_NUM_THREADS environment variable result in slower execution times. I don’t think OPENBLAS_NUM_THREADS actually has any effect.

With -framework accelerate I get:

 ===============================================
 Average wall-clock execution times
 ===============================================
Nested loops :   0.155139 seconds
MATMUL       :   0.046878 seconds
DGEMM        :   0.003025 seconds

MATMUL speedup over loops:      3.309 x
DGEMM speedup over loops :     51.286 x
DGEMM / MATMUL ratio      :     15.497 x

With -fexternal-blas -framework accelerate, I get

 ===============================================
 Average wall-clock execution times
 ===============================================
Nested loops :   0.120084 seconds
MATMUL       :   0.002834 seconds
DGEMM        :   0.002766 seconds

MATMUL speedup over loops:     42.367 x
DGEMM speedup over loops :     43.417 x
DGEMM / MATMUL ratio      :      1.025 x

It looks like openblas has made some significant improvements in the last year. The last time I compared to the Apple accelerate library openblas was some 6x slower. Now, it is only about 2x slower.

One puzzle is why the nested loop timings change in that last run; I assume it is some compiler optimization that is triggered by the -fexternal blas compiler option. Also in this case, the matmul() time is always slightly longer than the direct dgemm() time, but usually by <3%. However, I think this depends on exactly how matmul() appears in the code (e.g. a simple assignment, as in this code, or in a more complicated expression that requires stack allocation) and also whether the leading indexes of the matrix arguments are contiguous (a requirement for dgemm()).

Ron’s M2 numbers are the interesting part, because they make this reproducible across two different machines rather than one setup.

Converting Ian’s original timings (2N³ = 2 GFLOP at N=1000):

loops              3.65 GFLOP/s
MATMUL            11.98 GFLOP/s
DGEMM  1 thread   14.18 GFLOP/s
DGEMM  2 threads  28.99 GFLOP/s
DGEMM  4 threads  13.70 GFLOP/s

Two threads scale at 2.04×, essentially perfect. Four threads land below the single-threaded time. Ron sees the same direction on an M2.

What both machines have in common is heterogeneous cores — performance and efficiency cores on Apple Silicon, big.LITTLE on Ian’s ARM setup. DGEMM splits the work into roughly equal blocks and all threads meet at a barrier, so the slowest core sets the pace for the whole operation. Two fast cores scale cleanly; add efficiency cores at a fraction of the throughput and every block now waits on them, which can put you back below serial. OpenBLAS threads also spin rather than sleep while waiting, so the cost is worse than idle.

Ron, I think your -framework accelerate result may be the most telling thing in the thread: Accelerate is built for Apple’s specific core layout, whereas OpenBLAS partitions work as though every core were equal. A topology-aware library not degrading, while a topology-blind one does, is roughly the experiment you’d design to test this.

The check that would settle it — pin to performance cores only and re-run the higher thread counts. On Linux/Android, taskset -c 0-3. On macOS there’s no direct equivalent, but comparing OPENBLAS_NUM_THREADS set to the performance-core count against the total core count would show the same thing. If scaling returns once the efficiency cores are excluded, that’s the answer.

One aside on MATMUL: it’s flat across thread counts in both sets of results, which is expected — gfortran’s MATMUL is single-threaded and doesn’t call into BLAS unless built with -fexternal-blas. That also explains why Ron’s numbers moved when he added that flag.

I don’t have an M2 or an ARM/Android setup to test on, so this is a hypothesis rather than something I’ve confirmed. If either of you can run the pinned comparison I’d be very interested in the result.

That M2 machine has 8 performance cores and 4 efficiency cores. The timings previously reported showed improvements up to OMP_NUM_THREADS=8 and then slower times after that. So your hypothesis that it is the efficiency cores that slow things down is consistent.

The M1 and M2 also have a matrix coprocessor (a special matrix acceleration unit): GitHub - corsix/amx: Apple AMX Instruction Set · GitHub. In newer chips (M4 and later?) they upgraded this to the Arm SME extension.

In the past I did some benchmarking of the BLAS Level 3 dtrsm routine; in the plot below label dtrsm is for Apple Accelerate and the rest are variants written by GitHub Copilot, some with explicit vectorization using NEON intrinsics:

Accelerate is the fastest. Notice the the big jumps when the matrix size is a multiple of 8? I believe that’s the AMX extension.


Edit (Aug 28, 2026): there was also an interesting post about this on the Julia Discourse - Apple M4 Max AMX Linear Algebra performance versus CPU and GPU - Performance - Julia Programming Language, where the author PetarM wrote,

According to my findings, the 2 AMX cores achieve almost 3 times the peak performance of the 12 P-cores in FP32 and close to same performance as the Ryzen 9950X in dense matrix-matrix multiplication. At the same time they are 10 times more power efficient than the P-cores and about 6 times more power efficient than the Zen 5 cores.

1 Like

Is the calculation correct?

With -framework Accelerate Ron gave the timings,

 ===============================================
 Average wall-clock execution times
 ===============================================
Nested loops :   0.155139 seconds
MATMUL       :   0.046878 seconds
DGEMM        :   0.003025 seconds

When I take 2 × 1000³ / 0.003025 / 10⁹ ≈ 723 Gflop/s.

If you look at page 15 in Dongarra’s 2025 ATPESC talk,

the laptop line is at ~400 Gflop/s; presumably it’s the HPL value (LU factor and solve, which is expected to be a bit slower than DGEMM).

I wonder what the N=1 and N=500 mean in that graph?

I think that is the top-ranked machine and the 500th-ranked machine, respectively.

3 Likes

I agree with @themos. It also looks like Jack wanted to show the change in slope around ~2010, the gains in compute are slowing down. Of course there is a lot of interesting computing that doesn’t need Pflops.

Ah yes, that is obvious now in hindsight. I was trying to get my mind around matrix dimensions or something like that.

It looks like there are two dotted lines, one with the initial slope of the N=1 curve and one with the initial slope of the N=500 curve. Those two straight lines crossed about 2010. I wonder what kind of point he was making in his talk about those two lines?

Earlier in this talk, he mentioned the number of top 500 machines that were based on the intel i860 chip. I also mentioned this cpu a while back here in one of our discussions. That chip had tremendous potential. There were some problems with it, such as cache coherency in a shared memory environment, that needed to be addressed in future versions, but if it had been supported by intel it would have moved HPC technology forward by 10 to 15 years. It was a tremendous opportunity for intel and for the whole industry, squandered.

I saw that chip come up in a LinkedIn post by Laurie Kirk: This might be the most difficult CPU to program. The Intel i860 was useless for general operating systems. Context switches took ~2,000 cycles. *You* controlled the floating point pipeline. But, if… | Laurie Kirk | 73 comments.

Many people chimed in to the comment section.

(Laurie is known for her Youtube channel @lauriewired)

Laurie's i860 LinkedIn Post

This might be the most difficult CPU to program.

The Intel i860 was useless for general operating systems. Context switches took ~2,000 cycles.

You controlled the floating point pipeline. But, if you’re a genius, it was one of the most powerful chips that existed.

I can’t understate how crazy this was.

With modern chips, even raw assembly, you’re only requesting “vertical” microcode.

That is, the hardware handles decoding, scheduling and timing.

The i860 was horizontal (VLIW)…which is frankly insane to market to consumers.

If an ADD takes 3 cycles, you better push two more dummy instructions!

You basically had to write code where the input variable and the output variable on THE SAME LINE had nothing to do with each other.

Imagine: “pfadd R1, R2, R3”

R3 is the result from 3 cycles earlier!

The i860 never took off, but had some odd knock-on effects in the world of computing:

  • Windows NT was originally designed for the i860

  • Steve Job’s NeXT workstation “GPU” was actually just an i860 /w a Mach Kernel

  • Silicon Graphics used bundles of i860s to viewport things like Jurassic Park (RealityEngine)

  • If you’re in the supercomputing world, you likely use MPI. The difficulty of i860 synchronization indirectly led to the grandfather of MPI (Touchstone Delta)

1 Like

That is an interesting discussion. I would not call the i860 a VLIW machine because the instructions were only 32-bit words. I had used an FPS-164 machine some 10 years earlier that worked the same kind of way; the result of an instruction was two or three clock cycles after it was initiated, and it was the programmer (or the compiler) that had to get that timing right. I would call the FPS-164 a VLIW machine because its instructions were 64-bit words. I’m not sure about the i860, but on the FPS-164 you could write a one-instruction dot product loop. The two memory fetches, the multiply, the add, the test of the decrement counter, and the branch back to the same instruction could all fit into a single 64-bit word. The memory fetches took two and three cycles to complete, the multiply took three cycles to complete, and the add took two cycles, so it was complicated the first time you saw how it worked, but in the end you could get a new result every clock cycle. They did know how to do it in the early 1980s, so the i860 a decade later should not have had a problem with that kind of scheduling. I think it was just a lack of commitment by intel, which had a steady revenue stream from its x86 to protect, so it was a business decision, not a technical decision, that killed the project. As I said previously, the i860 did have some technical problems so it would have needed to evolve to address those. Those included things like 64-bit memory addressing and cache coherency in shared-memory situations. But intel’s x86 had those same limitations in the late 1980s, and they were eventually addressed and solved, so I would think intel could have done the same with the superior i860 architecture over time.

Thanks Ron. 8 performance + 4 efficiency is exactly the shape that would produce this, and the turn happening right at 8 threads is about as clean a confirmation as you could ask for.

Dear Ivan,

on the calculation, it’s just 2N³/t, so for Ian’s numbers 2×10⁹/0.548 = 3.65 GFLOP/s and so on. But I don’t reproduce your 723 from Ron’s Accelerate timing: I get 2×10⁹/0.003025 ≈ 661 GFLOP/s. 723 would need about 2.77 ms. Have I slipped somewhere?

Either way the number is high enough to be worth a second look. At ~3 ms the run is short enough that clock resolution and call overhead start to matter, so I’d want it inside a repeat loop with the minimum taken over several hundred calls before trusting it. If the timing is measuring less work than intended, that would inflate the figure regardless of which of us has the arithmetic right.

The AMX point is new to me and it’s the interesting part — thank you. If Accelerate is dispatching to the matrix coprocessor while OpenBLAS isn’t, that would explain both the raw throughput and why Accelerate doesn’t degrade with thread count, since it wouldn’t be relying on the same equal-partition threading at all. Your dtrsm plot with the jumps at multiples of 8 is fairly convincing evidence for that.

1 Like

Refer back to the original post and you will see that the timings are averaged over 5 runs. I only posted those average timings, I did not post the full output which contained also the individual run times. In most cases, the first run took a little longer than the subsequent runs, so the minimum value was shorter in all cases than the first timing. The exception to this is the -fexternal-blas -framework accelerate results; in this case the matmul() call actually translates to a dgemm() call, so the subsequent direct dgemm() calls did not need an initial warmup call to get to the optimal performance values, all 5 timings were about the same, about 0.002766 seconds. If you take that single value, it results in an average of 723 GFLOP/s, which was the number reported by @ivanpribec. I think he just copied and pasted the penultimate timing results rather then the ultimate timings. Here is a rerun with the full output:

$ gfortran -O3 -framework accelerate -fexternal-blas matmul_dgemm_benchmark.f90 && a.out

 Matrix multiplication benchmark
 Matrix size:        1000 x        1000
 Runs:           5

 SYSTEM_CLOCK rate:           1000000000  counts/second

 Nested DO loops
 Run  1:   0.118826 seconds
 Run  2:   0.117303 seconds
 Run  3:   0.116625 seconds
 Run  4:   0.116631 seconds
 Run  5:   0.116403 seconds
 Checksum =     2.5024690423E+08

 Fortran MATMUL
 Run  1:   0.002945 seconds
 Run  2:   0.002766 seconds
 Run  3:   0.002760 seconds
 Run  4:   0.002751 seconds
 Run  5:   0.002735 seconds
 Checksum =     2.5024690423E+08

 BLAS DGEMM
 Run  1:   0.002793 seconds
 Run  2:   0.002747 seconds
 Run  3:   0.002745 seconds
 Run  4:   0.002737 seconds
 Run  5:   0.002742 seconds
 Checksum =     2.5024690423E+08

 ===============================================
 Average wall-clock execution times
 ===============================================
Nested loops :   0.117158 seconds
MATMUL       :   0.002791 seconds
DGEMM        :   0.002753 seconds

MATMUL speedup over loops:     41.971 x
DGEMM speedup over loops :     42.559 x
DGEMM / MATMUL ratio      :      1.014 x

Notice that the first matmul/dgemm time is a little longer, 0.002945, then all of the subsequent matmul and later the direct dgemm times are all shorter, 0.0027xx. If I rerun this several times, that feature remains consistent, even with the timing noise of about 10 microsecond. I’m just guessing, but I expect this is an instruction cache feature. The first dgemm run loads the instructions, and the subsequent runs can then reuse that same memory before it evaporates. Each core of an Apple M2 has a 192 kB L1 instruction cache.

Thanks Ron, that resolves it — Ivan used 0.002766 and I used the 0.003025 that was in the thread, so both conversions were right off different data. Your rerun gives 726 GFLOP/s for DGEMM and 717 for MATMUL, and the 1.014 ratio is a nice confirmation that -fexternal-blas really is routing MATMUL straight into dgemm.

On the slower first call — I’m not sure instruction cache accounts for it. The gap is about 200 µs, which at ~3 GHz is on the order of 600,000 cycles, whereas filling a 192 kB L1 instruction cache should cost far less than that. It looks more like one-time initialisation inside Accelerate itself — thread pool setup, blocking parameter selection, or bringing up the matrix unit — which would then be amortised across the later calls. Would be interesting to see whether the penalty reappears if you sleep for a second between runs.

2 Likes

I added call sleep(1) just inside the final dgemm() loop, and here is the full output:

$ gfortran -O3 -framework accelerate -fexternal-blas matmul_dgemm_benchmark.f90 && a.out

 Matrix multiplication benchmark
 Matrix size:        1000 x        1000
 Runs:           5

 SYSTEM_CLOCK rate:           1000000000  counts/second

 Nested DO loops
 Run  1:   0.119768 seconds
 Run  2:   0.115626 seconds
 Run  3:   0.115515 seconds
 Run  4:   0.115494 seconds
 Run  5:   0.115565 seconds
 Checksum =     2.5007003109E+08

 Fortran MATMUL
 Run  1:   0.002942 seconds
 Run  2:   0.002916 seconds
 Run  3:   0.002800 seconds
 Run  4:   0.002745 seconds
 Run  5:   0.002732 seconds
 Checksum =     2.5007003109E+08

 BLAS DGEMM
 Run  1:   0.031651 seconds
 Run  2:   0.013865 seconds
 Run  3:   0.021354 seconds
 Run  4:   0.022002 seconds
 Run  5:   0.021812 seconds
 Checksum =     2.5007003109E+08

 ===============================================
 Average wall-clock execution times
 ===============================================
Nested loops :   0.116394 seconds
MATMUL       :   0.002827 seconds
DGEMM        :   0.022137 seconds

MATMUL speedup over loops:     41.172 x
DGEMM speedup over loops :      5.258 x
DGEMM / MATMUL ratio      :      0.128 x

While the do loop timings and the matmul() timings are largely unchanged, you are correct that this does make a large change in the dgemm() timings. It is unclear to me exactly why. It could be the instruction cache being overwritten, and/or the data cache being overwritten, or maybe the whole process is being swapped in and out and some of that effort is being charged to the user cpu time, and so on. Your idea of one-time initialization within the dgemm() call itself I think could also play a role, but if so, then that is being overwhelmed by whatever is happening during that 1-second sleep period (which is an eternity to a nanosecond system clock). Upon repeated runs, those dgemm() timings vary significantly, ranging in general from 0.011s to 0.027s, well over a factor of two. Without that sleep(1), the timings are much more consistent, within ±1% or so.

The Apple M-series has all kinds of clever optimizations. A few things are explained on this blog: M-series Macs – The Eclectic Light Company

Apple has published an optimization guide here: Apple Silicon CPU Optimization Guide Version 4 | Apple Developer Documentation. Downloading the PDF guide requires registering an account with Apple.

2 Likes

That’s a much bigger effect than I expected — thank you for running it.

Converting: DGEMM goes from 726 GFLOP/s to 90 GFLOP/s, an 8× penalty.

The detail I find most telling is that MATMUL didn’t move: 0.002791 → 0.002827, essentially unchanged. Since -fexternal-blas means MATMUL is Accelerate’s dgemm too, that’s the same routine on the same data — the only difference is that the sleep sits in the DGEMM loop. So whatever this is, it isn’t the routine, and it isn’t the data layout.

I’d also gently push back on cache eviction as the main cause. Three 1000×1000 float64 matrices is about 24 MB, against 16 MB of L2 — the working set already exceeds cache on every run, with or without the sleep. And a cache effect should be fairly reproducible, whereas you’re seeing 0.011–0.027 s, a factor of 2.5, against ±1% without the sleep. That variance looks more like a scheduling decision being made differently each time than like a deterministic cache miss.

My guess is that after a full second of idling the thread gets rescheduled — plausibly onto an efficiency core, and/or resuming at a low DVFS frequency before ramping back up. That would fit both the size of the penalty and the run-to-run scatter, and it would tie back to the P-core/E-core split we started with.

There’s a clean way to separate the two: replace call sleep(1) with a one-second busy-wait loop. A busy-wait disturbs the caches at least as much as sleeping does, but keeps the thread running hot on a performance core. If the penalty vanishes, it’s idle-related — scheduling or frequency — and not cache. If it survives, cache is genuinely implicated.

If you have powermetrics handy, sudo powermetrics --samplers cpu_power -i 500 alongside the run would show directly whether the work moves to the E-cluster after the sleep.


Thanks Ivan — the optimisation guide looks like it should cover the scheduler’s core-placement behaviour directly, which is exactly the thing in question here. I’ll have a read.