0

I have been working on a project which aims to automate performance testing of a few stored procedures on our servers using SSIS package. Previously it was done manually using SQL Server Profiler. We used to store the trace table and then compare the latest data (Duration, CPU, Reads) with the old data. As part of the automation, we are using extended events to store the events data to a file and then reading the data to a database table.

The problem I am facing is whenever I run the stored procedures manually the data I am getting is not consistent with data I am getting when running those stored procedures with the automation tool. I am pretty sure we have implemented the extended events correctly in the tool.

Below are the results I am getting (cache cleaned before testing manually as well as using tool)

Link to snapshot of the data

There is 40-50% CPU variation and >100% duration variation for a few stored procedures.

Can somebody please suggest the probable causes for the same? I could find no other way except using XEvents to automate the task.

EDIT1: Snapshot of the Data

  • Is there any difference in session settings between when you run things and when the tool runs things? There's a bunch of things that can influence query plans, and hence running time. See [Slow in the Application, Fast in SSMS?](http://www.sommarskog.se/query-plan-mysteries.html) for more background info. – Jeroen Mostert Aug 31 '18 at 08:50
  • How to verify if the session settings are the same? I am using basic start session query for Extended Events. CREATE EVENT SESSION [query_performance] ON SERVER ADD Event sqlserver.rpc_completed ADD TARGET package0.event_file(SET filename=N'T:\Temp\Unprocessed\TempTracesquery_performance.xel',max_file_size=(5),max_rollover_files=(500)) WITH (MAX_MEMORY=4096 KB,EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,MAX_DISPATCH_LATENCY=30 SECONDS,MAX_EVENT_SIZE=0 KB,MEMORY_PARTITION_MODE=NONE,TRACK_CAUSALITY=OFF,STARTUP_STATE=OFF) And the default settings for profiler. – Nikhil Nilawar Aug 31 '18 at 08:55
  • I have no idea how to do it in extended events, but while the session exists the values of the `SET` options can be found in `sys.dm_exec_sessions`. This isn't the only thing that can influence getting a different plan, though. You may wish to capture and compare execution plans for the procedures, in addition to durations; that, at least, is easy to do with extended events (`query_post_execution_showplan`). This event has some [performance impact](https://sqlperformance.com/2013/03/sql-plan/showplan-impact), so just use it to investigate the discrepancy. – Jeroen Mostert Aug 31 '18 at 09:02
  • Also, as an aside, I wouldn't use extended events as the main thing to investigate running times, for the simple reason that this does not represent the actual time as observed by the clients. Simply measuring wall clock time of an execution on the client end is both easier and more realistic. That also reminds me of another possible cause of trouble, though: do these procedures return data, and is that data processed? The speed of processing (network code, actual physical latency) has an impact on how long a query takes, although you'd need some really slow clients to see a big difference. – Jeroen Mostert Aug 31 '18 at 09:08
  • Do you mean if a query has exact same plan for both Profiler and extended events, data(CPU, Duration) will be consistent? – Nikhil Nilawar Aug 31 '18 at 09:11
  • No, because that also depends on the server load and the client speed. The point is that if the plans are *not* exactly the same (both in operators, and in rows processed in each operator, and in degree of parallelism) then you know the data will obviously also differ, which means you have a cause. If the plans *are* the same, but the performance still differs, then you've got something interesting. – Jeroen Mostert Aug 31 '18 at 09:12
  • @NikhilNilawar, did you capture logical reads as well? How do those values compare? – Dan Guzman Aug 31 '18 at 10:19
  • SQL Profiler trace has a column named Reads (Not logical/Physical). I am assuming that is logical reads. Extended events specifically captures logical reads. It seems there is a discrepancy there as well, though the database over which those stored procedures are run is the same. Please refer to Edit section in the post. – Nikhil Nilawar Aug 31 '18 at 10:46

0 Answers0