Onednn: MKL-DNN implements AlexNet slower than Intel Caffe Version

[adhere]

I implement the full AlexNet base on MKL-DNN examples/simple_net.cpp. Here is the code simple_net.cpp.

But it is slower comparing with runing on Intel Caffe. What is wrong?

Here is result:
Runing on Intel Caffe:

I0824 18:31:33.018908 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.046000 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.073365 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.114791 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.141913 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.168437 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.195310 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.222698 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.249254 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.275800 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.301800 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.327868 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.354158 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.379930 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.404937 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.429662 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.455044 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.480551 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.505774 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.534307 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.560242 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.584653 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.610103 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.635448 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.660980 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.687191 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.713146 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.738888 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.765086 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.790982 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.817167 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.843731 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.870255 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.896456 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.922837 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.948654 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796
I0824 18:31:33.975791 8489 benchmark.cpp:29] feature size 1000 0.3996730.9272431.22796

It is about 27 ms per time (set USE_MKLDNN_AS_DEFAULT_ENGINE ON or OFF have the same about result)

In MKL-DNN :

Times 12 use time 115
Times 13 use time 126
Times 14 use time 107
Times 15 use time 115
Times 16 use time 97
Times 17 use time 97
Times 18 use time 102
Times 19 use time 107
Times 20 use time 106
Times 21 use time 111
Times 22 use time 99
Times 23 use time 110
Times 24 use time 102
Times 25 use time 98
Times 26 use time 99
Times 27 use time 147
Times 28 use time 140
Times 29 use time 143
Times 30 use time 115
Times 31 use time 107
Times 32 use time 108
Times 33 use time 105
Times 34 use time 94
Times 35 use time 106
Times 36 use time 99
Times 37 use time 103
Times 38 use time 115
Times 39 use time 110

It is more than 100 ms per time.

The test machine:
CPU: Intel(R) Xeon(R) CPU E3-1231 v3 @ 3.40GHz
OS: Ubuntu 14.04

The Intel Caffe Version:
The lastest

The MKL-DNN version:
The lastest

The compiler version:
Ubuntu 4.8.5-2ubuntu1~14.04.1

Any suggestions ? Thanks !

[vpirogov]

You can actually measure Intel MKL-DNN performance on AlexNet using IntelCaffe. Use engine=MKLDNN to invoke Intel MKL-DNN backend and -forward_only -phase=TEST options to invoke inference path:

./build/tools/caffe time -model=alexnet.prototxt -forward_only -phase=TEST -engine=MKLDNN

Comparing IntelCaffe vs your code with the latest Intel MKL-DNN on Intel AVX2 system I see performance difference of about 2x. There're a couple of differences I see in the topology:

1. AlexNet has 2 groups in conv2, conv4 and conv5, while your implementation uses single group for these. This increases the number of operations 2x in your code.
2. Destination memory for pooling that goes to convolution input uses nchw format. This leads to suboptimal convolution performance. Destination memory format for auxillary primitives like pooling should be set to source format for the next convolution to get the best performance.

Vadim

[adhere]

Here is the IntelCaffe cmake config output:

-- Dependencies:
-- BLAS : Yes (MKL)
-- MKL2017_SUPPORTED : ON
-- MKLDNN_SUPPORTED : ON, is a default engine
-- Boost : Yes (ver. 1.54)
-- glog : Yes
-- gflags : Yes
-- protobuf : Yes (ver. 2.5.0)
-- lmdb : Yes (ver. 0.9.10)
-- LevelDB : Yes (ver. 1.15)
-- Snappy : Yes (ver. 1.1.0)
-- OpenCV : Yes (ver. 3.2.0)
-- CUDA : No

And

./build/tools/caffe time -model=alexnet.prototxt -forward_only -phase=TEST -engine=MKLDNN

