When compiled with MKL, fully_connected calls DNNL while dot and batch_dot call MKL

[kpuatamazon]

Problem

Not sure how much we care about MKL support but to the extent it still appears in the buld system, operator support should be consistent.

When compiled with MKL present (MKL is found in /opt/intel), MXNet calls MKL for dot and batch_dot and DNNL for fully_connected. These are all GEMM operators; why is it inconsistent? This is making Sockeye decoding 22% slower (see below).

This inconsistency did not matter much in MXNet 1.5.0 because MKLDNN would delegate to MKL. However, aa1074d upgraded to MKLDNN 1.0, which hid the ability of MKLDNN to delegate to MKL: uxlfoundation/oneDNN@3049150 . (MKLDNN has since been renamed DNNL.)

Since MKLDNN only hid support for delegating to MKL, it's possible to restore delegatation (see workaround).

Testing

Tested with MXNet cfb474b. Compiled with mostly-default cmake settings:

cmake -GNinja -DUSE_CUDA=OFF -DCMAKE_BUILD_TYPE=Release ..

Then when I run

export MKL_VERBOSE=1
export MKLDNN_VERBOSE=1
python3
Python 3.6.9 (default, Nov  7 2019, 10:44:02) 
[GCC 8.3.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import mxnet as mx
Numpy + Intel(R) MKL: THREADING LAYER: (null)
Numpy + Intel(R) MKL: setting Intel(R) MKL to use INTEL OpenMP runtime
Numpy + Intel(R) MKL: preloading libiomp5.so runtime
MKL_VERBOSE Intel(R) MKL 2019.0 Product build 20180829 for Intel(R) 64 architecture Intel(R) Advanced Vector Extensions 512 (Intel(R) AVX-512) enabled processors, Lnx 3.00GHz lp64 intel_thread
MKL_VERBOSE SDOT(2,0x1a0fdc0,1,0x1a0fdc0,1) 1.47ms CNR:OFF Dyn:1 FastMM:1 TID:0  NThr:24
>>> a = mx.nd.ones(shape=(2,2))
>>> mx.nd.FullyConnected(a,a,num_hidden=2,no_bias=True)
dnnl_verbose,info,DNNL v1.1.2 (commit cb2cc7ac17ff4e2ef50805c7048d33256d82be4d)
dnnl_verbose,info,Detected ISA is Intel AVX-512 with Intel DL Boost
dnnl_verbose,exec,cpu,inner_product,gemm:jit,forward_inference,src_f32::blocked:ab:f0 wei_f32::blocked:ab:f0 bia_undef::undef::f0 dst_f32::blocked:ab:f0,,,mb2ic2oc2,74.9971

[[2. 2.]
 [2. 2.]]
<NDArray 2x2 @cpu(0)>
>>> a = mx.nd.ones(shape=(2,2,2))
>>> mx.nd.batch_dot(a,a)
MKL_VERBOSE SGEMM_BATCH(N,N,0x7fc3238b809c,0x7fc3238b80a0,0x7fc3238b80a4,0x7fc3238b80b4,0x7fc228010b90,0x7fc3238b80a8,0x7fc22800f770,0x7fc3238b80ac,0x7fc3238b80b8,0x7fc2280190e0,0x7fc3238b80b0,0x7fc3238b7fc8,0x7 363.79us CNR:OFF Dyn:1 FastMM:1 TID:0  NThr:24

[[[2. 2.]
  [2. 2.]]

 [[2. 2.]
  [2. 2.]]]
>>> mx.nd.dot(a,a)
MKL_VERBOSE SGEMM(N,N,4,4,2,0x7fc3238b8198,0x7fc2280043c0,4,0x7fc2280043c0,2,0x7fc3238b81a0,0x7fc228004580,4) 8.52us CNR:OFF Dyn:1 FastMM:1 TID:0  NThr:24

[[[[2. 2.]
   [2. 2.]]

  [[2. 2.]
   [2. 2.]]]


 [[[2. 2.]
   [2. 2.]]

  [[2. 2.]
   [2. 2.]]]]
<NDArray 2x2x2x2 @cpu(0)>

You can see DNNL is called for FullyConnected while MKL is called for dot and batch_dot.

Performance impact

I timed Sockeye decoding. Commit aa1074d made decoding 22% slower (416.878s up from 342.037s for b5d07e3) even with MKL installed in /opt/intel/.

Commit	Compilation	Time(s)
b5d07e3 (before MKLDNN 1.0 change)	Default	342.037
aa1074d (MKLDNN 1.0 change)	Default	416.878
aa1074d (MKLDNN 1.0 change)	Workaround	343.706
cfb474b Recent	Default	385.587
cfb474b Recent	Workaround	312.509

(Default compilation is cmake -GNinja -DUSE_CUDA=OFF -DCMAKE_BUILD_TYPE=Release ..; workaround compilation is below.)

Tested on a Skylake Xeon, c5.9xlarge Intel(R) Xeon(R) Platinum 8124M CPU @ 3.00GHz with OMP_NUM_THREADS=4.

Workaround

Since DNNL hid support for delegating to MKL, it's still possible to turn delegation back on.

cmake -GNinja -DUSE_CUDA=OFF -DCMAKE_BUILD_TYPE=Release -D_DNNL_USE_MKL=FULL -DMKLINC=/opt/intel/mkl/include ..

which compiles but then triggers a link error at runtime OSError: /home/ubuntu/mxnet/build/3rdparty/mkldnn/src/libmkldnn.so.1: undefined symbol: cblas_gemm_s8u8s32_pack
So I kludged it with export LD_PRELOAD=/opt/intel/mkl/lib/intel64/libmkl_rt.so and was then able to use MXNet at runtime. There's probably a cleaner way of fixing the linkage.

Recommended fix

When compiled with MKL, MXNet should call MKL directly from FullyConnected like it already does for dot and batch_dot.

[TaoLv]

Thanks for raising the issue, @kpuatamazon. We plan to optimize the dot and batch_dot operator with DNNL MatMul primitive. But please note that, the performance of MatMul primitive was not optimized until v1.3 which was released last week. That's why we didn't integrate the primitive at the first time when it's introduced in v1.2.

When compiled with MKL, MXNet should call MKL directly from FullyConnected like it already does for dot and batch_dot.

As mentioned above, dot and batch_dot will also be optimized with DNNL. And as DNNL is more dedicated on deep learning, we will consider DNNL with high priority when both DNNL and MKL are enabled in compilation.

Please provide a simple reproducer if you find FullyConnected based on DNNL is slower than it based on MKL BLAS.

[kpuatamazon]

Here's some benchmarks on 2fff11d (current tip of master) with the same Skylake c5.9xlarge. DNNL is substantially slower than MKL.

(Which DNNL is in master?)

#!/usr/bin/env python3
import mxnet as mx
import time

def time_procedure(shape, count, proc):
  rows, inner, cols = shape
  a = mx.nd.random_uniform(shape=(rows, inner), low=-1.0, high=1.0)
  b = mx.nd.random_uniform(shape=(cols, inner), low=-1.0, high=1.0)
  # Burn in
  proc(a, b, cols)
  mx.nd.waitall()
  begin = time.time()
  for i in range(0, count):
    proc(a, b, cols)
    mx.nd.waitall()
  return (time.time() - begin) / count

shapes = [(5, 512, 512), (5,512,1536), (5,512,2048), (5,2048,512), (4,512,512)]
count = 1000

procedures = {
  "fullyconnected (DNNL)" : (lambda a, b, cols : mx.nd.FullyConnected(a, b, no_bias=True, num_hidden=cols)),
  "dot (MKL)" : (lambda a, b, cols : mx.nd.dot(a, b, transpose_b = True))
}
for s in shapes:
  print("Shape " + str(s))
  stats = {}
  for name, l in procedures.items():
    stats[name] = time_procedure(s, count, l)
    print("{:.7f} seconds for {}".format(stats[name], name))

Run as OMP_NUM_THREADS=4 ./mult_bench.py:

Shape (5, 512, 512)
0.0000961 seconds for fullyconnected (DNNL)
0.0000509 seconds for dot (MKL)
Shape (5, 512, 1536)
0.0002011 seconds for fullyconnected (DNNL)
0.0000735 seconds for dot (MKL)
Shape (5, 512, 2048)
0.0002521 seconds for fullyconnected (DNNL)
0.0001027 seconds for dot (MKL)
Shape (5, 2048, 512)
0.0003569 seconds for fullyconnected (DNNL)
0.0001018 seconds for dot (MKL)
Shape (4, 512, 512)
0.0000946 seconds for fullyconnected (DNNL)
0.0000496 seconds for dot (MKL)

I don't really mind what the default BLAS implementation is. But choosing to use MKL should be 1) atomic and 2) not require undocumented compilation options.

[kpuatamazon]

I also tried the latest DNNL:

cd 3rdparty
rm -rf mkldnn
git clone https://github.com/oneapi-src/oneDNN mkldnn
cd ../build && ninja -j 32

and DNNL is still slower:

Shape (5, 512, 512)
0.0000875 seconds for fullyconnected (DNNL)
0.0000507 seconds for dot (MKL)
Shape (5, 512, 1536)
0.0002005 seconds for fullyconnected (DNNL)
0.0000729 seconds for dot (MKL)
Shape (5, 512, 2048)
0.0002516 seconds for fullyconnected (DNNL)
0.0000974 seconds for dot (MKL)
Shape (5, 2048, 512)
0.0003564 seconds for fullyconnected (DNNL)
0.0000981 seconds for dot (MKL)
Shape (4, 512, 512)
0.0000928 seconds for fullyconnected (DNNL)
0.0000497 seconds for dot (MKL)

[TaoLv]

Thank you @kpuatamazon. I will try to reproduce the performance issue and get back to you later.

(Which DNNL is in master?)

It should be v1.2.2 but was down graded to v1.1.2 by #17084 (maybe by accident).

But choosing to use MKL should be 1) atomic and 2) not require undocumented compilation options.

