Slowdown when using openblas-pthreads alongside openmp based parallel code

[jeremiedbb]

Hi,

I have a code which mixes BLAS calls (gemm) and OpenMP based parallel loops (they are not nested). When OpenBLAS is built using OpenMP everything is fine but when OpenBLAS is built with pthreads there's a huge slowdown. Below is a reproducible example (sorry it's from python/cython)

%load_ext cython

%%cython -f --compile-args=-fopenmp --link-args=-fopenmp
# cython: profile=True, cdivision=True, boundscheck=False, wraparound=False

import time
import numpy as np
from cython.parallel import prange
 
def f2(double[:, ::1] A):
     cdef:
         double v = 0
         int m = A.shape[0]
         int n = A.shape[1]
         int i, j
 
    with nogil:
        for i in prange(m):      # OpenMP parallel for loop (*)
            for j in range(n):
                v += A[i, j]
 
    return v
    
    
def f1(U, V):
    v = 0
    for n_iter in range(100):
        UV = U @ V.T             # BLAS call (gemm)
        v += f2(UV)              # function runs an OpenMP parallel for loop
    return v
    

U = np.random.randn(10000, 100)
V = np.random.randn(10, 100)
 
t = time.time()
v = f1(U, V)
print(time.time() - t)

On my laptop (2 physical cores), when I use a sequential loop in (*), it runs in 0.26s. When I use a parallel loop it runs in 2.6s (10x slower). This is with OpenBLAS 0.3.12 built with pthreads. This conda env allows to reproduce conda create -n tmp -c conda-forge python numpy cython ipython.

However, if I use OpenBLAS built with OpenMP, it runs in 0.26s with and without prange. This is with OpenBLAS 0.3.9 built with OpenMP. This conda env allows to reproduce conda create -n tmp -c conda-forge python numpy cython ipython blas[build=openblas] libopenblas=0.3.9.

[martin-frbg]

most likely you get too many threads running in parallel in the non-openmp case

[jeremiedbb]

omp_get_max_threads() returns 4 (I have 2 physical cores + hyperthreading). Do you think OpenBLAS is using too many threads ?
It only occurs when I use an OpenMP loop, so it means there's an interaction between OpenBLAS built with pthreads and OpenMP.

[jeremiedbb]

For what it's wotrh the number of running threads showed by htop only increases by 4 when I run this

[jeremiedbb]

a profiling with linux perf shows that most of the time comes from do_wait from libgomp

[ogrisel]

Would be worth checking this:

2020-07-17
Conda-forge is building openblas with both pthreads and openmp on Linux
The main change is that openblas will use pthreads for threading by default on Linux instead of the previous openmp default. The openmp builds can be recovered by installing libopenblas=*=*openmp*.

from https://conda-forge.org/docs/user/announcements.html

[isuruf]

Is it really libgomp? Note that we are using libomp (from LLVM) with openblas openmp build because libgomp is not fork safe. If you are loading libgomp.so.3 from conda-forge, it's a symlink to libomp, but if you are loading libgomp.so.3 from the system it'll be the real libgomp and therefore you'll have two instances of openmp loaded which is not advisable.

[jeremiedbb]

My main concern is that the issue happens with OpenBLAS built with pthreads (not when built with OpenMP) !

When I execute my snippet above, libopenblas is loaded because numpy is imported and libgomp is loaded because of the prange loop. It can be confirmed with

from threadpoolctl import threadpool_info
threadpool_info()
[{'filepath': '/home/jeremie/miniconda/envs/tmp/lib/libopenblasp-r0.3.12.so',
  'prefix': 'libopenblas',
  'user_api': 'blas',
  'internal_api': 'openblas',
  'version': '0.3.12',
  'num_threads': 4,
  'threading_layer': 'pthreads'},
 {'filepath': '/home/jeremie/miniconda/envs/tmp/lib/libgomp.so.1.0.0',
  'prefix': 'libgomp',
  'user_api': 'openmp',
  'internal_api': 'openmp',
  'version': None,
  'num_threads': 4}]

