How to correctly interpret MiniProfiler timings logged by SqlServerStorage?

Question

I have a simple request that is being profiled, listed below.

public MyResponse GetOrders(OrdersRequest request)
{
    var profiler = MiniProfiler.Current;
    using (profiler.Step("GetOrders Service Requests"))
    {
        using (profiler.Step("_externalRepository.GetOrders"))
        {

        }
    }
    return result;
}

That yields the following rows in the database when executed.

So my question is how does the DurantionMilliseconds for the root object correlate to the timings of it's children? I see 73.400 and assume this is the total across this operation, is that correct?

Versions:

<package id="MiniProfiler" version="3.0.10-beta7" targetFramework="net45" />
<package id="MiniProfiler.EF5" version="3.0.10-beta1" targetFramework="net45" />

Answer 1

Yes, a Timing step's duration includes its children Timings' durations.

It's easier to visualize as a tree*:

> http://localhost:8203/ExternalService.svc   73.4 ms
>> GetOrders Service Requests                 56.1 ms
>>> _externalRepository.GetOrders             55.9 ms

So the root timing (i.e. the entire request) took 73.4 ms; GetOrders Service Requests was 56.1 ms of that entire 73.4 ms; and _externalRepository.GetOrders was 55.9 ms of its parent's 56.1 ms.

_{* the MiniProfiler extension method RenderPlainText() can output this format.}