Not sure I understand what do you mean. But using MKL BLAS is documented in:

• makefile: https://github.com/apache/incubator-mxnet/blob/master/make/config.mk#L120
• cmake: https://github.com/apache/incubator-mxnet/blob/master/cmake/ChooseBlas.cmake#L19
• website: https://mxnet.incubator.apache.org/get_started/build_from_source#math-library-selection

[kpuatamazon]

This still uses MKLDNN for FullyConnected

cmake -GNinja -DUSE_CUDA=OFF -DCMAKE_BUILD_TYPE=Release -DBLAS=MKL -DUSE_MKL_IF_AVAILABLE=ON ..

I was able to get MKL to run by disabling MKLDNN entirely:

cmake -GNinja -DUSE_CUDA=OFF -DCMAKE_BUILD_TYPE=Release -DBLAS=MKL -DUSE_MKL_IF_AVAILABLE=ON -DUSE_MKLDNN=OFF ..

But then I lose other kernels like DNNL softmax and actually Sockeye randomly crashes:

mxnet.base.MXNetError: MXNetError: Out of range value for value, value='inf', in operator _full(name="", dtype="float32", value="inf", ctx="cpu(0)", shape="(5, 1)")

(bizarrely this happens after it translated many sentences with that same code.)

How do I achieve the fastest combination of DNNL softmax and MKL matrix multiply for FullyConnected using only documented options?

