Different execution times for different runs using ArmNN with Onnxruntime

[adjhawar]

I am trying to run onnx models on mobile device using ArmNN ( neon ) as the execution provider. When I run a model on the device, I have observed a time difference of 1-1.5 seconds between the first run and the subsequent runs. Is this behaviour expected?

What I have observed that the initial inference run does certain computations which are missing in the next runs. Below are the log snippets:

First Run: Time between A and B is around 60-90 ms

05-28 01:24:07.841 V/onnxruntime(24655):  [V:onnxruntime:MNIST, conv.cc:116 Compute] Conv ArmNN:
05-28 01:24:07.841 V/onnxruntime(24655):  [V:onnxruntime:MNIST, conv.cc:117 Compute] X {1,384,8,8}
05-28 01:24:07.841 V/onnxruntime(24655):  [V:onnxruntime:MNIST, conv.cc:118 Compute] W {384,384,3,1}
05-28 01:24:07.841 V/onnxruntime(24655):  [V:onnxruntime:MNIST, conv.cc:119 Compute] B {384}        -------------------------- A
05-28 01:24:07.842 V/onnxruntime(24655):  [V:onnxruntime:MNIST, conv.cc:58 createConvDescriptor] padding: {0,0,1,1}
05-28 01:24:07.842 V/onnxruntime(24655):  [V:onnxruntime:MNIST, conv.cc:59 createConvDescriptor] strides: {1,1}
05-28 01:24:07.842 V/onnxruntime(24655):  [V:onnxruntime:MNIST, conv.cc:202 Compute] ArmNN 2D convolution
05-28 01:24:07.918 V/onnxruntime(24655):  [V:onnxruntime:MNIST, conv.cc:296 Compute]                 -------------------------- B
05-28 01:24:07.918 V/onnxruntime(24655):

Second Run: Time Between A and B is around 5-7 ms

05-28 01:33:55.829 V/onnxruntime(24655):  [V:onnxruntime:MNIST, conv.cc:116 Compute] Conv ArmNN:
05-28 01:33:55.829 V/onnxruntime(24655):  [V:onnxruntime:MNIST, conv.cc:117 Compute] X {1,384,8,8}
05-28 01:33:55.829 V/onnxruntime(24655):  [V:onnxruntime:MNIST, conv.cc:118 Compute] W {384,384,3,1}
05-28 01:33:55.829 V/onnxruntime(24655):  [V:onnxruntime:MNIST, conv.cc:119 Compute] B {384}        -------------------------- A    
05-28 01:33:55.834 V/onnxruntime(24655):  [V:onnxruntime:MNIST, conv.cc:296 Compute]                  -------------------------- B
05-28 01:33:55.834 V/onnxruntime(24655):

In the second run, the log with ArmNN 2D convolution is not there. I even tried looking for the conv.cc that is being referred in the logs but could not find it anywhere. I am stuck here, trying to find out the cause of the difference in inference time. Any leads on this will be highly appreciated.

[morgolock]

Hi @adjhawar

You could use the -e option in ExecuteNetwork to generate profiling information, ideally redirecting it to a file with >. Then comparing the two files should reveal the answer.

Hope this helps.

[MikeJKelly]

Closing as I think this has been resolved. If you need more help please open another issue.