January 9, 2012 at 3:23 am
I'd like to know how often a stored procedure is called, also useful would be the time, which user made the call, and how long it took.
Before I go and write some extra code to record this data from inside the stored procedure it occurred to me that the information is probably already available somewhere.
Does SQL Server already do this - perhaps in one of the sys.dm_ views or is it possible to search the transaction log for this data?
January 9, 2012 at 5:46 am
You can find a few information in DMVs (sys.dm_exec_query_stats) but there will not be that many details.
You will only know how many times it has been called since last server restart.
You can use profiler to gather following information :
- who called the SP (hostname, loginname or ntusername depending on the authentication type)
- when it was called
- ...
January 9, 2012 at 6:39 am
I use server-side traces to do that kind of thing. Won't necessarily tell you who called a proc, if it's being called by a web-based application for example, but will tell you how often, how long, et al. Capture the text data on it and you can even get parameter values so you can check for things like injection attempts, or common options (for optimization purposes).
Very useful technique.
Check out sp_trace_create, and fn_trace_getinfo, and fn_trace_gettable. Takes a little bit of study and usually a tiny bit of trial and error, but once you get how to use them and are comfortable with them, server-side traces are a wonderful tool.
- Gus "GSquared", RSVP, OODA, MAP, NMVP, FAQ, SAT, SQL, DNA, RNA, UOI, IOU, AM, PM, AD, BC, BCE, USA, UN, CF, ROFL, LOL, ETC
Property of The Thread
"Nobody knows the age of the human race, but everyone agrees it's old enough to know better." - Anon
January 9, 2012 at 6:45 am
Thanks, The profiler creates exactly what I want.
But on production I don't have access to profiler, only SSMS. Can I script the profiler actions to create a table for the output?
Are profiler jobs resource-intensive? since I'm only logging one rarely-used stored procedure I hope it won't be.
January 9, 2012 at 6:47 am
GSquared (1/9/2012)
Check out sp_trace_create, and fn_trace_getinfo, and fn_trace_gettable. Takes a little bit of study and usually a tiny bit of trial and error, but once you get how to use them and are comfortable with them, server-side traces are a wonderful tool.
You must be psychic, I was just asking for this 😀
January 9, 2012 at 9:27 am
Is there a trick to setting up traces?
I have a trace - all set up and working, and collecting data - with the filter set on textdata like '%MyProcName%'
exec sp_trace_setfilter @TraceID, 1, 1, 6, N'%MyProcName%'
It detects calls from SSMS but not from the application.
The call from the application is happening because the call count increases when looking at
SELECT TOP 100 T.*, P.*
FROM sys.dm_exec_cached_plans AS P
CROSS APPLY sys.dm_exec_sql_text(P.plan_handle) T
WHERE text like '%MyProcName%'
January 9, 2012 at 11:07 am
Profiler is quite resource-hungry, but server-side traces barely impact the server at all.
I haven't tried filtering by a specific proc name. I sometimes filter by a particular database.
Can you post the script you used to create the trace? That would make helping you a bit easier.
- Gus "GSquared", RSVP, OODA, MAP, NMVP, FAQ, SAT, SQL, DNA, RNA, UOI, IOU, AM, PM, AD, BC, BCE, USA, UN, CF, ROFL, LOL, ETC
Property of The Thread
"Nobody knows the age of the human race, but everyone agrees it's old enough to know better." - Anon
January 10, 2012 at 4:22 am
azdzn (1/9/2012)
You can find a few information in DMVs (sys.dm_exec_query_stats) but there will not be that many details.You will only know how many times it has been called since last server restart.
You can use profiler to gather following information :
- who called the SP (hostname, loginname or ntusername depending on the authentication type)
- when it was called
- ...
sys.dm_exec_query_stats doesn't keep information since the last server restart. It keeps information on each query from the time that query enters cache until it leaves cache. When that query leaves the cache, all that data goes away. If that query goes into cache again, it starts over.
Also, Profiler is not the tool I'd recommend. Instead I'd use a server side trace, which is a scripted mechanism for gathering the data. Profiler has additional overhead when hitting the system that should be avoided.
"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
January 10, 2012 at 4:31 am
Thanks G^2
But I've managed to work it out with BOL on sp_trace_setevent
I needed to track events SP:Starting and SP:Completed for calls by the application, and SQL:BatchStarting and SQL:BatchCompleted for calls from SSMS.
January 10, 2012 at 7:11 am
Yep. Glad you worked it out. Happy to be able to help.
- Gus "GSquared", RSVP, OODA, MAP, NMVP, FAQ, SAT, SQL, DNA, RNA, UOI, IOU, AM, PM, AD, BC, BCE, USA, UN, CF, ROFL, LOL, ETC
Property of The Thread
"Nobody knows the age of the human race, but everyone agrees it's old enough to know better." - Anon
January 11, 2012 at 12:51 pm
In case this helps anyone, here is how I do in-SPROC logging. In addition to the normal stuff, I also log the input parameter values that are sent to the SPROC.
/* ========================================================================================== */
/* Example: How to log SPROC execution */
/* ========================================================================================== */
CREATE TABLE DBActivityLog
(DBActivityID int IDENTITY NOT NULL
CONSTRAINT PK_DBActivityLog_On_DBActivityID PRIMARY KEY CLUSTERED,
DBASPROCvarchar(300)NULL,
DBAMessagevarchar(1000)NULL,
DBAAppNamevarchar(150)NULLDEFAULT APP_NAME(),
DBAHostvarchar(50)NULLDEFAULT HOST_NAME(),
DBAUservarchar(50)NULLDEFAULT USER,
DBADatedatetimeNULLDEFAULT GETDATE()
)
ON MyDatabase_data
GO
/* ========================================================================================== */
CREATE TABLE AppErrorLog
(EID int IDENTITY NOT NULL
CONSTRAINT PK_AppErrorLog_On_EID PRIMARY KEY CLUSTERED,
EDatedatetimeNOT NULL,
EUservarchar(50)NULL,
EMessagevarchar(1000)NULL,
ESource varchar(150)NOT NULL,
ENointNOT NULLDEFAULT 0,
ESeverityintNOT NULLDEFAULT 0,
ELineNo intNOT NULLDEFAULT 0,
EHost varchar(50)NULL
)
ON MyDatabase_data
GO
/* ========================================================================================== */
/* ========================================================================================== */
-- Example Stored Procedure using both tables created above
CREATE PROCEDURE dbo.xp_usp_Read_Account_Rec
@acctidint,
@spstatintOUTPUT,
@errmsgvarchar(200)OUTPUT,
@recnintOUTPUT
AS
DECLARE @numrecs int
DECLARE @pvalue varchar(1000) --log db activity
SET NOCOUNT ON
SET @spstat = 1 -- go ahead and set to ok
SET @errmsg = '' -- go ahead and set to ok
SET @recn = 0 -- go ahead and set to ok
BEGIN TRY
--log db activity
SET @pvalue = CONVERT(varchar(100),@acctid)
INSERT INTO DBActivityLog
VALUES ('dbo.xp_usp_Read_Account_Rec',CONVERT(varchar(1000),'SPROC call - Params= ' + @pvalue),APP_NAME(),HOST_NAME(),USER,GETDATE())
--Select the desired information
SELECT AcctID,CandidateID,CandidateStatusID,AcctOpen,AcctStatusID,AcctComment,CurrRec,LCHost,LCUser,LCDate
FROM Account
WHERE AcctID=@acctid
SET @numrecs = @@rowcount
if @numrecs=0
BEGIN
SET @spstat = -1
SET @errmsg = 'No record selected'
SET @recn = 0
END
RETURN @spstat
END TRY
BEGIN CATCH
DECLARE@ErrorNoint,
@Severityint,
@Stateint,
@LineNoint,
@errmessagevarchar(1000)
SELECT@ErrorNo = ERROR_NUMBER(),
@Severity = ERROR_SEVERITY(),
@State = ERROR_STATE(),
@LineNo = ERROR_LINE(),
@errmessage = ERROR_MESSAGE()
SET @errmsg = CONVERT(varchar(200), @errmessage)
SET @spstat = 0
INSERT INTO AppErrorLog
VALUES (GETDATE(), USER, @errmessage, 'dbo.xp_usp_Read_Account_Rec', @ErrorNo, @Severity, @LineNo, HOST_NAME())
END CATCH
GO
Viewing 11 posts - 1 through 10 (of 10 total)
You must be logged in to reply to this topic. Login to reply