Issue with Caffe's timing code

[ethereon]

Caffe's time command includes two timers: a per layer timer and an overall timer. However, the overall timer currently also includes the overhead of the per-layer timers. For instance, for forward prop: https://github.com/BVLC/caffe/blob/master/tools/caffe.cpp#L383-L389

This overhead can be significant. For instance, the current version of Caffe reports the following for ResNet-152 on an Nvidia Tegra TX1:

Average Forward pass: 406.875 ms.

After commenting out the nested timers:

Average Forward pass: 193.922 ms.

Similar caveats apply for the backward pass and total iteration timers.

[flx42]

Right, the solution is to do 2 passes. Use a new timer for each individual layer, then use another timer for a full forward pass. I'm doing something like that here: https://github.com/flx42/caffe/commit/89064913221c57aeb0aabef1643afe4c931e12fc (in this patch I also removed the backward pass because I was just benchmarking inference).

[ujsyehao]

@flx42 Hi, I use your method, but I found the problem: caffe_net.Forward() consumes time unmatch sum of each layer consume time Code below: net forward time: 5.1ms ~ 5.2ms the sum of each layer forward time: 4.4 ~ 4.5ms