[TaoLv]

Yes, USE_MKLDNN is ON by default on Linux. See https://github.com/apache/incubator-mxnet/blob/master/CMakeLists.txt#L44. If want to disable DNNL optimizations, you need set USE_MKLDNN to OFF explicitly in the cmake line.

How do I achieve the fastest combination of DNNL softmax and MKL matrix multiply for FullyConnected using only documented options?

I don't think it's possible at this moment. I think the real question is how to improve the performance of FullyConnected when DNNL is used. In fact, I see the performance of DNNL primitive kernel is good, compared with the output of the script. Take the last shape as an example (on my machine, not ec2):

dnnl_verbose,exec,cpu,inner_product,gemm:jit,forward_inference,src_f32::blocked:ab:f0 wei_f32::blocked:ab:f0 bia_undef::undef::f0 dst_f32::blocked:ab:f0,,,mb4ic512oc512,0.0490723
0.0001380 seconds for fullyconnected (DNNL)
0.0000556 seconds for dot (MKL)

You can set DNNL_VERBOSE=1 when running the script to get the verbose output.

[kpuatamazon]

I don't think it's possible at this moment.

Can we please have a build option to force MKL usage for all GEMM calls? This is a pretty big performance regression.

I think the real question is how to improve the performance of FullyConnected when DNNL is used.

