October 8, 2016 at 7:35 am
Cross posting from the general forum, because I never got any comments on it...
Hey all,
I've been pulling some data on a server we're tuning and one of the things I was looking for was excessive execution of queries, etc... I found a reporting SP that said it was executed over 57,000 times in a < 24 hour period. My first thought was "Oh man, something is really wrong!"
So I set up a profiler to look for the RPC Complete on this particular SP, and I wasn't getting anything, but yet the execution_count continued to click up on it. So I went in and actually executed the SSRS report that calls that procedure, and I saw the execution_count tick up *AND* I saw the RPC complete show up in my profiler.
So my problem... I no longer can trust the execution_count numbers from this DMV and I really need this data to keep up with this (and other) servers. The number is increasing when the SP is not actually executing, and I've found other instances of this as well on other SP's. I've focused on the reporting ones because those are all interactive or scheduled reports and it is much easier to determine when those were actually run versus the procedures associated to the applications. But if it is happening on these reporting procedures, I have to believe it is happening elsewhere and now all this data is suspect.
I found someone else having the same issue on the link below, but my questions for this group:
1) Can someone explain what is going on and why it might be doing this?
2) Is there a way to fix this or another way I should be getting execution_counts?
As a quick sanity check I focused on just the reporting procedures...
I queried the DMV and saved the execution count
I did a WAITFOR 2 minutes
I re-queried the DMV and saved that execution count
Then I compared that versus the report execution log in ReportServer.
No entries of the report being run, but some of the report counts had increased by 4 to 15 execution counts in that 2 minutes.
Any help would be appreciated!
Update: I have this now on procedures other than reports... a single procedure I was monitoring is executed interactively by the user via an application. The single SP takes a good 60 seconds to complete, and only one user runs it, so at most they will normally execute it maybe 1-2 times per hour, and the most I would ever expect in a day is maybe 10-15 times. The dm_exec_procedure_stats was reporting over 1,000 executions in a single hour for multiple hours in a row.
THen on other stays it seems to be perfectly accurate, and behaves as expected. I cannot understand this and cannot figure out a way to get more accurate data on this.
October 10, 2016 at 6:39 am
It's possible that the query is not being executed as a remote procedure call, but as a SQL Batch. You can call procedures that way. You may be seeing that. Try capturing that event in the trace. I haven't seen the DMVs be wildly inaccurate in the data they represent. They might not be perfect, but it shouldn't be off by thousands of calls. That suggests that something else is going on in the system.
"The credit belongs to the man who is actually in the arena, whose face is marred by dust and sweat and blood"
- Theodore Roosevelt
Author of:
SQL Server Execution Plans
SQL Server Query Performance Tuning
October 10, 2016 at 7:53 am
Hi Grant, that's an interesting thought, but all of these are called by a single application that goes through a common connection layer with standard .Net SQLDataAdapters for all SP executions....So they're all called consistently for good or for ill.
I found one other guy having a similar issue, and he had found that looking in the query stats DM yielded different results than the perf stats. So he ended up doing the following:
select
st.dbid db_id
,st.objectID
,isNull(OBJECT_NAME(st.objectID,st.dbid),'') as objName
,DB_Name(st.dbid) DBName
,max(execution_count) execution_count
fromsys.dm_exec_query_stats qs
cross apply sys.dm_exec_sql_text(sql_handle) as st
where total_logical_reads >0
and isNull(OBJECT_NAME(st.objectID,st.dbid),'') not like 'MSmerge%'
and DB_Name(st.dbid) is not null
group by st.objectID, st.dbid
When I do this the numbers seem to make more sense, but then when I compare the query stats versus the perf stats for something like total worker time, they sometimes match and sometimes don't. I can't make heads or tales of it and it is making me doubt the data and wonder if this is useless.
Grant Fritchey (10/10/2016)
It's possible that the query is not being executed as a remote procedure call, but as a SQL Batch. You can call procedures that way. You may be seeing that. Try capturing that event in the trace. I haven't seen the DMVs be wildly inaccurate in the data they represent. They might not be perfect, but it shouldn't be off by thousands of calls. That suggests that something else is going on in the system.
October 10, 2016 at 8:05 am
Query stats and procedure stats can be very different because a proc can consist of multiple queries, or, you may even have a query in multiple procs. The execution of the proc will be counted once. The query may be run multiple times within the proc or multiple times. These counts really can vary.
However, if you are seeing active calls, you might just be seeing the fact that writes to the DMV are somewhat asynchronous from the data being collected. Microsoft warns about that in the MSDN entry.
If you really are seeing wildly disparate counts with no actual evidence of query execution, you may have found a bug. You might want to report it to Microsoft.
I haven't seen this kind of behavior before.
"The credit belongs to the man who is actually in the arena, whose face is marred by dust and sweat and blood"
- Theodore Roosevelt
Author of:
SQL Server Execution Plans
SQL Server Query Performance Tuning
October 10, 2016 at 8:14 am
Also keep in mind that RPC completed is fired when the application calls a procedure directly procedure. If the application calls a procedure which then calls the one you're investigating, there won't be an RPC complete for it (there will be a module_end event), but the execution count will still go up as the procedure is being run.
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability
Viewing 5 posts - 1 through 4 (of 4 total)
You must be logged in to reply to this topic. Login to reply