If I replace prange by range, libgomp disappears from the list and if I don't import numpy libopenblas disappears.

It also confirms that I have only 1 OpenMP runtime loaded (threadpoolctl takes symlinks into account).
Also, for this specific environment (conda create -n tmp -c conda-forge python numpy cython ipython) it's libgomp and not libomp which is installed by conda-forge

libgomp            conda-forge/linux-64::libgomp-9.3.0-h2828fa1_19

[isuruf]

Thanks for the info. That's to be expected though. When running openmp, you create a few threads and then each thread calls blas which in turn creates more threads. In a multi-threaded environment, it's safest to just do openblas_set_num_threads(1) before calling blas.

[jeremiedbb]

It's not an oversubscription issue here. They are not nested. I first call gemm and then call a function which executes a parallel loop (with no blas inside).

[jeremiedbb]

Also I ran ps -o nlwp <pid> on the process running my python script and it returns 8 which is what I'd expect: 4 from openblas and 4 from openmp

[isuruf]

I see the same issue. 30x slowdown with libgomp and 2x slowdown with libomp.

[isuruf]

OMP_PROC_BIND=TRUE reduces the slowdown in libgomp.

[brada4]

OpenBLAS assumes each thread has CPU at its hands with all outermost caches. 30x slowdoen means multiple threads are stuck on same CPU and actually get to spill to the main memory instead of cache.
You can set OPENBLAS_NUM_THREADS=1 running samples right now, before building OMP version to address oversubscription issue. pthread version has no idea of OpenMP spinnnging full room of threads, and spins up own in each thread.
EDIT: hyperthreads do not add any value to HPC.You can disable them to get single-threaded stuff end faster, parallel will have half double-speed cores essentially, i.e same timing as with HT

[jeremiedbb]

Sorry I'm not sure to understand your answer. I agree that HT is useless in HPC most of the time but it does not seem to be the only issue here since the program is fast when OpenBLAS is built with pthreads and I run the loop in sequential mode. The issue only appears when I also run the loop in parallel with OpenMP. I recall that they are not nested but run one after the other.

I post a pure C reproducible code here, hope it will make my concerns clearer.

#include <stdlib.h>
#include <stdio.h>
#include <omp.h>
#include "cblas.h"


double f2(double *X, int n){
    double v = 0.0;

    #pragma omp parallel for reduction(+:v)
    for(int i=0; i<n; i++){
        v += X[i];
    }

    return v;
}


int main(int argc, char **argv){
    int m = 10000,
        n = 10,
        k = 100;

    double *A = (double*) malloc(m * k * sizeof(double)),
           *B = (double*) malloc(n * k * sizeof(double)),
           *C = (double*) malloc(m * n * sizeof(double));

    for(int i=0; i<m*k; i++){
        A[i] = 0.1;
    }
    for(int i=0; i<n*k; i++){
        B[i] = 1.2;
    }

    double v = 0.0;

    for(int i=0; i<1000; i++){
        // BLAS call
        cblas_dgemm(CblasRowMajor, CblasNoTrans, CblasTrans, m, n, k, 1.0, A, k, B, k, 0.0, C, n);    // C <- A @ B.T
        // Followed by parallel loop
        v += f2(C, m * n);
    }

    free(A), free(B), free(C);

    return 0;
}

Here a the timings on a 40 cores machine (20 physical + HT).

	openblas pthreads	openblas openmp
sequential loop	1.22s	0.62s
parallel loop	21s	0.51s

Focusing on the pthreads + parallel loop case:

• If I set OPENBLAS_NUM_THREADS=20 and OMP_NUM_THREADS=20 the result becomes 0.34s which confirms that HT is detrimental but I don't understand what is the difference with the openblas openmp + sequential loop case.
• If I set OPENBLAS_NUM_THREADS=21 and OMP_NUM_THREADS=21, the result is 0.5s, i.e. 50% slower than above, which I would not expect since it's only 1 more thread.
• If I set OPENBLAS_NUM_THREADS=22 and OMP_NUM_THREADS=22, the result is 5s ! I don't think the only issue here is basic oversubscription.