Hmmm, when DNNL delegates to MKL, that happens internally to DNNL, right? If the MXNet wrapper is the problem, then why is delegating to MKL much faster?

Applying my workaround:

cmake -GNinja -DUSE_CUDA=OFF -DCMAKE_BUILD_TYPE=Release -D_DNNL_USE_MKL=FULL -DMKLINC=/opt/intel/mkl/include ..
ninja -j 30
export LD_PRELOAD=/opt/intel/mkl/lib/intel64/libmkl_rt.so
export OMP_NUM_THREADS=4
./mult_bench.py #NB I edited the script to label things more clearly.  

Output:

Shape (5, 512, 512)
0.0000628 seconds for fullyconnected (MKL workaround)
0.0000488 seconds for dot (MKL)
Shape (5, 512, 1536)
0.0000816 seconds for fullyconnected (MKL workaround)
0.0000661 seconds for dot (MKL)
Shape (5, 512, 2048)
0.0001109 seconds for fullyconnected (MKL workaround)
0.0000957 seconds for dot (MKL)
Shape (5, 2048, 512)
0.0001078 seconds for fullyconnected (MKL workaround)
0.0000954 seconds for dot (MKL)
Shape (4, 512, 512)
0.0000501 seconds for fullyconnected (MKL workaround)
0.0000434 seconds for dot (MKL)

There is something less efficient about FullyConnected than dot but it's nowhere near explaining DNNL's slowdown.

FYI I usually wear this hat (as opposed to @kpu) on Mondays so expect slower responses on other days.

[TaoLv]

@emfomenk What's -D_DNNL_USE_MKL=FULL for? I'm not aware of this option and guessing it's not a user facing option.

[emfomenk]

@TaoLv, it is a developer's option to enable Intel MKL gemm back (instead of the jitted one). I would suggest to avoid using it, as it internal one (marked with leading underscore). I think it was even broken somewhere in v1.1 to v1.3...

[TaoLv]

@emfomenk Thanks for the explanation. Do you think that enabling this option can improve the performance of inner product primitive for the above cases?

[pengzhao-intel]

@bartekkuncer please help take a look for this issue as well

[emfomenk]

Do you think that enabling this option can improve the performance of inner product primitive for the above cases?

@TaoLv, yes, this could be. Two reasons for that:

1. If Intel MKL is linked, then most likely libiomp5.so will be used instead of libgomp.so. So, if you see the performance difference, I would suggest to test Intel MKL-DNN v1.0 / DNNL v1.1+ with LD_PRELOAD=libiomp5.so, just to confirm that the issue due to or not due to OpenMP run-time.
2. Performance bug in Intel MKL-DNN v1.0 / DNNL v1.1+. We definitely fixed few performance issues in the library since v1.0.

I would also suggest to try upgrading the library to the most recent version and check the performance.
I strongly suggest not using this developer's option. It is unsupported, not tested, and as I said, it is most likely broken in the subsequent releases.

[kpu]

If Intel MKL is linked

MKL was linked in both cases and in fact called in both cases from dot just not from FullyConnected

libiomp5.so will be used instead of libgomp.so

I tried single-threaded (OMP_NUM_THREADS=1) and still saw a performance drop. There shouldn't be much difference between OMP libraries then right?

I would also suggest to try upgrading the library to the most recent version

See my post above "I also tried the latest DNNL". Performance was unchanged.