does ssms elapsed time display reflect true sproc run time?

  • I created a console app in .NET to call a sproc 25 times concurrently. Max return time was 999ms, min was 20ms and avg was 565ms.

    Then I exec'd the same sproc in SSMS and the elapsed time displayed in the bottom right-hand corner of SSMS was betweem 1s-3s based on multiple concurrent runs.

    Does SSMS round up to 1s for response times 500ms or higher? Does SSMS display elapsed times based on SSMS rendering in addition to the run time of the actual sproc/query? This particular sproc returns 11 result sets so I can see how including results rendering time in the elapsed time could increase the elapsed time number.

    Is there another way to test the response time of the query in SSMS without displaying the result sets in order to ensure that only the backend execution is included in the calculate response time of the sproc?

  • sqlguy-736318 (12/5/2016)


    I created a console app in .NET to call a sproc 25 times concurrently. Max return time was 999ms, min was 20ms and avg was 565ms.

    Then I exec'd the same sproc in SSMS and the elapsed time displayed in the bottom right-hand corner of SSMS was betweem 1s-3s based on multiple concurrent runs.

    Does SSMS round up to 1s for response times 500ms or higher? Does SSMS display elapsed times based on SSMS rendering in addition to the run time of the actual sproc/query? This particular sproc returns 11 result sets so I can see how including results rendering time in the elapsed time could increase the elapsed time number.

    Is there another way to test the response time of the query in SSMS without displaying the result sets in order to ensure that only the backend execution is included in the calculate response time of the sproc?

    The elapsed time in SSMS is not really an accurate method of measuring execution times, it is more an indication (quick/slow). There are few common methods such as statistic time, timing variables, timing tables and extended events, the last being in my experience the most granular and accurate. In fact my testing has shown that the other methods can affect the actual timings.

    😎

    You should also look for the timings for the different phases of the execution, i.e. parsing and compilation, physical I/O, CPU etc., gives much better understanding of what is happening.

  • Thanks SSC. I tried using SET STATISTICS TIME ON per your recommendation. The particular sproc I'm trying to measure returns 11 result sets so SSMS is returning stats for each result set as opposed to the aggregate/complete sproc. Do you know if there's an easier way to get the aggregate/total run time for a sproc?

  • I prefer using Extended Events when working with MARS result sets, little bit more work but cleaner to process especially if you take the result straight into Excel or PowerBI.

    😎

    One thing that's worth mentioning, SSMS is notoriously slow in displaying the result sets and that will affect the timings.

  • Any downside to using the following query to get elapsed time of the last sproc exec,

    where object_id represents the object_id of the sproc under test?:

    select last_elapsed_time, *

    from sys.dm_exec_procedure_stats

    where object_id = 1607832940

  • Total response time will depend on the client and network. For a web application, you may have 2 - 3 seconds of user perceived latency on top of a query that ran for less than 1 second on the server. Also the parameters used impacts total pages read, and also whether the pages were read from buffer cache (logical reads) versus physical reads can impact it significantly.

    "Do not seek to follow in the footsteps of the wise. Instead, seek what they sought." - Matsuo Basho

Viewing 6 posts - 1 through 5 (of 5 total)

You must be logged in to reply to this topic. Login to reply