I0825 09:38:29.449357 15069 caffe.cpp:583] Iteration: 44 forward time: 27 ms.
I0825 09:38:29.477376 15069 caffe.cpp:583] Iteration: 45 forward time: 27 ms.
I0825 09:38:29.505455 15069 caffe.cpp:583] Iteration: 46 forward time: 28 ms.
I0825 09:38:29.533669 15069 caffe.cpp:583] Iteration: 47 forward time: 28 ms.
I0825 09:38:29.563020 15069 caffe.cpp:583] Iteration: 48 forward time: 29 ms.
I0825 09:38:29.592273 15069 caffe.cpp:583] Iteration: 49 forward time: 29 ms.
I0825 09:38:29.621350 15069 caffe.cpp:583] Iteration: 50 forward time: 29 ms.
I0825 09:38:29.621390 15069 caffe.cpp:587] Average time per layer:
I0825 09:38:29.621398 15069 caffe.cpp:590] data forward: 0.00146 ms.
I0825 09:38:29.621409 15069 caffe.cpp:590] conv1 forward: 0.99256 ms.
I0825 09:38:29.621417 15069 caffe.cpp:590] norm1 forward: 0.35236 ms.
I0825 09:38:29.621425 15069 caffe.cpp:590] pool1 forward: 0.10128 ms.
I0825 09:38:29.621433 15069 caffe.cpp:590] conv2 forward: 1.86946 ms.
I0825 09:38:29.621440 15069 caffe.cpp:590] norm2 forward: 0.23236 ms.
I0825 09:38:29.621448 15069 caffe.cpp:590] pool2 forward: 0.06906 ms.
I0825 09:38:29.621456 15069 caffe.cpp:590] conv3 forward: 1.86882 ms.
I0825 09:38:29.621464 15069 caffe.cpp:590] conv4 forward: 1.29004 ms.
I0825 09:38:29.621471 15069 caffe.cpp:590] conv5 forward: 0.88138 ms.
I0825 09:38:29.621479 15069 caffe.cpp:590] pool5 forward: 0.03134 ms.
I0825 09:38:29.621486 15069 caffe.cpp:590] fc6 forward: 12.8522 ms.
I0825 09:38:29.621495 15069 caffe.cpp:590] relu6 forward: 0.02472 ms.
I0825 09:38:29.621502 15069 caffe.cpp:590] drop6 forward: 0.0043 ms.
I0825 09:38:29.621511 15069 caffe.cpp:590] fc7 forward: 6.64152 ms.
I0825 09:38:29.621523 15069 caffe.cpp:590] relu7 forward: 0.02456 ms.
I0825 09:38:29.621536 15069 caffe.cpp:590] drop7 forward: 0.00396 ms.
I0825 09:38:29.621546 15069 caffe.cpp:590] fc8 forward: 1.4443 ms.
I0825 09:38:29.621559 15069 caffe.cpp:590] prob forward: 0.01804 ms.
I0825 09:38:29.621572 15069 caffe.cpp:600] Average Forward pass: 28.7619 ms.
I0825 09:38:29.621583 15069 caffe.cpp:608] Total Time: 1441 ms.

I make a mistake while dealing conv2(conv4 conv5 have done before), fix it now(Maybe It is still wrong -_).
Change

memory::dims conv2_weights_tz = {256, 96, 5, 5};
to

> memory::dims conv2_weights_tz = {2, 128, 48, 5, 5};

Destination memory for pooling that goes to convolution input uses nchw format. This leads to suboptimal convolution performance. Destination memory format for auxillary primitives like pooling should be set to source format for the next convolution to get the best performance.

I don't understand which format should be use or how to set the format(just take pool1_dst_memory for example. I read the mkldnn_types.h and test_pooling_forward.cpp and try to find it out from IntelCaffe, but failed-_, please help-_)

In IntelCaffe mkldnn_pooling_layer.cpp there is

    memory::format mfmt_nchw = memory::format::nchw;

    // ---- Initialize memory descriptors -------------
    typedef typename memory::primitive_desc MemPD; // short name for memory::primitive_desc
    memory::format cmfmt = mfmt_nchw;

    shared_ptr<MemPD> usr_bottom_data_mpd(new MemPD({{bottom_tz}, mpcsn, mfmt_nchw}, cpu_engine));
    shared_ptr<MemPD> usr_top_data_mpd(new MemPD({{top_tz}, mpcsn, mfmt_nchw}, cpu_engine));

So I think the pooling output still nchw.

After changing conv2, the test result:

Times 23 use time 103
Times 24 use time 109
Times 25 use time 123
Times 26 use time 116
Times 27 use time 112
Times 28 use time 99
Times 29 use time 102
Times 30 use time 99
Times 31 use time 118
Times 32 use time 120
Times 33 use time 110
Times 34 use time 128
Times 35 use time 110
Times 36 use time 117
Times 37 use time 104
Times 38 use time 109
Times 39 use time 123
Times 40 use time 109
Times 41 use time 118
Times 42 use time 145
Times 43 use time 147
Times 44 use time 156
Times 45 use time 121
Times 46 use time 120
Times 47 use time 128
Times 48 use time 123

Thanks for your help!

[adhere]

If change the pool1 destination memory format from

auto pool1_dst_memory = memory({{{pool1_dst_tz}, memory::data_type::f32,
memory::format::nchw}, cpu_engine}, pool1_dst.data());

to

auto pool1_dst_memory = memory({{{pool1_dst_tz}, memory::data_type::f32,
static_cast\

It becomes more slower.

[vpirogov]

Hi @adhere,

The reason code becomes slower when you change pooling output format is that dst layout for conv5 is not optimal for fc6. Because of that fc6 runs reference implementation which is slow. If you add a conversion before fc6 performance will become better.

I made a few changes to your code to be more in line with how IntelCaffe uses Intel MKL-DNN. Now I see 12-14 ms for this code which is in line with IntelCaffe performance.

[adhere]

Thank you @vpirogov !!!