Search code examples
mvc-mini-profiler

MVC Mini Profiler "duration" vs "with children"


I really like the tool, but I haven't been able to find any guidelines to help with interpreting the results of the mini profiler. I seem to get one expandable tab per action method, and I can plainly figure out the durations of my manually-created profiler steps, but I cannot intuitively (or with the help of google) figure out the difference between "duration" and "with children." Typing this question I have come up with a guess: Does "duration" mean "excluding children?"


Solution

  • Duration is the executing time of that monitored code minus any reported children. The MVC Mini Profiler uses a hierarchy to track timings of different paths of code. That hierarchy is not created based on functions but on how you log the calls.

    Here is a sample example from a project. There is a page which calls "ListService", which executes "getList", then "FilListWithOptions", and so on.

    http://www.temppage.com:80/something.aspx 
     ListService
       getList                                
       FillListWithOptions  
        QtyBreakPrices  
        FillProductDataWithOptions  
         GetProducts    
     ProductService
    

    These don't have to be individual functions, just nested code that's wrapped in the monitoring code:

    using (profiler.Step("ListService"))
    {
        using (profiler.Step("getList"))
        { // something more interesting here
        }
        using (profiler.Step("FillListWithOptions"))
        { // and here
        }
    }
    using (profiler.Step("ProductService"))
    {      
        // blah
    }
    

    The duration of http://www.temppage.com:80/something.aspx might be 615.2ms, with children is 2222.5ms. Duration of "ListService" is 3ms, with children is 807ms.

    So from those stats we can determine that you are correct; duration is only the code executed, excluding reported children. With children combines duration and childrens time to get a total.

    But "ProductService" doesn't have any reported children and it's duration and with children are the same at 400ms. I know the ProductService does call other functions which call other functions. The profiler doesn't count those as children because it doesn't know about them. It reports the same for both unless you wrap them with the using statements.